2015-01-22T21:21:16.936Z,1421961676.936 [Supervisor](DEBUG): Initializing supervisor.
2015-01-22T21:21:16.939Z,1421961676.939 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-22T21:21:16.940Z,1421961676.940 [SyncHandler](INFO): Protected caller Thread ID is 1931
2015-01-22T21:21:16.940Z,1421961676.940 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-22T21:21:16.941Z,1421961676.941 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-22T21:21:16.942Z,1421961676.942 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1932
2015-01-22T21:21:16.945Z,1421961676.945 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-22T21:21:16.958Z,1421961676.958 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-22T21:21:16.959Z,1421961676.959 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-22T21:21:16.959Z,1421961676.959 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1933
2015-01-22T21:21:16.960Z,1421961676.960 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-22T21:21:16.961Z,1421961676.961 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-22T21:21:16.961Z,1421961676.961 [logger ThreadHandler](INFO): Protected caller Thread ID is 1934
2015-01-22T21:21:16.964Z,1421961676.964 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-22T21:21:16.964Z,1421961676.964 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-22T21:21:16.965Z,1421961676.965 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-22T21:21:17.286Z,1421961677.286 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-22T21:21:17.287Z,1421961677.287 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-22T21:21:17.442Z,1421961677.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-22T21:21:17.442Z,1421961677.442 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-22T21:21:17.549Z,1421961677.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-22T21:21:17.550Z,1421961677.550 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-22T21:21:17.670Z,1421961677.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-22T21:21:17.670Z,1421961677.670 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-22T21:21:17.755Z,1421961677.755 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-22T21:21:17.912Z,1421961677.912 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-22T21:21:17.913Z,1421961677.913 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-22T21:21:17.998Z,1421961677.998 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-22T21:21:17.999Z,1421961677.999 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-22T21:21:18.203Z,1421961678.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-22T21:21:18.203Z,1421961678.203 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-22T21:21:18.568Z,1421961678.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-22T21:21:18.569Z,1421961678.569 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-22T21:21:18.882Z,1421961678.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-22T21:21:18.883Z,1421961678.883 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-22T21:21:19.381Z,1421961679.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-22T21:21:19.381Z,1421961679.381 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-22T21:21:19.577Z,1421961679.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-22T21:21:19.578Z,1421961679.578 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-22T21:21:19.681Z,1421961679.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-22T21:21:19.681Z,1421961679.681 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-22T21:21:20.112Z,1421961680.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-22T21:21:20.112Z,1421961680.112 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-22T21:21:20.225Z,1421961680.225 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-22T21:21:20.227Z,1421961680.227 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-22T21:21:20.228Z,1421961680.228 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-22T21:21:20.491Z,1421961680.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-22T21:21:20.492Z,1421961680.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-22T21:21:20.671Z,1421961680.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-22T21:21:20.769Z,1421961680.769 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-22T21:21:20.864Z,1421961680.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-22T21:21:20.991Z,1421961680.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-22T21:21:21.129Z,1421961681.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-22T21:21:21.296Z,1421961681.296 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-22T21:21:21.396Z,1421961681.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-22T21:21:21.486Z,1421961681.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-22T21:21:21.585Z,1421961681.585 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-22T21:21:21.680Z,1421961681.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-22T21:21:21.871Z,1421961681.871 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-22T21:21:21.885Z,1421961681.885 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-22T21:21:21.949Z,1421961681.949 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-22T21:21:22.067Z,1421961682.067 [VerticalControl] Loaded
2015-01-22T21:21:22.067Z,1421961682.067 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-22T21:21:22.068Z,1421961682.068 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-22T21:21:22.140Z,1421961682.140 [HorizontalControl] Loaded
2015-01-22T21:21:22.140Z,1421961682.140 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-22T21:21:22.140Z,1421961682.140 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-22T21:21:22.146Z,1421961682.146 [SpeedControl] Loaded
2015-01-22T21:21:22.146Z,1421961682.146 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-22T21:21:22.147Z,1421961682.147 [LoopControl](DEBUG): Construct LoopControl.
2015-01-22T21:21:22.148Z,1421961682.148 [LoopControl] Loaded
2015-01-22T21:21:22.148Z,1421961682.148 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-22T21:21:22.148Z,1421961682.148 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-22T21:21:22.149Z,1421961682.149 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-22T21:21:22.244Z,1421961682.244 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-22T21:21:22.255Z,1421961682.255 [SBIT] Loaded
2015-01-22T21:21:22.255Z,1421961682.255 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-22T21:21:22.256Z,1421961682.256 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-22T21:21:22.284Z,1421961682.284 [IBIT] Loaded
2015-01-22T21:21:22.285Z,1421961682.285 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-22T21:21:22.287Z,1421961682.287 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-22T21:21:22.406Z,1421961682.406 [CBIT] Loaded
2015-01-22T21:21:22.407Z,1421961682.407 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-22T21:21:22.407Z,1421961682.407 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-22T21:21:22.408Z,1421961682.408 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-22T21:21:22.426Z,1421961682.426 [DepthRateCalculator] Loaded
2015-01-22T21:21:22.426Z,1421961682.426 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-22T21:21:22.432Z,1421961682.432 [PitchRateCalculator] Loaded
2015-01-22T21:21:22.432Z,1421961682.432 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-22T21:21:22.443Z,1421961682.443 [SpeedCalculator] Loaded
2015-01-22T21:21:22.444Z,1421961682.444 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-22T21:21:22.460Z,1421961682.460 [TempGradientCalculator] Loaded
2015-01-22T21:21:22.461Z,1421961682.461 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-22T21:21:22.466Z,1421961682.466 [YawRateCalculator] Loaded
2015-01-22T21:21:22.466Z,1421961682.466 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-22T21:21:22.467Z,1421961682.467 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-22T21:21:22.467Z,1421961682.467 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-22T21:21:22.517Z,1421961682.517 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-22T21:21:22.517Z,1421961682.517 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-22T21:21:22.744Z,1421961682.744 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-22T21:21:22.745Z,1421961682.745 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-22T21:21:22.802Z,1421961682.802 [NavChart] Loaded
2015-01-22T21:21:22.802Z,1421961682.802 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-22T21:21:22.809Z,1421961682.809 [UniversalFixResidualReporter] Loaded
2015-01-22T21:21:22.809Z,1421961682.809 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-22T21:21:22.809Z,1421961682.809 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-22T21:21:22.810Z,1421961682.810 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-22T21:21:22.816Z,1421961682.816 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-22T21:21:22.816Z,1421961682.816 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-22T21:21:22.902Z,1421961682.902 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-22T21:21:22.903Z,1421961682.903 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-22T21:21:23.220Z,1421961683.220 [DataOverHttps] Loaded
2015-01-22T21:21:23.221Z,1421961683.221 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-22T21:21:23.304Z,1421961683.304 [Depth_Keller] Loaded
2015-01-22T21:21:23.305Z,1421961683.305 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-22T21:21:23.399Z,1421961683.399 [NAL9602] Loaded
2015-01-22T21:21:23.399Z,1421961683.399 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-22T21:21:23.440Z,1421961683.440 [Onboard] Loaded
2015-01-22T21:21:23.441Z,1421961683.441 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-22T21:21:23.448Z,1421961683.448 [Radio_Surface] Loaded
2015-01-22T21:21:23.448Z,1421961683.448 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-22T21:21:23.449Z,1421961683.449 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-22T21:21:23.449Z,1421961683.449 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2017
2015-01-22T21:21:25.292Z,1421961685.292 [BPC1] Loaded
2015-01-22T21:21:25.293Z,1421961685.293 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-22T21:21:25.293Z,1421961685.293 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-22T21:21:25.294Z,1421961685.294 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-22T21:21:25.391Z,1421961685.391 [BuoyancyServo] Loaded
2015-01-22T21:21:25.391Z,1421961685.391 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-22T21:21:25.403Z,1421961685.403 [ElevatorServo] Loaded
2015-01-22T21:21:25.408Z,1421961685.408 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-22T21:21:25.422Z,1421961685.422 [RudderServo] Loaded
2015-01-22T21:21:25.422Z,1421961685.422 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-22T21:21:25.434Z,1421961685.434 [ThrusterServo] Loaded
2015-01-22T21:21:25.434Z,1421961685.434 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-22T21:21:25.434Z,1421961685.434 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-22T21:21:25.435Z,1421961685.435 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-22T21:21:25.535Z,1421961685.535 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-22T21:21:25.535Z,1421961685.535 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-22T21:21:25.560Z,1421961685.560 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-22T21:21:25.562Z,1421961685.562 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-22T21:21:25.563Z,1421961685.563 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-22T21:21:25.570Z,1421961685.570 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-22T21:21:25.571Z,1421961685.571 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-22T21:21:25.571Z,1421961685.571 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2018
2015-01-22T21:21:25.576Z,1421961685.576 [Supervisor](INFO): Main Thread ID is 1930
2015-01-22T21:21:25.576Z,1421961685.576 [Supervisor](DEBUG): Running supervisor.
2015-01-22T21:21:25.577Z,1421961685.577 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2019
2015-01-22T21:21:25.582Z,1421961685.582 [controlThread ThreadHandler](INFO): Handler Thread ID is 2020
2015-01-22T21:21:25.582Z,1421961685.582 [controlThread](DEBUG): Initializing ControlThread
2015-01-22T21:21:25.583Z,1421961685.583 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-22T21:21:25.585Z,1421961685.585 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-22T21:21:25.585Z,1421961685.585 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-22T21:21:25.586Z,1421961685.586 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-22T21:21:25.586Z,1421961685.586 [SBIT](INFO): Initialize SBIT Component.
2015-01-22T21:21:25.586Z,1421961685.586 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-22T21:21:25.587Z,1421961685.587 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-22T21:21:25.587Z,1421961685.587 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-22T21:21:25.588Z,1421961685.588 [IBIT](INFO): Initialize IBIT Component.
2015-01-22T21:21:25.589Z,1421961685.589 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-22T21:21:25.589Z,1421961685.589 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-22T21:21:25.590Z,1421961685.590 [logger ThreadHandler](INFO): Handler Thread ID is 2021
2015-01-22T21:21:25.609Z,1421961685.609 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2022
2015-01-22T21:21:25.613Z,1421961685.613 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T21:21:25.614Z,1421961685.614 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-22T21:21:25.614Z,1421961685.614 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-22T21:21:25.614Z,1421961685.614 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-22T21:21:25.615Z,1421961685.615 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-22T21:21:25.615Z,1421961685.615 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-22T21:21:25.616Z,1421961685.616 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-22T21:21:25.623Z,1421961685.623 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-22T21:21:25.634Z,1421961685.634 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T21:21:25.637Z,1421961685.637 [Radio_Surface](INFO): Powering up
2015-01-22T21:21:25.641Z,1421961685.641 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2023
2015-01-22T21:21:25.645Z,1421961685.645 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-22T21:21:25.646Z,1421961685.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-22T21:21:25.646Z,1421961685.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-22T21:21:25.646Z,1421961685.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-22T21:21:25.646Z,1421961685.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-22T21:21:25.647Z,1421961685.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-22T21:21:25.647Z,1421961685.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-22T21:21:25.647Z,1421961685.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-22T21:21:25.648Z,1421961685.648 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-22T21:21:25.678Z,1421961685.678 [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>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2015-01-22T21:21:25.679Z,1421961685.679 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-22T21:21:25.764Z,1421961685.764 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-22T21:21:25.768Z,1421961685.768 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-22T21:21:25.792Z,1421961685.792 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T21:21:25.817Z,1421961685.817 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-22T21:21:25.839Z,1421961685.839 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-22T21:21:25.872Z,1421961685.872 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-22T21:21:25.902Z,1421961685.902 [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="TimeMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <DefineArg Name="ElapsedSinceMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <Aggregate Id="StartClock">

        <Sequence/>

        <Assign><Arg Name="TimeMissionWasStarted"/><Universal:time/></Assign>

    </Aggregate>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

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

<!-- TODO: Do we really want this When operating on platform_communications? or on something else like time_fix? -->

<!-- Run application at high speed -->

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

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:latitude_fix/>
        </ReadDatum>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <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="UpdateAndReportMinutesSinceMissionStarted">

        <When>
            <Elapsed><Arg Name="ElapsedSinceMissionWasStarted"/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
        </When>

        <Assign><Arg Name="ElapsedSinceMissionWasStarted"/><Universal:time/><Sub><Arg Name="TimeMissionWasStarted"/></Sub></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceMissionWasStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

    </Aggregate>

</Mission>


2015-01-22T21:21:25.906Z,1421961685.906 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-01-22T21:21:26.040Z,1421961686.040 [NAL9602](INFO): Start
2015-01-22T21:21:26.592Z,1421961686.592 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-22T21:21:26.598Z,1421961686.598 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-22T21:21:26.613Z,1421961686.613 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-22T21:21:26.618Z,1421961686.618 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-22T21:21:26.624Z,1421961686.624 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-22T21:21:26.630Z,1421961686.630 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-22T21:21:26.655Z,1421961686.655 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-22T21:21:26.662Z,1421961686.662 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-22T21:21:26.836Z,1421961686.836 [NAL9602](INFO): Start
2015-01-22T21:21:36.199Z,1421961696.199 [NAL9602](INFO): Start
2015-01-22T21:21:36.200Z,1421961696.200 [NAL9602](INFO): Powering up NAL9602
2015-01-22T21:21:37.431Z,1421961697.431 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003500
2015-01-22T21:21:41.239Z,1421961701.239 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-22T21:21:41.241Z,1421961701.241 [CBIT](IMPORTANT): Beginning GF scan
2015-01-22T21:21:47.047Z,1421961707.047 [NAL9602](INFO): ************** CMDMODE **************

2015-01-22T21:21:47.047Z,1421961707.047 [NAL9602](INFO): NAL9602 initialized
2015-01-22T21:21:54.367Z,1421961714.367 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T21:22:02.265Z,1421961722.265 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5E%57
$C1,01,7F,02,00,03,7F,04,00,05,00,06,00,07,00%72
$B11,0A,FFFD%31
$B12,0A,FFFD%32
$B13,0A,FFFD%33
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$S,01,270F,02,00,04,5E%57
$C1,01,7F,02,00,03,7F,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B9D,09,3D37,0A,FFFC,0B,FFFD%3C
$B11,0C,0001,0D,005A,0E,0054,0F,1457,10,173A,11,FFFF,12,FFFF%43
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41
$B11,1A,0031,1B,4357,1C,00AD%31
$B12,02,000A,01,026C,03,0001,08,0B96,09,3D38,0A,FFFC,0B,FFFC%45
$B12,0C,0001,0D,005A,0E,0055,0F,1462,10,16AC,11,FFFF,12,FFFF%36
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,00AB%34
$B13,02,000A,01,026C,03,0001,08,0B8A,09,3D34,0A,FFFD,0B,FFFD%3E
$B13,0C,0001,0D,0063,0E,0054,0F,144C,10,16AE,11,FFFF,12,FFFF%32
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4357,1C,00B1%45
$B14,02,000A,01,026C,03,0001,08,0B92,09,3D32,0A,FFFD,0B,FFFD%4D
$B14,0C,0001,0D,0057,0E,0051,0F,1370,10,1688,11,FFFF,12,FFFF%44
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,00A0%40
$B15,02,000A,01,026C,03,0001,08,0B98,09,3C28,0A,0000,0B,0000%4A
$B15,0C,0001,0D,0064,0E,005C,0F,1615,10,1736,11,FFFF,12,FFFF%35
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008B%4A
$B16,02,000A,01,026C,03,0001,08,0B89,09,3D2E,0A,0000,0B,0000%33
$B16,0C,0001,0D,0062,0E,005B,0F,15E7,10,178C,11,FFFF,12,FFFF%3A
$B16,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%45
$B16,1A,0031,1B,4339,1C,007F%4A
$B17,02,000A,01,026C,03,0001,08,0B84,09,3C1F,0A,0000,0B,0000%38
$B17,0C,0001,0D,0064,0E,005D,0F,164F,10,16E1,11,FFFF,12,FFFF%36
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00B4%44

2015-01-22T21:22:02.265Z,1421961722.265 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T21:22:02.270Z,1421961722.270 [BPC1] Data Fault, FailCount= 1
2015-01-22T21:22:02.270Z,1421961722.270 [BPC1](ERROR): Data Fault
2015-01-22T21:22:02.529Z,1421961722.529 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T21:22:03.563Z,1421961723.563 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T21:22:03.563Z,1421961723.563 [BPC1] No Fault, FailCount= 1
2015-01-22T21:22:07.562Z,1421961727.562 [CBIT](IMPORTANT): No ground fault detected
2015-01-22T21:22:21.173Z,1421961741.173 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T21:22:21.173Z,1421961741.173 [SBIT](FAULT): Control surface position failure.
2015-01-22T21:22:34.714Z,1421961754.714 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T21:22:34.714Z,1421961754.714 [SBIT](FAULT): Control surface position failure.
2015-01-22T21:22:35.128Z,1421961755.128 [SBIT](CRITICAL): SBIT FAILED
2015-01-22T21:22:35.129Z,1421961755.129 [CommandLine](FAULT): Scheduling is paused
2015-01-22T21:22:35.508Z,1421961755.508 [MissionManager](IMPORTANT): Started mission Startup
2015-01-22T21:22:35.508Z,1421961755.508 [Startup] Running Loop=1
2015-01-22T21:22:35.509Z,1421961755.509 [Startup](INFO): Aggregate::initialize Startup
2015-01-22T21:22:35.509Z,1421961755.509 [Startup:A.GoToSurface] Running Loop=1
2015-01-22T21:22:35.509Z,1421961755.509 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-22T21:22:35.509Z,1421961755.509 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-22T21:22:35.510Z,1421961755.510 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-22T21:22:35.510Z,1421961755.510 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-22T21:22:35.557Z,1421961755.557 [Startup:StartupSatComms] Running Loop=1
2015-01-22T21:22:35.557Z,1421961755.557 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-22T21:22:35.557Z,1421961755.557 [Startup:StartupSatComms:A] Running Loop=1
2015-01-22T21:22:35.930Z,1421961755.930 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-22T21:22:47.900Z,1421961767.900 [BPC1](FAULT): Failed to receive battery data
2015-01-22T21:22:47.900Z,1421961767.900 [BPC1] Communications Fault, FailCount= 1
2015-01-22T21:22:47.900Z,1421961767.900 [BPC1](ERROR): Communications Fault
2015-01-22T21:22:47.914Z,1421961767.914 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T21:22:49.115Z,1421961769.115 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T21:22:49.115Z,1421961769.115 [BPC1] No Fault, FailCount= 1
2015-01-22T21:22:56.304Z,1421961776.304 [CommandLine](IMPORTANT): got command quit
2015-01-22T21:22:57.314Z,1421961777.314 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T21:22:57.314Z,1421961777.314 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.335Z,1421961777.335 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-22T21:22:57.335Z,1421961777.335 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.336Z,1421961777.336 [CommandLine](INFO): Join timeout helper Thread ID is 2046
2015-01-22T21:22:57.363Z,1421961777.363 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-22T21:22:57.364Z,1421961777.364 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.364Z,1421961777.364 [NavChartDb](INFO): Join timeout helper Thread ID is 2047
2015-01-22T21:22:57.584Z,1421961777.584 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T21:22:57.584Z,1421961777.584 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.588Z,1421961777.588 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-22T21:22:57.588Z,1421961777.588 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.588Z,1421961777.588 [Radio_Surface](INFO): Join timeout helper Thread ID is 2048
2015-01-22T21:22:57.773Z,1421961777.773 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T21:22:57.774Z,1421961777.774 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.792Z,1421961777.792 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-22T21:22:57.792Z,1421961777.792 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.793Z,1421961777.793 [logger](INFO): Join timeout helper Thread ID is 2049
2015-01-22T21:22:57.824Z,1421961777.824 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T21:22:57.825Z,1421961777.825 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.832Z,1421961777.832 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-22T21:22:57.832Z,1421961777.832 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.832Z,1421961777.832 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-22T21:22:57.832Z,1421961777.832 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:57.833Z,1421961777.833 [controlThread](INFO): Join timeout helper Thread ID is 2050
2015-01-22T21:22:57.888Z,1421961777.888 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T21:22:57.889Z,1421961777.889 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-22T21:22:57.890Z,1421961777.890 [NAL9602](INFO): Uninitialize
2015-01-22T21:22:57.890Z,1421961777.890 [NAL9602](INFO): Powering down
2015-01-22T21:22:57.892Z,1421961777.892 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T21:22:57.893Z,1421961777.893 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-22T21:22:57.896Z,1421961777.896 [Startup] Stopped
2015-01-22T21:22:57.896Z,1421961777.896 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-22T21:22:57.896Z,1421961777.896 [Startup:A.GoToSurface] Stopped
2015-01-22T21:22:57.896Z,1421961777.896 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-22T21:22:57.896Z,1421961777.896 [Startup:StartupSatComms] Stopped
2015-01-22T21:22:57.896Z,1421961777.896 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-22T21:22:57.897Z,1421961777.897 [Startup:StartupSatComms:A] Stopped
2015-01-22T21:22:57.898Z,1421961777.898 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-22T21:22:57.898Z,1421961777.898 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-22T21:22:57.898Z,1421961777.898 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-22T21:22:57.898Z,1421961777.898 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-22T21:22:57.899Z,1421961777.899 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-22T21:22:57.899Z,1421961777.899 [BuoyancyServo](INFO): Powering down
2015-01-22T21:22:57.913Z,1421961777.913 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-22T21:22:57.913Z,1421961777.913 [ElevatorServo](INFO): Powering down
2015-01-22T21:22:57.914Z,1421961777.914 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-22T21:22:57.914Z,1421961777.914 [RudderServo](INFO): Powering down
2015-01-22T21:22:57.914Z,1421961777.914 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-22T21:22:57.915Z,1421961777.915 [ThrusterServo](INFO): Powering down
2015-01-22T21:22:57.915Z,1421961777.915 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-22T21:22:57.916Z,1421961777.916 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-22T21:22:57.916Z,1421961777.916 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-22T21:22:57.949Z,1421961777.949 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:58.219Z,1421961778.219 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:58.362Z,1421961778.362 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T21:22:58.460Z,1421961778.460 [logger ThreadHandler](INFO): Thread cancelled.