2015-01-22T20:16:10.594Z,1421957770.594 [Supervisor](DEBUG): Initializing supervisor.
2015-01-22T20:16:10.596Z,1421957770.596 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-22T20:16:10.597Z,1421957770.597 [SyncHandler](INFO): Protected caller Thread ID is 1083
2015-01-22T20:16:10.597Z,1421957770.597 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-22T20:16:10.598Z,1421957770.598 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-22T20:16:10.599Z,1421957770.599 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1084
2015-01-22T20:16:10.601Z,1421957770.601 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-22T20:16:10.613Z,1421957770.613 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-22T20:16:10.614Z,1421957770.614 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-22T20:16:10.615Z,1421957770.615 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1085
2015-01-22T20:16:10.616Z,1421957770.616 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-22T20:16:10.616Z,1421957770.616 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-22T20:16:10.617Z,1421957770.617 [logger ThreadHandler](INFO): Protected caller Thread ID is 1086
2015-01-22T20:16:10.619Z,1421957770.619 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-22T20:16:10.619Z,1421957770.619 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-22T20:16:10.621Z,1421957770.621 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-22T20:16:10.937Z,1421957770.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-22T20:16:10.937Z,1421957770.937 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-22T20:16:11.091Z,1421957771.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-22T20:16:11.091Z,1421957771.091 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-22T20:16:11.197Z,1421957771.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-22T20:16:11.197Z,1421957771.197 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-22T20:16:11.317Z,1421957771.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-22T20:16:11.317Z,1421957771.317 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-22T20:16:11.401Z,1421957771.401 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-22T20:16:11.557Z,1421957771.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-22T20:16:11.558Z,1421957771.558 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-22T20:16:11.642Z,1421957771.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-22T20:16:11.643Z,1421957771.643 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-22T20:16:11.845Z,1421957771.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-22T20:16:11.845Z,1421957771.845 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-22T20:16:12.206Z,1421957772.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-22T20:16:12.206Z,1421957772.206 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-22T20:16:12.512Z,1421957772.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-22T20:16:12.512Z,1421957772.512 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-22T20:16:13.012Z,1421957773.012 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-22T20:16:13.013Z,1421957773.013 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-22T20:16:13.200Z,1421957773.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-22T20:16:13.201Z,1421957773.201 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-22T20:16:13.303Z,1421957773.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-22T20:16:13.304Z,1421957773.304 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-22T20:16:13.718Z,1421957773.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-22T20:16:13.719Z,1421957773.719 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-22T20:16:13.829Z,1421957773.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-22T20:16:13.831Z,1421957773.831 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-22T20:16:13.832Z,1421957773.832 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-22T20:16:14.071Z,1421957774.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-22T20:16:14.071Z,1421957774.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-22T20:16:14.190Z,1421957774.190 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-22T20:16:14.286Z,1421957774.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-22T20:16:14.381Z,1421957774.381 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-22T20:16:14.493Z,1421957774.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-22T20:16:14.633Z,1421957774.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-22T20:16:14.803Z,1421957774.803 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-22T20:16:14.905Z,1421957774.905 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-22T20:16:14.993Z,1421957774.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-22T20:16:15.094Z,1421957775.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-22T20:16:15.192Z,1421957775.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-22T20:16:15.454Z,1421957775.454 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-22T20:16:15.468Z,1421957775.468 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-22T20:16:15.518Z,1421957775.518 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-22T20:16:15.634Z,1421957775.634 [VerticalControl] Loaded
2015-01-22T20:16:15.634Z,1421957775.634 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-22T20:16:15.635Z,1421957775.635 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-22T20:16:15.706Z,1421957775.706 [HorizontalControl] Loaded
2015-01-22T20:16:15.707Z,1421957775.707 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-22T20:16:15.707Z,1421957775.707 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-22T20:16:15.713Z,1421957775.713 [SpeedControl] Loaded
2015-01-22T20:16:15.713Z,1421957775.713 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-22T20:16:15.714Z,1421957775.714 [LoopControl](DEBUG): Construct LoopControl.
2015-01-22T20:16:15.714Z,1421957775.714 [LoopControl] Loaded
2015-01-22T20:16:15.715Z,1421957775.715 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-22T20:16:15.715Z,1421957775.715 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-22T20:16:15.716Z,1421957775.716 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-22T20:16:15.809Z,1421957775.809 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-22T20:16:15.821Z,1421957775.821 [SBIT] Loaded
2015-01-22T20:16:15.821Z,1421957775.821 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-22T20:16:15.822Z,1421957775.822 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-22T20:16:15.850Z,1421957775.850 [IBIT] Loaded
2015-01-22T20:16:15.850Z,1421957775.850 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-22T20:16:15.852Z,1421957775.852 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-22T20:16:15.970Z,1421957775.970 [CBIT] Loaded
2015-01-22T20:16:15.970Z,1421957775.970 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-22T20:16:15.971Z,1421957775.971 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-22T20:16:15.971Z,1421957775.971 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-22T20:16:15.989Z,1421957775.989 [DepthRateCalculator] Loaded
2015-01-22T20:16:15.990Z,1421957775.990 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-22T20:16:15.995Z,1421957775.995 [PitchRateCalculator] Loaded
2015-01-22T20:16:15.995Z,1421957775.995 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-22T20:16:16.007Z,1421957776.007 [SpeedCalculator] Loaded
2015-01-22T20:16:16.007Z,1421957776.007 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-22T20:16:16.024Z,1421957776.024 [TempGradientCalculator] Loaded
2015-01-22T20:16:16.024Z,1421957776.024 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-22T20:16:16.029Z,1421957776.029 [YawRateCalculator] Loaded
2015-01-22T20:16:16.029Z,1421957776.029 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-22T20:16:16.030Z,1421957776.030 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-22T20:16:16.030Z,1421957776.030 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-22T20:16:16.080Z,1421957776.080 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-22T20:16:16.080Z,1421957776.080 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-22T20:16:16.319Z,1421957776.319 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-22T20:16:16.320Z,1421957776.320 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-22T20:16:16.363Z,1421957776.363 [NavChart] Loaded
2015-01-22T20:16:16.363Z,1421957776.363 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-22T20:16:16.369Z,1421957776.369 [UniversalFixResidualReporter] Loaded
2015-01-22T20:16:16.370Z,1421957776.370 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-22T20:16:16.370Z,1421957776.370 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-22T20:16:16.371Z,1421957776.371 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-22T20:16:16.376Z,1421957776.376 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-22T20:16:16.377Z,1421957776.377 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-22T20:16:16.461Z,1421957776.461 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-22T20:16:16.462Z,1421957776.462 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-22T20:16:16.766Z,1421957776.766 [DataOverHttps] Loaded
2015-01-22T20:16:16.766Z,1421957776.766 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-22T20:16:16.847Z,1421957776.847 [Depth_Keller] Loaded
2015-01-22T20:16:16.847Z,1421957776.847 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-22T20:16:16.941Z,1421957776.941 [NAL9602] Loaded
2015-01-22T20:16:16.941Z,1421957776.941 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-22T20:16:16.982Z,1421957776.982 [Onboard] Loaded
2015-01-22T20:16:16.982Z,1421957776.982 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-22T20:16:16.989Z,1421957776.989 [Radio_Surface] Loaded
2015-01-22T20:16:16.989Z,1421957776.989 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-22T20:16:16.990Z,1421957776.990 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-22T20:16:16.991Z,1421957776.991 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1169
2015-01-22T20:16:18.837Z,1421957778.837 [BPC1] Loaded
2015-01-22T20:16:18.838Z,1421957778.838 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-22T20:16:18.838Z,1421957778.838 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-22T20:16:18.839Z,1421957778.839 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-22T20:16:18.935Z,1421957778.935 [BuoyancyServo] Loaded
2015-01-22T20:16:18.935Z,1421957778.935 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-22T20:16:18.947Z,1421957778.947 [ElevatorServo] Loaded
2015-01-22T20:16:18.947Z,1421957778.947 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-22T20:16:18.959Z,1421957778.959 [RudderServo] Loaded
2015-01-22T20:16:18.959Z,1421957778.959 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-22T20:16:18.971Z,1421957778.971 [ThrusterServo] Loaded
2015-01-22T20:16:18.971Z,1421957778.971 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-22T20:16:18.972Z,1421957778.972 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-22T20:16:18.972Z,1421957778.972 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-22T20:16:19.071Z,1421957779.071 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-22T20:16:19.071Z,1421957779.071 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-22T20:16:19.095Z,1421957779.095 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-22T20:16:19.097Z,1421957779.097 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-22T20:16:19.098Z,1421957779.098 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-22T20:16:19.104Z,1421957779.104 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-22T20:16:19.106Z,1421957779.106 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-22T20:16:19.106Z,1421957779.106 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1170
2015-01-22T20:16:19.111Z,1421957779.111 [Supervisor](INFO): Main Thread ID is 1082
2015-01-22T20:16:19.111Z,1421957779.111 [Supervisor](DEBUG): Running supervisor.
2015-01-22T20:16:19.112Z,1421957779.112 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1171
2015-01-22T20:16:19.116Z,1421957779.116 [controlThread ThreadHandler](INFO): Handler Thread ID is 1172
2015-01-22T20:16:19.116Z,1421957779.116 [controlThread](DEBUG): Initializing ControlThread
2015-01-22T20:16:19.117Z,1421957779.117 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-22T20:16:19.119Z,1421957779.119 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-22T20:16:19.119Z,1421957779.119 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-22T20:16:19.120Z,1421957779.120 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-22T20:16:19.120Z,1421957779.120 [SBIT](INFO): Initialize SBIT Component.
2015-01-22T20:16:19.121Z,1421957779.121 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-22T20:16:19.121Z,1421957779.121 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-22T20:16:19.121Z,1421957779.121 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-22T20:16:19.122Z,1421957779.122 [IBIT](INFO): Initialize IBIT Component.
2015-01-22T20:16:19.123Z,1421957779.123 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-22T20:16:19.123Z,1421957779.123 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-22T20:16:19.124Z,1421957779.124 [logger ThreadHandler](INFO): Handler Thread ID is 1173
2015-01-22T20:16:19.144Z,1421957779.144 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1174
2015-01-22T20:16:19.148Z,1421957779.148 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T20:16:19.148Z,1421957779.148 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-22T20:16:19.148Z,1421957779.148 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-22T20:16:19.149Z,1421957779.149 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-22T20:16:19.149Z,1421957779.149 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-22T20:16:19.150Z,1421957779.150 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-22T20:16:19.150Z,1421957779.150 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-22T20:16:19.156Z,1421957779.156 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-22T20:16:19.166Z,1421957779.166 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T20:16:19.168Z,1421957779.168 [Radio_Surface](INFO): Powering up
2015-01-22T20:16:19.172Z,1421957779.172 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1175
2015-01-22T20:16:19.175Z,1421957779.175 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-22T20:16:19.176Z,1421957779.176 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-22T20:16:19.176Z,1421957779.176 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-22T20:16:19.177Z,1421957779.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-22T20:16:19.177Z,1421957779.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-22T20:16:19.177Z,1421957779.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-22T20:16:19.178Z,1421957779.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-22T20:16:19.178Z,1421957779.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-22T20:16:19.178Z,1421957779.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-22T20:16:19.209Z,1421957779.209 [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:16:19.209Z,1421957779.209 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-22T20:16:19.293Z,1421957779.293 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-22T20:16:19.297Z,1421957779.297 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-22T20:16:19.321Z,1421957779.321 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-22T20:16:19.350Z,1421957779.350 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-22T20:16:19.355Z,1421957779.355 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-22T20:16:19.379Z,1421957779.379 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-22T20:16:19.441Z,1421957779.441 [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:16:19.452Z,1421957779.452 [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:16:19.583Z,1421957779.583 [NAL9602](INFO): Start
2015-01-22T20:16:20.018Z,1421957780.018 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:16:20.026Z,1421957780.026 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-22T20:16:20.040Z,1421957780.040 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:16:20.045Z,1421957780.045 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-22T20:16:20.067Z,1421957780.067 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:16:20.074Z,1421957780.074 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-22T20:16:20.087Z,1421957780.087 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-22T20:16:20.094Z,1421957780.094 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-22T20:16:20.261Z,1421957780.261 [NAL9602](INFO): Start
2015-01-22T20:16:29.528Z,1421957789.528 [NAL9602](INFO): Start
2015-01-22T20:16:29.528Z,1421957789.528 [NAL9602](INFO): Powering up NAL9602
2015-01-22T20:16:30.677Z,1421957790.677 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003400
2015-01-22T20:16:34.887Z,1421957794.887 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-22T20:16:34.897Z,1421957794.897 [CBIT](IMPORTANT): Beginning GF scan
2015-01-22T20:16:40.715Z,1421957800.715 [NAL9602](INFO): ************** CMDMODE **************

2015-01-22T20:16:40.715Z,1421957800.715 [NAL9602](INFO): NAL9602 initialized
2015-01-22T20:16:48.043Z,1421957808.043 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:17:01.242Z,1421957821.242 [CBIT](IMPORTANT): No ground fault detected
2015-01-22T20:17:14.448Z,1421957834.448 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:17:14.448Z,1421957834.448 [SBIT](FAULT): Control surface position failure.
2015-01-22T20:17:24.397Z,1421957844.397 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,60%21
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFA%36
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,60%21
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B98,09,3D29,0A,FFFC,0B,FFFD%4F
$B11,0C,0001,0D,005C,0E,0058,0F,153B,10,1787,11,FFFF,12,FFFF%42
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41
$B11,1A,0031,1B,4357,1C,00A7%42
$B12,02,000A,01,026C,03,0001,08,0B97,09,3C40,0A,0000,0B,0001%4D
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,0000,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4F
$B12,1A,0031,1B,4357,1C,009E%4B
$B13,02,000A,01,026C,03,0001,08,0B95,09,3D2C,0A,FFFB,0B,FFFC%3C
$B13,0C,0001,0D,0063,0E,0057,0F,14FA,10,17AC,11,FBB8,12,FFFF%38
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4357,1C,0089%37
$B14,02,000A,01,026C,03,0001,08,0B9A,09,3D2D,0A,FFFC,0B,FFFD%4E
$B14,0C,0001,0D,005B,0E,0056,0F,14C9,10,16F6,11,FFFF,12,FFFF%3C
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,00A6%46
$B15,02,000A,01,026C,03,0001,08,0B9B,09,3C2A,0A,0000,0B,0001%48
$B15,0C,0001,0D,0064,0E,005C,0F,162E,10,171F,11,FFFF,12,FFFF%34
$B15,13,387C,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%37
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B91,09,3D34,0A,0000,0B,0000%4A
$B16,0C,0001,0D,0063,0E,0059,0F,1556,10,1698,11,FFFF,12,FFFF%4A
$B16,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%45
$B16,1A,0031,1B,4357,1C,00A8%4A
$B17,02,000A,01,026C,03,0001,08,0B8C,09,3D30,0A,0000,0B,0000%3C
$B17,0C,0001,0D,005F,0E,0058,0F,153F,10,16E3,11,FFFF,12,FFFF%3D
$B17,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%44
$B17,1A,0031,1B,4357,1C,0096%3D
$B18,02,000A,01,026C,03,0001,08,0B93,09,3CDB,0A,0000,0B,0000%40
$B18,0C,0001,0D,005D,0E,0059,0F,1574,10,17CC,11,FFFF,12,FFFF%30
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,009B%46

2015-01-22T20:17:24.397Z,1421957844.397 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-22T20:17:24.397Z,1421957844.397 [BPC1] Data Fault, FailCount= 1
2015-01-22T20:17:24.398Z,1421957844.398 [BPC1](ERROR): Data Fault
2015-01-22T20:17:24.452Z,1421957844.452 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:17:25.602Z,1421957845.602 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:17:25.603Z,1421957845.603 [BPC1] No Fault, FailCount= 1
2015-01-22T20:17:28.013Z,1421957848.013 [SBIT](ERROR): Could not read massPosReader_.
2015-01-22T20:17:28.013Z,1421957848.013 [SBIT](FAULT): Control surface position failure.
2015-01-22T20:17:28.401Z,1421957848.401 [SBIT](CRITICAL): SBIT FAILED
2015-01-22T20:17:28.402Z,1421957848.402 [CommandLine](FAULT): Scheduling is paused
2015-01-22T20:17:28.811Z,1421957848.811 [MissionManager](IMPORTANT): Started mission Startup
2015-01-22T20:17:28.812Z,1421957848.812 [Startup] Running Loop=1
2015-01-22T20:17:28.812Z,1421957848.812 [Startup](INFO): Aggregate::initialize Startup
2015-01-22T20:17:28.812Z,1421957848.812 [Startup:A.GoToSurface] Running Loop=1
2015-01-22T20:17:28.812Z,1421957848.812 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-22T20:17:28.813Z,1421957848.813 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-22T20:17:28.813Z,1421957848.813 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-22T20:17:28.813Z,1421957848.813 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-22T20:17:28.819Z,1421957848.819 [Startup:StartupSatComms] Running Loop=1
2015-01-22T20:17:28.819Z,1421957848.819 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-22T20:17:28.819Z,1421957848.819 [Startup:StartupSatComms:A] Running Loop=1
2015-01-22T20:17:29.197Z,1421957849.197 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-22T20:18:28.949Z,1421957908.949 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-22T20:17:28.8Z
2015-01-22T20:18:28.949Z,1421957908.949 [Startup:StartupSatComms:A] Stopped
2015-01-22T20:18:28.949Z,1421957908.949 [Startup:StartupSatComms:B] Running Loop=1
2015-01-22T20:18:29.347Z,1421957909.347 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-22T20:18:33.769Z,1421957913.769 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20150122T200749/Courier0004.lzma
2015-01-22T20:18:34.568Z,1421957914.568 [DataOverHttps](INFO): Moved sent file to Logs/20150122T200749/Courier0004.lzma.bak
2015-01-22T20:18:34.568Z,1421957914.568 [DataOverHttps](INFO): SBD MOMSN=1503843
2015-01-22T20:18:44.252Z,1421957924.252 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150122T200749/Courier0008.lzma
2015-01-22T20:18:45.047Z,1421957925.047 [DataOverHttps](INFO): Moved sent file to Logs/20150122T200749/Courier0008.lzma.bak
2015-01-22T20:18:45.048Z,1421957925.048 [DataOverHttps](INFO): SBD MOMSN=1503846
2015-01-22T20:18:54.442Z,1421957934.442 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150122T201610/Courier0000.lzma
2015-01-22T20:18:55.235Z,1421957935.235 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Courier0000.lzma.bak
2015-01-22T20:18:55.235Z,1421957935.235 [DataOverHttps](INFO): SBD MOMSN=1503848
2015-01-22T20:19:04.945Z,1421957944.945 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20150122T200749/Express0005.lzma
2015-01-22T20:19:05.740Z,1421957945.740 [DataOverHttps](INFO): Moved sent file to Logs/20150122T200749/Express0005.lzma.bak
2015-01-22T20:19:05.740Z,1421957945.740 [DataOverHttps](INFO): SBD MOMSN=1503852
2015-01-22T20:19:19.460Z,1421957959.460 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20150122T200749/Express0009.lzma
2015-01-22T20:19:20.333Z,1421957960.333 [DataOverHttps](INFO): Moved sent file to Logs/20150122T200749/Express0009.lzma.bak
2015-01-22T20:19:20.334Z,1421957960.334 [DataOverHttps](INFO): SBD MOMSN=1503864
2015-01-22T20:19:32.052Z,1421957972.052 [Startup:StartupSatComms:B](INFO): Timed out from 2015-01-22T20:18:28.9Z
2015-01-22T20:19:32.052Z,1421957972.052 [Startup:StartupSatComms:B] Stopped
2015-01-22T20:19:32.052Z,1421957972.052 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-22T20:19:32.052Z,1421957972.052 [Startup:StartupSatComms] Stopped
2015-01-22T20:19:32.053Z,1421957972.053 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-22T20:19:32.053Z,1421957972.053 [Startup](INFO): Completed Startup
2015-01-22T20:19:32.053Z,1421957972.053 [Startup] Stopped
2015-01-22T20:19:32.054Z,1421957972.054 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-22T20:19:32.054Z,1421957972.054 [Startup:A.GoToSurface] Stopped
2015-01-22T20:19:32.054Z,1421957972.054 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-22T20:19:32.225Z,1421957972.225 [MissionManager](IMPORTANT): Started mission Default
2015-01-22T20:19:32.225Z,1421957972.225 [Default] Running Loop=1
2015-01-22T20:19:32.225Z,1421957972.225 [Default](INFO): Aggregate::initialize Default
2015-01-22T20:19:32.225Z,1421957972.225 [Default:B.GoToSurface] Running Loop=1
2015-01-22T20:19:32.225Z,1421957972.225 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-22T20:19:32.225Z,1421957972.225 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-22T20:19:32.226Z,1421957972.226 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-22T20:19:32.226Z,1421957972.226 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-22T20:19:32.226Z,1421957972.226 [Default:StartClock] Running Loop=1
2015-01-22T20:19:32.226Z,1421957972.226 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-22T20:19:32.226Z,1421957972.226 [Default:StartClock:A] Running Loop=1
2015-01-22T20:19:32.227Z,1421957972.227 [Default:CheckIn] Running Loop=1
2015-01-22T20:19:32.227Z,1421957972.227 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-22T20:19:32.227Z,1421957972.227 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:19:32.227Z,1421957972.227 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-22T20:19:32.228Z,1421957972.228 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-22T20:19:32.229Z,1421957972.229 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-22T20:19:32.230Z,1421957972.230 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:19:32.267Z,1421957972.267 [Default:StartClock:A] Stopped
2015-01-22T20:19:32.267Z,1421957972.267 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-22T20:19:32.267Z,1421957972.267 [Default:StartClock] Stopped
2015-01-22T20:19:32.268Z,1421957972.268 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-22T20:19:32.477Z,1421957972.477 [DataOverHttps](INFO): Sending 545 bytes from file Logs/20150122T201610/Express0001.lzma
2015-01-22T20:19:32.507Z,1421957972.507 [Default:WaitAtTheSurface] Running Loop=1
2015-01-22T20:19:32.507Z,1421957972.507 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-22T20:19:32.508Z,1421957972.508 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-22T20:19:32.508Z,1421957972.508 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-22T20:19:32.887Z,1421957972.887 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-22T20:19:33.270Z,1421957973.270 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Express0001.lzma.bak
2015-01-22T20:19:33.270Z,1421957973.270 [DataOverHttps](INFO): SBD MOMSN=1503867
2015-01-22T20:20:17.767Z,1421958017.767 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,FFFB%34
$B13,0A,FFFB%35
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B99,09,3D2F,0A,FFFD,0B,FFFC%31
$B11,0C,0001,0D,0057,0E,0051,0F,136E,10,16D9,11,FFFF,12,FFFF%48
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41
$B11,1A,0031,1B,4357,1C,00BE%33
$B12,02,000A,01,026C,03,0001,08,0B92,09,3D30,0A,FFFB,0B,FFFB%49
$B12,0C,0001,0D,0055,0E,0051,0F,1387,10,1722,11,EA54,12,EA54%49
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,00A3%45
$B13,02,000A,01,026C,03,0001,08,0B92,09,3D2F,0A,FFFC,0B,FFFB%3E
$B13,0C,0001,0D,005F,0E,0051,0F,1396,10,170F,11,FFFF,12,EB08%42
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4357,1C,0091%3E
$B14,02,000A,01,026C,03,0001,08,0B99,09,3D38,0A,FFFD,0B,FFFD%4C
$B14,0C,0001,0D,0059,0E,0054,0F,1427,10,16C5,11,FFFF,12,FFFF%3C
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,00B7%44
$B15,02,000A,01,026C,03,0001,08,0B9C,09,3C28,0A,0000,0B,0000%31
$B15,0C,0001,0D,0064,0E,005D,0F,1657,10,177E,11,FFFF,12,FFFF%43
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008F%4E
$B16,02,000A,01,026C,03,0001,08,0B94,09,3C3A,0A,0000,0B,0000%3D
$B16,0C,0001,0D,0064,0E,005A,0F,15AE,10,16B8,11,FFFF,12,FFFF%49
$B16,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4B
$B16,1A,0031,1B,4357,1C,0088%33
$B17,02,000A,01,026C,03,0001,08,0B92,09,3C37,0A,0000,0B,0000%4C
$B17,0C,0001,0D,0064,0E,005E,0F,16BC,10,16D1,11,FFFF,12,FFFF%45
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,0098%33
$B18,02,000A,01,026C,03,0001,08,0B92,09,3CEF,0A,0000,0B,0000%44
$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:20:17.767Z,1421958017.767 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-22T20:20:17.767Z,1421958017.767 [BPC1] Data Fault, FailCount= 1
2015-01-22T20:20:17.767Z,1421958017.767 [BPC1](ERROR): Data Fault
2015-01-22T20:20:17.839Z,1421958017.839 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:20:18.981Z,1421958018.981 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:20:18.981Z,1421958018.981 [BPC1] No Fault, FailCount= 1
2015-01-22T20:21:19.418Z,1421958079.418 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-22T20:21:19.418Z,1421958079.418 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:21:19.418Z,1421958079.418 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-22T20:21:19.421Z,1421958079.421 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-22T20:21:19.421Z,1421958079.421 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-22T20:21:19.803Z,1421958079.803 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 1.788574 min 
2015-01-22T20:21:19.805Z,1421958079.805 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-22T20:21:19.805Z,1421958079.805 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:21:19.805Z,1421958079.805 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-22T20:21:19.805Z,1421958079.805 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:21:44.211Z,1421958104.211 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-22T20:21:47.017Z,1421958107.017 [BPC1](FAULT): Failed to receive battery data
2015-01-22T20:21:47.017Z,1421958107.017 [BPC1] Communications Fault, FailCount= 1
2015-01-22T20:21:47.017Z,1421958107.017 [BPC1](ERROR): Communications Fault
2015-01-22T20:21:47.061Z,1421958107.061 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T20:21:48.224Z,1421958108.224 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:21:48.224Z,1421958108.224 [BPC1] No Fault, FailCount= 1
2015-01-22T20:21:49.810Z,1421958109.810 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:21:49.811Z,1421958109.811 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:21:49.823Z,1421958109.823 [Default:CheckIn:Read_GPS] Stopped
2015-01-22T20:21:49.823Z,1421958109.823 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-22T20:21:50.232Z,1421958110.232 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-22T20:21:54.633Z,1421958114.633 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20150122T201610/Courier0004.lzma
2015-01-22T20:21:55.043Z,1421958115.043 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:21:55.043Z,1421958115.043 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:21:55.432Z,1421958115.432 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Courier0004.lzma.bak
2015-01-22T20:21:55.433Z,1421958115.433 [DataOverHttps](INFO): SBD MOMSN=1503881
2015-01-22T20:22:00.306Z,1421958120.306 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:00.307Z,1421958120.307 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:04.806Z,1421958124.806 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20150122T201610/Express0005.lzma
2015-01-22T20:22:05.198Z,1421958125.198 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:05.198Z,1421958125.198 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:05.587Z,1421958125.587 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Express0005.lzma.bak
2015-01-22T20:22:05.587Z,1421958125.587 [DataOverHttps](INFO): SBD MOMSN=1503884
2015-01-22T20:22:06.344Z,1421958126.344 [Default:CheckIn:Read_Iridium] Stopped
2015-01-22T20:22:06.345Z,1421958126.345 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-22T20:22:06.345Z,1421958126.345 [Default:CheckIn] Stopped
2015-01-22T20:22:06.345Z,1421958126.345 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-22T20:22:06.345Z,1421958126.345 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-22T20:22:06.345Z,1421958126.345 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:22:16.400Z,1421958136.400 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:16.400Z,1421958136.400 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:16.410Z,1421958136.410 [BPC1](FAULT): B bank: No match for serial number:5911 was found in the onboard configuration.
2015-01-22T20:22:16.410Z,1421958136.410 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-22T20:22:16.410Z,1421958136.410 [BPC1] Data Fault, FailCount= 1
2015-01-22T20:22:16.410Z,1421958136.410 [BPC1](ERROR): Data Fault
2015-01-22T20:22:16.425Z,1421958136.425 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:22:31.415Z,1421958151.415 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:22:31.416Z,1421958151.416 [BPC1] No Fault, FailCount= 1
2015-01-22T20:22:41.395Z,1421958161.395 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:22:41.395Z,1421958161.395 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:06.393Z,1421958186.393 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:06.394Z,1421958186.394 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:31.401Z,1421958211.401 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:31.401Z,1421958211.401 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:41.407Z,1421958221.407 [BPC1](FAULT): Failed to receive battery data
2015-01-22T20:23:41.407Z,1421958221.407 [BPC1] Communications Fault, FailCount= 1
2015-01-22T20:23:41.407Z,1421958221.407 [BPC1](ERROR): Communications Fault
2015-01-22T20:23:41.421Z,1421958221.421 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T20:23:56.399Z,1421958236.399 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:56.399Z,1421958236.399 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:23:56.419Z,1421958236.419 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:23:56.419Z,1421958236.419 [BPC1] No Fault, FailCount= 1
2015-01-22T20:24:19.235Z,1421958259.235 [BPC1](ERROR): Failed to parse message.
2015-01-22T20:24:19.235Z,1421958259.235 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-22T20:24:19.235Z,1421958259.235 [BPC1] Data Fault, FailCount= 2
2015-01-22T20:24:19.235Z,1421958259.235 [BPC1](ERROR): Data Fault
2015-01-22T20:24:19.298Z,1421958259.298 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-22T20:24:21.398Z,1421958261.398 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:24:21.398Z,1421958261.398 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:24:31.421Z,1421958271.421 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:24:31.421Z,1421958271.421 [BPC1] No Fault, FailCount= 2
2015-01-22T20:24:46.389Z,1421958286.389 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:24:46.389Z,1421958286.389 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:25:11.403Z,1421958311.403 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:25:11.403Z,1421958311.403 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:25:19.231Z,1421958319.231 [BPC1](DEBUG): Received data from all battery sticks
2015-01-22T20:25:31.414Z,1421958331.414 [BPC1](FAULT): Failed to receive battery data
2015-01-22T20:25:31.414Z,1421958331.414 [BPC1] Communications Fault, FailCount= 1
2015-01-22T20:25:31.414Z,1421958331.414 [BPC1](ERROR): Communications Fault
2015-01-22T20:25:31.429Z,1421958331.429 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T20:25:36.391Z,1421958336.391 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:25:36.391Z,1421958336.391 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:25:46.418Z,1421958346.418 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:25:46.418Z,1421958346.418 [BPC1] No Fault, FailCount= 1
2015-01-22T20:26:01.398Z,1421958361.398 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:26:01.398Z,1421958361.398 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:26:16.408Z,1421958376.408 [BPC1](FAULT): Failed to receive battery data
2015-01-22T20:26:16.408Z,1421958376.408 [BPC1] Communications Fault, FailCount= 2
2015-01-22T20:26:16.408Z,1421958376.408 [BPC1](ERROR): Communications Fault
2015-01-22T20:26:16.423Z,1421958376.423 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-22T20:26:24.209Z,1421958384.209 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-22T20:26:24.209Z,1421958384.209 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:26:24.209Z,1421958384.209 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-22T20:26:24.210Z,1421958384.210 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-22T20:26:24.210Z,1421958384.210 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-22T20:26:26.392Z,1421958386.392 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:26:26.393Z,1421958386.393 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:26:26.441Z,1421958386.441 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 6.821937 min 
2015-01-22T20:26:26.441Z,1421958386.441 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-22T20:26:26.441Z,1421958386.441 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:26:26.441Z,1421958386.441 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-22T20:26:26.441Z,1421958386.441 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-22T20:26:31.428Z,1421958391.428 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-22T20:26:31.428Z,1421958391.428 [BPC1] No Fault, FailCount= 2
2015-01-22T20:26:51.395Z,1421958411.395 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:26:51.396Z,1421958411.396 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:06.435Z,1421958426.435 [Default:CheckIn] Running Loop=1
2015-01-22T20:27:06.435Z,1421958426.435 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-22T20:27:06.435Z,1421958426.435 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-22T20:27:06.435Z,1421958426.435 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-22T20:27:06.436Z,1421958426.436 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-22T20:27:07.196Z,1421958427.196 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:07.196Z,1421958427.196 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:07.241Z,1421958427.241 [Default:CheckIn:Read_GPS] Stopped
2015-01-22T20:27:07.241Z,1421958427.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-22T20:27:12.035Z,1421958432.035 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20150122T201610/Courier0008.lzma
2015-01-22T20:27:12.047Z,1421958432.047 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:12.047Z,1421958432.047 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:12.829Z,1421958432.829 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Courier0008.lzma.bak
2015-01-22T20:27:12.829Z,1421958432.829 [DataOverHttps](INFO): SBD MOMSN=1503893
2015-01-22T20:27:17.309Z,1421958437.309 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:17.309Z,1421958437.309 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:22.550Z,1421958442.550 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:22.550Z,1421958442.550 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:22.682Z,1421958442.682 [DataOverHttps](INFO): Sending 474 bytes from file Logs/20150122T201610/Express0009.lzma
2015-01-22T20:27:23.474Z,1421958443.474 [DataOverHttps](INFO): Moved sent file to Logs/20150122T201610/Express0009.lzma.bak
2015-01-22T20:27:23.474Z,1421958443.474 [DataOverHttps](INFO): SBD MOMSN=1503896
2015-01-22T20:27:24.275Z,1421958444.275 [Default:CheckIn:Read_Iridium] Stopped
2015-01-22T20:27:24.276Z,1421958444.276 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-22T20:27:24.276Z,1421958444.276 [Default:CheckIn] Stopped
2015-01-22T20:27:24.276Z,1421958444.276 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-22T20:27:24.276Z,1421958444.276 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-22T20:27:24.276Z,1421958444.276 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:27:29.303Z,1421958449.303 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:29.303Z,1421958449.303 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:54.297Z,1421958474.297 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:27:54.297Z,1421958474.297 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:28:19.296Z,1421958499.296 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:28:19.297Z,1421958499.297 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:28:44.307Z,1421958524.307 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:28:44.307Z,1421958524.307 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:29:07.796Z,1421958547.796 [CommandLine](IMPORTANT): got command quit
2015-01-22T20:29:08.804Z,1421958548.804 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:29:08.804Z,1421958548.804 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:08.869Z,1421958548.869 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-22T20:29:08.869Z,1421958548.869 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:08.870Z,1421958548.870 [CommandLine](INFO): Join timeout helper Thread ID is 1189
2015-01-22T20:29:08.887Z,1421958548.887 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-22T20:29:08.887Z,1421958548.887 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:08.888Z,1421958548.888 [NavChartDb](INFO): Join timeout helper Thread ID is 1190
2015-01-22T20:29:09.082Z,1421958549.082 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:29:09.082Z,1421958549.082 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.094Z,1421958549.094 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-22T20:29:09.094Z,1421958549.094 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.094Z,1421958549.094 [Radio_Surface](INFO): Join timeout helper Thread ID is 1191
2015-01-22T20:29:09.302Z,1421958549.302 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:29:09.302Z,1421958549.302 [NAL9602](IMPORTANT): GPS fix at: -1.000000
2015-01-22T20:29:09.366Z,1421958549.366 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:29:09.367Z,1421958549.367 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.378Z,1421958549.378 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-22T20:29:09.378Z,1421958549.378 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.379Z,1421958549.379 [logger](INFO): Join timeout helper Thread ID is 1192
2015-01-22T20:29:09.402Z,1421958549.402 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:29:09.403Z,1421958549.403 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.422Z,1421958549.422 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-22T20:29:09.422Z,1421958549.422 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.422Z,1421958549.422 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-22T20:29:09.422Z,1421958549.422 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:09.423Z,1421958549.423 [controlThread](INFO): Join timeout helper Thread ID is 1193
2015-01-22T20:29:14.290Z,1421958554.290 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-22T20:29:14.290Z,1421958554.290 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-22T20:29:14.291Z,1421958554.291 [NAL9602](INFO): Uninitialize
2015-01-22T20:29:14.291Z,1421958554.291 [NAL9602](INFO): Powering down
2015-01-22T20:29:14.293Z,1421958554.293 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-22T20:29:14.294Z,1421958554.294 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-22T20:29:14.294Z,1421958554.294 [Default] Stopped
2015-01-22T20:29:14.294Z,1421958554.294 [Default](INFO): Aggregate::uninitialize Default
2015-01-22T20:29:14.294Z,1421958554.294 [Default:B.GoToSurface] Stopped
2015-01-22T20:29:14.294Z,1421958554.294 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-22T20:29:14.295Z,1421958554.295 [Default:WaitAtTheSurface] Stopped
2015-01-22T20:29:14.295Z,1421958554.295 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-01-22T20:29:14.295Z,1421958554.295 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-01-22T20:29:14.295Z,1421958554.295 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-01-22T20:29:14.298Z,1421958554.298 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-22T20:29:14.299Z,1421958554.299 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-22T20:29:14.299Z,1421958554.299 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-22T20:29:14.299Z,1421958554.299 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-22T20:29:14.299Z,1421958554.299 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-22T20:29:14.300Z,1421958554.300 [BuoyancyServo](INFO): Powering down
2015-01-22T20:29:14.314Z,1421958554.314 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-22T20:29:14.314Z,1421958554.314 [ElevatorServo](INFO): Powering down
2015-01-22T20:29:14.315Z,1421958554.315 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-22T20:29:14.315Z,1421958554.315 [RudderServo](INFO): Powering down
2015-01-22T20:29:14.316Z,1421958554.316 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-22T20:29:14.316Z,1421958554.316 [ThrusterServo](INFO): Powering down
2015-01-22T20:29:14.316Z,1421958554.316 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-22T20:29:14.317Z,1421958554.317 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-22T20:29:14.317Z,1421958554.317 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-22T20:29:14.354Z,1421958554.354 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:14.562Z,1421958554.562 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:14.637Z,1421958554.637 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-22T20:29:14.719Z,1421958554.719 [logger ThreadHandler](INFO): Thread cancelled.