2015-01-22T20:29:26.982Z,1421958566.982 [Supervisor](DEBUG): Initializing supervisor.
2015-01-22T20:29:26.985Z,1421958566.985 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-22T20:29:26.985Z,1421958566.985 [SyncHandler](INFO): Protected caller Thread ID is 1198
2015-01-22T20:29:26.986Z,1421958566.986 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-22T20:29:26.987Z,1421958566.987 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-22T20:29:26.987Z,1421958566.987 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1199
2015-01-22T20:29:26.990Z,1421958566.990 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-22T20:29:27.001Z,1421958567.001 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-22T20:29:27.002Z,1421958567.002 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-22T20:29:27.003Z,1421958567.003 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1200
2015-01-22T20:29:27.004Z,1421958567.004 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-22T20:29:27.005Z,1421958567.005 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-22T20:29:27.005Z,1421958567.005 [logger ThreadHandler](INFO): Protected caller Thread ID is 1201
2015-01-22T20:29:27.007Z,1421958567.007 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-22T20:29:27.007Z,1421958567.007 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-22T20:29:27.009Z,1421958567.009 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-22T20:29:27.328Z,1421958567.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-22T20:29:27.328Z,1421958567.328 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-22T20:29:27.483Z,1421958567.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-22T20:29:27.483Z,1421958567.483 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-22T20:29:27.589Z,1421958567.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-22T20:29:27.589Z,1421958567.589 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-22T20:29:27.708Z,1421958567.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-22T20:29:27.709Z,1421958567.709 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-22T20:29:27.793Z,1421958567.793 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-22T20:29:27.950Z,1421958567.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-22T20:29:27.951Z,1421958567.951 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-22T20:29:28.036Z,1421958568.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-22T20:29:28.036Z,1421958568.036 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-22T20:29:28.239Z,1421958568.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-22T20:29:28.239Z,1421958568.239 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-22T20:29:28.601Z,1421958568.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-22T20:29:28.602Z,1421958568.602 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-22T20:29:28.909Z,1421958568.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-22T20:29:28.910Z,1421958568.910 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-22T20:29:29.400Z,1421958569.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-22T20:29:29.400Z,1421958569.400 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-22T20:29:29.588Z,1421958569.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-22T20:29:29.589Z,1421958569.589 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-22T20:29:29.691Z,1421958569.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-22T20:29:29.692Z,1421958569.692 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-22T20:29:30.106Z,1421958570.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-22T20:29:30.106Z,1421958570.106 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-22T20:29:30.215Z,1421958570.215 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-22T20:29:30.217Z,1421958570.217 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-22T20:29:30.218Z,1421958570.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-22T20:29:30.454Z,1421958570.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-22T20:29:30.454Z,1421958570.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-22T20:29:30.567Z,1421958570.567 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-22T20:29:30.664Z,1421958570.664 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-22T20:29:30.758Z,1421958570.758 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-22T20:29:30.870Z,1421958570.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-22T20:29:31.008Z,1421958571.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-22T20:29:31.174Z,1421958571.174 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-22T20:29:31.273Z,1421958571.273 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-22T20:29:31.361Z,1421958571.361 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-22T20:29:31.459Z,1421958571.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-22T20:29:31.553Z,1421958571.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-22T20:29:31.730Z,1421958571.730 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-22T20:29:31.744Z,1421958571.744 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-22T20:29:31.794Z,1421958571.794 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-22T20:29:31.913Z,1421958571.913 [VerticalControl] Loaded
2015-01-22T20:29:31.913Z,1421958571.913 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-22T20:29:31.914Z,1421958571.914 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-22T20:29:31.986Z,1421958571.986 [HorizontalControl] Loaded
2015-01-22T20:29:31.986Z,1421958571.986 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-22T20:29:31.987Z,1421958571.987 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-22T20:29:31.992Z,1421958571.992 [SpeedControl] Loaded
2015-01-22T20:29:31.993Z,1421958571.993 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-22T20:29:31.993Z,1421958571.993 [LoopControl](DEBUG): Construct LoopControl.
2015-01-22T20:29:31.994Z,1421958571.994 [LoopControl] Loaded
2015-01-22T20:29:31.994Z,1421958571.994 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-22T20:29:31.994Z,1421958571.994 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-22T20:29:31.995Z,1421958571.995 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-22T20:29:32.091Z,1421958572.091 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-22T20:29:32.102Z,1421958572.102 [SBIT] Loaded
2015-01-22T20:29:32.102Z,1421958572.102 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-22T20:29:32.103Z,1421958572.103 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-22T20:29:32.132Z,1421958572.132 [IBIT] Loaded
2015-01-22T20:29:32.132Z,1421958572.132 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-22T20:29:32.134Z,1421958572.134 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-22T20:29:32.254Z,1421958572.254 [CBIT] Loaded
2015-01-22T20:29:32.254Z,1421958572.254 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-22T20:29:32.255Z,1421958572.255 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-22T20:29:32.255Z,1421958572.255 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-22T20:29:32.274Z,1421958572.274 [DepthRateCalculator] Loaded
2015-01-22T20:29:32.274Z,1421958572.274 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-22T20:29:32.279Z,1421958572.279 [PitchRateCalculator] Loaded
2015-01-22T20:29:32.280Z,1421958572.280 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-22T20:29:32.291Z,1421958572.291 [SpeedCalculator] Loaded
2015-01-22T20:29:32.291Z,1421958572.291 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-22T20:29:32.308Z,1421958572.308 [TempGradientCalculator] Loaded
2015-01-22T20:29:32.308Z,1421958572.308 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-22T20:29:32.314Z,1421958572.314 [YawRateCalculator] Loaded
2015-01-22T20:29:32.314Z,1421958572.314 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-22T20:29:32.314Z,1421958572.314 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-22T20:29:32.315Z,1421958572.315 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-22T20:29:32.365Z,1421958572.365 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-22T20:29:32.366Z,1421958572.366 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-22T20:29:32.602Z,1421958572.602 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-22T20:29:32.603Z,1421958572.603 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-22T20:29:32.646Z,1421958572.646 [NavChart] Loaded
2015-01-22T20:29:32.647Z,1421958572.647 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-22T20:29:32.653Z,1421958572.653 [UniversalFixResidualReporter] Loaded
2015-01-22T20:29:32.653Z,1421958572.653 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-22T20:29:32.654Z,1421958572.654 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-22T20:29:32.654Z,1421958572.654 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-22T20:29:32.660Z,1421958572.660 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-22T20:29:32.661Z,1421958572.661 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-22T20:29:32.747Z,1421958572.747 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-22T20:29:32.747Z,1421958572.747 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-22T20:29:33.056Z,1421958573.056 [DataOverHttps] Loaded
2015-01-22T20:29:33.056Z,1421958573.056 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-22T20:29:33.138Z,1421958573.138 [Depth_Keller] Loaded
2015-01-22T20:29:33.138Z,1421958573.138 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-22T20:29:33.233Z,1421958573.233 [NAL9602] Loaded
2015-01-22T20:29:33.234Z,1421958573.234 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-22T20:29:33.275Z,1421958573.275 [Onboard] Loaded
2015-01-22T20:29:33.276Z,1421958573.276 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-22T20:29:33.282Z,1421958573.282 [Radio_Surface] Loaded
2015-01-22T20:29:33.283Z,1421958573.283 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-22T20:29:33.284Z,1421958573.284 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-22T20:29:33.284Z,1421958573.284 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1283
2015-01-22T20:29:35.129Z,1421958575.129 [BPC1] Loaded
2015-01-22T20:29:35.129Z,1421958575.129 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-22T20:29:35.129Z,1421958575.129 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-22T20:29:35.130Z,1421958575.130 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-22T20:29:35.248Z,1421958575.248 [BuoyancyServo] Loaded
2015-01-22T20:29:35.249Z,1421958575.249 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-22T20:29:35.261Z,1421958575.261 [ElevatorServo] Loaded
2015-01-22T20:29:35.261Z,1421958575.261 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-22T20:29:35.273Z,1421958575.273 [RudderServo] Loaded
2015-01-22T20:29:35.273Z,1421958575.273 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-22T20:29:35.284Z,1421958575.284 [ThrusterServo] Loaded
2015-01-22T20:29:35.285Z,1421958575.285 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-22T20:29:35.285Z,1421958575.285 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-22T20:29:35.286Z,1421958575.286 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-22T20:29:35.386Z,1421958575.386 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-22T20:29:35.387Z,1421958575.387 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-22T20:29:35.411Z,1421958575.411 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-22T20:29:35.413Z,1421958575.413 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-22T20:29:35.414Z,1421958575.414 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-22T20:29:35.420Z,1421958575.420 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-22T20:29:35.421Z,1421958575.421 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-22T20:29:35.422Z,1421958575.422 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1284
2015-01-22T20:29:35.427Z,1421958575.427 [Supervisor](INFO): Main Thread ID is 1197
2015-01-22T20:29:35.427Z,1421958575.427 [Supervisor](DEBUG): Running supervisor.
2015-01-22T20:29:35.428Z,1421958575.428 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1285
2015-01-22T20:29:35.430Z,1421958575.430 [controlThread ThreadHandler](INFO): Handler Thread ID is 1286
2015-01-22T20:29:35.431Z,1421958575.431 [controlThread](DEBUG): Initializing ControlThread
2015-01-22T20:29:35.432Z,1421958575.432 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-22T20:29:35.433Z,1421958575.433 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-22T20:29:35.434Z,1421958575.434 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-22T20:29:35.434Z,1421958575.434 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-22T20:29:35.435Z,1421958575.435 [SBIT](INFO): Initialize SBIT Component.
2015-01-22T20:29:35.435Z,1421958575.435 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-22T20:29:35.436Z,1421958575.436 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-22T20:29:35.436Z,1421958575.436 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-22T20:29:35.436Z,1421958575.436 [IBIT](INFO): Initialize IBIT Component.
2015-01-22T20:29:35.437Z,1421958575.437 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-22T20:29:35.437Z,1421958575.437 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-22T20:29:35.438Z,1421958575.438 [logger ThreadHandler](INFO): Handler Thread ID is 1287
2015-01-22T20:29:35.459Z,1421958575.459 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1288
2015-01-22T20:29:35.463Z,1421958575.463 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T20:29:35.463Z,1421958575.463 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-22T20:29:35.463Z,1421958575.463 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-22T20:29:35.464Z,1421958575.464 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-22T20:29:35.464Z,1421958575.464 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-22T20:29:35.464Z,1421958575.464 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-22T20:29:35.465Z,1421958575.465 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-22T20:29:35.471Z,1421958575.471 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-22T20:29:35.473Z,1421958575.473 [Radio_Surface](INFO): Powering up
2015-01-22T20:29:35.479Z,1421958575.479 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1289
2015-01-22T20:29:35.482Z,1421958575.482 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-22T20:29:35.483Z,1421958575.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-22T20:29:35.483Z,1421958575.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-22T20:29:35.483Z,1421958575.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-22T20:29:35.483Z,1421958575.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-22T20:29:35.484Z,1421958575.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-22T20:29:35.484Z,1421958575.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-22T20:29:35.484Z,1421958575.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-22T20:29:35.484Z,1421958575.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-22T20:29:52.971Z,1421958592.971 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T20:29:52.980Z,1421958592.980 [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-22T20:29:52.981Z,1421958592.981 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-22T20:29:53.071Z,1421958593.071 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-22T20:29:53.074Z,1421958593.074 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-22T20:29:53.091Z,1421958593.091 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T20:29:53.099Z,1421958593.099 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-22T20:29:53.137Z,1421958593.137 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-22T20:29:53.162Z,1421958593.162 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-22T20:29:53.184Z,1421958593.184 [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-22T20:29:53.188Z,1421958593.188 [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-22T20:29:53.343Z,1421958593.343 [NAL9602](INFO): Start
2015-01-22T20:29:53.343Z,1421958593.343 [NAL9602](INFO): Powering up NAL9602
2015-01-22T20:29:53.667Z,1421958593.667 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:29:53.675Z,1421958593.675 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-22T20:29:53.681Z,1421958593.681 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:29:53.707Z,1421958593.707 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-22T20:29:53.713Z,1421958593.713 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:29:53.719Z,1421958593.719 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-22T20:29:53.725Z,1421958593.725 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:29:53.731Z,1421958593.731 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-22T20:29:53.985Z,1421958593.985 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-22T20:29:53.988Z,1421958593.988 [CBIT](IMPORTANT): Beginning GF scan
2015-01-22T20:30:01.475Z,1421958601.475 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003800
2015-01-22T20:30:04.277Z,1421958604.277 [NAL9602](INFO): ************** CMDMODE **************

2015-01-22T20:30:04.277Z,1421958604.277 [NAL9602](INFO): NAL9602 initialized
2015-01-22T20:30:07.262Z,1421958607.262 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:30:21.608Z,1421958621.608 [CBIT](FAULT): Chan 4 High side GF detected
mA:
CHAN 5 (24V): 0.391695
CHAN 4 (Batt): 0.000957
CHAN 2 (12V): 0.000478
CHAN 1 (5V): 0.000383
CHAN 0 (3.3V): 0.003061
OPEN: 0.007174
Full Scale Calc: 0.392
2015-01-22T20:30:33.973Z,1421958633.973 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:30:33.973Z,1421958633.973 [SBIT](FAULT): Control surface position failure.
2015-01-22T20:30:47.501Z,1421958647.501 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:30:47.501Z,1421958647.501 [SBIT](FAULT): Control surface position failure.
2015-01-22T20:30:47.895Z,1421958647.895 [SBIT](CRITICAL): SBIT FAILED
2015-01-22T20:30:47.896Z,1421958647.896 [CommandLine](FAULT): Scheduling is paused
2015-01-22T20:30:48.291Z,1421958648.291 [MissionManager](IMPORTANT): Started mission Startup
2015-01-22T20:30:48.291Z,1421958648.291 [Startup] Running Loop=1
2015-01-22T20:30:48.291Z,1421958648.291 [Startup](INFO): Aggregate::initialize Startup
2015-01-22T20:30:48.292Z,1421958648.292 [Startup:A.GoToSurface] Running Loop=1
2015-01-22T20:30:48.292Z,1421958648.292 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-22T20:30:48.292Z,1421958648.292 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-22T20:30:48.293Z,1421958648.293 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-22T20:30:48.293Z,1421958648.293 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-22T20:30:48.299Z,1421958648.299 [Startup:StartupSatComms] Running Loop=1
2015-01-22T20:30:48.299Z,1421958648.299 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-22T20:30:48.299Z,1421958648.299 [Startup:StartupSatComms:A] Running Loop=1
2015-01-22T20:30:48.761Z,1421958648.761 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-22T20:31:48.375Z,1421958708.375 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-22T20:30:48.3Z
2015-01-22T20:31:48.375Z,1421958708.375 [Startup:StartupSatComms:A] Stopped
2015-01-22T20:31:48.375Z,1421958708.375 [Startup:StartupSatComms:B] Running Loop=1
2015-01-22T20:31:48.763Z,1421958708.763 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-22T20:31:53.144Z,1421958713.144 [DataOverHttps](INFO): Sending 57 bytes from file Logs/20150122T201610/Courier0012.lzma
2015-01-22T20:31:53.943Z,1421958713.943 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Courier0012.lzma.bak
2015-01-22T20:31:53.943Z,1421958713.943 [DataOverHttps](INFO): SBD MOMSN=1503928
2015-01-22T20:32:03.660Z,1421958723.660 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150122T202926/Courier0000.lzma
2015-01-22T20:32:04.459Z,1421958724.459 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Courier0000.lzma.bak
2015-01-22T20:32:04.459Z,1421958724.459 [DataOverHttps](INFO): SBD MOMSN=1503931
2015-01-22T20:32:14.140Z,1421958734.140 [DataOverHttps](INFO): Sending 124 bytes from file Logs/20150122T201610/Express0013.lzma
2015-01-22T20:32:14.939Z,1421958734.939 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Express0013.lzma.bak
2015-01-22T20:32:14.939Z,1421958734.939 [DataOverHttps](INFO): SBD MOMSN=1503935
2015-01-22T20:32:24.664Z,1421958744.664 [DataOverHttps](INFO): Sending 599 bytes from file Logs/20150122T202926/Express0001.lzma
2015-01-22T20:32:26.145Z,1421958746.145 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Express0001.lzma.bak
2015-01-22T20:32:26.145Z,1421958746.145 [DataOverHttps](INFO): SBD MOMSN=1503948
2015-01-22T20:32:26.564Z,1421958746.564 [Startup:StartupSatComms:B] Stopped
2015-01-22T20:32:26.565Z,1421958746.565 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-22T20:32:26.565Z,1421958746.565 [Startup:StartupSatComms] Stopped
2015-01-22T20:32:26.565Z,1421958746.565 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-22T20:32:26.566Z,1421958746.566 [Startup](INFO): Completed Startup
2015-01-22T20:32:26.566Z,1421958746.566 [Startup] Stopped
2015-01-22T20:32:26.566Z,1421958746.566 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-22T20:32:26.566Z,1421958746.566 [Startup:A.GoToSurface] Stopped
2015-01-22T20:32:26.566Z,1421958746.566 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-22T20:32:26.696Z,1421958746.696 [MissionManager](IMPORTANT): Started mission Default
2015-01-22T20:32:26.696Z,1421958746.696 [Default] Running Loop=1
2015-01-22T20:32:26.697Z,1421958746.697 [Default](INFO): Aggregate::initialize Default
2015-01-22T20:32:26.697Z,1421958746.697 [Default:B.GoToSurface] Running Loop=1
2015-01-22T20:32:26.697Z,1421958746.697 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-22T20:32:26.697Z,1421958746.697 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-22T20:32:26.697Z,1421958746.697 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-22T20:32:26.698Z,1421958746.698 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-22T20:32:26.698Z,1421958746.698 [Default:StartClock] Running Loop=1
2015-01-22T20:32:26.698Z,1421958746.698 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-22T20:32:26.698Z,1421958746.698 [Default:StartClock:A] Running Loop=1
2015-01-22T20:32:26.726Z,1421958746.726 [Default:StartClock:A] Stopped
2015-01-22T20:32:26.726Z,1421958746.726 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-22T20:32:26.726Z,1421958746.726 [Default:StartClock] Stopped
2015-01-22T20:32:26.727Z,1421958746.727 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-22T20:32:29.861Z,1421958749.861 [Default:WaitAtTheSurface] Running Loop=1
2015-01-22T20:32:29.861Z,1421958749.861 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-22T20:32:29.861Z,1421958749.861 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-22T20:32:29.861Z,1421958749.861 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-22T20:32:29.951Z,1421958749.951 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-22T20:33:59.906Z,1421958839.906 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5E%57
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B8A,09,3C3D,0A,0000,0B,0005%4E
$B11,0C,0001,0D,0064,0E,005B,0F,15E0,10,1641,11,FFFF,12,FFFF%43
$B11,13,048C,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%30
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B93,09,3D20,0A,FFFB,0B,0004%49
$B12,0C,0001,0D,0055,0E,0053,0F,140D,10,17B2,11,F09C,12,FFFF%4B
$B12,13,36AB,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B96,09,3D1F,0A,FFFC,0B,0003%3E
$B13,0C,0001,0D,005F,0E,0051,0F,1366,10,16D7,11,FFFF,12,FFFF%46
$B13,13,44D4,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%33
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B94,09,3D20,0A,FFFC,0B,0003%4E
$B14,0C,0001,0D,0055,0E,004F,0F,130E,10,168C,11,FFFF,12,FFFF%39
$B14,13,45D8,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%39
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B97,09,3C2A,0A,0000,0B,0004%38
$B15,0C,0001,0D,0064,0E,005B,0F,15FF,10,16B6,11,FFFF,12,FFFF%43
$B15,13,0AB9,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%42
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B8F,09,3C32,0A,0000,0B,0001%3C
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,0000,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4B
$B16,1A,0031,1B,4357,1C,00B9%48
$B17,02,000A,01,026C,03,0001,08,0B92,09,3C2D,0A,0000,0B,0004%3A
$B17,0C,0001,0D,0064,0E,005F,0F,16D3,10,1701,11,FFFF,12,FFFF%45
$B17,13,02B2,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%38
$B17,1A,0031,1B,4357,1C,00A5%46
0B85,09,3C1E,0A,0000,0B,0000%3A
$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
4357,1C,0098%33
$B18,02,000A,01,026C,03,0001,08,0B92,09,3CF0,0A,0000,0B,0000%31
$B18,0C,0001,0D,0054,0E,004C,0F,1266,10,1692,11,FFFF,12,FFFF%35
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00B3%4C

2015-01-22T20:33:59.906Z,1421958839.906 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:33:59.906Z,1421958839.906 [BPC1] Data Fault, FailCount= 1
2015-01-22T20:33:59.906Z,1421958839.906 [BPC1](ERROR): Data Fault
2015-01-22T20:33:59.922Z,1421958839.922 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:34:14.905Z,1421958854.905 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:34:14.905Z,1421958854.905 [BPC1] No Fault, FailCount= 1
2015-01-22T20:34:34.891Z,1421958874.891 [BPC1](ERROR): Failed to parse message.
2015-01-22T20:34:34.891Z,1421958874.891 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:34:34.891Z,1421958874.891 [BPC1] Data Fault, FailCount= 2
2015-01-22T20:34:34.891Z,1421958874.891 [BPC1](ERROR): Data Fault
2015-01-22T20:34:34.907Z,1421958874.907 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:34:49.920Z,1421958889.920 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:34:49.920Z,1421958889.920 [BPC1] No Fault, FailCount= 2
2015-01-22T20:34:54.952Z,1421958894.952 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-22T20:34:54.952Z,1421958894.952 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:34:54.952Z,1421958894.952 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-22T20:34:54.954Z,1421958894.954 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-22T20:34:54.954Z,1421958894.954 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-22T20:34:59.944Z,1421958899.944 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 2.470705 min 
2015-01-22T20:34:59.946Z,1421958899.946 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-22T20:34:59.946Z,1421958899.946 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:34:59.946Z,1421958899.946 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-22T20:34:59.946Z,1421958899.946 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:35:09.876Z,1421958909.876 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-22T20:35:24.885Z,1421958924.885 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:35:24.886Z,1421958924.886 [NAL9602](IMPORTANT): GPS fix at: 1421958918.00
2015-01-22T20:35:49.891Z,1421958949.891 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:35:49.892Z,1421958949.892 [NAL9602](IMPORTANT): GPS fix at: 1421958943.00
2015-01-22T20:36:14.889Z,1421958974.889 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:36:14.889Z,1421958974.889 [NAL9602](IMPORTANT): GPS fix at: 1421958969.00
2015-01-22T20:36:39.883Z,1421958999.883 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:36:39.883Z,1421958999.883 [NAL9602](IMPORTANT): GPS fix at: 1421958994.00
2015-01-22T20:37:04.882Z,1421959024.882 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:04.883Z,1421959024.883 [NAL9602](IMPORTANT): GPS fix at: 1421959019.00
2015-01-22T20:37:04.948Z,1421959024.948 [BPC1](DEBUG): Received data from all battery sticks
2015-01-22T20:37:29.885Z,1421959049.885 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:29.885Z,1421959049.885 [NAL9602](IMPORTANT): GPS fix at: 1421959044.00
2015-01-22T20:37:29.924Z,1421959049.924 [Default:CheckIn] Running Loop=1
2015-01-22T20:37:29.924Z,1421959049.924 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-22T20:37:29.924Z,1421959049.924 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:37:29.924Z,1421959049.924 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-22T20:37:29.924Z,1421959049.924 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-22T20:37:29.925Z,1421959049.925 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-22T20:37:29.927Z,1421959049.927 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:37:32.681Z,1421959052.681 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:32.681Z,1421959052.681 [NAL9602](IMPORTANT): GPS fix at: 1421959052.00
2015-01-22T20:37:32.724Z,1421959052.724 [Default:CheckIn:Read_GPS] Stopped
2015-01-22T20:37:32.724Z,1421959052.724 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-22T20:37:33.110Z,1421959053.110 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-22T20:37:37.580Z,1421959057.580 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20150122T202926/Courier0004.lzma
2015-01-22T20:37:37.985Z,1421959057.985 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:37.986Z,1421959057.986 [NAL9602](IMPORTANT): GPS fix at: 1421959057.00
2015-01-22T20:37:38.374Z,1421959058.374 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Courier0004.lzma.bak
2015-01-22T20:37:38.374Z,1421959058.374 [DataOverHttps](INFO): SBD MOMSN=1503961
2015-01-22T20:37:43.306Z,1421959063.306 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:43.306Z,1421959063.306 [NAL9602](IMPORTANT): GPS fix at: 1421959062.00
2015-01-22T20:37:47.802Z,1421959067.802 [DataOverHttps](INFO): Sending 407 bytes from file Logs/20150122T202926/Express0005.lzma
2015-01-22T20:37:48.209Z,1421959068.209 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:48.210Z,1421959068.210 [NAL9602](IMPORTANT): GPS fix at: 1421959067.00
2015-01-22T20:37:48.600Z,1421959068.600 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Express0005.lzma.bak
2015-01-22T20:37:48.600Z,1421959068.600 [DataOverHttps](INFO): SBD MOMSN=1503964
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn:Read_Iridium] Stopped
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn] Stopped
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-22T20:37:49.317Z,1421959069.317 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:37:59.407Z,1421959079.407 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:37:59.407Z,1421959079.407 [NAL9602](IMPORTANT): GPS fix at: 1421959077.00
2015-01-22T20:38:24.406Z,1421959104.406 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:38:24.406Z,1421959104.406 [NAL9602](IMPORTANT): GPS fix at: 1421959099.00
2015-01-22T20:38:49.408Z,1421959129.408 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:38:49.409Z,1421959129.409 [NAL9602](IMPORTANT): GPS fix at: 1421959124.00
2015-01-22T20:39:14.411Z,1421959154.411 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:39:14.412Z,1421959154.412 [NAL9602](IMPORTANT): GPS fix at: 1421959149.00
2015-01-22T20:39:39.406Z,1421959179.406 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:39:39.407Z,1421959179.407 [NAL9602](IMPORTANT): GPS fix at: 1421959174.00
2015-01-22T20:40:02.280Z,1421959202.280 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-22T20:40:02.280Z,1421959202.280 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:40:02.280Z,1421959202.280 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-22T20:40:02.281Z,1421959202.281 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-22T20:40:02.281Z,1421959202.281 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-22T20:40:04.405Z,1421959204.405 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:40:04.406Z,1421959204.406 [NAL9602](IMPORTANT): GPS fix at: 1421959202.00
2015-01-22T20:40:04.421Z,1421959204.421 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 7.546069 min 
2015-01-22T20:40:04.421Z,1421959204.421 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-22T20:40:04.421Z,1421959204.421 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:40:04.422Z,1421959204.422 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-22T20:40:04.422Z,1421959204.422 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:40:29.406Z,1421959229.406 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:40:29.407Z,1421959229.407 [NAL9602](IMPORTANT): GPS fix at: 1421959224.00
2015-01-22T20:40:54.411Z,1421959254.411 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:40:54.411Z,1421959254.411 [NAL9602](IMPORTANT): GPS fix at: 1421959249.00
2015-01-22T20:41:19.408Z,1421959279.408 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:41:19.408Z,1421959279.408 [NAL9602](IMPORTANT): GPS fix at: 1421959274.00
2015-01-22T20:41:44.404Z,1421959304.404 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:41:44.405Z,1421959304.405 [NAL9602](IMPORTANT): GPS fix at: 1421959299.00
2015-01-22T20:42:09.413Z,1421959329.413 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:42:09.413Z,1421959329.413 [NAL9602](IMPORTANT): GPS fix at: 1421959327.00
2015-01-22T20:42:34.411Z,1421959354.411 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:42:34.411Z,1421959354.411 [NAL9602](IMPORTANT): GPS fix at: 1421959349.00
2015-01-22T20:42:49.454Z,1421959369.454 [Default:CheckIn] Running Loop=1
2015-01-22T20:42:49.454Z,1421959369.454 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-22T20:42:49.454Z,1421959369.454 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:42:49.454Z,1421959369.454 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-22T20:42:49.455Z,1421959369.455 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-22T20:42:50.203Z,1421959370.203 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:42:50.203Z,1421959370.203 [NAL9602](IMPORTANT): GPS fix at: 1421959369.00
2015-01-22T20:42:50.268Z,1421959370.268 [Default:CheckIn:Read_GPS] Stopped
2015-01-22T20:42:50.268Z,1421959370.268 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-22T20:42:55.042Z,1421959375.042 [DataOverHttps](INFO): Sending 57 bytes from file Logs/20150122T202926/Courier0008.lzma
2015-01-22T20:42:55.051Z,1421959375.051 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:42:55.052Z,1421959375.052 [NAL9602](IMPORTANT): GPS fix at: 1421959374.00
2015-01-22T20:42:55.836Z,1421959375.836 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Courier0008.lzma.bak
2015-01-22T20:42:55.836Z,1421959375.836 [DataOverHttps](INFO): SBD MOMSN=1503985
2015-01-22T20:43:00.857Z,1421959380.857 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:43:00.857Z,1421959380.857 [NAL9602](IMPORTANT): GPS fix at: 1421959377.00
2015-01-22T20:43:06.195Z,1421959386.195 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20150122T202926/Express0009.lzma
2015-01-22T20:43:06.240Z,1421959386.240 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:43:06.240Z,1421959386.240 [NAL9602](IMPORTANT): GPS fix at: 1421959385.00
2015-01-22T20:43:06.986Z,1421959386.986 [DataOverHttps](INFO): Moved sent file to Logs/20150122T202926/Express0009.lzma.bak
2015-01-22T20:43:06.986Z,1421959386.986 [DataOverHttps](INFO): SBD MOMSN=1503988
2015-01-22T20:43:07.742Z,1421959387.742 [Default:CheckIn:Read_Iridium] Stopped
2015-01-22T20:43:07.743Z,1421959387.743 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-22T20:43:07.743Z,1421959387.743 [Default:CheckIn] Stopped
2015-01-22T20:43:07.743Z,1421959387.743 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-22T20:43:07.743Z,1421959387.743 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-22T20:43:07.743Z,1421959387.743 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:43:17.798Z,1421959397.798 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:43:17.798Z,1421959397.798 [NAL9602](IMPORTANT): GPS fix at: 1421959395.00
2015-01-22T20:43:32.797Z,1421959412.797 [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,FFFC%35
$B13,0A,FFFC%34
$B14,0A,FFFC%33
$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,0B9E,09,3D37,0A,FFFD,0B,FFFD%3A
$B11,0C,0001,0D,005A,0E,0054,0F,1458,10,173A,11,FFFF,12,FFFF%4C
$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,0B8D,09,3D35,0A,FFFC,0B,FFFC%3A
$B13,0C,0001,0D,0063,0E,0054,0F,144D,10,16AE,11,FFFF,12,FFFF%35
$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,0B94,09,3D32,0A,FFFC,0B,FFFC%4B
$B14,0C,0001,0D,0057,0E,0051,0F,1371,10,1688,11,FFFF,12,FFFF%45
$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,0B99,09,3C28,0A,0000,0B,0000%4B
$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,0B8B,09,3D2E,0A,0000,0B,0000%48
$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,0B85,09,3C1F,0A,0000,0B,0000%39
$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
4357,1C,0098%33
$B18,02,000A,01,026C,03,0001,08,0B92,09,3CF1,0A,0000,0B,0000%30
$B18,0C,0001,0D,0054,0E,004C,0F,1266,10,1692,11,FFFF,12,FFFF%35
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00B3%4C

2015-01-22T20:43:32.797Z,1421959412.797 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:43:32.797Z,1421959412.797 [BPC1] Data Fault, FailCount= 1
2015-01-22T20:43:32.797Z,1421959412.797 [BPC1](ERROR): Data Fault
2015-01-22T20:43:32.812Z,1421959412.812 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:43:42.789Z,1421959422.789 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:43:42.789Z,1421959422.789 [NAL9602](IMPORTANT): GPS fix at: 1421959417.00
2015-01-22T20:43:47.825Z,1421959427.825 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:43:47.825Z,1421959427.825 [BPC1] No Fault, FailCount= 1
2015-01-22T20:44:07.796Z,1421959447.796 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:44:07.796Z,1421959447.796 [NAL9602](IMPORTANT): GPS fix at: 1421959442.00
2015-01-22T20:44:07.803Z,1421959447.803 [BPC1](ERROR): Failed to parse message.
2015-01-22T20:44:07.803Z,1421959447.803 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:44:07.803Z,1421959447.803 [BPC1] Data Fault, FailCount= 2
2015-01-22T20:44:07.803Z,1421959447.803 [BPC1](ERROR): Data Fault
2015-01-22T20:44:07.819Z,1421959447.819 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:44:22.815Z,1421959462.815 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:44:22.815Z,1421959462.815 [BPC1] No Fault, FailCount= 2
2015-01-22T20:44:32.803Z,1421959472.803 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:44:32.803Z,1421959472.803 [NAL9602](IMPORTANT): GPS fix at: 1421959467.00
2015-01-22T20:44:42.805Z,1421959482.805 [BPC1](ERROR): Failed to parse message.
2015-01-22T20:44:42.805Z,1421959482.805 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:44:42.805Z,1421959482.805 [BPC1] Data Fault, FailCount= 3
2015-01-22T20:44:42.805Z,1421959482.805 [BPC1](ERROR): Data Fault
2015-01-22T20:44:42.821Z,1421959482.821 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:44:57.796Z,1421959497.796 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:44:57.796Z,1421959497.796 [NAL9602](IMPORTANT): GPS fix at: 1421959492.00
2015-01-22T20:44:57.816Z,1421959497.816 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:44:57.817Z,1421959497.817 [BPC1] No Fault, FailCount= 3
2015-01-22T20:45:02.862Z,1421959502.862 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-22T20:45:02.862Z,1421959502.862 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:45:02.862Z,1421959502.862 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-22T20:45:02.863Z,1421959502.863 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-22T20:45:02.863Z,1421959502.863 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-22T20:45:07.838Z,1421959507.838 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 12.602534 min 
2015-01-22T20:45:07.838Z,1421959507.838 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-22T20:45:07.838Z,1421959507.838 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:45:07.838Z,1421959507.838 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-22T20:45:07.838Z,1421959507.838 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:45:25.586Z,1421959525.586 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:45:25.586Z,1421959525.586 [NAL9602](IMPORTANT): GPS fix at: 1421959517.00
2015-01-22T20:45:25.592Z,1421959525.592 [BPC1](FAULT): Failed to receive battery data
2015-01-22T20:45:25.593Z,1421959525.593 [BPC1] Communications Fault, FailCount= 4
2015-01-22T20:45:25.593Z,1421959525.593 [BPC1](ERROR): Communications Fault
2015-01-22T20:45:25.667Z,1421959525.667 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T20:45:37.823Z,1421959537.823 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:45:37.823Z,1421959537.823 [BPC1] No Fault, FailCount= 4
2015-01-22T20:45:47.787Z,1421959547.787 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:45:47.788Z,1421959547.788 [NAL9602](IMPORTANT): GPS fix at: 1421959542.00
2015-01-22T20:46:12.794Z,1421959572.794 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:46:12.795Z,1421959572.795 [NAL9602](IMPORTANT): GPS fix at: 1421959567.00
2015-01-22T20:46:37.793Z,1421959597.793 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:46:37.793Z,1421959597.793 [NAL9602](IMPORTANT): GPS fix at: 1421959592.00
2015-01-22T20:47:02.792Z,1421959622.792 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:47:02.792Z,1421959622.792 [NAL9602](IMPORTANT): GPS fix at: 1421959617.00
2015-01-22T20:47:07.826Z,1421959627.826 [CommandLine](IMPORTANT): got command quit
2015-01-22T20:47:08.840Z,1421959628.840 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:47:08.840Z,1421959628.840 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.017Z,1421959629.017 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-22T20:47:09.017Z,1421959629.017 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.018Z,1421959629.018 [CommandLine](INFO): Join timeout helper Thread ID is 1303
2015-01-22T20:47:09.019Z,1421959629.019 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-22T20:47:09.019Z,1421959629.019 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.019Z,1421959629.019 [NavChartDb](INFO): Join timeout helper Thread ID is 1304
2015-01-22T20:47:09.278Z,1421959629.278 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:47:09.278Z,1421959629.278 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.282Z,1421959629.282 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-22T20:47:09.282Z,1421959629.282 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.283Z,1421959629.283 [Radio_Surface](INFO): Join timeout helper Thread ID is 1305
2015-01-22T20:47:09.390Z,1421959629.390 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:47:09.391Z,1421959629.391 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.402Z,1421959629.402 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-22T20:47:09.402Z,1421959629.402 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.402Z,1421959629.402 [logger](INFO): Join timeout helper Thread ID is 1306
2015-01-22T20:47:09.426Z,1421959629.426 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:47:09.426Z,1421959629.426 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.442Z,1421959629.442 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-22T20:47:09.442Z,1421959629.442 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.443Z,1421959629.443 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-22T20:47:09.443Z,1421959629.443 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:09.443Z,1421959629.443 [controlThread](INFO): Join timeout helper Thread ID is 1307
2015-01-22T20:47:12.779Z,1421959632.779 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:47:12.780Z,1421959632.780 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-22T20:47:12.781Z,1421959632.781 [NAL9602](INFO): Uninitialize
2015-01-22T20:47:12.781Z,1421959632.781 [NAL9602](INFO): Powering down
2015-01-22T20:47:12.784Z,1421959632.784 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T20:47:12.784Z,1421959632.784 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-22T20:47:12.785Z,1421959632.785 [Default] Stopped
2015-01-22T20:47:12.785Z,1421959632.785 [Default](INFO): Aggregate::uninitialize Default
2015-01-22T20:47:12.785Z,1421959632.785 [Default:B.GoToSurface] Stopped
2015-01-22T20:47:12.785Z,1421959632.785 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-22T20:47:12.785Z,1421959632.785 [Default:WaitAtTheSurface] Stopped
2015-01-22T20:47:12.785Z,1421959632.785 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-01-22T20:47:12.786Z,1421959632.786 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-01-22T20:47:12.786Z,1421959632.786 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:47:12.789Z,1421959632.789 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-22T20:47:12.789Z,1421959632.789 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-22T20:47:12.789Z,1421959632.789 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-22T20:47:12.790Z,1421959632.790 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-22T20:47:12.790Z,1421959632.790 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-22T20:47:12.790Z,1421959632.790 [BuoyancyServo](INFO): Powering down
2015-01-22T20:47:12.808Z,1421959632.808 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-22T20:47:12.808Z,1421959632.808 [ElevatorServo](INFO): Powering down
2015-01-22T20:47:12.809Z,1421959632.809 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-22T20:47:12.809Z,1421959632.809 [RudderServo](INFO): Powering down
2015-01-22T20:47:12.809Z,1421959632.809 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-22T20:47:12.810Z,1421959632.810 [ThrusterServo](INFO): Powering down
2015-01-22T20:47:12.810Z,1421959632.810 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-22T20:47:12.811Z,1421959632.811 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-22T20:47:12.811Z,1421959632.811 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-22T20:47:12.844Z,1421959632.844 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:12.994Z,1421959632.994 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:13.043Z,1421959633.043 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:47:13.130Z,1421959633.130 [logger ThreadHandler](INFO): Thread cancelled.