2015-01-28T17:12:20.969Z,1422465140.969 [Supervisor](DEBUG): Initializing supervisor.
2015-01-28T17:12:20.971Z,1422465140.971 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-28T17:12:20.972Z,1422465140.972 [SyncHandler](INFO): Protected caller Thread ID is 2248
2015-01-28T17:12:20.972Z,1422465140.972 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-28T17:12:20.974Z,1422465140.974 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-28T17:12:20.974Z,1422465140.974 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2249
2015-01-28T17:12:20.977Z,1422465140.977 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-28T17:12:20.988Z,1422465140.988 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-28T17:12:20.989Z,1422465140.989 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-28T17:12:20.990Z,1422465140.990 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2250
2015-01-28T17:12:20.991Z,1422465140.991 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-28T17:12:20.991Z,1422465140.991 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-28T17:12:20.992Z,1422465140.992 [logger ThreadHandler](INFO): Protected caller Thread ID is 2251
2015-01-28T17:12:20.994Z,1422465140.994 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-28T17:12:20.994Z,1422465140.994 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-28T17:12:20.996Z,1422465140.996 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-28T17:12:21.328Z,1422465141.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-28T17:12:21.329Z,1422465141.329 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-28T17:12:21.488Z,1422465141.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-28T17:12:21.488Z,1422465141.488 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-28T17:12:21.600Z,1422465141.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-28T17:12:21.600Z,1422465141.600 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-28T17:12:21.726Z,1422465141.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-28T17:12:21.727Z,1422465141.727 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-28T17:12:21.813Z,1422465141.813 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-28T17:12:21.983Z,1422465141.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-28T17:12:21.984Z,1422465141.984 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-28T17:12:22.072Z,1422465142.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-28T17:12:22.073Z,1422465142.073 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-28T17:12:22.290Z,1422465142.290 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-28T17:12:22.291Z,1422465142.291 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-28T17:12:22.674Z,1422465142.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-28T17:12:22.675Z,1422465142.675 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-28T17:12:23.002Z,1422465143.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-28T17:12:23.003Z,1422465143.003 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-28T17:12:23.590Z,1422465143.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-28T17:12:23.591Z,1422465143.591 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-28T17:12:23.788Z,1422465143.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-28T17:12:23.789Z,1422465143.789 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-28T17:12:23.894Z,1422465143.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-28T17:12:23.895Z,1422465143.895 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-28T17:12:24.321Z,1422465144.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-28T17:12:24.322Z,1422465144.322 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-28T17:12:24.433Z,1422465144.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-28T17:12:24.435Z,1422465144.435 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-28T17:12:24.436Z,1422465144.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-28T17:12:24.676Z,1422465144.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-28T17:12:24.676Z,1422465144.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-28T17:12:24.794Z,1422465144.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-28T17:12:24.894Z,1422465144.894 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-28T17:12:24.990Z,1422465144.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-28T17:12:25.106Z,1422465145.106 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-28T17:12:25.249Z,1422465145.249 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-28T17:12:25.421Z,1422465145.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-28T17:12:25.522Z,1422465145.522 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-28T17:12:25.613Z,1422465145.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-28T17:12:25.715Z,1422465145.715 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-28T17:12:25.813Z,1422465145.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-28T17:12:25.997Z,1422465145.997 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-01-28T17:12:25.997Z,1422465145.997 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-01-28T17:12:26.011Z,1422465146.011 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-28T17:12:26.061Z,1422465146.061 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-28T17:12:26.180Z,1422465146.180 [VerticalControl] Loaded
2015-01-28T17:12:26.180Z,1422465146.180 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-28T17:12:26.181Z,1422465146.181 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-28T17:12:26.254Z,1422465146.254 [HorizontalControl] Loaded
2015-01-28T17:12:26.254Z,1422465146.254 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-28T17:12:26.255Z,1422465146.255 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-28T17:12:26.260Z,1422465146.260 [SpeedControl] Loaded
2015-01-28T17:12:26.261Z,1422465146.261 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-28T17:12:26.261Z,1422465146.261 [LoopControl](DEBUG): Construct LoopControl.
2015-01-28T17:12:26.262Z,1422465146.262 [LoopControl] Loaded
2015-01-28T17:12:26.262Z,1422465146.262 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-28T17:12:26.263Z,1422465146.263 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-28T17:12:26.263Z,1422465146.263 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-28T17:12:26.357Z,1422465146.357 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-28T17:12:26.368Z,1422465146.368 [SBIT] Loaded
2015-01-28T17:12:26.369Z,1422465146.369 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-28T17:12:26.369Z,1422465146.369 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-28T17:12:26.398Z,1422465146.398 [IBIT] Loaded
2015-01-28T17:12:26.399Z,1422465146.399 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-28T17:12:26.401Z,1422465146.401 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-28T17:12:26.522Z,1422465146.522 [CBIT] Loaded
2015-01-28T17:12:26.522Z,1422465146.522 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-28T17:12:26.523Z,1422465146.523 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-28T17:12:26.523Z,1422465146.523 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-28T17:12:26.542Z,1422465146.542 [DepthRateCalculator] Loaded
2015-01-28T17:12:26.542Z,1422465146.542 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-28T17:12:26.547Z,1422465146.547 [PitchRateCalculator] Loaded
2015-01-28T17:12:26.548Z,1422465146.548 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-28T17:12:26.574Z,1422465146.574 [SpeedCalculator] Loaded
2015-01-28T17:12:26.574Z,1422465146.574 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-28T17:12:26.620Z,1422465146.620 [TempGradientCalculator] Loaded
2015-01-28T17:12:26.620Z,1422465146.620 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-28T17:12:26.625Z,1422465146.625 [YawRateCalculator] Loaded
2015-01-28T17:12:26.626Z,1422465146.626 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-28T17:12:26.626Z,1422465146.626 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-28T17:12:26.627Z,1422465146.627 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-28T17:12:26.676Z,1422465146.676 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-28T17:12:26.676Z,1422465146.676 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-28T17:12:26.902Z,1422465146.902 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-28T17:12:26.903Z,1422465146.903 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-28T17:12:26.989Z,1422465146.989 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-01-28T17:12:26.990Z,1422465146.990 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-01-28T17:12:27.007Z,1422465147.007 [NavChart] Loaded
2015-01-28T17:12:27.007Z,1422465147.007 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-28T17:12:27.012Z,1422465147.012 [UniversalFixResidualReporter] Loaded
2015-01-28T17:12:27.012Z,1422465147.012 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-28T17:12:27.012Z,1422465147.012 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-28T17:12:27.013Z,1422465147.013 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-28T17:12:27.019Z,1422465147.019 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-28T17:12:27.019Z,1422465147.019 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-28T17:12:27.105Z,1422465147.105 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-28T17:12:27.106Z,1422465147.106 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-28T17:12:27.418Z,1422465147.418 [DataOverHttps] Loaded
2015-01-28T17:12:27.418Z,1422465147.418 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-28T17:12:27.513Z,1422465147.513 [Depth_Keller] Loaded
2015-01-28T17:12:27.514Z,1422465147.514 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-28T17:12:27.608Z,1422465147.608 [NAL9602] Loaded
2015-01-28T17:12:27.609Z,1422465147.609 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-28T17:12:27.651Z,1422465147.651 [Onboard] Loaded
2015-01-28T17:12:27.652Z,1422465147.652 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-28T17:12:27.659Z,1422465147.659 [Radio_Surface] Loaded
2015-01-28T17:12:27.659Z,1422465147.659 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-28T17:12:27.660Z,1422465147.660 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-28T17:12:27.661Z,1422465147.661 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2334
2015-01-28T17:12:27.709Z,1422465147.709 [PNI_TCM] Loaded
2015-01-28T17:12:27.709Z,1422465147.709 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2015-01-28T17:12:29.565Z,1422465149.565 [BPC1] Loaded
2015-01-28T17:12:29.565Z,1422465149.565 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-28T17:12:29.566Z,1422465149.566 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-28T17:12:29.566Z,1422465149.566 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-28T17:12:29.666Z,1422465149.666 [BuoyancyServo] Loaded
2015-01-28T17:12:29.666Z,1422465149.666 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-28T17:12:29.678Z,1422465149.678 [ElevatorServo] Loaded
2015-01-28T17:12:29.678Z,1422465149.678 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-28T17:12:29.690Z,1422465149.690 [RudderServo] Loaded
2015-01-28T17:12:29.691Z,1422465149.691 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-28T17:12:29.702Z,1422465149.702 [ThrusterServo] Loaded
2015-01-28T17:12:29.702Z,1422465149.702 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-28T17:12:29.703Z,1422465149.703 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-28T17:12:29.703Z,1422465149.703 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-28T17:12:29.954Z,1422465149.954 [ExternalSim] Loaded
2015-01-28T17:12:29.954Z,1422465149.954 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-01-28T17:12:29.955Z,1422465149.955 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-28T17:12:29.956Z,1422465149.956 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-28T17:12:29.980Z,1422465149.980 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-28T17:12:29.982Z,1422465149.982 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-28T17:12:29.983Z,1422465149.983 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-28T17:12:29.989Z,1422465149.989 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-28T17:12:29.991Z,1422465149.991 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-28T17:12:29.991Z,1422465149.991 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2335
2015-01-28T17:12:29.996Z,1422465149.996 [Supervisor](INFO): Main Thread ID is 2247
2015-01-28T17:12:29.996Z,1422465149.996 [Supervisor](DEBUG): Running supervisor.
2015-01-28T17:12:29.997Z,1422465149.997 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2336
2015-01-28T17:12:30.001Z,1422465150.001 [controlThread ThreadHandler](INFO): Handler Thread ID is 2337
2015-01-28T17:12:30.001Z,1422465150.001 [controlThread](DEBUG): Initializing ControlThread
2015-01-28T17:12:30.002Z,1422465150.002 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-28T17:12:30.004Z,1422465150.004 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-28T17:12:30.005Z,1422465150.005 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-28T17:12:30.005Z,1422465150.005 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-28T17:12:30.006Z,1422465150.006 [SBIT](INFO): Initialize SBIT Component.
2015-01-28T17:12:30.006Z,1422465150.006 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-28T17:12:30.006Z,1422465150.006 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-28T17:12:30.007Z,1422465150.007 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-28T17:12:30.007Z,1422465150.007 [IBIT](INFO): Initialize IBIT Component.
2015-01-28T17:12:30.008Z,1422465150.008 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-28T17:12:30.008Z,1422465150.008 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-01-28T17:12:30.009Z,1422465150.009 [logger ThreadHandler](INFO): Handler Thread ID is 2338
2015-01-28T17:12:30.028Z,1422465150.028 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2339
2015-01-28T17:12:30.034Z,1422465150.034 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-28T17:12:30.034Z,1422465150.034 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-28T17:12:30.034Z,1422465150.034 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-28T17:12:30.034Z,1422465150.034 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-28T17:12:30.035Z,1422465150.035 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-28T17:12:30.036Z,1422465150.036 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:12:30.036Z,1422465150.036 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-28T17:12:30.036Z,1422465150.036 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-28T17:12:30.041Z,1422465150.041 [ExternalSim](INFO): ExternalSim initializing...
2015-01-28T17:12:30.060Z,1422465150.060 [Radio_Surface](INFO): Powering up
2015-01-28T17:12:30.064Z,1422465150.064 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2340
2015-01-28T17:12:30.067Z,1422465150.067 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-28T17:12:30.068Z,1422465150.068 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-28T17:12:30.068Z,1422465150.068 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-28T17:12:30.068Z,1422465150.068 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-28T17:12:30.068Z,1422465150.068 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-28T17:12:30.069Z,1422465150.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-28T17:12:30.069Z,1422465150.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-28T17:12:30.069Z,1422465150.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-28T17:12:30.070Z,1422465150.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-28T17:12:30.270Z,1422465150.270 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-01-28T17:12:30.270Z,1422465150.270 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-01-28T17:12:30.270Z,1422465150.270 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-01-28T17:12:30.419Z,1422465150.419 [ExternalSim](DEBUG): Simulator initialized
2015-01-28T17:12:30.426Z,1422465150.426 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-28T17:12:30.436Z,1422465150.436 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-28T17:12:30.473Z,1422465150.473 [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-28T17:12:30.474Z,1422465150.474 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-28T17:12:30.555Z,1422465150.555 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-28T17:12:30.558Z,1422465150.558 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-28T17:12:30.578Z,1422465150.578 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-28T17:12:30.595Z,1422465150.595 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-28T17:12:30.606Z,1422465150.606 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-28T17:12:30.638Z,1422465150.638 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-28T17:12:30.660Z,1422465150.660 [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-28T17:12:30.680Z,1422465150.680 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-01-28T17:12:30.899Z,1422465150.899 [NAL9602](INFO): Start
2015-01-28T17:12:31.183Z,1422465151.183 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:31.323Z,1422465151.323 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:12:31.330Z,1422465151.330 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-28T17:12:31.344Z,1422465151.344 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:12:31.349Z,1422465151.349 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-28T17:12:31.368Z,1422465151.368 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:12:31.378Z,1422465151.378 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-28T17:12:31.399Z,1422465151.399 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:12:31.406Z,1422465151.406 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-28T17:12:31.732Z,1422465151.732 [NAL9602](INFO): Start
2015-01-28T17:12:31.767Z,1422465151.767 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:40.789Z,1422465160.789 [NAL9602](INFO): Start
2015-01-28T17:12:40.790Z,1422465160.790 [NAL9602](INFO): Powering up NAL9602
2015-01-28T17:12:40.831Z,1422465160.831 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:41.492Z,1422465161.492 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:41.793Z,1422465161.793 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:42.019Z,1422465162.019 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003706
2015-01-28T17:12:42.069Z,1422465162.069 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:12:45.715Z,1422465165.715 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-28T17:12:45.725Z,1422465165.725 [CBIT](IMPORTANT): Beginning GF scan
2015-01-28T17:12:51.939Z,1422465171.939 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T17:12:51.939Z,1422465171.939 [NAL9602](INFO): NAL9602 initialized
2015-01-28T17:12:52.728Z,1422465172.728 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:12:53.129Z,1422465173.129 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:12:55.128Z,1422465175.128 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:12:55.921Z,1422465175.921 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:12:58.722Z,1422465178.722 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:13:00.203Z,1422465180.203 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:00.985Z,1422465180.985 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:05.392Z,1422465185.392 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:06.181Z,1422465186.181 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:10.580Z,1422465190.580 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:12.408Z,1422465192.408 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:12.585Z,1422465192.585 [CBIT](IMPORTANT): No ground fault detected
2015-01-28T17:13:20.700Z,1422465200.700 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:25.219Z,1422465205.219 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:13:25.219Z,1422465205.219 [SBIT](FAULT): Control surface position failure.
2015-01-28T17:13:27.963Z,1422465207.963 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:38.034Z,1422465218.034 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:38.847Z,1422465218.847 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:13:38.847Z,1422465218.847 [SBIT](FAULT): Control surface position failure.
2015-01-28T17:13:39.275Z,1422465219.275 [SBIT](CRITICAL): SBIT FAILED
2015-01-28T17:13:39.276Z,1422465219.276 [CommandLine](FAULT): Scheduling is paused
2015-01-28T17:13:39.665Z,1422465219.665 [MissionManager](IMPORTANT): Started mission Startup
2015-01-28T17:13:39.665Z,1422465219.665 [Startup] Running Loop=1
2015-01-28T17:13:39.666Z,1422465219.666 [Startup](INFO): Aggregate::initialize Startup
2015-01-28T17:13:39.666Z,1422465219.666 [Startup:A.GoToSurface] Running Loop=1
2015-01-28T17:13:39.666Z,1422465219.666 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-28T17:13:39.666Z,1422465219.666 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-28T17:13:39.667Z,1422465219.667 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-28T17:13:39.667Z,1422465219.667 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-28T17:13:39.673Z,1422465219.673 [Startup:StartupSatComms] Running Loop=1
2015-01-28T17:13:39.673Z,1422465219.673 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-28T17:13:39.673Z,1422465219.673 [Startup:StartupSatComms:A] Running Loop=1
2015-01-28T17:13:40.060Z,1422465220.060 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-28T17:13:41.216Z,1422465221.216 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:41.868Z,1422465221.868 [CommandLine](IMPORTANT): got command get latitude
2015-01-28T17:13:41.868Z,1422465221.868 [CommandLine](FAULT): Element has no value
2015-01-28T17:13:45.614Z,1422465225.614 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:13:47.528Z,1422465227.528 [CommandLine](IMPORTANT): got command get NAL9602.latitude_fix
2015-01-28T17:13:47.529Z,1422465227.529 [CommandLine](IMPORTANT): NAL9602.latitude_fix nan arcdeg
2015-01-28T17:13:53.659Z,1422465233.659 [NAL9602](INFO): Requesting MT sbdi session.
2015-01-28T17:13:54.080Z,1422465234.080 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:54.481Z,1422465234.481 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:54.856Z,1422465234.856 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:55.282Z,1422465235.282 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:55.682Z,1422465235.682 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:56.082Z,1422465236.082 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:56.451Z,1422465236.451 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:56.888Z,1422465236.888 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:57.256Z,1422465237.256 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:57.689Z,1422465237.689 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:58.050Z,1422465238.050 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:58.518Z,1422465238.518 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:58.859Z,1422465238.859 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:59.264Z,1422465239.264 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:13:59.652Z,1422465239.652 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:00.073Z,1422465240.073 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:00.453Z,1422465240.453 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:00.858Z,1422465240.858 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:00.859Z,1422465240.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=5457, MT Status=2, MTMSN=0
2015-01-28T17:14:00.860Z,1422465240.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2015-01-28T17:14:01.247Z,1422465241.247 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:05.657Z,1422465245.657 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:08.458Z,1422465248.458 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:17.284Z,1422465257.284 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:21.286Z,1422465261.286 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:25.649Z,1422465265.649 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:30.085Z,1422465270.085 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:35.103Z,1422465275.103 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:14:39.936Z,1422465279.936 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-28T17:13:39.7Z
2015-01-28T17:14:39.936Z,1422465279.936 [Startup:StartupSatComms:A] Stopped
2015-01-28T17:14:39.936Z,1422465279.936 [Startup:StartupSatComms:B] Running Loop=1
2015-01-28T17:14:40.321Z,1422465280.321 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-28T17:14:44.299Z,1422465284.299 [NAL9602](INFO): Requesting MT sbdi session.
2015-01-28T17:14:44.619Z,1422465284.619 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150128T170604/Courier0004.lzma
2015-01-28T17:14:44.630Z,1422465284.630 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:44.910Z,1422465284.910 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:45.256Z,1422465285.256 [DataOverHttps](INFO): Moved sent file to Logs/20150128T170604/Courier0004.lzma.bak
2015-01-28T17:14:45.256Z,1422465285.256 [DataOverHttps](INFO): SBD MOMSN=1510229
2015-01-28T17:14:45.267Z,1422465285.267 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:45.891Z,1422465285.891 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:46.088Z,1422465286.088 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:49.385Z,1422465289.385 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:49.770Z,1422465289.770 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:49.990Z,1422465289.990 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:50.375Z,1422465290.375 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:50.776Z,1422465290.776 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:51.180Z,1422465291.180 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:54.442Z,1422465294.442 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:54.825Z,1422465294.825 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150128T171220/Courier0000.lzma
2015-01-28T17:14:54.834Z,1422465294.834 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:14:55.039Z,1422465295.039 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:02.963Z,1422465302.963 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Courier0000.lzma.bak
2015-01-28T17:15:02.963Z,1422465302.963 [DataOverHttps](INFO): SBD MOMSN=1510231
2015-01-28T17:15:02.975Z,1422465302.975 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:02.977Z,1422465302.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=5457, MT Status=2, MTMSN=0
2015-01-28T17:15:02.977Z,1422465302.977 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2015-01-28T17:15:03.584Z,1422465303.584 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:15:06.946Z,1422465306.946 [NAL9602](INFO): Requesting MT sbdi session.
2015-01-28T17:15:07.129Z,1422465307.129 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:07.525Z,1422465307.525 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:07.930Z,1422465307.930 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:08.331Z,1422465308.331 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:08.727Z,1422465308.727 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:11.927Z,1422465311.927 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:12.117Z,1422465312.117 [DataOverHttps](INFO): Sending 582 bytes from file Logs/20150128T170604/Express0001.lzma
2015-01-28T17:15:12.129Z,1422465312.129 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:12.525Z,1422465312.525 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:12.914Z,1422465312.914 [DataOverHttps](INFO): Moved sent file to Logs/20150128T170604/Express0001.lzma.bak
2015-01-28T17:15:12.914Z,1422465312.914 [DataOverHttps](INFO): SBD MOMSN=1510235
2015-01-28T17:15:12.930Z,1422465312.930 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:13.731Z,1422465313.731 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:13.892Z,1422465313.892 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:17.073Z,1422465317.073 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:17.197Z,1422465317.197 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:17.601Z,1422465317.601 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:18.002Z,1422465318.002 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:18.403Z,1422465318.403 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:18.799Z,1422465318.799 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:22.012Z,1422465322.012 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:22.167Z,1422465322.167 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20150128T170604/Express0005.lzma
2015-01-28T17:15:22.176Z,1422465322.176 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:22.565Z,1422465322.565 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:22.570Z,1422465322.570 [NAL9602](INFO): SBD MO Status=2, MOMSN=5457, MT Status=2, MTMSN=0
2015-01-28T17:15:22.570Z,1422465322.570 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2015-01-28T17:15:22.958Z,1422465322.958 [DataOverHttps](INFO): Moved sent file to Logs/20150128T170604/Express0005.lzma.bak
2015-01-28T17:15:22.959Z,1422465322.959 [DataOverHttps](INFO): SBD MOMSN=1510250
2015-01-28T17:15:22.976Z,1422465322.976 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:15:27.288Z,1422465327.288 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:15:32.078Z,1422465332.078 [NAL9602](INFO): Requesting MT sbdi session.
2015-01-28T17:15:32.148Z,1422465332.148 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:15:32.148Z,1422465332.148 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-01-28T17:15:32.148Z,1422465332.148 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:15:32.192Z,1422465332.192 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:15:32.311Z,1422465332.311 [DataOverHttps](INFO): Sending 580 bytes from file Logs/20150128T171220/Express0001.lzma
2015-01-28T17:15:32.329Z,1422465332.329 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:32.380Z,1422465332.380 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:15:32.380Z,1422465332.380 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-01-28T17:15:32.685Z,1422465332.685 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:32.756Z,1422465332.756 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:15:33.081Z,1422465333.081 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Express0001.lzma.bak
2015-01-28T17:15:33.082Z,1422465333.082 [DataOverHttps](INFO): SBD MOMSN=1510256
2015-01-28T17:15:33.094Z,1422465333.094 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:33.112Z,1422465333.112 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:33.905Z,1422465333.905 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:33.924Z,1422465333.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:33.926Z,1422465333.926 [Startup:StartupSatComms:B] Stopped
2015-01-28T17:15:33.927Z,1422465333.927 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-28T17:15:33.927Z,1422465333.927 [Startup:StartupSatComms] Stopped
2015-01-28T17:15:33.927Z,1422465333.927 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-28T17:15:33.928Z,1422465333.928 [Startup](INFO): Completed Startup
2015-01-28T17:15:33.928Z,1422465333.928 [Startup] Stopped
2015-01-28T17:15:33.928Z,1422465333.928 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-28T17:15:33.928Z,1422465333.928 [Startup:A.GoToSurface] Stopped
2015-01-28T17:15:33.928Z,1422465333.928 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-28T17:15:34.119Z,1422465334.119 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:34.171Z,1422465334.171 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:34.173Z,1422465334.173 [MissionManager](IMPORTANT): Started mission Default
2015-01-28T17:15:34.173Z,1422465334.173 [Default] Running Loop=1
2015-01-28T17:15:34.173Z,1422465334.173 [Default](INFO): Aggregate::initialize Default
2015-01-28T17:15:34.173Z,1422465334.173 [Default:B.GoToSurface] Running Loop=1
2015-01-28T17:15:34.173Z,1422465334.173 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-28T17:15:34.173Z,1422465334.173 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-28T17:15:34.174Z,1422465334.174 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-28T17:15:34.174Z,1422465334.174 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-28T17:15:34.174Z,1422465334.174 [Default:StartClock] Running Loop=1
2015-01-28T17:15:34.175Z,1422465334.175 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-28T17:15:34.175Z,1422465334.175 [Default:StartClock:A] Running Loop=1
2015-01-28T17:15:34.202Z,1422465334.202 [Default:StartClock:A] Stopped
2015-01-28T17:15:34.203Z,1422465334.203 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-28T17:15:34.203Z,1422465334.203 [Default:StartClock] Stopped
2015-01-28T17:15:34.203Z,1422465334.203 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-28T17:15:37.312Z,1422465337.312 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:37.331Z,1422465337.331 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:37.333Z,1422465337.333 [Default:WaitAtTheSurface] Running Loop=1
2015-01-28T17:15:37.333Z,1422465337.333 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-28T17:15:37.334Z,1422465337.334 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-28T17:15:37.334Z,1422465337.334 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-28T17:15:37.453Z,1422465337.453 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:37.509Z,1422465337.509 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:37.511Z,1422465337.511 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-28T17:15:42.436Z,1422465342.436 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:42.492Z,1422465342.492 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:15:47.448Z,1422465347.448 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:52.440Z,1422465352.440 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:15:52.441Z,1422465352.441 [NAL9602](INFO): SBD MO Status=2, MOMSN=5457, MT Status=2, MTMSN=0
2015-01-28T17:15:52.441Z,1422465352.441 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2015-01-28T17:15:57.439Z,1422465357.439 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:16:12.439Z,1422465372.439 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:16:22.462Z,1422465382.462 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:16:37.442Z,1422465397.442 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:16:45.718Z,1422465405.718 [CommandLine](INFO): End of History
2015-01-28T17:16:45.899Z,1422465405.899 [CommandLine](INFO): End of History
2015-01-28T17:16:46.083Z,1422465406.083 [CommandLine](INFO): End of History
2015-01-28T17:16:46.264Z,1422465406.264 [CommandLine](INFO): End of History
2015-01-28T17:16:46.444Z,1422465406.444 [CommandLine](INFO): End of History
2015-01-28T17:16:46.625Z,1422465406.625 [CommandLine](INFO): End of History
2015-01-28T17:16:46.807Z,1422465406.807 [CommandLine](INFO): End of History
2015-01-28T17:16:46.988Z,1422465406.988 [CommandLine](INFO): End of History
2015-01-28T17:16:47.172Z,1422465407.172 [CommandLine](INFO): End of History
2015-01-28T17:16:47.358Z,1422465407.358 [CommandLine](INFO): End of History
2015-01-28T17:16:50.915Z,1422465410.915 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:16:55.129Z,1422465415.129 [CommandLine](IMPORTANT): got command get latitude
2015-01-28T17:16:55.129Z,1422465415.129 [CommandLine](FAULT): Element has no value
2015-01-28T17:17:02.445Z,1422465422.445 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:17:17.444Z,1422465437.444 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:17:27.439Z,1422465447.439 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:17:32.509Z,1422465452.509 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:17:32.509Z,1422465452.509 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:17:32.509Z,1422465452.509 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:17:32.512Z,1422465452.512 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:17:32.512Z,1422465452.512 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:17:37.447Z,1422465457.447 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:17:37.468Z,1422465457.468 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 1.972570 min 
2015-01-28T17:17:37.470Z,1422465457.470 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:17:37.470Z,1422465457.470 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:17:37.471Z,1422465457.471 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:17:37.471Z,1422465457.471 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:17:39.798Z,1422465459.798 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2015-01-28T17:17:42.524Z,1422465462.524 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T17:17:50.297Z,1422465470.297 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:17:50.297Z,1422465470.297 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:17:50.297Z,1422465470.297 [BPC1](ERROR): Communications Fault
2015-01-28T17:17:50.363Z,1422465470.363 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:17:52.442Z,1422465472.442 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:17:57.442Z,1422465477.442 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-28T17:18:02.501Z,1422465482.501 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:18:02.501Z,1422465482.501 [BPC1] No Fault, FailCount= 1
2015-01-28T17:18:02.620Z,1422465482.620 [CommandLine](IMPORTANT): got command show stack
2015-01-28T17:18:02.620Z,1422465482.620 [CommandLine](IMPORTANT): Behavior Stack:

2015-01-28T17:18:02.621Z,1422465482.621 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2015-01-28T17:18:02.621Z,1422465482.621 [Default:WaitAtTheSurface](IMPORTANT): Priority 1: Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed
2015-01-28T17:18:07.441Z,1422465487.441 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:18:12.442Z,1422465492.442 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:18:32.436Z,1422465512.436 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:18:37.441Z,1422465517.441 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:18:37.528Z,1422465517.528 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:18:37.528Z,1422465517.528 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-01-28T17:18:37.528Z,1422465517.528 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:18:37.543Z,1422465517.543 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:18:42.489Z,1422465522.489 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:18:42.489Z,1422465522.489 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-01-28T17:18:47.510Z,1422465527.510 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:18:55.315Z,1422465535.315 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:18:57.448Z,1422465537.448 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:18:57.506Z,1422465537.506 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:19:02.444Z,1422465542.444 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:19:02.514Z,1422465542.514 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:19:07.526Z,1422465547.526 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:19:12.520Z,1422465552.520 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:19:17.476Z,1422465557.476 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:19:22.466Z,1422465562.466 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:19:27.443Z,1422465567.443 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:19:42.471Z,1422465582.471 [BPC1](DEBUG): Received data from all battery sticks
2015-01-28T17:19:47.441Z,1422465587.441 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:19:52.446Z,1422465592.446 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:12.448Z,1422465612.448 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:17.441Z,1422465617.441 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:37.443Z,1422465637.443 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:37.517Z,1422465637.517 [Default:CheckIn] Running Loop=1
2015-01-28T17:20:37.517Z,1422465637.517 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-28T17:20:37.517Z,1422465637.517 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T17:20:37.517Z,1422465637.517 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-28T17:20:37.517Z,1422465637.517 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-28T17:20:37.518Z,1422465637.518 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-28T17:20:37.520Z,1422465637.520 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T17:20:37.924Z,1422465637.924 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:40.239Z,1422465640.239 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:40.637Z,1422465640.637 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:43.044Z,1422465643.044 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:43.429Z,1422465643.429 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:46.244Z,1422465646.244 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:46.642Z,1422465646.642 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:51.637Z,1422465651.637 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:52.034Z,1422465652.034 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:54.017Z,1422465654.017 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:54.443Z,1422465654.443 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:20:57.242Z,1422465657.242 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:20:57.640Z,1422465657.640 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:00.044Z,1422465660.044 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:00.440Z,1422465660.440 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:03.423Z,1422465663.423 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:03.629Z,1422465663.629 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:06.047Z,1422465666.047 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:06.450Z,1422465666.450 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:09.245Z,1422465669.245 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:09.630Z,1422465669.630 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:12.045Z,1422465672.045 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:12.458Z,1422465672.458 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:15.230Z,1422465675.230 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:15.636Z,1422465675.636 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:18.034Z,1422465678.034 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:18.459Z,1422465678.459 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:21.216Z,1422465681.216 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:21.628Z,1422465681.628 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:23.251Z,1422465683.251 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:21:23.251Z,1422465683.251 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:21:23.251Z,1422465683.251 [BPC1](ERROR): Communications Fault
2015-01-28T17:21:23.321Z,1422465683.321 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:21:24.031Z,1422465684.031 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:24.429Z,1422465684.429 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:24.520Z,1422465684.520 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:21:24.520Z,1422465684.520 [BPC1] No Fault, FailCount= 1
2015-01-28T17:21:27.236Z,1422465687.236 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:27.654Z,1422465687.654 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:30.033Z,1422465690.033 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:30.454Z,1422465690.454 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:33.234Z,1422465693.234 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:33.635Z,1422465693.635 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:36.034Z,1422465696.034 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:36.424Z,1422465696.424 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:39.291Z,1422465699.291 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:39.637Z,1422465699.637 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:42.043Z,1422465702.043 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:42.457Z,1422465702.457 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:45.231Z,1422465705.231 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:45.638Z,1422465705.638 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:47.660Z,1422465707.660 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:21:47.660Z,1422465707.660 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2015-01-28T17:21:47.660Z,1422465707.660 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:21:47.697Z,1422465707.697 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:21:48.045Z,1422465708.045 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:48.100Z,1422465708.100 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:21:48.101Z,1422465708.101 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2015-01-28T17:21:48.443Z,1422465708.443 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:48.474Z,1422465708.474 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:21:48.895Z,1422465708.895 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:52.054Z,1422465712.054 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:52.188Z,1422465712.188 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:52.563Z,1422465712.563 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:52.617Z,1422465712.617 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:52.966Z,1422465712.966 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:53.042Z,1422465713.042 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:53.406Z,1422465713.406 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:21:54.955Z,1422465714.955 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:55.369Z,1422465715.369 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:21:58.160Z,1422465718.160 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:21:58.582Z,1422465718.582 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:00.961Z,1422465720.961 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:01.358Z,1422465721.358 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:04.182Z,1422465724.182 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:04.560Z,1422465724.560 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:06.962Z,1422465726.962 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:07.357Z,1422465727.357 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:10.187Z,1422465730.187 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:10.589Z,1422465730.589 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:12.987Z,1422465732.987 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:13.389Z,1422465733.389 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:15.776Z,1422465735.776 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:16.189Z,1422465736.189 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:18.188Z,1422465738.188 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:18.589Z,1422465738.589 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:20.988Z,1422465740.988 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:21.389Z,1422465741.389 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:24.189Z,1422465744.189 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:24.627Z,1422465744.627 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:26.607Z,1422465746.607 [BPC1](FAULT): A bank: No match for serial number:5911 was found in the onboard configuration.
2015-01-28T17:22:26.607Z,1422465746.607 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-28T17:22:26.607Z,1422465746.607 [BPC1] Data Fault, FailCount= 1
2015-01-28T17:22:26.608Z,1422465746.608 [BPC1](ERROR): Data Fault
2015-01-28T17:22:26.685Z,1422465746.685 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T17:22:26.989Z,1422465746.989 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:27.392Z,1422465747.392 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:27.852Z,1422465747.852 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:22:27.852Z,1422465747.852 [BPC1] No Fault, FailCount= 1
2015-01-28T17:22:30.191Z,1422465750.191 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:30.594Z,1422465750.594 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:32.614Z,1422465752.614 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:22:32.614Z,1422465752.614 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:22:32.615Z,1422465752.615 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:22:32.615Z,1422465752.615 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:22:32.615Z,1422465752.615 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:22:32.995Z,1422465752.995 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:33.044Z,1422465753.044 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 6.975019 min 
2015-01-28T17:22:33.044Z,1422465753.044 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:22:33.044Z,1422465753.044 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:22:33.044Z,1422465753.044 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:22:33.044Z,1422465753.044 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:22:33.388Z,1422465753.388 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:36.188Z,1422465756.188 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:36.589Z,1422465756.589 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:39.008Z,1422465759.008 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:39.389Z,1422465759.389 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:42.217Z,1422465762.217 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:42.591Z,1422465762.591 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:43.800Z,1422465763.800 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:22:43.800Z,1422465763.800 [BPC1] Communications Fault, FailCount= 2
2015-01-28T17:22:43.800Z,1422465763.800 [BPC1](ERROR): Communications Fault
2015-01-28T17:22:43.873Z,1422465763.873 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:22:44.989Z,1422465764.989 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:45.079Z,1422465765.079 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:22:45.079Z,1422465765.079 [BPC1] No Fault, FailCount= 2
2015-01-28T17:22:45.395Z,1422465765.395 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:48.190Z,1422465768.190 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:22:48.621Z,1422465768.621 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:22:52.774Z,1422465772.774 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-28T17:22:52.774Z,1422465772.774 [NAL9602] Data Fault, FailCount= 1
2015-01-28T17:22:52.774Z,1422465772.774 [NAL9602](ERROR): Data Fault
2015-01-28T17:22:52.804Z,1422465772.804 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-28T17:22:52.805Z,1422465772.805 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-28T17:22:53.146Z,1422465773.146 [NAL9602](INFO): Stop
2015-01-28T17:22:53.146Z,1422465773.146 [NAL9602](INFO): Uninitialize
2015-01-28T17:22:53.146Z,1422465773.146 [NAL9602](INFO): Powering down
2015-01-28T17:22:53.538Z,1422465773.538 [NAL9602](INFO): Stopping
2015-01-28T17:22:54.000Z,1422465774.000 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-28T17:22:54.000Z,1422465774.000 [NAL9602] No Fault, FailCount= 1
2015-01-28T17:22:54.343Z,1422465774.343 [NAL9602](INFO): Start
2015-01-28T17:22:54.740Z,1422465774.740 [NAL9602](INFO): Start
2015-01-28T17:22:55.141Z,1422465775.141 [NAL9602](INFO): Start
2015-01-28T17:22:55.541Z,1422465775.541 [NAL9602](INFO): Start
2015-01-28T17:22:56.062Z,1422465776.062 [NAL9602](INFO): Start
2015-01-28T17:22:56.333Z,1422465776.333 [NAL9602](INFO): Start
2015-01-28T17:22:56.743Z,1422465776.743 [NAL9602](INFO): Start
2015-01-28T17:22:57.144Z,1422465777.144 [NAL9602](INFO): Start
2015-01-28T17:22:57.540Z,1422465777.540 [NAL9602](INFO): Start
2015-01-28T17:22:57.941Z,1422465777.941 [NAL9602](INFO): Start
2015-01-28T17:22:58.342Z,1422465778.342 [NAL9602](INFO): Start
2015-01-28T17:22:58.342Z,1422465778.342 [NAL9602](INFO): Powering up NAL9602
2015-01-28T17:23:08.377Z,1422465788.377 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T17:23:09.152Z,1422465789.152 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T17:23:09.152Z,1422465789.152 [NAL9602](INFO): NAL9602 initialized
2015-01-28T17:23:09.961Z,1422465789.961 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:10.349Z,1422465790.349 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:12.343Z,1422465792.343 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:12.750Z,1422465792.750 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:15.148Z,1422465795.148 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:15.550Z,1422465795.550 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:18.350Z,1422465798.350 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:18.758Z,1422465798.758 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:21.142Z,1422465801.142 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:21.719Z,1422465801.719 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:24.342Z,1422465804.342 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:24.744Z,1422465804.744 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:27.143Z,1422465807.143 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:27.536Z,1422465807.536 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:30.336Z,1422465810.336 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:30.741Z,1422465810.741 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:33.173Z,1422465813.173 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:33.571Z,1422465813.571 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:36.374Z,1422465816.374 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:36.743Z,1422465816.743 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:39.142Z,1422465819.142 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:39.543Z,1422465819.543 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:42.350Z,1422465822.350 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:42.744Z,1422465822.744 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:45.147Z,1422465825.147 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:45.544Z,1422465825.544 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:47.947Z,1422465827.947 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:48.345Z,1422465828.345 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:52.895Z,1422465832.895 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:53.300Z,1422465833.300 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:55.303Z,1422465835.303 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:55.697Z,1422465835.697 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:58.103Z,1422465838.103 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:23:58.127Z,1422465838.127 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:23:58.127Z,1422465838.127 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:23:58.127Z,1422465838.127 [BPC1](ERROR): Communications Fault
2015-01-28T17:23:58.213Z,1422465838.213 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:23:58.489Z,1422465838.489 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:23:59.378Z,1422465839.378 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:23:59.379Z,1422465839.379 [BPC1] No Fault, FailCount= 1
2015-01-28T17:24:00.895Z,1422465840.895 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:01.314Z,1422465841.314 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:04.100Z,1422465844.100 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:04.522Z,1422465844.522 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:06.900Z,1422465846.900 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:07.302Z,1422465847.302 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:10.102Z,1422465850.102 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:10.503Z,1422465850.503 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:11.724Z,1422465851.724 [BPC1](ERROR): A 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,0B9D,09,3C2C,0A,FFFC,0B,0000%4C
$B11,0C,0001,0D,0056,0E,0051,0F,139B,10,173A,11,FFFF,12,FFFF%4F
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41
$B11,1A,0031,1B,4357,1C,00AD%31
$B12,02,000A,01,026C,03,0001,08,0B95,09,3C2C,0A,FFFC,0B,0001%3F
$B12,0C,0001,0D,0058,0E,0052,0F,13C2,10,16AC,11,FFFF,12,FFFF%3A
$B12,13,AED8,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%3A
$B12,1A,0031,1B,4357,1C,00AB%34
$B13,02,000A,01,026C,03,1717,08,0B8F,09,3C28,0A,FFFD,0B,0001%31
$B13,0C,0001,0D,0061,0E,0051,0F,1395,10,16AE,11,FFFF,12,FFFF%49
$B13,13,B9DC,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%3F
$B13,1A,0031,1B,4357,1C,00B1%45
$B14,02,000A,01,026C,03,0001,08,0B95,09,3C26,0A,FFFC,0B,0001%4C
$B14,0C,0001,0D,0054,0E,004E,0F,12D6,10,1688,11,FFFF,12,FFFF%46
$B14,13,DDB8,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%3E
$B14,1A,0031,1B,4357,1C,00A0%40
$B15,02,000A,01,026C,03,0001,08,0B99,09,3C07,0A,0000,0B,0003%45
$B15,0C,0001,0D,0064,0E,005C,0F,1615,10,1736,11,FFFF,12,FFFF%35
$B15,13,1694,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%42
$B15,1A,0031,1B,4357,1C,008B%4A
$B16,02,000A,01,026C,03,0001,08,0B8A,09,3C22,0A,0000,0B,0002%39
$B16,0C,0001,0D,0060,0E,0059,0F,157C,10,178C,11,FFFF,12,FFFF%45
$B16,13,3DE0,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%47
$B16,1A,0031,1B,4339,1C,007F%4A
$B17,02,000A,01,026C,03,0001,08,0B88,09,3C00,0A,0000,0B,0002%41
$B17,0C,0001,0D,0064,0E,005D,0F,1653,10,16E1,11,FFFF,12,FFFF%42
$B17,13,10A4,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%3E
$B17,1A,0031,1B,4357,1C,00B4%44
,026C,03,0001,08,0B95,09,3C12,0A,0000,0B,0000%4C
$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,0B92,09,3C06,0A,0000,0B,0000%41
$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-28T17:24:11.724Z,1422465851.724 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-28T17:24:11.725Z,1422465851.725 [BPC1] Data Fault, FailCount= 2
2015-01-28T17:24:11.725Z,1422465851.725 [BPC1](ERROR): Data Fault
2015-01-28T17:24:11.743Z,1422465851.743 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T17:24:12.874Z,1422465852.874 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:12.965Z,1422465852.965 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:24:12.965Z,1422465852.965 [BPC1] No Fault, FailCount= 2
2015-01-28T17:24:13.311Z,1422465853.311 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:16.111Z,1422465856.111 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:16.496Z,1422465856.496 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:18.908Z,1422465858.908 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:19.310Z,1422465859.310 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:22.108Z,1422465862.108 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:22.518Z,1422465862.518 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:24.925Z,1422465864.925 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:25.327Z,1422465865.327 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:28.310Z,1422465868.310 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:28.512Z,1422465868.512 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:30.910Z,1422465870.910 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:31.324Z,1422465871.324 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:34.095Z,1422465874.095 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:34.513Z,1422465874.513 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:36.912Z,1422465876.912 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:37.314Z,1422465877.314 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:40.124Z,1422465880.124 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:40.522Z,1422465880.522 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:42.901Z,1422465882.901 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:43.326Z,1422465883.326 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:46.102Z,1422465886.102 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:46.520Z,1422465886.520 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:48.757Z,1422465888.757 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:24:48.757Z,1422465888.757 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2015-01-28T17:24:48.758Z,1422465888.758 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:24:48.793Z,1422465888.793 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:24:48.974Z,1422465888.974 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:49.052Z,1422465889.052 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:24:49.052Z,1422465889.052 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2015-01-28T17:24:49.321Z,1422465889.321 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:49.375Z,1422465889.375 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:24:52.614Z,1422465892.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:52.771Z,1422465892.771 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:53.199Z,1422465893.199 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:53.573Z,1422465893.573 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:53.942Z,1422465893.942 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:54.028Z,1422465894.028 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:54.360Z,1422465894.360 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:54.392Z,1422465894.392 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:24:57.131Z,1422465897.131 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:24:57.536Z,1422465897.536 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:24:59.930Z,1422465899.930 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:00.337Z,1422465900.337 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:03.168Z,1422465903.168 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:03.566Z,1422465903.566 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:05.941Z,1422465905.941 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:06.342Z,1422465906.342 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:09.193Z,1422465909.193 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:09.535Z,1422465909.535 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:11.970Z,1422465911.970 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:12.368Z,1422465912.368 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:15.135Z,1422465915.135 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:15.557Z,1422465915.557 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:17.932Z,1422465917.932 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:18.334Z,1422465918.334 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:21.164Z,1422465921.164 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:21.562Z,1422465921.562 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:23.957Z,1422465923.957 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:24.639Z,1422465924.639 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:27.242Z,1422465927.242 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:27.644Z,1422465927.644 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:30.039Z,1422465930.039 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:30.447Z,1422465930.447 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:33.215Z,1422465933.215 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:33.637Z,1422465933.637 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:36.036Z,1422465936.036 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:36.437Z,1422465936.437 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:36.475Z,1422465936.475 [BPC1](ERROR): A 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,0A,FFFC%36
$B12,0A,FFFC%35
$B13,0A,FFFD%33
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$S,01,270F,02,00,04,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,0B9D,09,3C2C,0A,FFFC,0B,FFFC%49
$B11,0C,0001,0D,0056,0E,0051,0F,139B,10,173A,11,FFFF,12,FFFF%4F
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41
$B11,1A,0031,1B,4357,1C,00AD%31
$B12,02,000A,01,026C,03,0001,08,0B96,09,3C2C,0A,FFFC,0B,FFFC%38
$B12,0C,0001,0D,0058,0E,0052,0F,13C2,10,16AC,11,FFFF,12,FFFF%3A
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,00AB%34
$B13,02,000A,01,026C,03,0001,08,0B8F,09,3C28,0A,FFFD,0B,FFFD%33
$B13,0C,0001,0D,0061,0E,0051,0F,1395,10,16AE,11,FFFF,12,FFFF%49
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4357,1C,00B1%45
$B14,02,000A,01,026C,03,0001,08,0B96,09,3C26,0A,FFFD,0B,FFFD%4B
$B14,0C,0001,0D,0054,0E,004E,0F,12D6,10,1688,11,FFFF,12,FFFF%46
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,00A0%40
$B15,02,000A,01,026C,03,0001,08,0B99,09,3C07,0A,0000,0B,0000%46
$B15,0C,0001,0D,0064,0E,005C,0F,1615,10,1736,11,FFFF,12,FFFF%35
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008B%4A
$B16,02,000A,01,026C,03,0001,08,0B8B,09,3C23,0A,0000,0B,0000%39
$B16,0C,0001,0D,0060,0E,0059,0F,157C,10,178C,11,FFFF,12,FFFF%45
$B16,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%45
$B16,1A,0031,1B,4339,1C,007F%4A
$B17,02,000A,01,026C,03,0001,08,0B89,09,3C01,0A,0000,0B,0000%43
$B17,0C,0001,0D,0064,0E,005D,0F,1653,10,16E1,11,FFFF,12,FFFF%42
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00B4%44
4357,1C,0098%33
$B18,02,000A,01,026C,03,0001,08,0B92,09,3C06,0A,0000,0B,0000%41
$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-28T17:25:36.475Z,1422465936.475 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-28T17:25:36.476Z,1422465936.476 [BPC1] Data Fault, FailCount= 1
2015-01-28T17:25:36.476Z,1422465936.476 [BPC1](ERROR): Data Fault
2015-01-28T17:25:36.534Z,1422465936.534 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T17:25:37.671Z,1422465937.671 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T17:20:37.5Z
2015-01-28T17:25:37.672Z,1422465937.672 [Default:CheckIn:Read_GPS] Stopped
2015-01-28T17:25:37.672Z,1422465937.672 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-28T17:25:37.681Z,1422465937.681 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:25:37.681Z,1422465937.681 [BPC1] No Fault, FailCount= 1
2015-01-28T17:25:38.124Z,1422465938.124 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-28T17:25:42.096Z,1422465942.096 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:42.272Z,1422465942.272 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20150128T171220/Courier0004.lzma
2015-01-28T17:25:42.282Z,1422465942.282 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:43.057Z,1422465943.057 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Courier0004.lzma.bak
2015-01-28T17:25:43.057Z,1422465943.057 [DataOverHttps](INFO): SBD MOMSN=1510273
2015-01-28T17:25:47.282Z,1422465947.282 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:47.499Z,1422465947.499 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:52.480Z,1422465952.480 [DataOverHttps](INFO): Sending 843 bytes from file Logs/20150128T171220/Express0005.lzma
2015-01-28T17:25:52.487Z,1422465952.487 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:25:52.878Z,1422465952.878 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:25:53.289Z,1422465953.289 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Express0005.lzma.bak
2015-01-28T17:25:53.289Z,1422465953.289 [DataOverHttps](INFO): SBD MOMSN=1510275
2015-01-28T17:25:54.147Z,1422465954.147 [Default:CheckIn:Read_Iridium] Stopped
2015-01-28T17:25:54.147Z,1422465954.147 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-28T17:25:54.147Z,1422465954.147 [Default:CheckIn] Stopped
2015-01-28T17:25:54.147Z,1422465954.147 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-28T17:25:54.147Z,1422465954.147 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-28T17:25:54.148Z,1422465954.148 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-28T17:26:02.089Z,1422465962.089 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:26:04.304Z,1422465964.304 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:26:24.310Z,1422465984.310 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:26:29.309Z,1422465989.309 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:26:49.315Z,1422466009.315 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:26:54.312Z,1422466014.312 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:27:14.300Z,1422466034.300 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:27:19.325Z,1422466039.325 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:27:24.328Z,1422466044.328 [BPC1](DEBUG): Received data from all battery sticks
2015-01-28T17:27:34.398Z,1422466054.398 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:27:34.398Z,1422466054.398 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:27:34.398Z,1422466054.398 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:27:34.399Z,1422466054.399 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:27:34.399Z,1422466054.399 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:27:39.313Z,1422466059.313 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:27:39.347Z,1422466059.347 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 12.003574 min 
2015-01-28T17:27:39.347Z,1422466059.347 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:27:39.347Z,1422466059.347 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:27:39.348Z,1422466059.348 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:27:39.348Z,1422466059.348 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:27:44.300Z,1422466064.300 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:27:54.371Z,1422466074.371 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:27:54.371Z,1422466074.371 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2015-01-28T17:27:54.371Z,1422466074.371 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:27:54.382Z,1422466074.382 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:27:59.352Z,1422466079.352 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:27:59.352Z,1422466079.352 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2015-01-28T17:28:07.104Z,1422466087.104 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:28:07.152Z,1422466087.152 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:28:09.307Z,1422466089.307 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:28:09.370Z,1422466089.370 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:14.396Z,1422466094.396 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:19.342Z,1422466099.342 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:24.376Z,1422466104.376 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:29.293Z,1422466109.293 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:28:29.356Z,1422466109.356 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:34.294Z,1422466114.294 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:28:34.395Z,1422466114.395 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:28:54.529Z,1422466134.529 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:28:59.305Z,1422466139.305 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:29:19.307Z,1422466159.307 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:29:24.303Z,1422466164.303 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:29:44.302Z,1422466184.302 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:29:49.302Z,1422466189.302 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:30:12.105Z,1422466212.105 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:30:14.305Z,1422466214.305 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:30:34.303Z,1422466234.303 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:30:39.308Z,1422466239.308 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:30:54.335Z,1422466254.335 [Default:CheckIn] Running Loop=1
2015-01-28T17:30:54.335Z,1422466254.335 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-28T17:30:54.336Z,1422466254.336 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T17:30:54.336Z,1422466254.336 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-28T17:30:54.336Z,1422466254.336 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-28T17:30:54.703Z,1422466254.703 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:30:55.097Z,1422466255.097 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:30:57.407Z,1422466257.407 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:30:57.588Z,1422466257.588 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:30:59.991Z,1422466259.991 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:03.179Z,1422466263.179 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:04.915Z,1422466264.915 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:05.321Z,1422466265.321 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:07.359Z,1422466267.359 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:31:07.359Z,1422466267.359 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2015-01-28T17:31:07.359Z,1422466267.359 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:31:07.370Z,1422466267.370 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:31:07.864Z,1422466267.864 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:31:07.864Z,1422466267.864 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2015-01-28T17:31:08.116Z,1422466268.116 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:08.210Z,1422466268.210 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:31:08.517Z,1422466268.517 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:08.583Z,1422466268.583 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:08.988Z,1422466268.988 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:09.373Z,1422466269.373 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:09.802Z,1422466269.802 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:10.198Z,1422466270.198 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:10.556Z,1422466270.556 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:31:10.916Z,1422466270.916 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:11.354Z,1422466271.354 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:14.137Z,1422466274.137 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:14.519Z,1422466274.519 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:16.929Z,1422466276.929 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:17.327Z,1422466277.327 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:20.135Z,1422466280.135 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:20.524Z,1422466280.524 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:22.939Z,1422466282.939 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:23.329Z,1422466283.329 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:24.914Z,1422466284.914 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:25.324Z,1422466285.324 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:28.120Z,1422466288.120 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:28.541Z,1422466288.541 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:30.935Z,1422466290.935 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:31.317Z,1422466291.317 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:32.919Z,1422466292.919 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:33.324Z,1422466293.324 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:36.123Z,1422466296.123 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:36.537Z,1422466296.537 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:38.940Z,1422466298.940 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:39.326Z,1422466299.326 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:42.141Z,1422466302.141 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:42.530Z,1422466302.530 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:44.913Z,1422466304.913 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:45.319Z,1422466305.319 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:46.932Z,1422466306.932 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:47.334Z,1422466307.334 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:50.142Z,1422466310.142 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:50.536Z,1422466310.536 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:52.939Z,1422466312.939 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:53.341Z,1422466313.341 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:56.115Z,1422466316.115 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:56.551Z,1422466316.551 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:31:58.915Z,1422466318.915 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:31:59.325Z,1422466319.325 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:03.482Z,1422466323.482 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:03.924Z,1422466323.924 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:06.303Z,1422466326.303 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:06.672Z,1422466326.672 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:09.071Z,1422466329.071 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:09.468Z,1422466329.468 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:11.887Z,1422466331.887 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:12.257Z,1422466332.257 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:14.283Z,1422466334.283 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:14.677Z,1422466334.677 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:17.079Z,1422466337.079 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:17.489Z,1422466337.489 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:19.887Z,1422466339.887 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:20.307Z,1422466340.307 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:22.275Z,1422466342.275 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:22.684Z,1422466342.684 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:25.088Z,1422466345.088 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:25.478Z,1422466345.478 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:28.280Z,1422466348.280 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:28.693Z,1422466348.693 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:31.093Z,1422466351.093 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:31.475Z,1422466351.475 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:34.286Z,1422466354.286 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:34.698Z,1422466354.698 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:34.756Z,1422466354.756 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:32:34.756Z,1422466354.756 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:32:34.756Z,1422466354.756 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:32:34.757Z,1422466354.757 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:32:34.757Z,1422466354.757 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:32:35.137Z,1422466355.137 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 17.009695 min 
2015-01-28T17:32:35.137Z,1422466355.137 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:32:35.137Z,1422466355.137 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:32:35.137Z,1422466355.137 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:32:35.137Z,1422466355.137 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:32:37.079Z,1422466357.079 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:37.464Z,1422466357.464 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:40.280Z,1422466360.280 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:40.687Z,1422466360.687 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:43.081Z,1422466363.081 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:43.485Z,1422466363.485 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:46.289Z,1422466366.289 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:46.690Z,1422466366.690 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:49.239Z,1422466369.239 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:49.486Z,1422466369.486 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:52.281Z,1422466372.281 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:52.688Z,1422466372.688 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:55.162Z,1422466375.162 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:55.492Z,1422466375.492 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:32:58.267Z,1422466378.267 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:32:58.689Z,1422466378.689 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:03.696Z,1422466383.696 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:33:04.117Z,1422466384.117 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:06.096Z,1422466386.096 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:33:06.498Z,1422466386.498 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:08.912Z,1422466388.912 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:33:09.298Z,1422466389.298 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:10.895Z,1422466390.895 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-28T17:33:10.895Z,1422466390.895 [NAL9602] Data Fault, FailCount= 2
2015-01-28T17:33:10.895Z,1422466390.895 [NAL9602](ERROR): Data Fault
2015-01-28T17:33:10.925Z,1422466390.925 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-28T17:33:10.926Z,1422466390.926 [Reporter](INFO): NAL9602.sigQuality no_value
2015-01-28T17:33:11.308Z,1422466391.308 [NAL9602](INFO): Stop
2015-01-28T17:33:11.308Z,1422466391.308 [NAL9602](INFO): Uninitialize
2015-01-28T17:33:11.308Z,1422466391.308 [NAL9602](INFO): Powering down
2015-01-28T17:33:11.692Z,1422466391.692 [NAL9602](INFO): Stopping
2015-01-28T17:33:12.131Z,1422466392.131 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-28T17:33:12.131Z,1422466392.131 [NAL9602] No Fault, FailCount= 2
2015-01-28T17:33:12.489Z,1422466392.489 [NAL9602](INFO): Start
2015-01-28T17:33:12.894Z,1422466392.894 [NAL9602](INFO): Start
2015-01-28T17:33:13.303Z,1422466393.303 [NAL9602](INFO): Start
2015-01-28T17:33:13.687Z,1422466393.687 [NAL9602](INFO): Start
2015-01-28T17:33:14.104Z,1422466394.104 [NAL9602](INFO): Start
2015-01-28T17:33:14.492Z,1422466394.492 [NAL9602](INFO): Start
2015-01-28T17:33:14.881Z,1422466394.881 [NAL9602](INFO): Start
2015-01-28T17:33:15.309Z,1422466395.309 [NAL9602](INFO): Start
2015-01-28T17:33:15.710Z,1422466395.710 [NAL9602](INFO): Start
2015-01-28T17:33:16.091Z,1422466396.091 [NAL9602](INFO): Start
2015-01-28T17:33:16.487Z,1422466396.487 [NAL9602](INFO): Start
2015-01-28T17:33:16.488Z,1422466396.488 [NAL9602](INFO): Powering up NAL9602
2015-01-28T17:33:26.538Z,1422466406.538 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T17:33:27.288Z,1422466407.288 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T17:33:27.289Z,1422466407.289 [NAL9602](INFO): NAL9602 initialized
2015-01-28T17:33:28.090Z,1422466408.090 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:33:28.491Z,1422466408.491 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:30.489Z,1422466410.489 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:33:30.983Z,1422466410.983 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:33:31.731Z,1422466411.731 [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,FFFD%31
$B12,0A,FFFC%35
$B13,0A,FFFD%33
$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,0B98,09,3C22,0A,FFFD,0B,FFFD%44
$B11,0C,0001,0D,0054,0E,004E,0F,12C9,10,16D9,11,FFFF,12,FFFF%36
$B11,13,1717,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,0B91,09,3C24,0A,FFFC,0B,FFFC%48
$B12,0C,0001,0D,0052,0E,004E,0F,12D5,10,1722,11,FFFF,12,FFFF%44
$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,0B93,09,3C22,0A,FFFC,0B,FFFC%4D
$B13,0C,0001,0D,005B,0E,004E,0F,12C9,10,170F,11,FFFF,12,FFFF%48
$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,0B9A,09,3C2C,0A,FFFC,0B,FFFC%49
$B14,0C,0001,0D,0056,0E,0051,0F,1388,10,16C5,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,00B7%44
$B15,02,000A,01,026C,03,0001,08,0B9D,09,3C07,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,0B94,09,3C12,0A,0000,0B,0000%4C
$B16,0C,0001,0D,0064,0E,005A,0F,15AB,10,16B8,11,FFFF,12,FFFF%4E
$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,0B95,09,3C13,0A,0000,0B,0000%4D
$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,0B92,09,3C05,0A,0000,0B,0000%42
$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-28T17:33:31.731Z,1422466411.731 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-28T17:33:31.731Z,1422466411.731 [BPC1] Data Fault, FailCount= 1
2015-01-28T17:33:31.731Z,1422466411.731 [BPC1](ERROR): Data Fault
2015-01-28T17:33:31.748Z,1422466411.748 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T17:33:32.948Z,1