2015-01-27T23:05:57.039Z,1422399957.039 [Supervisor](DEBUG): Initializing supervisor.
2015-01-27T23:05:57.041Z,1422399957.041 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-27T23:05:57.042Z,1422399957.042 [SyncHandler](INFO): Protected caller Thread ID is 3088
2015-01-27T23:05:57.042Z,1422399957.042 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-27T23:05:57.043Z,1422399957.043 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-27T23:05:57.044Z,1422399957.044 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3089
2015-01-27T23:05:57.046Z,1422399957.046 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-27T23:05:57.058Z,1422399957.058 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-27T23:05:57.059Z,1422399957.059 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-27T23:05:57.060Z,1422399957.060 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3090
2015-01-27T23:05:57.060Z,1422399957.060 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-27T23:05:57.061Z,1422399957.061 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-27T23:05:57.062Z,1422399957.062 [logger ThreadHandler](INFO): Protected caller Thread ID is 3091
2015-01-27T23:05:57.064Z,1422399957.064 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-27T23:05:57.064Z,1422399957.064 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-27T23:05:57.066Z,1422399957.066 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-27T23:05:57.394Z,1422399957.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-27T23:05:57.394Z,1422399957.394 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-27T23:05:57.558Z,1422399957.558 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-27T23:05:57.558Z,1422399957.558 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-27T23:05:57.665Z,1422399957.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-27T23:05:57.665Z,1422399957.665 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-27T23:05:57.785Z,1422399957.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-27T23:05:57.785Z,1422399957.785 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-27T23:05:57.870Z,1422399957.870 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-27T23:05:58.029Z,1422399958.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-27T23:05:58.030Z,1422399958.030 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-27T23:05:58.117Z,1422399958.117 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-27T23:05:58.117Z,1422399958.117 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-27T23:05:58.320Z,1422399958.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-27T23:05:58.321Z,1422399958.321 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-27T23:05:58.694Z,1422399958.694 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-27T23:05:58.695Z,1422399958.695 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-27T23:05:59.014Z,1422399959.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-27T23:05:59.014Z,1422399959.014 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-27T23:05:59.592Z,1422399959.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-27T23:05:59.593Z,1422399959.593 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-27T23:05:59.780Z,1422399959.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-27T23:05:59.781Z,1422399959.781 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-27T23:05:59.883Z,1422399959.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-27T23:05:59.884Z,1422399959.884 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-27T23:06:00.295Z,1422399960.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-27T23:06:00.295Z,1422399960.295 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-27T23:06:00.403Z,1422399960.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-27T23:06:00.406Z,1422399960.406 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-27T23:06:00.406Z,1422399960.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-27T23:06:00.641Z,1422399960.641 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-27T23:06:00.642Z,1422399960.642 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-27T23:06:00.755Z,1422399960.755 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-27T23:06:00.852Z,1422399960.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-27T23:06:00.947Z,1422399960.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-27T23:06:01.060Z,1422399961.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-27T23:06:01.202Z,1422399961.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-27T23:06:01.368Z,1422399961.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-27T23:06:01.467Z,1422399961.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-27T23:06:01.556Z,1422399961.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-27T23:06:01.654Z,1422399961.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-27T23:06:01.749Z,1422399961.749 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-27T23:06:01.925Z,1422399961.925 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-01-27T23:06:01.926Z,1422399961.926 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-27T23:06:01.939Z,1422399961.939 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-27T23:06:02.003Z,1422399962.003 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-27T23:06:02.120Z,1422399962.120 [VerticalControl] Loaded
2015-01-27T23:06:02.120Z,1422399962.120 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-27T23:06:02.121Z,1422399962.121 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-27T23:06:02.192Z,1422399962.192 [HorizontalControl] Loaded
2015-01-27T23:06:02.192Z,1422399962.192 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-27T23:06:02.193Z,1422399962.193 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-27T23:06:02.198Z,1422399962.198 [SpeedControl] Loaded
2015-01-27T23:06:02.199Z,1422399962.199 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-27T23:06:02.199Z,1422399962.199 [LoopControl](DEBUG): Construct LoopControl.
2015-01-27T23:06:02.200Z,1422399962.200 [LoopControl] Loaded
2015-01-27T23:06:02.200Z,1422399962.200 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-27T23:06:02.201Z,1422399962.201 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-27T23:06:02.201Z,1422399962.201 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-27T23:06:02.294Z,1422399962.294 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-27T23:06:02.305Z,1422399962.305 [SBIT] Loaded
2015-01-27T23:06:02.306Z,1422399962.306 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-27T23:06:02.306Z,1422399962.306 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-27T23:06:02.335Z,1422399962.335 [IBIT] Loaded
2015-01-27T23:06:02.335Z,1422399962.335 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-27T23:06:02.337Z,1422399962.337 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-27T23:06:02.455Z,1422399962.455 [CBIT] Loaded
2015-01-27T23:06:02.456Z,1422399962.456 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-27T23:06:02.456Z,1422399962.456 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-27T23:06:02.457Z,1422399962.457 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-27T23:06:02.475Z,1422399962.475 [DepthRateCalculator] Loaded
2015-01-27T23:06:02.475Z,1422399962.475 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-27T23:06:02.480Z,1422399962.480 [PitchRateCalculator] Loaded
2015-01-27T23:06:02.481Z,1422399962.481 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-27T23:06:02.492Z,1422399962.492 [SpeedCalculator] Loaded
2015-01-27T23:06:02.492Z,1422399962.492 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-27T23:06:02.509Z,1422399962.509 [TempGradientCalculator] Loaded
2015-01-27T23:06:02.509Z,1422399962.509 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-27T23:06:02.514Z,1422399962.514 [YawRateCalculator] Loaded
2015-01-27T23:06:02.515Z,1422399962.515 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-27T23:06:02.515Z,1422399962.515 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-27T23:06:02.516Z,1422399962.516 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-27T23:06:02.564Z,1422399962.564 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-27T23:06:02.565Z,1422399962.565 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-27T23:06:02.788Z,1422399962.788 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-27T23:06:02.788Z,1422399962.788 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-27T23:06:02.831Z,1422399962.831 [NavChart] Loaded
2015-01-27T23:06:02.831Z,1422399962.831 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-27T23:06:02.838Z,1422399962.838 [UniversalFixResidualReporter] Loaded
2015-01-27T23:06:02.838Z,1422399962.838 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-27T23:06:02.839Z,1422399962.839 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-27T23:06:02.839Z,1422399962.839 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-27T23:06:02.845Z,1422399962.845 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-27T23:06:02.846Z,1422399962.846 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-27T23:06:02.959Z,1422399962.959 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-27T23:06:02.960Z,1422399962.960 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-27T23:06:03.262Z,1422399963.262 [DataOverHttps] Loaded
2015-01-27T23:06:03.263Z,1422399963.263 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-27T23:06:03.344Z,1422399963.344 [Depth_Keller] Loaded
2015-01-27T23:06:03.345Z,1422399963.345 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-27T23:06:03.438Z,1422399963.438 [NAL9602] Loaded
2015-01-27T23:06:03.438Z,1422399963.438 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-27T23:06:03.479Z,1422399963.479 [Onboard] Loaded
2015-01-27T23:06:03.479Z,1422399963.479 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-27T23:06:03.486Z,1422399963.486 [Radio_Surface] Loaded
2015-01-27T23:06:03.486Z,1422399963.486 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-27T23:06:03.487Z,1422399963.487 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-27T23:06:03.488Z,1422399963.488 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3174
2015-01-27T23:06:05.314Z,1422399965.314 [BPC1] Loaded
2015-01-27T23:06:05.314Z,1422399965.314 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-27T23:06:05.315Z,1422399965.315 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-27T23:06:05.315Z,1422399965.315 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-27T23:06:05.411Z,1422399965.411 [BuoyancyServo] Loaded
2015-01-27T23:06:05.412Z,1422399965.412 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-27T23:06:05.424Z,1422399965.424 [ElevatorServo] Loaded
2015-01-27T23:06:05.424Z,1422399965.424 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-27T23:06:05.477Z,1422399965.477 [RudderServo] Loaded
2015-01-27T23:06:05.478Z,1422399965.478 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-27T23:06:05.489Z,1422399965.489 [ThrusterServo] Loaded
2015-01-27T23:06:05.489Z,1422399965.489 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-27T23:06:05.490Z,1422399965.490 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-27T23:06:05.490Z,1422399965.490 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-27T23:06:05.589Z,1422399965.589 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-27T23:06:05.590Z,1422399965.590 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-27T23:06:05.614Z,1422399965.614 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-27T23:06:05.615Z,1422399965.615 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-27T23:06:05.616Z,1422399965.616 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-27T23:06:05.623Z,1422399965.623 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-27T23:06:05.624Z,1422399965.624 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-27T23:06:05.624Z,1422399965.624 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3175
2015-01-27T23:06:05.629Z,1422399965.629 [Supervisor](INFO): Main Thread ID is 3087
2015-01-27T23:06:05.629Z,1422399965.629 [Supervisor](DEBUG): Running supervisor.
2015-01-27T23:06:05.630Z,1422399965.630 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3176
2015-01-27T23:06:05.634Z,1422399965.634 [controlThread ThreadHandler](INFO): Handler Thread ID is 3177
2015-01-27T23:06:05.634Z,1422399965.634 [controlThread](DEBUG): Initializing ControlThread
2015-01-27T23:06:05.635Z,1422399965.635 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-27T23:06:05.637Z,1422399965.637 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-27T23:06:05.637Z,1422399965.637 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-27T23:06:05.638Z,1422399965.638 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-27T23:06:05.638Z,1422399965.638 [SBIT](INFO): Initialize SBIT Component.
2015-01-27T23:06:05.639Z,1422399965.639 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-27T23:06:05.639Z,1422399965.639 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-27T23:06:05.639Z,1422399965.639 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-27T23:06:05.640Z,1422399965.640 [IBIT](INFO): Initialize IBIT Component.
2015-01-27T23:06:05.641Z,1422399965.641 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-27T23:06:05.641Z,1422399965.641 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-27T23:06:05.642Z,1422399965.642 [logger ThreadHandler](INFO): Handler Thread ID is 3178
2015-01-27T23:06:05.661Z,1422399965.661 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3179
2015-01-27T23:06:05.665Z,1422399965.665 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-27T23:06:05.665Z,1422399965.665 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-27T23:06:05.666Z,1422399965.666 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-27T23:06:05.666Z,1422399965.666 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-27T23:06:05.667Z,1422399965.667 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-27T23:06:05.667Z,1422399965.667 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-27T23:06:05.667Z,1422399965.667 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-27T23:06:05.673Z,1422399965.673 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-27T23:06:05.683Z,1422399965.683 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-27T23:06:05.685Z,1422399965.685 [Radio_Surface](INFO): Powering up
2015-01-27T23:06:05.697Z,1422399965.697 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3180
2015-01-27T23:06:05.700Z,1422399965.700 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-27T23:06:05.701Z,1422399965.701 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-27T23:06:05.701Z,1422399965.701 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-27T23:06:05.702Z,1422399965.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-27T23:06:05.702Z,1422399965.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-27T23:06:05.702Z,1422399965.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-27T23:06:05.703Z,1422399965.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-27T23:06:05.703Z,1422399965.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-27T23:06:05.703Z,1422399965.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-27T23:06:05.730Z,1422399965.730 [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-27T23:06:05.731Z,1422399965.731 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-27T23:06:05.820Z,1422399965.820 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-27T23:06:05.823Z,1422399965.823 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-27T23:06:05.844Z,1422399965.844 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-27T23:06:05.872Z,1422399965.872 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-27T23:06:05.894Z,1422399965.894 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-27T23:06:05.930Z,1422399965.930 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-27T23:06:05.944Z,1422399965.944 [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-27T23:06:05.948Z,1422399965.948 [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-27T23:06:06.110Z,1422399966.110 [NAL9602](INFO): Start
2015-01-27T23:06:06.402Z,1422399966.402 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-27T23:06:06.410Z,1422399966.410 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-27T23:06:06.424Z,1422399966.424 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-27T23:06:06.430Z,1422399966.430 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-27T23:06:06.456Z,1422399966.456 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-27T23:06:06.462Z,1422399966.462 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-27T23:06:06.468Z,1422399966.468 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-27T23:06:06.474Z,1422399966.474 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-27T23:06:06.640Z,1422399966.640 [NAL9602](INFO): Start
2015-01-27T23:06:11.037Z,1422399971.037 [CommandLine](IMPORTANT): got command show variable quality
2015-01-27T23:06:11.124Z,1422399971.124 [CommandLine](IMPORTANT): NAL9602.sigQuality (count)
2015-01-27T23:06:16.151Z,1422399976.151 [NAL9602](INFO): Start
2015-01-27T23:06:16.151Z,1422399976.151 [NAL9602](INFO): Powering up NAL9602
2015-01-27T23:06:17.327Z,1422399977.327 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003300
2015-01-27T23:06:18.284Z,1422399978.284 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2015-01-27T23:06:18.878Z,1422399978.878 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T23:06:21.005Z,1422399981.005 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-27T23:06:21.007Z,1422399981.007 [CBIT](IMPORTANT): Beginning GF scan
2015-01-27T23:06:26.955Z,1422399986.955 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T23:06:26.955Z,1422399986.955 [NAL9602](INFO): NAL9602 initialized
2015-01-27T23:06:29.756Z,1422399989.756 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:30.279Z,1422399990.279 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-27T23:06:30.575Z,1422399990.575 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:31.780Z,1422399991.780 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5A%53
$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,5A%53
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B96,09,3C4E,0A,FFFC,0B,FFFC%3B
$B11,0C,0001,0D,0054,0E,004E,0F,12E4,10,16D9,11,FFFF,12,FFFF%3D
$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,0B8E,09,3C50,0A,FFFC,0B,FFFC%3E
$B12,0C,0001,0D,0052,0E,004F,0F,12EF,10,1722,11,FFFF,12,FFFF%35
$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,0B8E,09,3C4D,0A,FFFB,0B,FFFB%4A
$B13,0C,0001,0D,005B,0E,004F,0F,12E7,10,170F,11,E2D4,12,E2D4%43
$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,0B92,09,3C54,0A,FFFD,0B,FFFD%4A
$B14,0C,0001,0D,0057,0E,0052,0F,13A0,10,16C5,11,FFFF,12,FFFF%47
$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,0B9A,09,3C11,0A,0000,0B,0000%39
$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,0B8C,09,3C21,0A,0000,0B,0000%3A
$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,0B94,09,3C1F,0A,0000,0B,0000%39
$B17,0C,0001,0D,0064,0E,005F,0F,16C8,10,16D1,11,FFFF,12,FFFF%3C
$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,0B8F,09,3C08,0A,0000,0B,0000%3A
$B18,0C,0001,0D,004E,0E,0046,0F,10F0,10,168E,11,FFFF,12,FFFF%32
$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-27T23:06:31.780Z,1422399991.780 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-27T23:06:31.780Z,1422399991.780 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:06:31.781Z,1422399991.781 [BPC1](ERROR): Data Fault
2015-01-27T23:06:31.913Z,1422399991.913 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:06:33.075Z,1422399993.075 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:06:33.075Z,1422399993.075 [BPC1] No Fault, FailCount= 1
2015-01-27T23:06:34.299Z,1422399994.299 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T23:06:34.551Z,1422399994.551 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:36.154Z,1422399996.154 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:44.555Z,1422400004.555 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:47.474Z,1422400007.474 [CBIT](IMPORTANT): No ground fault detected
2015-01-27T23:06:48.954Z,1422400008.954 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:06:49.364Z,1422400009.364 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:06:49.364Z,1422400009.364 [BPC1] Communications Fault, FailCount= 2
2015-01-27T23:06:49.364Z,1422400009.364 [BPC1](ERROR): Communications Fault
2015-01-27T23:06:49.493Z,1422400009.493 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:06:50.674Z,1422400010.674 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:06:50.675Z,1422400010.675 [BPC1] No Fault, FailCount= 2
2015-01-27T23:06:57.751Z,1422400017.751 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:01.081Z,1422400021.081 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T23:07:01.081Z,1422400021.081 [SBIT](FAULT): Control surface position failure.
2015-01-27T23:07:06.156Z,1422400026.156 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:10.575Z,1422400030.575 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:14.604Z,1422400034.604 [SBIT](ERROR): Could not read massPosReader_.
2015-01-27T23:07:14.605Z,1422400034.605 [SBIT](FAULT): Control surface position failure.
2015-01-27T23:07:15.005Z,1422400035.005 [SBIT](CRITICAL): SBIT FAILED
2015-01-27T23:07:15.006Z,1422400035.006 [CommandLine](FAULT): Scheduling is paused
2015-01-27T23:07:15.415Z,1422400035.415 [MissionManager](IMPORTANT): Started mission Startup
2015-01-27T23:07:15.415Z,1422400035.415 [Startup] Running Loop=1
2015-01-27T23:07:15.415Z,1422400035.415 [Startup](INFO): Aggregate::initialize Startup
2015-01-27T23:07:15.415Z,1422400035.415 [Startup:A.GoToSurface] Running Loop=1
2015-01-27T23:07:15.415Z,1422400035.415 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-27T23:07:15.416Z,1422400035.416 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-27T23:07:15.416Z,1422400035.416 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-27T23:07:15.416Z,1422400035.416 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-27T23:07:15.422Z,1422400035.422 [Startup:StartupSatComms] Running Loop=1
2015-01-27T23:07:15.422Z,1422400035.422 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-27T23:07:15.422Z,1422400035.422 [Startup:StartupSatComms:A] Running Loop=1
2015-01-27T23:07:15.782Z,1422400035.782 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-27T23:07:19.373Z,1422400039.373 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:19.779Z,1422400039.779 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:07:19.779Z,1422400039.779 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:07:19.779Z,1422400039.779 [BPC1](ERROR): Communications Fault
2015-01-27T23:07:19.818Z,1422400039.818 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:07:20.989Z,1422400040.989 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:07:20.989Z,1422400040.989 [BPC1] No Fault, FailCount= 1
2015-01-27T23:07:23.367Z,1422400043.367 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:27.774Z,1422400047.774 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:28.571Z,1422400048.571 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:32.570Z,1422400052.570 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:33.371Z,1422400053.371 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:37.373Z,1422400057.373 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:38.174Z,1422400058.174 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:42.569Z,1422400062.569 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:43.370Z,1422400063.370 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:47.773Z,1422400067.773 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:48.570Z,1422400068.570 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:52.973Z,1422400072.973 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:53.766Z,1422400073.766 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:58.173Z,1422400078.173 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:07:58.970Z,1422400078.970 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:03.373Z,1422400083.373 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:04.170Z,1422400084.170 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:09.872Z,1422400089.872 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:10.629Z,1422400090.629 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:15.024Z,1422400095.024 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:15.453Z,1422400095.453 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-27T23:07:15.4Z
2015-01-27T23:08:15.453Z,1422400095.453 [Startup:StartupSatComms:A] Stopped
2015-01-27T23:08:15.453Z,1422400095.453 [Startup:StartupSatComms:B] Running Loop=1
2015-01-27T23:08:15.825Z,1422400095.825 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:15.872Z,1422400095.872 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-27T23:08:19.979Z,1422400099.979 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:20.321Z,1422400100.321 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150127T230050/Courier0004.lzma
2015-01-27T23:08:20.728Z,1422400100.728 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:21.116Z,1422400101.116 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230050/Courier0004.lzma.bak
2015-01-27T23:08:21.116Z,1422400101.116 [DataOverHttps](INFO): SBD MOMSN=1508832
2015-01-27T23:08:25.240Z,1422400105.240 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:25.989Z,1422400105.989 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:30.460Z,1422400110.460 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150127T230557/Courier0000.lzma
2015-01-27T23:08:30.513Z,1422400110.513 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:31.244Z,1422400111.244 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0000.lzma.bak
2015-01-27T23:08:31.244Z,1422400111.244 [DataOverHttps](INFO): SBD MOMSN=1508834
2015-01-27T23:08:31.264Z,1422400111.264 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:35.776Z,1422400115.776 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:36.529Z,1422400116.529 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:41.048Z,1422400121.048 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:41.396Z,1422400121.396 [DataOverHttps](INFO): Sending 553 bytes from file Logs/20150127T224408/Express0001.lzma
2015-01-27T23:08:41.798Z,1422400121.798 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:42.586Z,1422400122.586 [DataOverHttps](INFO): Moved sent file to Logs/20150127T224408/Express0001.lzma.bak
2015-01-27T23:08:42.586Z,1422400122.586 [DataOverHttps](INFO): SBD MOMSN=1508838
2015-01-27T23:08:46.769Z,1422400126.769 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:08:51.993Z,1422400131.993 [DataOverHttps](INFO): Sending 627 bytes from file Logs/20150127T224530/Express0001.lzma
2015-01-27T23:08:52.789Z,1422400132.789 [DataOverHttps](INFO): Moved sent file to Logs/20150127T224530/Express0001.lzma.bak
2015-01-27T23:08:52.790Z,1422400132.790 [DataOverHttps](INFO): SBD MOMSN=1508854
2015-01-27T23:08:57.413Z,1422400137.413 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:02.662Z,1422400142.662 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:02.997Z,1422400142.997 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20150127T225241/Express0001.lzma
2015-01-27T23:09:03.791Z,1422400143.791 [DataOverHttps](INFO): Moved sent file to Logs/20150127T225241/Express0001.lzma.bak
2015-01-27T23:09:03.791Z,1422400143.791 [DataOverHttps](INFO): SBD MOMSN=1508872
2015-01-27T23:09:04.689Z,1422400144.689 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:08.278Z,1422400148.278 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:09.514Z,1422400149.514 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:10.316Z,1422400150.316 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:13.954Z,1422400153.954 [DataOverHttps](INFO): Sending 590 bytes from file Logs/20150127T225448/Express0001.lzma
2015-01-27T23:09:14.362Z,1422400154.362 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:14.752Z,1422400154.752 [DataOverHttps](INFO): Moved sent file to Logs/20150127T225448/Express0001.lzma.bak
2015-01-27T23:09:14.752Z,1422400154.752 [DataOverHttps](INFO): SBD MOMSN=1508886
2015-01-27T23:09:15.548Z,1422400155.548 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:15.589Z,1422400155.589 [Startup:StartupSatComms:B](INFO): Timed out from 2015-01-27T23:08:15.5Z
2015-01-27T23:09:15.589Z,1422400155.589 [Startup:StartupSatComms:B] Stopped
2015-01-27T23:09:15.589Z,1422400155.589 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-27T23:09:15.589Z,1422400155.589 [Startup:StartupSatComms] Stopped
2015-01-27T23:09:15.589Z,1422400155.589 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-27T23:09:15.590Z,1422400155.590 [Startup](INFO): Completed Startup
2015-01-27T23:09:15.590Z,1422400155.590 [Startup] Stopped
2015-01-27T23:09:15.590Z,1422400155.590 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-27T23:09:15.591Z,1422400155.591 [Startup:A.GoToSurface] Stopped
2015-01-27T23:09:15.591Z,1422400155.591 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-27T23:09:15.676Z,1422400155.676 [MissionManager](IMPORTANT): Started mission Default
2015-01-27T23:09:15.677Z,1422400155.677 [Default] Running Loop=1
2015-01-27T23:09:15.677Z,1422400155.677 [Default](INFO): Aggregate::initialize Default
2015-01-27T23:09:15.677Z,1422400155.677 [Default:B.GoToSurface] Running Loop=1
2015-01-27T23:09:15.677Z,1422400155.677 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-27T23:09:15.677Z,1422400155.677 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-27T23:09:15.677Z,1422400155.677 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-27T23:09:15.678Z,1422400155.678 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-27T23:09:15.678Z,1422400155.678 [Default:StartClock] Running Loop=1
2015-01-27T23:09:15.678Z,1422400155.678 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-27T23:09:15.678Z,1422400155.678 [Default:StartClock:A] Running Loop=1
2015-01-27T23:09:15.679Z,1422400155.679 [Default:CheckIn] Running Loop=1
2015-01-27T23:09:15.679Z,1422400155.679 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-27T23:09:15.679Z,1422400155.679 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:09:15.679Z,1422400155.679 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-27T23:09:15.679Z,1422400155.679 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-27T23:09:15.680Z,1422400155.680 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-27T23:09:15.682Z,1422400155.682 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:09:15.696Z,1422400155.696 [Default:StartClock:A] Stopped
2015-01-27T23:09:15.696Z,1422400155.696 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-27T23:09:15.696Z,1422400155.696 [Default:StartClock] Stopped
2015-01-27T23:09:15.696Z,1422400155.696 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-27T23:09:18.846Z,1422400158.846 [Default:WaitAtTheSurface] Running Loop=1
2015-01-27T23:09:18.846Z,1422400158.846 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-27T23:09:18.846Z,1422400158.846 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-27T23:09:18.846Z,1422400158.846 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-27T23:09:18.949Z,1422400158.949 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-27T23:09:19.270Z,1422400159.270 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:20.077Z,1422400160.077 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:24.467Z,1422400164.467 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:25.271Z,1422400165.271 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:29.666Z,1422400169.666 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:30.468Z,1422400170.468 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:34.866Z,1422400174.866 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:35.673Z,1422400175.673 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:40.064Z,1422400180.064 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:40.868Z,1422400180.868 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:44.871Z,1422400184.871 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:48.067Z,1422400188.067 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:09:56.469Z,1422400196.469 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:00.867Z,1422400200.867 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:05.263Z,1422400205.263 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:06.070Z,1422400206.070 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:10.063Z,1422400210.063 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:10.870Z,1422400210.870 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:14.862Z,1422400214.862 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:15.670Z,1422400215.670 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:19.354Z,1422400219.354 [DataOverHttps](INFO): Sending 443 bytes from file Logs/20150127T225705/Express0001.lzma
2015-01-27T23:10:20.323Z,1422400220.323 [DataOverHttps](INFO): Moved sent file to Logs/20150127T225705/Express0001.lzma.bak
2015-01-27T23:10:20.323Z,1422400220.323 [DataOverHttps](INFO): SBD MOMSN=1508902
2015-01-27T23:10:20.339Z,1422400220.339 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:20.943Z,1422400220.943 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:25.346Z,1422400225.346 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:26.144Z,1422400226.144 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:30.542Z,1422400230.542 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:31.348Z,1422400231.348 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:35.746Z,1422400235.746 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:36.544Z,1422400236.544 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:40.947Z,1422400240.947 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:41.748Z,1422400241.748 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:46.147Z,1422400246.147 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:46.944Z,1422400246.944 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:51.347Z,1422400251.347 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:52.148Z,1422400252.148 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:56.543Z,1422400256.543 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:10:57.348Z,1422400257.348 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:01.747Z,1422400261.747 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:05.344Z,1422400265.344 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:06.152Z,1422400266.152 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:11:06.152Z,1422400266.152 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:11:06.152Z,1422400266.152 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:11:06.155Z,1422400266.155 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:11:06.155Z,1422400266.155 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:11:06.560Z,1422400266.560 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 1.842249 min 
2015-01-27T23:11:06.562Z,1422400266.562 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:11:06.562Z,1422400266.562 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:11:06.562Z,1422400266.562 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:11:06.563Z,1422400266.563 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:11:13.745Z,1422400273.745 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:19.458Z,1422400279.458 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:22.607Z,1422400282.607 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:23.404Z,1422400283.404 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:27.407Z,1422400287.407 [NAL9602](INFO): MT Sig Qty requested
2015-01-27T23:11:29.803Z,1422400289.803 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-27T23:12:15.444Z,1422400335.444 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:14:15.973Z,1422400455.973 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-27T23:09:15.7Z
2015-01-27T23:14:15.973Z,1422400455.973 [Default:CheckIn:Read_GPS] Stopped
2015-01-27T23:14:15.973Z,1422400455.973 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-27T23:14:16.336Z,1422400456.336 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-27T23:14:19.773Z,1422400459.773 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20150127T230557/Courier0004.lzma
2015-01-27T23:14:20.567Z,1422400460.567 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0004.lzma.bak
2015-01-27T23:14:20.567Z,1422400460.567 [DataOverHttps](INFO): SBD MOMSN=1508913
2015-01-27T23:14:30.693Z,1422400470.693 [DataOverHttps](INFO): Sending 506 bytes from file Logs/20150127T230050/Express0001.lzma
2015-01-27T23:14:31.480Z,1422400471.480 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230050/Express0001.lzma.bak
2015-01-27T23:14:31.480Z,1422400471.480 [DataOverHttps](INFO): SBD MOMSN=1508915
2015-01-27T23:14:40.885Z,1422400480.885 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20150127T230050/Express0005.lzma
2015-01-27T23:14:41.684Z,1422400481.684 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230050/Express0005.lzma.bak
2015-01-27T23:14:41.684Z,1422400481.684 [DataOverHttps](INFO): SBD MOMSN=1508928
2015-01-27T23:14:51.555Z,1422400491.555 [DataOverHttps](INFO): Sending 638 bytes from file Logs/20150127T230557/Express0001.lzma
2015-01-27T23:14:52.341Z,1422400492.341 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0001.lzma.bak
2015-01-27T23:14:52.341Z,1422400492.341 [DataOverHttps](INFO): SBD MOMSN=1508933
2015-01-27T23:15:02.487Z,1422400502.487 [DataOverHttps](INFO): Sending 366 bytes from file Logs/20150127T230557/Express0005.lzma
2015-01-27T23:15:03.286Z,1422400503.286 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0005.lzma.bak
2015-01-27T23:15:03.286Z,1422400503.286 [DataOverHttps](INFO): SBD MOMSN=1508952
2015-01-27T23:15:04.083Z,1422400504.083 [Default:CheckIn:Read_Iridium] Stopped
2015-01-27T23:15:04.084Z,1422400504.084 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-27T23:15:04.084Z,1422400504.084 [Default:CheckIn] Stopped
2015-01-27T23:15:04.084Z,1422400504.084 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-27T23:15:04.084Z,1422400504.084 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-27T23:15:04.084Z,1422400504.084 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-27T23:15:11.941Z,1422400511.941 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:15:11.941Z,1422400511.941 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:15:11.942Z,1422400511.942 [BPC1](ERROR): Communications Fault
2015-01-27T23:15:11.985Z,1422400511.985 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:15:24.166Z,1422400524.166 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:15:24.166Z,1422400524.166 [BPC1] No Fault, FailCount= 1
2015-01-27T23:15:57.294Z,1422400557.294 [CommandLine](IMPORTANT): got command report
2015-01-27T23:15:57.295Z,1422400557.295 [Reporter](INFO): NAL9602.sigQuality reporting changes
2015-01-27T23:16:09.174Z,1422400569.174 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:16:09.174Z,1422400569.174 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:16:09.175Z,1422400569.175 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:16:09.175Z,1422400569.175 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:16:09.175Z,1422400569.175 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:16:17.001Z,1422400577.001 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 6.891901 min 
2015-01-27T23:16:17.001Z,1422400577.001 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:16:17.001Z,1422400577.001 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:16:17.001Z,1422400577.001 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:16:17.001Z,1422400577.001 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:16:44.127Z,1422400604.127 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-27T23:16:44.127Z,1422400604.127 [NAL9602] Data Fault, FailCount= 1
2015-01-27T23:16:44.128Z,1422400604.128 [NAL9602](ERROR): Data Fault
2015-01-27T23:16:44.193Z,1422400604.193 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T23:16:44.194Z,1422400604.194 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T23:16:49.123Z,1422400609.123 [NAL9602](INFO): Stop
2015-01-27T23:16:49.123Z,1422400609.123 [NAL9602](INFO): Uninitialize
2015-01-27T23:16:49.123Z,1422400609.123 [NAL9602](INFO): Powering down
2015-01-27T23:16:54.127Z,1422400614.127 [NAL9602](INFO): Stopping
2015-01-27T23:16:59.174Z,1422400619.174 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T23:16:59.174Z,1422400619.174 [NAL9602] No Fault, FailCount= 1
2015-01-27T23:17:04.126Z,1422400624.126 [NAL9602](INFO): Start
2015-01-27T23:17:04.127Z,1422400624.127 [NAL9602](INFO): Powering up NAL9602
2015-01-27T23:17:14.170Z,1422400634.170 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5D%56
$C1,01,7F,02,00,03,7F,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B9A,09,3C57,0A,FFFC,0B,0002%38
$B11,0C,0001,0D,0056,0E,0052,0F,13B6,10,173A,11,FFFF,12,FFFF%43
$B11,13,6978,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,0B8D,09,3C54,0A,FFFD,0B,0002%3B
$B12,0C,0001,0D,0058,0E,0052,0F,13D9,10,16AC,11,FFFF,12,FFFF%36
$B12,13,54BA,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%40
$B12,1A,0031,1B,4357,1C,00AB%34
$B13,02,000A,01,026C,03,0001,08,0B90,09,3C53,0A,FFFC,0B,0003%4E
$B13,0C,0001,0D,0061,0E,0052,0F,13B1,10,16AE,11,FFFF,12,FFFF%35
$B13,13,3BC4,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%45
$B13,1A,0031,1B,4357,1C,00B1%45
$B14,02,000A,01,026C,03,0001,08,0B93,09,3C50,0A,FFFD,0B,0002%4F
$B14,0C,0001,0D,0054,0E,004F,0F,12EC,10,1688,11,FFFF,12,FFFF%31
$B14,13,6C48,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%3D
$B14,1A,0031,1B,4357,1C,00A0%40
$B15,02,000A,01,026C,03,0001,08,0B8F,09,3C11,0A,0000,0B,0004%3B
$B15,0C,0001,0D,0064,0E,005C,0F,1615,10,1736,11,FFFF,12,FFFF%35
$B15,13,10EF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B15,1A,0031,1B,4357,1C,008B%4A
$B16,02,000A,01,026C,03,0001,08,0B88,09,3C52,0A,0000,0B,0003%46
$B16,0C,0001,0D,0060,0E,005A,0F,158F,10,178C,11,FFFF,12,FFFF%37
$B16,13,27C4,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%37
$B16,1A,0031,1B,4339,1C,007F%4A
$B17,02,000A,01,026C,03,0001,08,0B85,09,3C09,0A,0000,0B,0003%44
$B17,0C,0001,0D,0064,0E,005D,0F,1653,10,16E1,11,FFFF,12,FFFF%42
$B17,13,0B18,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%31
$B17,1A,0031,1B,4357,1C,00B4%44
$S,01,270F,02,00,04,5D%56
$C1,01,7F,02,00,03,7F,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,FFFD%32
$B13,0A,FFFC%34
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
4357,1C,0098%33
$B18,02,000A,01,026C,03,0001,08,0B8F,09,3C0A,0A,0000,0B,0000%43
$B18,0C,0001,0D,004E,0E,0046,0F,10F0,10,168E,11,FFFF,12,FFFF%32
$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-27T23:17:14.170Z,1422400634.170 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T23:17:14.170Z,1422400634.170 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:17:14.170Z,1422400634.170 [BPC1](ERROR): Data Fault
2015-01-27T23:17:14.185Z,1422400634.185 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:17:14.186Z,1422400634.186 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-27T23:17:24.130Z,1422400644.130 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T23:17:24.130Z,1422400644.130 [NAL9602](INFO): NAL9602 initialized
2015-01-27T23:17:29.165Z,1422400649.165 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:17:29.165Z,1422400649.165 [BPC1] No Fault, FailCount= 1
2015-01-27T23:19:19.148Z,1422400759.148 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:19:19.148Z,1422400759.148 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:19:19.149Z,1422400759.149 [BPC1](ERROR): Communications Fault
2015-01-27T23:19:19.186Z,1422400759.186 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:19:34.151Z,1422400774.151 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:19:34.151Z,1422400774.151 [BPC1] No Fault, FailCount= 1
2015-01-27T23:20:04.165Z,1422400804.165 [Default:CheckIn] Running Loop=1
2015-01-27T23:20:04.165Z,1422400804.165 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-27T23:20:04.165Z,1422400804.165 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:20:04.165Z,1422400804.165 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-27T23:20:04.165Z,1422400804.165 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-27T23:20:06.131Z,1422400806.131 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:21:09.525Z,1422400869.525 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:21:09.525Z,1422400869.525 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:21:09.525Z,1422400869.525 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:21:09.526Z,1422400869.526 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:21:09.526Z,1422400869.526 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:21:09.933Z,1422400869.933 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 11.898422 min 
2015-01-27T23:21:09.934Z,1422400869.934 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:21:09.934Z,1422400869.934 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:21:09.934Z,1422400869.934 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:21:09.934Z,1422400869.934 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:21:14.742Z,1422400874.742 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5D%56
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,0000%33
$B12,0A,FFFC%35
$B13,0A,FFFC%34
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFE4%4B
$S,01,270F,02,00,04,5D%56
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B8C,09,3C20,0A,0000,0B,0000%3C
$B11,0C,0001,0D,0064,0E,005B,0F,15E2,10,1641,11,FFFF,12,FFFF%41
$B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B91,09,3C4B,0A,FFFB,0B,FFFC%39
$B12,0C,0001,0D,0053,0E,0051,0F,137A,10,17B2,11,E9B8,12,FFFF%40
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B99,09,3C49,0A,FFFC,0B,FFFC%4A
$B13,0C,0001,0D,005C,0E,004E,0F,12CE,10,16D7,11,FFFF,12,FFFF%31
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B8F,09,3C4A,0A,FFFC,0B,FFFC%4B
$B14,0C,0001,0D,0053,0E,004D,0F,1280,10,168C,11,FFFF,12,FFFF%41
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B92,09,3C13,0A,0000,0B,0000%48
$B15,0C,0001,0D,0064,0E,005B,0F,1602,10,16B6,11,FFFF,12,FFFF%42
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B8E,09,3C19,0A,0000,0B,0000%37
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,FFFF,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,0B90,09,3C15,0A,0000,0B,0000%4E
$B17,0C,0001,0D,0064,0E,005F,0F,16DB,10,1701,11,FFFF,12,FFFF%34
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00A5%46
$B18,02,000A,01,026C,03,0001,08,0B92,09,3C2F,0A,FFE0,0B,FFE4%37
$B18,0C,0001,0D,0059,0E,0051,0F,1385,10,16A5,11,1D48,12,2863%4E
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00AE%39

2015-01-27T23:21:14.742Z,1422400874.742 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T23:21:14.742Z,1422400874.742 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:21:14.743Z,1422400874.743 [BPC1](ERROR): Data Fault
2015-01-27T23:21:14.758Z,1422400874.758 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:21:18.400Z,1422400878.400 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:21:18.401Z,1422400878.401 [BPC1] No Fault, FailCount= 1
2015-01-27T23:23:45.758Z,1422401025.758 [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,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFB%35
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFDB%3C
$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,0B92,09,3C52,0A,FFFC,0B,FFFC%49
$B11,0C,0001,0D,005A,0E,0056,0F,14B0,10,1787,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,00A7%42
$B12,02,000A,01,026C,03,0001,08,0B8F,09,3C24,0A,0000,0B,0000%3E
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,FFFF,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,0B97,09,3C56,0A,FFFA,0B,FFFB%49
$B13,0C,0001,0D,0060,0E,0054,0F,1456,10,17AC,11,CB5C,12,F408%4F
$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,3C56,0A,FFFC,0B,FFFC%3B
$B14,0C,0001,0D,0059,0E,0054,0F,1438,10,16F6,11,FFFF,12,FFFF%34
$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,0B93,09,3C15,0A,0000,0B,0000%4F
$B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B8E,09,3C5C,0A,0000,0B,0000%49
$B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44
$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,0B90,09,3C56,0A,0000,0B,0000%49
$B17,0C,0001,0D,005E,0E,0057,0F,14E5,10,16E3,11,FFFF,12,FFFF%35
$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,3C2F,0A,FFDB,0B,FFDA%31
$B18,0C,0001,0D,0059,0E,0056,0F,1498,10,17BE,11,2165,12,2084%48
$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-27T23:23:45.758Z,1422401025.758 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-27T23:23:45.758Z,1422401025.758 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:23:45.758Z,1422401025.758 [BPC1](ERROR): Data Fault
2015-01-27T23:23:45.774Z,1422401025.774 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:23:46.964Z,1422401026.964 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:23:46.964Z,1422401026.964 [BPC1] No Fault, FailCount= 1
2015-01-27T23:25:04.218Z,1422401104.218 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-27T23:20:04.2Z
2015-01-27T23:25:04.218Z,1422401104.218 [Default:CheckIn:Read_GPS] Stopped
2015-01-27T23:25:04.218Z,1422401104.218 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-27T23:25:09.074Z,1422401109.074 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150127T230557/Courier0008.lzma
2015-01-27T23:25:09.869Z,1422401109.869 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0008.lzma.bak
2015-01-27T23:25:09.869Z,1422401109.869 [DataOverHttps](INFO): SBD MOMSN=1508957
2015-01-27T23:25:19.371Z,1422401119.371 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20150127T230557/Express0009.lzma
2015-01-27T23:25:20.150Z,1422401120.150 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0009.lzma.bak
2015-01-27T23:25:20.151Z,1422401120.151 [DataOverHttps](INFO): SBD MOMSN=1508959
2015-01-27T23:25:20.970Z,1422401120.970 [Default:CheckIn:Read_Iridium] Stopped
2015-01-27T23:25:20.971Z,1422401120.971 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-27T23:25:20.971Z,1422401120.971 [Default:CheckIn] Stopped
2015-01-27T23:25:20.971Z,1422401120.971 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-27T23:25:20.971Z,1422401120.971 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-27T23:25:20.971Z,1422401120.971 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-27T23:26:11.015Z,1422401171.015 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:26:11.015Z,1422401171.015 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:26:11.015Z,1422401171.015 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:26:11.015Z,1422401171.015 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:26:11.015Z,1422401171.015 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:26:16.021Z,1422401176.021 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 16.923039 min 
2015-01-27T23:26:16.022Z,1422401176.022 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:26:16.022Z,1422401176.022 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:26:16.022Z,1422401176.022 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:26:16.022Z,1422401176.022 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:27:21.005Z,1422401241.005 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:27:33.807Z,1422401253.807 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:27:33.807Z,1422401253.807 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:27:33.808Z,1422401253.808 [BPC1](ERROR): Communications Fault
2015-01-27T23:27:33.842Z,1422401253.842 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:27:35.997Z,1422401255.997 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-27T23:27:35.998Z,1422401255.998 [NAL9602] Data Fault, FailCount= 2
2015-01-27T23:27:35.998Z,1422401255.998 [NAL9602](ERROR): Data Fault
2015-01-27T23:27:36.041Z,1422401256.041 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T23:27:36.042Z,1422401256.042 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T23:27:40.993Z,1422401260.993 [NAL9602](INFO): Stop
2015-01-27T23:27:40.993Z,1422401260.993 [NAL9602](INFO): Uninitialize
2015-01-27T23:27:40.993Z,1422401260.993 [NAL9602](INFO): Powering down
2015-01-27T23:27:45.993Z,1422401265.993 [NAL9602](INFO): Stopping
2015-01-27T23:27:46.031Z,1422401266.031 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:27:46.031Z,1422401266.031 [BPC1] No Fault, FailCount= 1
2015-01-27T23:27:51.070Z,1422401271.070 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T23:27:51.070Z,1422401271.070 [NAL9602] No Fault, FailCount= 2
2015-01-27T23:27:55.992Z,1422401275.992 [NAL9602](INFO): Start
2015-01-27T23:27:55.993Z,1422401275.993 [NAL9602](INFO): Powering up NAL9602
2015-01-27T23:28:11.057Z,1422401291.057 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-27T23:28:20.992Z,1422401300.992 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T23:28:20.992Z,1422401300.992 [NAL9602](INFO): NAL9602 initialized
2015-01-27T23:30:21.029Z,1422401421.029 [Default:CheckIn] Running Loop=1
2015-01-27T23:30:21.030Z,1422401421.030 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-27T23:30:21.030Z,1422401421.030 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:30:21.030Z,1422401421.030 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-27T23:30:21.030Z,1422401421.030 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-27T23:31:02.726Z,1422401462.726 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5D%56
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,0000%33
$B12,0A,FFFC%35
$B13,0A,FFFC%34
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFD7%49
$S,01,270F,02,00,04,5D%56
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B8C,09,3C20,0A,0000,0B,0000%3C
$B11,0C,0001,0D,0064,0E,005B,0F,15E2,10,1641,11,FFFF,12,FFFF%41
$B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B91,09,3C4B,0A,FFFB,0B,FFFC%39
$B12,0C,0001,0D,0053,0E,0051,0F,137A,10,17B2,11,FFFF,12,FFFF%46
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B99,09,3C4B,0A,FFFC,0B,FFFC%31
$B13,0C,0001,0D,005C,0E,004E,0F,12CE,10,16D7,11,FFFF,12,FFFF%31
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B90,09,3C4A,0A,FFFC,0B,FFFC%3C
$B14,0C,0001,0D,0053,0E,004D,0F,1280,10,168C,11,FFFF,12,FFFF%41
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B92,09,3C12,0A,0000,0B,0000%49
$B15,0C,0001,0D,0064,0E,005B,0F,1602,10,16B6,11,FFFF,12,FFFF%42
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B8E,09,3C1A,0A,0000,0B,0000%4F
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,FFFF,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,0B90,09,3C15,0A,0000,0B,0000%4E
$B17,0C,0001,0D,0064,0E,005F,0F,16DB,10,1701,11,FFFF,12,FFFF%34
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00A5%46
$B18,02,000A,01,026C,03,0001,08,0B93,09,3C2B,0A,FFE3,0B,FFE3%36
$B18,0C,0001,0D,0059,0E,0051,0F,1380,10,16A5,11,2858,12,2858%3D
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00AE%39

2015-01-27T23:31:02.726Z,1422401462.726 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T23:31:02.726Z,1422401462.726 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:31:02.726Z,1422401462.726 [BPC1](ERROR): Data Fault
2015-01-27T23:31:02.741Z,1422401462.741 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:31:03.947Z,1422401463.947 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:31:03.947Z,1422401463.947 [BPC1] No Fault, FailCount= 1
2015-01-27T23:31:11.134Z,1422401471.134 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:31:11.134Z,1422401471.134 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:31:11.134Z,1422401471.134 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:31:11.135Z,1422401471.135 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:31:11.135Z,1422401471.135 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:31:11.523Z,1422401471.523 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 21.925085 min 
2015-01-27T23:31:11.523Z,1422401471.523 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:31:11.524Z,1422401471.524 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:31:11.524Z,1422401471.524 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:31:11.524Z,1422401471.524 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:33:31.270Z,1422401611.270 [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,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFB%35
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFDB%3C
$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,0B92,09,3C52,0A,FFFC,0B,FFFC%49
$B11,0C,0001,0D,005A,0E,0056,0F,14B0,10,1787,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,00A7%42
$B12,02,000A,01,026C,03,0001,08,0B90,09,3C24,0A,0000,0B,0000%49
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,FFFF,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,0B97,09,3C55,0A,FFFB,0B,FFFB%49
$B13,0C,0001,0D,0060,0E,0054,0F,1456,10,17AC,11,F408,12,F408%42
$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,3C57,0A,FFFC,0B,FFFC%3A
$B14,0C,0001,0D,0059,0E,0054,0F,1438,10,16F6,11,1717,12,FFFF%34
$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,0B93,09,3C15,0A,0000,0B,0000%4F
$B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B8F,09,3C5B,0A,0000,0B,0000%4B
$B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44
$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,0B90,09,3C56,0A,0000,0B,0000%49
$B17,0C,0001,0D,005E,0E,0057,0F,14E5,10,16E3,11,FFFF,12,FFFF%35
$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,3C2B,0A,FFDB,0B,FFDA%35
$B18,0C,0001,0D,0059,0E,0055,0F,1492,10,17BE,11,1E1A,12,207B%3C
$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-27T23:33:31.270Z,1422401611.270 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-27T23:33:31.270Z,1422401611.270 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:33:31.270Z,1422401611.270 [BPC1](ERROR): Data Fault
2015-01-27T23:33:31.286Z,1422401611.286 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:33:34.971Z,1422401614.971 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:33:34.971Z,1422401614.971 [BPC1] No Fault, FailCount= 1
2015-01-27T23:34:05.696Z,1422401645.696 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:35:21.054Z,1422401721.054 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-27T23:30:21.0Z
2015-01-27T23:35:21.054Z,1422401721.054 [Default:CheckIn:Read_GPS] Stopped
2015-01-27T23:35:21.054Z,1422401721.054 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-27T23:35:25.830Z,1422401725.830 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150127T230557/Courier0012.lzma
2015-01-27T23:35:26.626Z,1422401726.626 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0012.lzma.bak
2015-01-27T23:35:26.626Z,1422401726.626 [DataOverHttps](INFO): SBD MOMSN=1508970
2015-01-27T23:35:36.442Z,1422401736.442 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20150127T230557/Express0013.lzma
2015-01-27T23:35:37.233Z,1422401737.233 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0013.lzma.bak
2015-01-27T23:35:37.233Z,1422401737.233 [DataOverHttps](INFO): SBD MOMSN=1508972
2015-01-27T23:35:38.028Z,1422401738.028 [Default:CheckIn:Read_Iridium] Stopped
2015-01-27T23:35:38.029Z,1422401738.029 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-27T23:35:38.029Z,1422401738.029 [Default:CheckIn] Stopped
2015-01-27T23:35:38.029Z,1422401738.029 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-27T23:35:38.029Z,1422401738.029 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-27T23:35:38.029Z,1422401738.029 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-27T23:36:13.082Z,1422401773.082 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:36:13.082Z,1422401773.082 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:36:13.082Z,1422401773.082 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:36:13.083Z,1422401773.083 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:36:13.083Z,1422401773.083 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:36:18.110Z,1422401778.110 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 26.957316 min 
2015-01-27T23:36:18.110Z,1422401778.110 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:36:18.110Z,1422401778.110 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:36:18.110Z,1422401778.110 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:36:18.111Z,1422401778.111 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:38:38.051Z,1422401918.051 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-27T23:38:38.052Z,1422401918.052 [NAL9602] Data Fault, FailCount= 3
2015-01-27T23:38:38.052Z,1422401918.052 [NAL9602](ERROR): Data Fault
2015-01-27T23:38:38.120Z,1422401918.120 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T23:38:38.121Z,1422401918.121 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T23:38:43.051Z,1422401923.051 [NAL9602](INFO): Stop
2015-01-27T23:38:43.051Z,1422401923.051 [NAL9602](INFO): Uninitialize
2015-01-27T23:38:43.051Z,1422401923.051 [NAL9602](INFO): Powering down
2015-01-27T23:38:48.051Z,1422401928.051 [NAL9602](INFO): Stopping
2015-01-27T23:38:55.877Z,1422401935.877 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T23:38:55.878Z,1422401935.878 [NAL9602] No Fault, FailCount= 3
2015-01-27T23:38:58.054Z,1422401938.054 [NAL9602](INFO): Start
2015-01-27T23:38:58.054Z,1422401938.054 [NAL9602](INFO): Powering up NAL9602
2015-01-27T23:39:13.094Z,1422401953.094 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-27T23:39:23.053Z,1422401963.053 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T23:39:23.054Z,1422401963.054 [NAL9602](INFO): NAL9602 initialized
2015-01-27T23:40:38.061Z,1422402038.061 [Default:CheckIn] Running Loop=1
2015-01-27T23:40:38.061Z,1422402038.061 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-27T23:40:38.061Z,1422402038.061 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:40:38.061Z,1422402038.061 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-27T23:40:38.061Z,1422402038.061 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-27T23:41:13.311Z,1422402073.311 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:41:13.311Z,1422402073.311 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:41:13.312Z,1422402073.312 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:41:13.312Z,1422402073.312 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:41:13.312Z,1422402073.312 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:41:13.727Z,1422402073.727 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 31.961499 min 
2015-01-27T23:41:13.727Z,1422402073.727 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:41:13.727Z,1422402073.727 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:41:13.727Z,1422402073.727 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:41:13.728Z,1422402073.728 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:41:22.124Z,1422402082.124 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:45:00.889Z,1422402300.889 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5A%53
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,FFFC%35
$B13,0A,FFFB%35
$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,5A%53
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B97,09,3C4E,0A,FFFD,0B,FFFC%3D
$B11,0C,0001,0D,0054,0E,004E,0F,12E4,10,16D9,11,FFFF,12,FFFF%3D
$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,0B8F,09,3C4E,0A,FFFB,0B,FFFB%49
$B12,0C,0001,0D,0052,0E,004F,0F,12EF,10,1722,11,E334,12,E334%35
$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,0B8F,09,3C4E,0A,FFFB,0B,FFFB%48
$B13,0C,0001,0D,005B,0E,004F,0F,12E7,10,170F,11,E2D4,12,E2D4%43
$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,0B93,09,3C53,0A,FFFC,0B,FFFC%4C
$B14,0C,0001,0D,0057,0E,0052,0F,13A0,10,16C5,11,FFFF,12,FFFF%47
$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,0B9B,09,3C10,0A,0000,0B,0000%3B
$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,0B8E,09,3C21,0A,0000,0B,0000%3C
$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,0B96,09,3C1E,0A,0000,0B,0000%38
$B17,0C,0001,0D,0064,0E,005F,0F,16C8,10,16D1,11,FFFF,12,FFFF%3C
$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,0B90,09,3C09,0A,0000,0B,0000%4C
$B18,0C,0001,0D,004E,0E,0046,0F,10F0,10,168E,11,FFFF,12,FFFF%32
$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-27T23:45:00.896Z,1422402300.896 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-27T23:45:00.896Z,1422402300.896 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:45:00.897Z,1422402300.897 [BPC1](ERROR): Data Fault
2015-01-27T23:45:00.912Z,1422402300.912 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:45:02.115Z,1422402302.115 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:45:02.115Z,1422402302.115 [BPC1] No Fault, FailCount= 1
2015-01-27T23:45:38.107Z,1422402338.107 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-27T23:40:38.1Z
2015-01-27T23:45:38.107Z,1422402338.107 [Default:CheckIn:Read_GPS] Stopped
2015-01-27T23:45:38.107Z,1422402338.107 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-27T23:45:42.926Z,1422402342.926 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150127T230557/Courier0016.lzma
2015-01-27T23:45:43.721Z,1422402343.721 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0016.lzma.bak
2015-01-27T23:45:43.721Z,1422402343.721 [DataOverHttps](INFO): SBD MOMSN=1508980
2015-01-27T23:45:53.821Z,1422402353.821 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20150127T230557/Express0017.lzma
2015-01-27T23:45:54.618Z,1422402354.618 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0017.lzma.bak
2015-01-27T23:45:54.618Z,1422402354.618 [DataOverHttps](INFO): SBD MOMSN=1508982
2015-01-27T23:45:55.416Z,1422402355.416 [Default:CheckIn:Read_Iridium] Stopped
2015-01-27T23:45:55.417Z,1422402355.417 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-27T23:45:55.417Z,1422402355.417 [Default:CheckIn] Stopped
2015-01-27T23:45:55.417Z,1422402355.417 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-27T23:45:55.417Z,1422402355.417 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-27T23:45:55.417Z,1422402355.417 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-27T23:46:08.244Z,1422402368.244 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:46:08.244Z,1422402368.244 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:46:08.244Z,1422402368.244 [BPC1](ERROR): Communications Fault
2015-01-27T23:46:08.259Z,1422402368.259 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:46:15.469Z,1422402375.469 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:46:15.469Z,1422402375.469 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:46:15.469Z,1422402375.469 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:46:15.470Z,1422402375.470 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:46:15.470Z,1422402375.470 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:46:20.470Z,1422402380.470 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 36.997136 min 
2015-01-27T23:46:20.470Z,1422402380.470 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:46:20.470Z,1422402380.470 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:46:20.470Z,1422402380.470 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:46:20.470Z,1422402380.470 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:46:20.479Z,1422402380.479 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:46:20.479Z,1422402380.479 [BPC1] No Fault, FailCount= 1
2015-01-27T23:46:45.459Z,1422402405.459 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:
2015-01-27T23:46:45.459Z,1422402405.459 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-27T23:46:45.459Z,1422402405.459 [BPC1] Data Fault, FailCount= 2
2015-01-27T23:46:45.459Z,1422402405.459 [BPC1](ERROR): Data Fault
2015-01-27T23:46:45.475Z,1422402405.475 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:47:00.464Z,1422402420.464 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:47:00.464Z,1422402420.464 [BPC1] No Fault, FailCount= 2
2015-01-27T23:48:08.248Z,1422402488.248 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:48:08.248Z,1422402488.248 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:48:08.248Z,1422402488.248 [BPC1](ERROR): Communications Fault
2015-01-27T23:48:08.263Z,1422402488.263 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:48:20.475Z,1422402500.475 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:48:20.475Z,1422402500.475 [BPC1] No Fault, FailCount= 1
2015-01-27T23:49:35.434Z,1422402575.434 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-27T23:49:35.434Z,1422402575.434 [NAL9602] Data Fault, FailCount= 4
2015-01-27T23:49:35.434Z,1422402575.434 [NAL9602](ERROR): Data Fault
2015-01-27T23:49:35.505Z,1422402575.505 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-27T23:49:35.506Z,1422402575.506 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-27T23:49:40.440Z,1422402580.440 [NAL9602](INFO): Stop
2015-01-27T23:49:40.440Z,1422402580.440 [NAL9602](INFO): Uninitialize
2015-01-27T23:49:40.440Z,1422402580.440 [NAL9602](INFO): Powering down
2015-01-27T23:49:45.439Z,1422402585.439 [NAL9602](INFO): Stopping
2015-01-27T23:49:50.503Z,1422402590.503 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-27T23:49:50.503Z,1422402590.503 [NAL9602] No Fault, FailCount= 4
2015-01-27T23:49:55.437Z,1422402595.437 [NAL9602](INFO): Start
2015-01-27T23:49:55.437Z,1422402595.437 [NAL9602](INFO): Powering up NAL9602
2015-01-27T23:49:55.456Z,1422402595.456 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:50:05.534Z,1422402605.534 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-27T23:50:15.447Z,1422402615.447 [NAL9602](INFO): ************** CMDMODE **************

2015-01-27T23:50:15.447Z,1422402615.447 [NAL9602](INFO): NAL9602 initialized
2015-01-27T23:50:55.503Z,1422402655.503 [Default:CheckIn] Running Loop=1
2015-01-27T23:50:55.504Z,1422402655.504 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-27T23:50:55.504Z,1422402655.504 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-27T23:50:55.504Z,1422402655.504 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-27T23:50:55.504Z,1422402655.504 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-27T23:51:15.508Z,1422402675.508 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:51:15.508Z,1422402675.508 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:51:15.509Z,1422402675.509 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:51:15.509Z,1422402675.509 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:51:15.509Z,1422402675.509 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:51:15.891Z,1422402675.891 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 41.997713 min 
2015-01-27T23:51:15.891Z,1422402675.891 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:51:15.891Z,1422402675.891 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:51:15.892Z,1422402675.892 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:51:15.892Z,1422402675.892 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:53:04.819Z,1422402784.819 [BPC1](ERROR): B 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,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFB%35
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFDC%3D
$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,0B93,09,3C51,0A,FFFC,0B,FFFC%4B
$B11,0C,0001,0D,005A,0E,0056,0F,14B0,10,1787,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,00A7%42
$B12,02,000A,01,026C,03,0001,08,0B91,09,3C24,0A,0000,0B,0000%48
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,FFFF,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,0B98,09,3C55,0A,FFFB,0B,FFFB%46
$B13,0C,0001,0D,0060,0E,0054,0F,1455,10,17AC,11,F3FC,12,F3FC%41
$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,0B9B,09,3C57,0A,FFFC,0B,FFFC%39
$B14,0C,0001,0D,0059,0E,0054,0F,1438,10,16F6,11,FFFF,12,FFFF%34
$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,0B94,09,3C14,0A,0000,0B,0000%49
$B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B90,09,3C5A,0A,0000,0B,0000%3F
$B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44
$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,0B91,09,3C54,0A,0000,0B,0000%4A
$B17,0C,0001,0D,005E,0E,0057,0F,14E5,10,16E3,11,FFFF,12,FFFF%35
$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,3C24,0A,FFD7,0B,FFDA%36
$B18,0C,0001,0D,0059,0E,0055,0F,1487,10,17BE,11,1E0A,12,2069%43
$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-27T23:53:04.819Z,1422402784.819 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T23:53:04.819Z,1422402784.819 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:53:04.819Z,1422402784.819 [BPC1](ERROR): Data Fault
2015-01-27T23:53:04.834Z,1422402784.834 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:53:06.008Z,1422402786.008 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:53:06.008Z,1422402786.008 [BPC1] No Fault, FailCount= 1
2015-01-27T23:54:17.303Z,1422402857.303 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5A%53
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,FFFC%35
$B13,0A,FFFB%35
$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,5A%53
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B97,09,3C4D,0A,FFFC,0B,FFFC%3B
$B11,0C,0001,0D,0054,0E,004E,0F,12E3,10,16D9,11,FFFF,12,FFFF%3A
$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,0B90,09,3C4F,0A,FFFC,0B,FFFC%3D
$B12,0C,0001,0D,0052,0E,004F,0F,12EF,10,1722,11,FFFF,12,FFFF%35
$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,0B90,09,3C4E,0A,FFFB,0B,FFFB%3F
$B13,0C,0001,0D,005B,0E,004F,0F,12E6,10,170F,11,E2C8,12,E2C8%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,0B94,09,3C53,0A,FFFC,0B,FFFC%4B
$B14,0C,0001,0D,0057,0E,0052,0F,13A0,10,16C5,11,FFFF,12,FFFF%47
$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,0B9B,09,3C10,0A,0000,0B,0000%3B
$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,0B8E,09,3C21,0A,0000,0B,0000%3C
$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,0B96,09,3C1F,0A,0000,0B,0000%3B
$B17,0C,0001,0D,0064,0E,005F,0F,16C8,10,16D1,11,FFFF,12,FFFF%3C
$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,0B90,09,3C09,0A,0000,0B,0000%4C
$B18,0C,0001,0D,004E,0E,0046,0F,10F0,10,168E,11,FFFF,12,FFFF%32
$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-27T23:54:17.303Z,1422402857.303 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-27T23:54:17.303Z,1422402857.303 [BPC1] Data Fault, FailCount= 1
2015-01-27T23:54:17.303Z,1422402857.303 [BPC1](ERROR): Data Fault
2015-01-27T23:54:17.318Z,1422402857.318 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-27T23:54:18.527Z,1422402858.527 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:54:18.527Z,1422402858.527 [BPC1] No Fault, FailCount= 1
2015-01-27T23:55:50.519Z,1422402950.519 [BPC1](FAULT): Failed to receive battery data
2015-01-27T23:55:50.519Z,1422402950.519 [BPC1] Communications Fault, FailCount= 1
2015-01-27T23:55:50.519Z,1422402950.519 [BPC1](ERROR): Communications Fault
2015-01-27T23:55:50.534Z,1422402950.534 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-27T23:55:51.740Z,1422402951.740 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-27T23:55:51.741Z,1422402951.741 [BPC1] No Fault, FailCount= 1
2015-01-27T23:55:55.724Z,1422402955.724 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-27T23:50:55.5Z
2015-01-27T23:55:55.725Z,1422402955.725 [Default:CheckIn:Read_GPS] Stopped
2015-01-27T23:55:55.725Z,1422402955.725 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-27T23:56:00.560Z,1422402960.560 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150127T230557/Courier0020.lzma
2015-01-27T23:56:01.353Z,1422402961.353 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0020.lzma.bak
2015-01-27T23:56:01.354Z,1422402961.354 [DataOverHttps](INFO): SBD MOMSN=1508988
2015-01-27T23:56:11.131Z,1422402971.131 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20150127T230557/Express0021.lzma
2015-01-27T23:56:11.930Z,1422402971.930 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0021.lzma.bak
2015-01-27T23:56:11.930Z,1422402971.930 [DataOverHttps](INFO): SBD MOMSN=1508990
2015-01-27T23:56:11.981Z,1422402971.981 [BPC1](DEBUG): Received data from all battery sticks
2015-01-27T23:56:12.731Z,1422402972.731 [Default:CheckIn:Read_Iridium] Stopped
2015-01-27T23:56:12.731Z,1422402972.731 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-27T23:56:12.732Z,1422402972.732 [Default:CheckIn] Stopped
2015-01-27T23:56:12.732Z,1422402972.732 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-27T23:56:12.732Z,1422402972.732 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-27T23:56:12.732Z,1422402972.732 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-27T23:56:17.823Z,1422402977.823 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-27T23:56:17.824Z,1422402977.824 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:56:17.824Z,1422402977.824 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-27T23:56:17.824Z,1422402977.824 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-27T23:56:17.824Z,1422402977.824 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-27T23:56:25.591Z,1422402985.591 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 47.035688 min 
2015-01-27T23:56:25.592Z,1422402985.592 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-27T23:56:25.592Z,1422402985.592 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:56:25.592Z,1422402985.592 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-27T23:56:25.592Z,1422402985.592 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-27T23:59:47.748Z,1422403187.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2015-01-28T00:00:30.539Z,1422403230.539 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-28T00:00:30.539Z,1422403230.539 [NAL9602] Data Fault, FailCount= 5
2015-01-28T00:00:30.539Z,1422403230.539 [NAL9602](ERROR): Data Fault
2015-01-28T00:00:30.599Z,1422403230.599 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-28T00:00:30.600Z,1422403230.600 [CBIT](CRITICAL): Data Fault in component: NAL9602
2015-01-28T00:00:30.601Z,1422403230.601 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-28T00:00:32.752Z,1422403232.752 [NAL9602](INFO): Stop
2015-01-28T00:00:32.752Z,1422403232.752 [NAL9602](INFO): Uninitialize
2015-01-28T00:00:32.752Z,1422403232.752 [NAL9602](INFO): Powering down
2015-01-28T00:00:37.752Z,1422403237.752 [NAL9602](INFO): Stopping
2015-01-28T00:01:12.769Z,1422403272.769 [Default:CheckIn] Running Loop=1
2015-01-28T00:01:12.782Z,1422403272.782 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-28T00:01:12.782Z,1422403272.782 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T00:01:12.782Z,1422403272.782 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-28T00:01:12.782Z,1422403272.782 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-28T00:01:17.964Z,1422403277.964 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T00:01:17.964Z,1422403277.964 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:01:17.964Z,1422403277.964 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T00:01:17.965Z,1422403277.965 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T00:01:17.965Z,1422403277.965 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T00:01:18.369Z,1422403278.369 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 52.039065 min 
2015-01-28T00:01:18.369Z,1422403278.369 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T00:01:18.370Z,1422403278.370 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:01:18.370Z,1422403278.370 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T00:01:18.394Z,1422403278.394 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:02:30.891Z,1422403350.891 [CBIT](INFO): Clearing failed count for component NAL9602
2015-01-28T00:02:30.891Z,1422403350.891 [NAL9602] No Fault, FailCount= 5
2015-01-28T00:02:31.260Z,1422403351.260 [NAL9602](INFO): Start
2015-01-28T00:02:31.261Z,1422403351.261 [NAL9602](INFO): Powering up NAL9602
2015-01-28T00:02:41.293Z,1422403361.293 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T00:02:42.058Z,1422403362.058 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T00:02:42.058Z,1422403362.058 [NAL9602](INFO): NAL9602 initialized
2015-01-28T00:03:35.848Z,1422403415.848 [BPC1](DEBUG): Received data from all battery sticks
2015-01-28T00:03:36.213Z,1422403416.213 [BPC1](FAULT): B bank: No match for serial number:5911 was found in the onboard configuration.
2015-01-28T00:03:36.213Z,1422403416.213 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-28T00:03:36.213Z,1422403416.213 [BPC1] Data Fault, FailCount= 1
2015-01-28T00:03:36.213Z,1422403416.213 [BPC1](ERROR): Data Fault
2015-01-28T00:03:36.262Z,1422403416.262 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T00:03:37.438Z,1422403417.438 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T00:03:37.438Z,1422403417.438 [BPC1] No Fault, FailCount= 1
2015-01-28T00:05:37.989Z,1422403537.989 [BPC1](FAULT): Failed to receive battery data
2015-01-28T00:05:37.990Z,1422403537.990 [BPC1] Communications Fault, FailCount= 1
2015-01-28T00:05:37.990Z,1422403537.990 [BPC1](ERROR): Communications Fault
2015-01-28T00:05:38.005Z,1422403538.005 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T00:05:39.204Z,1422403539.204 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T00:05:39.204Z,1422403539.204 [BPC1] No Fault, FailCount= 1
2015-01-28T00:06:12.800Z,1422403572.800 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T00:01:12.8Z
2015-01-28T00:06:12.800Z,1422403572.800 [Default:CheckIn:Read_GPS] Stopped
2015-01-28T00:06:12.800Z,1422403572.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-28T00:06:17.615Z,1422403577.615 [DataOverHttps](INFO): Sending 111 bytes from file Logs/20150127T230557/Courier0024.lzma
2015-01-28T00:06:18.032Z,1422403578.032 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T00:06:18.032Z,1422403578.032 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:06:18.032Z,1422403578.032 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T00:06:18.033Z,1422403578.033 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T00:06:18.033Z,1422403578.033 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T00:06:18.414Z,1422403578.414 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0024.lzma.bak
2015-01-28T00:06:18.414Z,1422403578.414 [DataOverHttps](INFO): SBD MOMSN=1509001
2015-01-28T00:06:18.435Z,1422403578.435 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 57.040111 min 
2015-01-28T00:06:18.435Z,1422403578.435 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T00:06:18.435Z,1422403578.435 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:06:18.435Z,1422403578.435 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T00:06:18.435Z,1422403578.435 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:06:31.727Z,1422403591.727 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20150127T230557/Express0025.lzma
2015-01-28T00:06:32.579Z,1422403592.579 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0025.lzma.bak
2015-01-28T00:06:32.580Z,1422403592.580 [DataOverHttps](INFO): SBD MOMSN=1509004
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn:Read_Iridium] Stopped
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn] Stopped
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-28T00:06:33.374Z,1422403593.374 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-28T00:11:18.476Z,1422403878.476 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T00:11:18.476Z,1422403878.476 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:11:18.476Z,1422403878.476 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T00:11:18.477Z,1422403878.477 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T00:11:18.477Z,1422403878.477 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T00:11:23.416Z,1422403883.416 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 62.046432 min 
2015-01-28T00:11:23.416Z,1422403883.416 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T00:11:23.417Z,1422403883.417 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:11:23.417Z,1422403883.417 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T00:11:23.417Z,1422403883.417 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T00:11:33.426Z,1422403893.426 [Default:CheckIn] Running Loop=1
2015-01-28T00:11:33.427Z,1422403893.427 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-28T00:11:33.427Z,1422403893.427 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T00:11:33.427Z,1422403893.427 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-28T00:11:33.427Z,1422403893.427 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-28T00:11:34.608Z,1422403894.608 [BPC1](DEBUG): Received data from all battery sticks
2015-01-28T00:12:00.249Z,1422403920.249 [BPC1](ERROR): B 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,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFB%35
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFDC%3D
$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,0B94,09,3C51,0A,1717,0B,FFFC%49
$B11,0C,0001,0D,0059,0E,0056,0F,14B0,10,1787,11,FFFF,12,FFFF%34
$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,0B92,09,3C24,0A,0000,0B,0000%4B
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,FFFF,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,0B98,09,3C55,0A,FFFB,0B,FFFB%46
$B13,0C,0001,0D,0060,0E,0054,0F,1455,10,17AC,11,F3FC,12,F3FC%41
$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,0B9C,09,3C56,0A,FFFC,0B,FFFC%39
$B14,0C,0001,0D,0059,0E,0054,0F,1438,10,16F6,11,FFFF,12,FFFF%34
$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,0B95,09,3C14,0A,0000,0B,0000%48
$B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B90,09,3C5A,0A,0000,0B,0000%3F
$B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44
$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,0B92,09,3C55,0A,0000,0B,0000%48
$B17,0C,0001,0D,005E,0E,0057,0F,14E5,10,16E3,11,FFFF,12,FFFF%35
$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,0B94,09,3C1E,0A,FFD7,0B,FFDB%40
$B18,0C,0001,0D,0059,0E,0055,0F,147C,10,17BE,11,1DFA,12,2138%4A
$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-28T00:12:00.249Z,1422403920.249 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-28T00:12:00.249Z,1422403920.249 [BPC1] Data Fault, FailCount= 1
2015-01-28T00:12:00.249Z,1422403920.249 [BPC1](ERROR): Data Fault
2015-01-28T00:12:00.317Z,1422403920.317 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T00:12:01.479Z,1422403921.479 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T00:12:01.479Z,1422403921.479 [BPC1] No Fault, FailCount= 1
2015-01-28T00:12:28.248Z,1422403948.248 [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,0A,FFFC%36
$B12,0A,0000%30
$B13,0A,FFFB%35
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FFDC%3D
$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,0B94,09,3C51,0A,FFFC,0B,FFFC%4C
$B11,0C,0001,0D,005A,0E,0056,0F,14B0,10,1787,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,00A7%42
$B12,02,000A,01,026C,03,0001,08,0B92,09,3C24,0A,0000,0B,0000%4B
$B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42
$B12,13,FFFF,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,0B98,09,3C55,0A,FFFB,0B,FFFB%46
$B13,0C,0001,0D,0060,0E,0054,0F,1455,10,17AC,11,F3FC,12,F3FC%41
$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,0B9C,09,3C56,0A,FFFC,0B,FFFC%39
$B14,0C,0001,0D,0059,0E,0054,0F,1438,10,16F6,11,FFFF,12,FFFF%34
$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,0B95,09,3C14,0A,0000,0B,0000%48
$B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,00A9%48
$B16,02,000A,01,026C,03,0001,08,0B90,09,3C5A,0A,0000,0B,0000%3F
$B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44
$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,0B92,09,3C55,0A,0000,0B,0000%48
$B17,0C,0001,0D,005E,0E,0057,0F,14E5,10,16E3,11,FFFF,12,FFFF%35
$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,0B94,09,3C1F,0A,FFDC,0B,FFDC%36
$B18,0C,0001,0D,0059,0E,0055,0F,147C,10,17BE,11,2224,12,2224%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-28T00:12:28.249Z,1422403948.249 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-28T00:12:28.249Z,1422403948.249 [BPC1] Data Fault, FailCount= 1
2015-01-28T00:12:28.249Z,1422403948.249 [BPC1](ERROR): Data Fault
2015-01-28T00:12:28.308Z,1422403948.308 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T00:12:29.486Z,1422403949.486 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T00:12:29.486Z,1422403949.486 [BPC1] No Fault, FailCount= 1
2015-01-28T00:12:43.137Z,1422403963.137 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-28T00:12:43.137Z,1422403963.137 [NAL9602] Data Fault, FailCount= 1
2015-01-28T00:12:43.137Z,1422403963.137 [NAL9602](ERROR): Data Fault
2015-01-28T00:12:43.206Z,1422403963.206 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-28T00:12:43.207Z,1422403963.207 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-28T00:12:43.537Z,1422403963.537 [NAL9602](INFO): Stop
2015-01-28T00:12:43.537Z,1422403963.537 [NAL9602](INFO): Uninitialize
2015-01-28T00:12:43.537Z,1422403963.537 [NAL9602](INFO): Powering down
2015-01-28T00:12:43.933Z,1422403963.933 [NAL9602](INFO): Stopping
2015-01-28T00:12:44.392Z,1422403964.392 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-28T00:12:44.392Z,1422403964.392 [NAL9602] No Fault, FailCount= 1
2015-01-28T00:12:44.733Z,1422403964.733 [NAL9602](INFO): Start
2015-01-28T00:12:45.133Z,1422403965.133 [NAL9602](INFO): Start
2015-01-28T00:12:45.532Z,1422403965.532 [NAL9602](INFO): Start
2015-01-28T00:12:45.933Z,1422403965.933 [NAL9602](INFO): Start
2015-01-28T00:12:46.337Z,1422403966.337 [NAL9602](INFO): Start
2015-01-28T00:12:46.734Z,1422403966.734 [NAL9602](INFO): Start
2015-01-28T00:12:47.133Z,1422403967.133 [NAL9602](INFO): Start
2015-01-28T00:12:47.533Z,1422403967.533 [NAL9602](INFO): Start
2015-01-28T00:12:47.932Z,1422403967.932 [NAL9602](INFO): Start
2015-01-28T00:12:48.332Z,1422403968.332 [NAL9602](INFO): Start
2015-01-28T00:12:48.733Z,1422403968.733 [NAL9602](INFO): Start
2015-01-28T00:12:48.733Z,1422403968.733 [NAL9602](INFO): Powering up NAL9602
2015-01-28T00:12:58.779Z,1422403978.779 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T00:12:59.532Z,1422403979.532 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T00:12:59.532Z,1422403979.532 [NAL9602](INFO): NAL9602 initialized
2015-01-28T00:16:05.745Z,1422404165.745 [CommandLine](IMPORTANT): got command restart application
2015-01-28T00:16:06.755Z,1422404166.755 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T00:16:06.755Z,1422404166.755 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:06.880Z,1422404166.880 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-28T00:16:06.880Z,1422404166.880 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:06.881Z,1422404166.881 [CommandLine](INFO): Join timeout helper Thread ID is 3217
2015-01-28T00:16:06.881Z,1422404166.881 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-28T00:16:06.881Z,1422404166.881 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:06.882Z,1422404166.882 [NavChartDb](INFO): Join timeout helper Thread ID is 3218
2015-01-28T00:16:07.265Z,1422404167.265 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T00:16:07.265Z,1422404167.265 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.285Z,1422404167.285 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-28T00:16:07.285Z,1422404167.285 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.285Z,1422404167.285 [Radio_Surface](INFO): Join timeout helper Thread ID is 3219
2015-01-28T00:16:07.429Z,1422404167.429 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T00:16:07.430Z,1422404167.430 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.445Z,1422404167.445 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-28T00:16:07.445Z,1422404167.445 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.445Z,1422404167.445 [logger](INFO): Join timeout helper Thread ID is 3220
2015-01-28T00:16:07.449Z,1422404167.449 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T00:16:07.449Z,1422404167.449 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.465Z,1422404167.465 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-28T00:16:07.465Z,1422404167.465 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.465Z,1422404167.465 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-28T00:16:07.465Z,1422404167.465 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.466Z,1422404167.466 [controlThread](INFO): Join timeout helper Thread ID is 3221
2015-01-28T00:16:07.706Z,1422404167.706 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T00:16:07.706Z,1422404167.706 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-28T00:16:07.707Z,1422404167.707 [NAL9602](INFO): Uninitialize
2015-01-28T00:16:07.707Z,1422404167.707 [NAL9602](INFO): Powering down
2015-01-28T00:16:07.709Z,1422404167.709 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-28T00:16:07.709Z,1422404167.709 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-28T00:16:07.710Z,1422404167.710 [Default] Stopped
2015-01-28T00:16:07.710Z,1422404167.710 [Default](INFO): Aggregate::uninitialize Default
2015-01-28T00:16:07.710Z,1422404167.710 [Default:B.GoToSurface] Stopped
2015-01-28T00:16:07.710Z,1422404167.710 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-28T00:16:07.710Z,1422404167.710 [Default:CheckIn] Stopped
2015-01-28T00:16:07.710Z,1422404167.710 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-28T00:16:07.710Z,1422404167.710 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-28T00:16:07.710Z,1422404167.710 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-28T00:16:07.711Z,1422404167.711 [Default:CheckIn:Read_GPS] Stopped
2015-01-28T00:16:07.711Z,1422404167.711 [Default:WaitAtTheSurface] Stopped
2015-01-28T00:16:07.711Z,1422404167.711 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-01-28T00:16:07.711Z,1422404167.711 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-01-28T00:16:07.711Z,1422404167.711 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-01-28T00:16:07.714Z,1422404167.714 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-28T00:16:07.715Z,1422404167.715 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-28T00:16:07.715Z,1422404167.715 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-28T00:16:07.715Z,1422404167.715 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-28T00:16:07.715Z,1422404167.715 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-28T00:16:07.715Z,1422404167.715 [BuoyancyServo](INFO): Powering down
2015-01-28T00:16:07.730Z,1422404167.730 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-28T00:16:07.730Z,1422404167.730 [ElevatorServo](INFO): Powering down
2015-01-28T00:16:07.731Z,1422404167.731 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-28T00:16:07.731Z,1422404167.731 [RudderServo](INFO): Powering down
2015-01-28T00:16:07.732Z,1422404167.732 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-28T00:16:07.732Z,1422404167.732 [ThrusterServo](INFO): Powering down
2015-01-28T00:16:07.733Z,1422404167.733 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-28T00:16:07.733Z,1422404167.733 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-28T00:16:07.733Z,1422404167.733 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-28T00:16:07.766Z,1422404167.766 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.878Z,1422404167.878 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.919Z,1422404167.919 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T00:16:07.968Z,1422404167.968 [logger ThreadHandler](INFO): Thread cancelled.