2015-01-27T22:37:57.419Z,1422398277.419 [Supervisor](DEBUG): Initializing supervisor.
2015-01-27T22:37:57.422Z,1422398277.422 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-27T22:37:57.423Z,1422398277.423 [SyncHandler](INFO): Protected caller Thread ID is 1751
2015-01-27T22:37:57.423Z,1422398277.423 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-27T22:37:57.424Z,1422398277.424 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-27T22:37:57.424Z,1422398277.424 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1752
2015-01-27T22:37:57.427Z,1422398277.427 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-27T22:37:57.439Z,1422398277.439 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-27T22:37:57.440Z,1422398277.440 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-27T22:37:57.440Z,1422398277.440 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1753
2015-01-27T22:37:57.441Z,1422398277.441 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-27T22:37:57.442Z,1422398277.442 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-27T22:37:57.443Z,1422398277.443 [logger ThreadHandler](INFO): Protected caller Thread ID is 1754
2015-01-27T22:37:57.445Z,1422398277.445 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-27T22:37:57.445Z,1422398277.445 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-27T22:37:57.447Z,1422398277.447 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-27T22:37:57.782Z,1422398277.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-27T22:37:57.783Z,1422398277.783 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-27T22:37:57.943Z,1422398277.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-27T22:37:57.944Z,1422398277.944 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-27T22:37:58.051Z,1422398278.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-27T22:37:58.052Z,1422398278.052 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-27T22:37:58.174Z,1422398278.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-27T22:37:58.175Z,1422398278.175 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-27T22:37:58.260Z,1422398278.260 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-27T22:37:58.422Z,1422398278.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-27T22:37:58.423Z,1422398278.423 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-27T22:37:58.507Z,1422398278.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-27T22:37:58.508Z,1422398278.508 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-27T22:37:58.718Z,1422398278.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-27T22:37:58.718Z,1422398278.718 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-27T22:37:59.106Z,1422398279.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-27T22:37:59.107Z,1422398279.107 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-27T22:37:59.434Z,1422398279.434 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-27T22:37:59.434Z,1422398279.434 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-27T22:37:59.956Z,1422398279.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-27T22:37:59.957Z,1422398279.957 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-27T22:38:00.162Z,1422398280.162 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-27T22:38:00.163Z,1422398280.163 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-27T22:38:00.270Z,1422398280.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-27T22:38:00.271Z,1422398280.271 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-27T22:38:00.788Z,1422398280.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-27T22:38:00.788Z,1422398280.788 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-27T22:38:00.899Z,1422398280.899 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-27T22:38:00.901Z,1422398280.901 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-27T22:38:00.902Z,1422398280.902 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-27T22:38:01.143Z,1422398281.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-27T22:38:01.144Z,1422398281.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-27T22:38:01.260Z,1422398281.260 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-27T22:38:01.358Z,1422398281.358 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-27T22:38:01.455Z,1422398281.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-27T22:38:01.570Z,1422398281.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-27T22:38:01.712Z,1422398281.712 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-27T22:38:01.884Z,1422398281.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-27T22:38:01.984Z,1422398281.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-27T22:38:02.074Z,1422398282.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-27T22:38:02.176Z,1422398282.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-27T22:38:02.272Z,1422398282.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-27T22:38:02.457Z,1422398282.457 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-01-27T22:38:02.457Z,1422398282.457 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-27T22:38:02.471Z,1422398282.471 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-27T22:38:02.524Z,1422398282.524 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-27T22:38:02.647Z,1422398282.647 [VerticalControl] Loaded
2015-01-27T22:38:02.647Z,1422398282.647 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-27T22:38:02.648Z,1422398282.648 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-27T22:38:02.722Z,1422398282.722 [HorizontalControl] Loaded
2015-01-27T22:38:02.722Z,1422398282.722 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-27T22:38:02.723Z,1422398282.723 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-27T22:38:02.729Z,1422398282.729 [SpeedControl] Loaded
2015-01-27T22:38:02.729Z,1422398282.729 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-27T22:38:02.730Z,1422398282.730 [LoopControl](DEBUG): Construct LoopControl.
2015-01-27T22:38:02.730Z,1422398282.730 [LoopControl] Loaded
2015-01-27T22:38:02.731Z,1422398282.731 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-27T22:38:02.731Z,1422398282.731 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-27T22:38:02.732Z,1422398282.732 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-27T22:38:02.831Z,1422398282.831 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-27T22:38:02.843Z,1422398282.843 [SBIT] Loaded
2015-01-27T22:38:02.843Z,1422398282.843 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-27T22:38:02.844Z,1422398282.844 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-27T22:38:02.873Z,1422398282.873 [IBIT] Loaded
2015-01-27T22:38:02.874Z,1422398282.874 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-27T22:38:02.876Z,1422398282.876 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-27T22:38:02.000Z,1422398283.000 [CBIT] Loaded
2015-01-27T22:38:03.000Z,1422398283.000 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-27T22:38:03.001Z,1422398283.001 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-27T22:38:03.001Z,1422398283.001 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-27T22:38:03.035Z,1422398283.035 [DepthRateCalculator] Loaded
2015-01-27T22:38:03.036Z,1422398283.036 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-27T22:38:03.041Z,1422398283.041 [PitchRateCalculator] Loaded
2015-01-27T22:38:03.042Z,1422398283.042 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-27T22:38:03.053Z,1422398283.053 [SpeedCalculator] Loaded
2015-01-27T22:38:03.054Z,1422398283.054 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-27T22:38:03.071Z,1422398283.071 [TempGradientCalculator] Loaded
2015-01-27T22:38:03.071Z,1422398283.071 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-27T22:38:03.077Z,1422398283.077 [YawRateCalculator] Loaded
2015-01-27T22:38:03.077Z,1422398283.077 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-27T22:38:03.078Z,1422398283.078 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-27T22:38:03.078Z,1422398283.078 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-27T22:38:03.129Z,1422398283.129 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-27T22:38:03.130Z,1422398283.130 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-27T22:38:03.369Z,1422398283.369 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-27T22:38:03.369Z,1422398283.369 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-27T22:38:03.414Z,1422398283.414 [NavChart] Loaded
2015-01-27T22:38:03.414Z,1422398283.414 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-27T22:38:03.421Z,1422398283.421 [UniversalFixResidualReporter] Loaded
2015-01-27T22:38:03.421Z,1422398283.421 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-27T22:38:03.421Z,1422398283.421 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-27T22:38:03.422Z,1422398283.422 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-27T22:38:03.428Z,1422398283.428 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-27T22:38:03.429Z,1422398283.429 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-27T22:38:03.517Z,1422398283.517 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-27T22:38:03.518Z,1422398283.518 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-27T22:38:03.849Z,1422398283.849 [DataOverHttps] Loaded
2015-01-27T22:38:03.849Z,1422398283.849 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-27T22:38:03.932Z,1422398283.932 [Depth_Keller] Loaded
2015-01-27T22:38:03.933Z,1422398283.933 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-27T22:38:04.031Z,1422398284.031 [NAL9602] Loaded
2015-01-27T22:38:04.031Z,1422398284.031 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-27T22:38:04.074Z,1422398284.074 [Onboard] Loaded
2015-01-27T22:38:04.074Z,1422398284.074 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-27T22:38:04.081Z,1422398284.081 [Radio_Surface] Loaded
2015-01-27T22:38:04.082Z,1422398284.082 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-27T22:38:04.083Z,1422398284.083 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-27T22:38:04.083Z,1422398284.083 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1837
2015-01-27T22:38:05.994Z,1422398285.994 [BPC1] Loaded
2015-01-27T22:38:05.994Z,1422398285.994 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-27T22:38:05.995Z,1422398285.995 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-27T22:38:05.995Z,1422398285.995 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-27T22:38:06.098Z,1422398286.098 [BuoyancyServo] Loaded
2015-01-27T22:38:06.098Z,1422398286.098 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-27T22:38:06.110Z,1422398286.110 [ElevatorServo] Loaded
2015-01-27T22:38:06.110Z,1422398286.110 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-27T22:38:06.123Z,1422398286.123 [RudderServo] Loaded
2015-01-27T22:38:06.123Z,1422398286.123 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-27T22:38:06.135Z,1422398286.135 [ThrusterServo] Loaded
2015-01-27T22:38:06.135Z,1422398286.135 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-27T22:38:06.135Z,1422398286.135 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-27T22:38:06.136Z,1422398286.136 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-27T22:38:06.253Z,1422398286.253 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-27T22:38:06.253Z,1422398286.253 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-27T22:38:06.279Z,1422398286.279 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-27T22:38:06.281Z,1422398286.281 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-27T22:38:06.282Z,1422398286.282 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-27T22:38:06.288Z,1422398286.288 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-27T22:38:06.289Z,1422398286.289 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-27T22:38:06.290Z,1422398286.290 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1838
2015-01-27T22:38:06.295Z,1422398286.295 [Supervisor](INFO): Main Thread ID is 1750
2015-01-27T22:38:06.295Z,1422398286.295 [Supervisor](DEBUG): Running supervisor.
2015-01-27T22:38:06.295Z,1422398286.295 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1839
2015-01-27T22:38:06.299Z,1422398286.299 [controlThread ThreadHandler](INFO): Handler Thread ID is 1840
2015-01-27T22:38:06.300Z,1422398286.300 [controlThread](DEBUG): Initializing ControlThread
2015-01-27T22:38:06.301Z,1422398286.301 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-27T22:38:06.302Z,1422398286.302 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-27T22:38:06.303Z,1422398286.303 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-27T22:38:06.304Z,1422398286.304 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-27T22:38:06.304Z,1422398286.304 [SBIT](INFO): Initialize SBIT Component.
2015-01-27T22:38:06.304Z,1422398286.304 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-27T22:38:06.305Z,1422398286.305 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-27T22:38:06.305Z,1422398286.305 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-27T22:38:06.306Z,1422398286.306 [IBIT](INFO): Initialize IBIT Component.
2015-01-27T22:38:06.306Z,1422398286.306 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-27T22:38:06.307Z,1422398286.307 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-27T22:38:06.308Z,1422398286.308 [logger ThreadHandler](INFO): Handler Thread ID is 1841
2015-01-27T22:38:06.333Z,1422398286.333 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-27T22:38:06.333Z,1422398286.333 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-27T22:38:06.333Z,1422398286.333 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-27T22:38:06.334Z,1422398286.334 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-27T22:38:06.334Z,1422398286.334 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-27T22:38:06.335Z,1422398286.335 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-27T22:38:06.335Z,1422398286.335 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-27T22:38:06.339Z,1422398286.339 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-27T22:38:06.345Z,1422398286.345 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1842
2015-01-27T22:38:06.351Z,1422398286.351 [Radio_Surface](INFO): Powering up
2015-01-27T22:38:06.361Z,1422398286.361 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1843
2015-01-27T22:38:06.364Z,1422398286.364 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-27T22:38:06.365Z,1422398286.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-27T22:38:06.365Z,1422398286.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-27T22:38:06.365Z,1422398286.365 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-27T22:38:06.366Z,1422398286.366 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-27T22:38:06.366Z,1422398286.366 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-27T22:38:06.366Z,1422398286.366 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-27T22:38:06.367Z,1422398286.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-27T22:38:06.367Z,1422398286.367 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-27T22:38:06.385Z,1422398286.385 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-27T22:38:06.414Z,1422398286.414 [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-27T22:38:06.415Z,1422398286.415 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-27T22:38:06.506Z,1422398286.506 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-27T22:38:06.509Z,1422398286.509 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-27T22:38:06.529Z,1422398286.529 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-27T22:38:06.554Z,1422398286.554 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-27T22:38:06.560Z,1422398286.560 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-27T22:38:06.592Z,1422398286.592 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-27T22:38:06.622Z,1422398286.622 [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-27T22:38:06.632Z,1422398286.632 [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-27T22:38:06.776Z,1422398286.776 [NAL9602](INFO): Start
2015-01-27T22:38:07.092Z,1422398287.092 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-27T22:38:07.104Z,1422398287.104 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-27T22:38:07.118Z,1422398287.118 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-27T22:38:07.126Z,1422398287.126 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-27T22:38:07.144Z,1422398287.144 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-27T22:38:07.150Z,1422398287.150 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-27T22:38:07.168Z,1422398287.168 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-27T22:38:07.174Z,1422398287.174 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-27T22:38:07.351Z,1422398287.351 [NAL9602](INFO): Start
2015-01-27T22:38:15.050Z,1422398295.050 [CommandLine](IMPORTANT): got command show variable quality
2015-01-27T22:38:15.081Z,1422398295.081 [CommandLine](IMPORTANT): NAL9602.sigQuality (count)
2015-01-27T22:38:16.926Z,1422398296.926 [NAL9602](INFO): Start
2015-01-27T22:38:16.926Z,1422398296.926 [NAL9602](INFO): Powering up NAL9602
2015-01-27T22:38:18.098Z,1422398298.098 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003400
2015-01-27T22:38:21.748Z,1422398301.748 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-27T22:38:21.766Z,1422398301.766 [CBIT](IMPORTANT): Beginning GF scan
2015-01-27T22:38:28.096Z,1422398308.096 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T22:38:28.096Z,1422398308.096 [NAL9602](INFO): NAL9602 initialized
2015-01-27T22:38:30.120Z,1422398310.120 [BPC1](ERROR): Failed to parse message.
2015-01-27T22:38:30.120Z,1422398310.120 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T22:38:30.120Z,1422398310.120 [BPC1] Data Fault, FailCount= 1
2015-01-27T22:38:30.120Z,1422398310.120 [BPC1](ERROR): Data Fault
2015-01-27T22:38:30.237Z,1422398310.237 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T22:38:31.315Z,1422398311.315 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:31.315Z,1422398311.315 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T22:38:31.423Z,1422398311.423 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T22:38:31.423Z,1422398311.423 [BPC1] No Fault, FailCount= 1
2015-01-27T22:38:31.701Z,1422398311.701 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:31.974Z,1422398311.974 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2015-01-27T22:38:32.098Z,1422398312.098 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:32.274Z,1422398312.274 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T22:38:32.499Z,1422398312.499 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:32.895Z,1422398312.895 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:33.296Z,1422398313.296 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:33.701Z,1422398313.701 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:34.097Z,1422398314.097 [NAL9602](INFO): Bytes:2
2015-01-27T22:38:34.498Z,1422398314.498 [NAL9602](INFO): Bytes:12
2015-01-27T22:38:34.670Z,1422398314.670 [Reporter](INFO): NAL9602.sigQuality -1 count
2015-01-27T22:38:34.902Z,1422398314.902 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:35.039Z,1422398315.039 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T22:38:35.295Z,1422398315.295 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:35.696Z,1422398315.696 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:36.100Z,1422398316.100 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:36.501Z,1422398316.501 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:36.898Z,1422398316.898 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:37.302Z,1422398317.302 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:37.699Z,1422398317.699 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:38.095Z,1422398318.095 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:38.500Z,1422398318.500 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:38.900Z,1422398318.900 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:39.297Z,1422398319.297 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:39.702Z,1422398319.702 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:40.102Z,1422398320.102 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:40.499Z,1422398320.499 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:40.900Z,1422398320.900 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:41.312Z,1422398321.312 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:41.701Z,1422398321.701 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:42.102Z,1422398322.102 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:42.502Z,1422398322.502 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:42.895Z,1422398322.895 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:43.299Z,1422398323.299 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:43.700Z,1422398323.700 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:44.097Z,1422398324.097 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:44.501Z,1422398324.501 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:44.914Z,1422398324.914 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:45.299Z,1422398325.299 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:45.699Z,1422398325.699 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:46.100Z,1422398326.100 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:46.500Z,1422398326.500 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:46.901Z,1422398326.901 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:47.302Z,1422398327.302 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:47.703Z,1422398327.703 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:48.099Z,1422398328.099 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:48.286Z,1422398328.286 [CBIT](IMPORTANT): No ground fault detected
2015-01-27T22:38:48.499Z,1422398328.499 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:48.896Z,1422398328.896 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:49.301Z,1422398329.301 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:49.701Z,1422398329.701 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:50.098Z,1422398330.098 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:50.499Z,1422398330.499 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:50.899Z,1422398330.899 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:51.296Z,1422398331.296 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:51.700Z,1422398331.700 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:52.101Z,1422398332.101 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:52.502Z,1422398332.502 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:52.902Z,1422398332.902 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:53.299Z,1422398333.299 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:53.696Z,1422398333.696 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:54.100Z,1422398334.100 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:54.501Z,1422398334.501 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:54.902Z,1422398334.902 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:55.302Z,1422398335.302 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:55.699Z,1422398335.699 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:56.095Z,1422398336.095 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:56.496Z,1422398336.496 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:56.900Z,1422398336.900 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:57.301Z,1422398337.301 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:57.698Z,1422398337.698 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:58.102Z,1422398338.102 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:58.495Z,1422398338.495 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:58.896Z,1422398338.896 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:59.312Z,1422398339.312 [NAL9602](INFO): Bytes:0
2015-01-27T22:38:59.697Z,1422398339.697 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:00.098Z,1422398340.098 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:00.502Z,1422398340.502 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:00.895Z,1422398340.895 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:01.300Z,1422398341.300 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:01.700Z,1422398341.700 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:01.861Z,1422398341.861 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T22:39:01.861Z,1422398341.861 [SBIT](FAULT): Control surface position failure.
2015-01-27T22:39:02.097Z,1422398342.097 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:02.497Z,1422398342.497 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:02.910Z,1422398342.910 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:03.299Z,1422398343.299 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:03.695Z,1422398343.695 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:04.108Z,1422398344.108 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:04.509Z,1422398344.509 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:04.509Z,1422398344.509 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2015-01-27T22:39:05.028Z,1422398345.028 [NAL9602](FAULT): received: 
2015-01-27T22:39:05.028Z,1422398345.028 [NAL9602] Data Fault, FailCount= 1
2015-01-27T22:39:05.028Z,1422398345.028 [NAL9602](ERROR): Data Fault
2015-01-27T22:39:05.155Z,1422398345.155 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T22:39:05.160Z,1422398345.160 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T22:39:05.197Z,1422398345.197 [NAL9602](INFO): Stop
2015-01-27T22:39:05.197Z,1422398345.197 [NAL9602](INFO): Uninitialize
2015-01-27T22:39:05.197Z,1422398345.197 [NAL9602](INFO): Powering down
2015-01-27T22:39:05.584Z,1422398345.584 [NAL9602](INFO): Stopping
2015-01-27T22:39:06.164Z,1422398346.164 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T22:39:06.164Z,1422398346.164 [NAL9602] No Fault, FailCount= 1
2015-01-27T22:39:06.383Z,1422398346.383 [NAL9602](INFO): Start
2015-01-27T22:39:06.771Z,1422398346.771 [NAL9602](INFO): Start
2015-01-27T22:39:07.172Z,1422398347.172 [NAL9602](INFO): Start
2015-01-27T22:39:12.470Z,1422398352.470 [NAL9602](INFO): Start
2015-01-27T22:39:12.471Z,1422398352.471 [NAL9602](INFO): Powering up NAL9602
2015-01-27T22:39:15.406Z,1422398355.406 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T22:39:15.406Z,1422398355.406 [SBIT](FAULT): Control surface position failure.
2015-01-27T22:39:15.806Z,1422398355.806 [SBIT](CRITICAL): SBIT FAILED
2015-01-27T22:39:15.807Z,1422398355.807 [CommandLine](FAULT): Scheduling is paused
2015-01-27T22:39:16.195Z,1422398356.195 [MissionManager](IMPORTANT): Started mission Startup
2015-01-27T22:39:16.195Z,1422398356.195 [Startup] Running Loop=1
2015-01-27T22:39:16.195Z,1422398356.195 [Startup](INFO): Aggregate::initialize Startup
2015-01-27T22:39:16.195Z,1422398356.195 [Startup:A.GoToSurface] Running Loop=1
2015-01-27T22:39:16.195Z,1422398356.195 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-27T22:39:16.196Z,1422398356.196 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-27T22:39:16.196Z,1422398356.196 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-27T22:39:16.197Z,1422398356.197 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-27T22:39:16.203Z,1422398356.203 [Startup:StartupSatComms] Running Loop=1
2015-01-27T22:39:16.203Z,1422398356.203 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-27T22:39:16.203Z,1422398356.203 [Startup:StartupSatComms:A] Running Loop=1
2015-01-27T22:39:16.602Z,1422398356.602 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-27T22:39:22.609Z,1422398362.609 [Reporter](INFO): NAL9602.sigQuality -1 count
2015-01-27T22:39:23.382Z,1422398363.382 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T22:39:23.382Z,1422398363.382 [NAL9602](INFO): NAL9602 initialized
2015-01-27T22:39:26.984Z,1422398366.984 [NAL9602](INFO): Bytes:2
2015-01-27T22:39:26.984Z,1422398366.984 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T22:39:27.385Z,1422398367.385 [NAL9602](INFO): Bytes:12
2015-01-27T22:39:27.781Z,1422398367.781 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:28.186Z,1422398368.186 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:28.583Z,1422398368.583 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:28.983Z,1422398368.983 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:29.387Z,1422398369.387 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:29.784Z,1422398369.784 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:30.185Z,1422398370.185 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:30.585Z,1422398370.585 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:30.992Z,1422398370.992 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:31.393Z,1422398371.393 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:31.784Z,1422398371.784 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:32.180Z,1422398372.180 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:32.585Z,1422398372.585 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:32.981Z,1422398372.981 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:33.382Z,1422398373.382 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:33.783Z,1422398373.783 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:34.179Z,1422398374.179 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:34.584Z,1422398374.584 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:34.984Z,1422398374.984 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:35.385Z,1422398375.385 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:35.781Z,1422398375.781 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:36.182Z,1422398376.182 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:36.583Z,1422398376.583 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:36.979Z,1422398376.979 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:37.384Z,1422398377.384 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:37.780Z,1422398377.780 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:38.181Z,1422398378.181 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:38.582Z,1422398378.582 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:38.993Z,1422398378.993 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:39.379Z,1422398379.379 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:39.779Z,1422398379.779 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:40.180Z,1422398380.180 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:40.581Z,1422398380.581 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:40.981Z,1422398380.981 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:41.382Z,1422398381.382 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:41.779Z,1422398381.779 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:42.179Z,1422398382.179 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:42.580Z,1422398382.580 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:42.981Z,1422398382.981 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:43.381Z,1422398383.381 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:43.409Z,1422398383.409 [BPC1](FAULT): Failed to receive battery data
2015-01-27T22:39:43.410Z,1422398383.410 [BPC1] Communications Fault, FailCount= 1
2015-01-27T22:39:43.410Z,1422398383.410 [BPC1](ERROR): Communications Fault
2015-01-27T22:39:43.425Z,1422398383.425 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T22:39:43.786Z,1422398383.786 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:44.183Z,1422398384.183 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:44.583Z,1422398384.583 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:44.624Z,1422398384.624 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T22:39:44.624Z,1422398384.624 [BPC1] No Fault, FailCount= 1
2015-01-27T22:39:44.979Z,1422398384.979 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:45.385Z,1422398385.385 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:45.781Z,1422398385.781 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:46.181Z,1422398386.181 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:46.583Z,1422398386.583 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:46.983Z,1422398386.983 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:47.379Z,1422398387.379 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:47.780Z,1422398387.780 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:48.180Z,1422398388.180 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:48.581Z,1422398388.581 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:48.982Z,1422398388.982 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:49.383Z,1422398389.383 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:49.783Z,1422398389.783 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:50.180Z,1422398390.180 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:50.585Z,1422398390.585 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:50.981Z,1422398390.981 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:51.382Z,1422398391.382 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:51.783Z,1422398391.783 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:52.183Z,1422398392.183 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:52.580Z,1422398392.580 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:52.980Z,1422398392.980 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:53.380Z,1422398393.380 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:53.781Z,1422398393.781 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:54.191Z,1422398394.191 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:54.578Z,1422398394.578 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:54.979Z,1422398394.979 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:55.380Z,1422398395.380 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:55.780Z,1422398395.780 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:56.181Z,1422398396.181 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:56.582Z,1422398396.582 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:56.983Z,1422398396.983 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:57.379Z,1422398397.379 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:57.779Z,1422398397.779 [NAL9602](INFO): Bytes:0
2015-01-27T22:39:57.779Z,1422398397.779 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2015-01-27T22:39:58.295Z,1422398398.295 [NAL9602](FAULT): received: 
2015-01-27T22:39:58.295Z,1422398398.295 [NAL9602] Data Fault, FailCount= 2
2015-01-27T22:39:58.295Z,1422398398.295 [NAL9602](ERROR): Data Fault
2015-01-27T22:39:58.319Z,1422398398.319 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T22:39:58.320Z,1422398398.320 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T22:39:58.388Z,1422398398.388 [NAL9602](INFO): Stop
2015-01-27T22:39:58.388Z,1422398398.388 [NAL9602](INFO): Uninitialize
2015-01-27T22:39:58.388Z,1422398398.388 [NAL9602](INFO): Powering down
2015-01-27T22:39:58.728Z,1422398398.728 [NAL9602](INFO): Stopping
2015-01-27T22:39:59.184Z,1422398399.184 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T22:39:59.184Z,1422398399.184 [NAL9602] No Fault, FailCount= 2
2015-01-27T22:39:59.534Z,1422398399.534 [NAL9602](INFO): Start
2015-01-27T22:39:59.926Z,1422398399.926 [NAL9602](INFO): Start
2015-01-27T22:40:00.331Z,1422398400.331 [NAL9602](INFO): Start
2015-01-27T22:40:00.731Z,1422398400.731 [NAL9602](INFO): Start
2015-01-27T22:40:01.128Z,1422398401.128 [NAL9602](INFO): Start
2015-01-27T22:40:01.529Z,1422398401.529 [NAL9602](INFO): Start
2015-01-27T22:40:01.929Z,1422398401.929 [NAL9602](INFO): Start
2015-01-27T22:40:02.330Z,1422398402.330 [NAL9602](INFO): Start
2015-01-27T22:40:02.727Z,1422398402.727 [NAL9602](INFO): Start
2015-01-27T22:40:03.127Z,1422398403.127 [NAL9602](INFO): Start
2015-01-27T22:40:03.528Z,1422398403.528 [NAL9602](INFO): Start
2015-01-27T22:40:03.528Z,1422398403.528 [NAL9602](INFO): Powering up NAL9602
2015-01-27T22:40:13.635Z,1422398413.635 [Reporter](INFO): NAL9602.sigQuality -1 count
2015-01-27T22:40:14.390Z,1422398414.390 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T22:40:14.390Z,1422398414.390 [NAL9602](INFO): NAL9602 initialized
2015-01-27T22:40:16.408Z,1422398416.408 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-27T22:39:16.2Z
2015-01-27T22:40:16.408Z,1422398416.408 [Startup:StartupSatComms:A] Stopped
2015-01-27T22:40:16.409Z,1422398416.409 [Startup:StartupSatComms:B] Running Loop=1
2015-01-27T22:40:16.789Z,1422398416.789 [NAL9602](INFO): Bytes:2
2015-01-27T22:40:16.789Z,1422398416.789 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T22:40:16.804Z,1422398416.804 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-27T22:40:17.926Z,1422398417.926 [NAL9602](INFO): Bytes:12
2015-01-27T22:40:18.133Z,1422398418.133 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:21.366Z,1422398421.366 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:21.464Z,1422398421.464 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:21.810Z,1422398421.810 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150127T222937/Courier0004.lzma
2015-01-27T22:40:21.821Z,1422398421.821 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:22.220Z,1422398422.220 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:22.609Z,1422398422.609 [DataOverHttps](INFO): Moved sent file to Logs/20150127T222937/Courier0004.lzma.bak
2015-01-27T22:40:22.609Z,1422398422.609 [DataOverHttps](INFO): SBD MOMSN=1508786
2015-01-27T22:40:22.635Z,1422398422.635 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:23.202Z,1422398423.202 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:23.415Z,1422398423.415 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:26.621Z,1422398426.621 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:26.724Z,1422398426.724 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:27.079Z,1422398427.079 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:27.476Z,1422398427.476 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:27.877Z,1422398427.877 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:28.277Z,1422398428.277 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:28.674Z,1422398428.674 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:31.858Z,1422398431.858 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:31.976Z,1422398431.976 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:32.310Z,1422398432.310 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150127T223757/Courier0000.lzma
2015-01-27T22:40:32.317Z,1422398432.317 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:32.718Z,1422398432.718 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:33.109Z,1422398433.109 [DataOverHttps](INFO): Moved sent file to Logs/20150127T223757/Courier0000.lzma.bak
2015-01-27T22:40:33.110Z,1422398433.110 [DataOverHttps](INFO): SBD MOMSN=1508788
2015-01-27T22:40:33.141Z,1422398433.141 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:33.894Z,1422398433.894 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:33.988Z,1422398433.988 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:34.326Z,1422398434.326 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:37.588Z,1422398437.588 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:37.686Z,1422398437.686 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:38.020Z,1422398438.020 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:38.172Z,1422398438.172 [CommandLine](IMPORTANT): got command quit
2015-01-27T22:40:38.425Z,1422398438.425 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:38.825Z,1422398438.825 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:39.185Z,1422398439.185 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-27T22:40:39.185Z,1422398439.185 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.224Z,1422398439.224 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:39.354Z,1422398439.354 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-27T22:40:39.354Z,1422398439.354 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.355Z,1422398439.355 [CommandLine](INFO): Join timeout helper Thread ID is 1850
2015-01-27T22:40:39.356Z,1422398439.356 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-27T22:40:39.356Z,1422398439.356 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.356Z,1422398439.356 [NavChartDb](INFO): Join timeout helper Thread ID is 1851
2015-01-27T22:40:39.383Z,1422398439.383 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-27T22:40:39.383Z,1422398439.383 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.395Z,1422398439.395 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-27T22:40:39.395Z,1422398439.395 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.395Z,1422398439.395 [Radio_Surface](INFO): Join timeout helper Thread ID is 1852
2015-01-27T22:40:39.631Z,1422398439.631 [NAL9602](INFO): Bytes:0
2015-01-27T22:40:39.795Z,1422398439.795 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-27T22:40:39.796Z,1422398439.796 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.799Z,1422398439.799 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-27T22:40:39.799Z,1422398439.799 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.800Z,1422398439.800 [logger](INFO): Join timeout helper Thread ID is 1853
2015-01-27T22:40:39.819Z,1422398439.819 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-27T22:40:39.820Z,1422398439.820 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.839Z,1422398439.839 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-27T22:40:39.839Z,1422398439.839 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.839Z,1422398439.839 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-27T22:40:39.839Z,1422398439.839 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:39.840Z,1422398439.840 [controlThread](INFO): Join timeout helper Thread ID is 1854
2015-01-27T22:40:40.012Z,1422398440.012 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-27T22:40:40.012Z,1422398440.012 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-27T22:40:40.013Z,1422398440.013 [NAL9602](INFO): Uninitialize
2015-01-27T22:40:40.013Z,1422398440.013 [NAL9602](INFO): Powering down
2015-01-27T22:40:40.016Z,1422398440.016 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-27T22:40:40.016Z,1422398440.016 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-27T22:40:40.019Z,1422398440.019 [Startup] Stopped
2015-01-27T22:40:40.019Z,1422398440.019 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-27T22:40:40.020Z,1422398440.020 [Startup:A.GoToSurface] Stopped
2015-01-27T22:40:40.020Z,1422398440.020 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-27T22:40:40.020Z,1422398440.020 [Startup:StartupSatComms] Stopped
2015-01-27T22:40:40.020Z,1422398440.020 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-27T22:40:40.020Z,1422398440.020 [Startup:StartupSatComms:B] Stopped
2015-01-27T22:40:40.021Z,1422398440.021 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-27T22:40:40.021Z,1422398440.021 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-27T22:40:40.022Z,1422398440.022 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-27T22:40:40.022Z,1422398440.022 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-27T22:40:40.022Z,1422398440.022 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-27T22:40:40.022Z,1422398440.022 [BuoyancyServo](INFO): Powering down
2015-01-27T22:40:40.036Z,1422398440.036 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-27T22:40:40.036Z,1422398440.036 [ElevatorServo](INFO): Powering down
2015-01-27T22:40:40.037Z,1422398440.037 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-27T22:40:40.037Z,1422398440.037 [RudderServo](INFO): Powering down
2015-01-27T22:40:40.038Z,1422398440.038 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-27T22:40:40.038Z,1422398440.038 [ThrusterServo](INFO): Powering down
2015-01-27T22:40:40.038Z,1422398440.038 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-27T22:40:40.039Z,1422398440.039 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-27T22:40:40.039Z,1422398440.039 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-27T22:40:40.072Z,1422398440.072 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:40.174Z,1422398440.174 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:40.215Z,1422398440.215 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-27T22:40:40.265Z,1422398440.265 [logger ThreadHandler](INFO): Thread cancelled.