2015-01-28T17:36:28.881Z,1422466588.881 [Supervisor](DEBUG): Initializing supervisor.
2015-01-28T17:36:28.884Z,1422466588.884 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-28T17:36:28.885Z,1422466588.885 [SyncHandler](INFO): Protected caller Thread ID is 770
2015-01-28T17:36:28.885Z,1422466588.885 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-28T17:36:28.886Z,1422466588.886 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-28T17:36:28.886Z,1422466588.886 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 771
2015-01-28T17:36:28.889Z,1422466588.889 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-28T17:36:28.901Z,1422466588.901 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-28T17:36:28.902Z,1422466588.902 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-28T17:36:28.902Z,1422466588.902 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 772
2015-01-28T17:36:28.903Z,1422466588.903 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-28T17:36:28.904Z,1422466588.904 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-28T17:36:28.904Z,1422466588.904 [logger ThreadHandler](INFO): Protected caller Thread ID is 773
2015-01-28T17:36:28.906Z,1422466588.906 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-28T17:36:28.907Z,1422466588.907 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-28T17:36:28.911Z,1422466588.911 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-28T17:36:29.241Z,1422466589.241 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-28T17:36:29.243Z,1422466589.243 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-28T17:36:29.402Z,1422466589.402 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-28T17:36:29.403Z,1422466589.403 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-28T17:36:29.512Z,1422466589.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-28T17:36:29.512Z,1422466589.512 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-28T17:36:29.635Z,1422466589.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-28T17:36:29.636Z,1422466589.636 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-28T17:36:29.723Z,1422466589.723 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-28T17:36:29.884Z,1422466589.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-28T17:36:29.884Z,1422466589.884 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-28T17:36:29.972Z,1422466589.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-28T17:36:29.973Z,1422466589.973 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-28T17:36:30.181Z,1422466590.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-28T17:36:30.181Z,1422466590.181 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-28T17:36:30.552Z,1422466590.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-28T17:36:30.553Z,1422466590.553 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-28T17:36:30.870Z,1422466590.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-28T17:36:30.871Z,1422466590.871 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-28T17:36:31.364Z,1422466591.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-28T17:36:31.365Z,1422466591.365 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-28T17:36:31.561Z,1422466591.561 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-28T17:36:31.562Z,1422466591.562 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-28T17:36:31.667Z,1422466591.667 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-28T17:36:31.668Z,1422466591.668 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-28T17:36:32.089Z,1422466592.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-28T17:36:32.090Z,1422466592.090 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-28T17:36:32.202Z,1422466592.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-28T17:36:32.203Z,1422466592.203 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-28T17:36:32.208Z,1422466592.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-28T17:36:32.451Z,1422466592.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-28T17:36:36.115Z,1422466596.115 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-28T17:36:36.232Z,1422466596.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-28T17:36:46.850Z,1422466606.850 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-28T17:36:47.792Z,1422466607.792 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-28T17:36:47.908Z,1422466607.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-28T17:36:48.050Z,1422466608.050 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-28T17:36:48.220Z,1422466608.220 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-28T17:36:48.324Z,1422466608.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-28T17:36:48.414Z,1422466608.414 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-28T17:36:48.516Z,1422466608.516 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-28T17:36:48.613Z,1422466608.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-28T17:36:48.794Z,1422466608.794 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-01-28T17:36:48.801Z,1422466608.801 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-28T17:36:48.876Z,1422466608.876 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-28T17:36:48.994Z,1422466608.994 [VerticalControl] Loaded
2015-01-28T17:36:48.995Z,1422466608.995 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-28T17:36:48.995Z,1422466608.995 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-28T17:36:49.067Z,1422466609.067 [HorizontalControl] Loaded
2015-01-28T17:36:49.067Z,1422466609.067 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-28T17:36:49.068Z,1422466609.068 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-28T17:36:49.074Z,1422466609.074 [SpeedControl] Loaded
2015-01-28T17:36:49.074Z,1422466609.074 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-28T17:36:49.075Z,1422466609.075 [LoopControl](DEBUG): Construct LoopControl.
2015-01-28T17:36:49.075Z,1422466609.075 [LoopControl] Loaded
2015-01-28T17:36:49.076Z,1422466609.076 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-28T17:36:49.076Z,1422466609.076 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-28T17:36:49.077Z,1422466609.077 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-28T17:36:49.201Z,1422466609.201 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-28T17:36:49.212Z,1422466609.212 [SBIT] Loaded
2015-01-28T17:36:49.213Z,1422466609.213 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-28T17:36:49.213Z,1422466609.213 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-28T17:36:49.242Z,1422466609.242 [IBIT] Loaded
2015-01-28T17:36:49.242Z,1422466609.242 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-28T17:36:49.244Z,1422466609.244 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-28T17:36:49.363Z,1422466609.363 [CBIT] Loaded
2015-01-28T17:36:49.363Z,1422466609.363 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-28T17:36:49.363Z,1422466609.363 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-28T17:36:49.364Z,1422466609.364 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-28T17:36:49.393Z,1422466609.393 [DepthRateCalculator] Loaded
2015-01-28T17:36:49.394Z,1422466609.394 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-28T17:36:49.399Z,1422466609.399 [PitchRateCalculator] Loaded
2015-01-28T17:36:49.400Z,1422466609.400 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-28T17:36:49.411Z,1422466609.411 [SpeedCalculator] Loaded
2015-01-28T17:36:49.411Z,1422466609.411 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-28T17:36:49.428Z,1422466609.428 [TempGradientCalculator] Loaded
2015-01-28T17:36:49.428Z,1422466609.428 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-28T17:36:49.434Z,1422466609.434 [YawRateCalculator] Loaded
2015-01-28T17:36:49.434Z,1422466609.434 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-28T17:36:49.435Z,1422466609.435 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-28T17:36:49.435Z,1422466609.435 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-28T17:36:49.527Z,1422466609.527 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-28T17:36:49.529Z,1422466609.529 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-28T17:36:49.803Z,1422466609.803 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-28T17:36:49.803Z,1422466609.803 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-28T17:36:49.911Z,1422466609.911 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-01-28T17:36:49.911Z,1422466609.911 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-01-28T17:36:49.928Z,1422466609.928 [NavChart] Loaded
2015-01-28T17:36:49.929Z,1422466609.929 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-28T17:36:49.933Z,1422466609.933 [UniversalFixResidualReporter] Loaded
2015-01-28T17:36:49.933Z,1422466609.933 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-28T17:36:49.934Z,1422466609.934 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-28T17:36:49.934Z,1422466609.934 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-28T17:36:49.944Z,1422466609.944 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-28T17:36:49.944Z,1422466609.944 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-28T17:36:50.061Z,1422466610.061 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-28T17:36:50.061Z,1422466610.061 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-28T17:36:50.707Z,1422466610.707 [DataOverHttps] Loaded
2015-01-28T17:36:50.708Z,1422466610.708 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-28T17:36:50.789Z,1422466610.789 [Depth_Keller] Loaded
2015-01-28T17:36:50.790Z,1422466610.790 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-28T17:36:50.883Z,1422466610.883 [NAL9602] Loaded
2015-01-28T17:36:50.884Z,1422466610.884 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-28T17:36:50.926Z,1422466610.926 [Onboard] Loaded
2015-01-28T17:36:50.926Z,1422466610.926 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-28T17:36:50.934Z,1422466610.934 [Radio_Surface] Loaded
2015-01-28T17:36:50.934Z,1422466610.934 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-28T17:36:50.935Z,1422466610.935 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-28T17:36:50.935Z,1422466610.935 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 855
2015-01-28T17:36:51.124Z,1422466611.124 [PNI_TCM] Loaded
2015-01-28T17:36:51.124Z,1422466611.124 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2015-01-28T17:36:52.954Z,1422466612.954 [BPC1] Loaded
2015-01-28T17:36:52.955Z,1422466612.955 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-28T17:36:52.955Z,1422466612.955 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-28T17:36:52.956Z,1422466612.956 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-28T17:37:01.057Z,1422466621.057 [BuoyancyServo] Loaded
2015-01-28T17:37:01.057Z,1422466621.057 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-28T17:37:01.070Z,1422466621.070 [ElevatorServo] Loaded
2015-01-28T17:37:01.070Z,1422466621.070 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-28T17:37:01.083Z,1422466621.083 [RudderServo] Loaded
2015-01-28T17:37:01.083Z,1422466621.083 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-28T17:37:01.094Z,1422466621.094 [ThrusterServo] Loaded
2015-01-28T17:37:01.095Z,1422466621.095 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-28T17:37:01.095Z,1422466621.095 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-28T17:37:01.096Z,1422466621.096 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-28T17:37:01.368Z,1422466621.368 [ExternalSim] Loaded
2015-01-28T17:37:01.368Z,1422466621.368 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-01-28T17:37:01.369Z,1422466621.369 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-28T17:37:01.370Z,1422466621.370 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-28T17:37:01.411Z,1422466621.411 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-28T17:37:01.413Z,1422466621.413 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-28T17:37:01.414Z,1422466621.414 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-28T17:37:01.420Z,1422466621.420 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-28T17:37:01.421Z,1422466621.421 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-28T17:37:01.422Z,1422466621.422 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 856
2015-01-28T17:37:01.426Z,1422466621.426 [Supervisor](INFO): Main Thread ID is 768
2015-01-28T17:37:01.426Z,1422466621.426 [Supervisor](DEBUG): Running supervisor.
2015-01-28T17:37:01.427Z,1422466621.427 [CommandLine ThreadHandler](INFO): Handler Thread ID is 857
2015-01-28T17:37:01.430Z,1422466621.430 [controlThread ThreadHandler](INFO): Handler Thread ID is 858
2015-01-28T17:37:01.430Z,1422466621.430 [controlThread](DEBUG): Initializing ControlThread
2015-01-28T17:37:01.431Z,1422466621.431 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-28T17:37:01.433Z,1422466621.433 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-28T17:37:01.434Z,1422466621.434 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-28T17:37:01.434Z,1422466621.434 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-28T17:37:01.434Z,1422466621.434 [SBIT](INFO): Initialize SBIT Component.
2015-01-28T17:37:01.435Z,1422466621.435 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-28T17:37:01.435Z,1422466621.435 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-28T17:37:01.435Z,1422466621.435 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-28T17:37:01.436Z,1422466621.436 [IBIT](INFO): Initialize IBIT Component.
2015-01-28T17:37:01.437Z,1422466621.437 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-28T17:37:01.437Z,1422466621.437 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-01-28T17:37:01.437Z,1422466621.437 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2015-01-28T17:37:01.438Z,1422466621.438 [logger ThreadHandler](INFO): Handler Thread ID is 859
2015-01-28T17:37:01.459Z,1422466621.459 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 860
2015-01-28T17:37:01.463Z,1422466621.463 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-28T17:37:01.463Z,1422466621.463 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-28T17:37:01.463Z,1422466621.463 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-28T17:37:01.464Z,1422466621.464 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-28T17:37:01.464Z,1422466621.464 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-28T17:37:01.464Z,1422466621.464 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:37:01.465Z,1422466621.465 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-28T17:37:01.465Z,1422466621.465 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-28T17:37:01.471Z,1422466621.471 [ExternalSim](INFO): ExternalSim initializing...
2015-01-28T17:37:01.487Z,1422466621.487 [Radio_Surface](INFO): Powering up
2015-01-28T17:37:01.495Z,1422466621.495 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 861
2015-01-28T17:37:01.509Z,1422466621.509 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-28T17:37:01.512Z,1422466621.512 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-28T17:37:01.512Z,1422466621.512 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-28T17:37:01.512Z,1422466621.512 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-28T17:37:01.513Z,1422466621.513 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-28T17:37:01.513Z,1422466621.513 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-28T17:37:01.513Z,1422466621.513 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-28T17:37:01.513Z,1422466621.513 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-28T17:37:01.514Z,1422466621.514 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-28T17:37:02.020Z,1422466622.020 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-01-28T17:37:02.020Z,1422466622.020 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-01-28T17:37:02.020Z,1422466622.020 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-01-28T17:37:02.241Z,1422466622.241 [ExternalSim](DEBUG): Simulator initialized
2015-01-28T17:37:02.362Z,1422466622.362 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-28T17:37:02.391Z,1422466622.391 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-28T17:37:02.416Z,1422466622.416 [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:37:02.417Z,1422466622.417 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-28T17:37:02.510Z,1422466622.510 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-28T17:37:02.522Z,1422466622.522 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-28T17:37:02.526Z,1422466622.526 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-28T17:37:02.559Z,1422466622.559 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-28T17:37:02.577Z,1422466622.577 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-28T17:37:02.611Z,1422466622.611 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-28T17:37:02.649Z,1422466622.649 [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:37:02.654Z,1422466622.654 [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:37:02.861Z,1422466622.861 [NAL9602](INFO): Start
2015-01-28T17:37:02.861Z,1422466622.861 [NAL9602](INFO): Powering up NAL9602
2015-01-28T17:37:03.314Z,1422466623.314 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:03.438Z,1422466623.438 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:37:03.446Z,1422466623.446 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-28T17:37:03.452Z,1422466623.452 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:37:03.458Z,1422466623.458 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-28T17:37:03.480Z,1422466623.480 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:37:03.486Z,1422466623.486 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-28T17:37:03.507Z,1422466623.507 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-28T17:37:03.514Z,1422466623.514 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-28T17:37:03.546Z,1422466623.546 [CommandLine](FAULT): Scheduling is paused
2015-01-28T17:37:03.749Z,1422466623.749 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:11.597Z,1422466631.597 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:12.256Z,1422466632.256 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:12.536Z,1422466632.536 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:12.795Z,1422466632.795 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003606
2015-01-28T17:37:12.857Z,1422466632.857 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:37:14.008Z,1422466634.008 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T17:37:14.008Z,1422466634.008 [NAL9602](INFO): NAL9602 initialized
2015-01-28T17:37:14.801Z,1422466634.801 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:37:15.254Z,1422466635.254 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:37:16.939Z,1422466636.939 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-28T17:37:16.941Z,1422466636.941 [CBIT](IMPORTANT): Beginning GF scan
2015-01-28T17:37:17.253Z,1422466637.253 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:18.066Z,1422466638.066 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:18.497Z,1422466638.497 [BPC1](FAULT): Failed to initialize
2015-01-28T17:37:18.497Z,1422466638.497 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:37:18.497Z,1422466638.497 [BPC1](ERROR): Communications Fault
2015-01-28T17:37:18.637Z,1422466638.637 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:37:19.794Z,1422466639.794 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:37:19.795Z,1422466639.795 [BPC1] No Fault, FailCount= 1
2015-01-28T17:37:22.464Z,1422466642.464 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:23.265Z,1422466643.265 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:27.765Z,1422466647.765 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:28.555Z,1422466648.555 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:30.297Z,1422466650.297 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:37:32.965Z,1422466652.965 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:33.766Z,1422466653.766 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:38.165Z,1422466658.165 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:38.962Z,1422466658.962 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:43.353Z,1422466663.353 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:43.564Z,1422466663.564 [CBIT](IMPORTANT): No ground fault detected
2015-01-28T17:37:44.162Z,1422466664.162 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:48.607Z,1422466668.607 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:49.399Z,1422466669.399 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:53.397Z,1422466673.397 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:54.194Z,1422466674.194 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:56.732Z,1422466676.732 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:37:56.732Z,1422466676.732 [SBIT](FAULT): Control surface position failure.
2015-01-28T17:37:58.597Z,1422466678.597 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:37:59.398Z,1422466679.398 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:01.420Z,1422466681.420 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,0000%33
$B12,0A,FFFC%35
$B13,0A,FFFC%34
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B8B,09,3C0E,0A,0000,0B,0000%4A
$B11,0C,0001,0D,0064,0E,005B,0F,15DD,10,1641,11,FFFF,12,FFFF%36
$B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B93,09,3C23,0A,FFFC,0B,FFFC%4D
$B12,0C,0001,0D,0052,0E,0051,0F,1362,10,17B2,11,FFFF,12,FFFF%35
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B9A,09,3C21,0A,FFFC,0B,FFFC%3C
$B13,0C,0001,0D,005B,0E,004E,0F,12B8,10,16D7,11,FFFF,12,FFFF%4C
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B96,09,3C21,0A,FFFC,0B,FFFD%4B
$B14,0C,0001,0D,0052,0E,004D,0F,126B,10,168C,11,FFFF,12,FFFF%3C
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B98,09,3C06,0A,0000,0B,0000%46
$B15,0C,0001,0D,0064,0E,005B,0F,1602,10,16B6,11,FFFF,12,FFFF%42
$B15,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%48
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B8F,09,3C10,0A,0000,0B,0000%3D
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4B
$B16,1A,0031,1B,4357,1C,00B9%48
$B17,02,000A,01,026C,03,0001,08,0B96,09,3C0A,0A,0000,0B,0000%3D
$B17,0C,0001,0D,0064,0E,005F,0F,16DA,10,1701,11,FFFF,12,FFFF%37
$B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A
$B17,1A,0031,1B,4357,1C,00A5%46
$B18,02,000A,01,026C,03,0001,08,0B9B,09,3BB3,0A,0000,0B,0000%47
$B18,0C,0001,0D,0056,0E,004F,0F,12E5,10,16A5,11,FFFF,12,FFFF%3D
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00AE%39

2015-01-28T17:38:01.420Z,1422466681.420 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-28T17:38:01.420Z,1422466681.420 [BPC1] Data Fault, FailCount= 1
2015-01-28T17:38:01.421Z,1422466681.421 [BPC1](ERROR): Data Fault
2015-01-28T17:38:01.568Z,1422466681.568 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-28T17:38:02.684Z,1422466682.684 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:38:02.684Z,1422466682.684 [BPC1] No Fault, FailCount= 1
2015-01-28T17:38:08.970Z,1422466688.970 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:09.514Z,1422466689.514 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:10.338Z,1422466690.338 [SBIT](ERROR): Could not read massPosReader_.
2015-01-28T17:38:10.338Z,1422466690.338 [SBIT](FAULT): Control surface position failure.
2015-01-28T17:38:10.738Z,1422466690.738 [SBIT](CRITICAL): SBIT FAILED
2015-01-28T17:38:11.141Z,1422466691.141 [MissionManager](IMPORTANT): Started mission Startup
2015-01-28T17:38:11.141Z,1422466691.141 [Startup] Running Loop=1
2015-01-28T17:38:11.141Z,1422466691.141 [Startup](INFO): Aggregate::initialize Startup
2015-01-28T17:38:11.141Z,1422466691.141 [Startup:A.GoToSurface] Running Loop=1
2015-01-28T17:38:11.141Z,1422466691.141 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-28T17:38:11.142Z,1422466691.142 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-28T17:38:11.142Z,1422466691.142 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-28T17:38:11.143Z,1422466691.143 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-28T17:38:11.165Z,1422466691.165 [Startup:StartupSatComms] Running Loop=1
2015-01-28T17:38:11.165Z,1422466691.165 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-28T17:38:11.165Z,1422466691.165 [Startup:StartupSatComms:A] Running Loop=1
2015-01-28T17:38:11.541Z,1422466691.541 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-28T17:38:13.908Z,1422466693.908 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:17.514Z,1422466697.514 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:26.320Z,1422466706.320 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:30.715Z,1422466710.715 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:34.312Z,1422466714.312 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:40.318Z,1422466720.318 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:44.706Z,1422466724.706 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:48.715Z,1422466728.715 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:49.540Z,1422466729.540 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:53.542Z,1422466733.542 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:55.922Z,1422466735.922 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:38:56.719Z,1422466736.719 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:01.114Z,1422466741.114 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:01.936Z,1422466741.936 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:06.883Z,1422466746.883 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:08.891Z,1422466748.891 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:11.324Z,1422466751.324 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-28T17:38:11.2Z
2015-01-28T17:39:11.324Z,1422466751.324 [Startup:StartupSatComms:A] Stopped
2015-01-28T17:39:11.324Z,1422466751.324 [Startup:StartupSatComms:B] Running Loop=1
2015-01-28T17:39:11.730Z,1422466751.730 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-28T17:39:17.169Z,1422466757.169 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150128T171220/Courier0008.lzma
2015-01-28T17:39:17.179Z,1422466757.179 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:17.987Z,1422466757.987 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Courier0008.lzma.bak
2015-01-28T17:39:18.001Z,1422466758.001 [DataOverHttps](INFO): SBD MOMSN=1510301
2015-01-28T17:39:22.118Z,1422466762.118 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:27.095Z,1422466767.095 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20150128T173628/Courier0000.lzma
2015-01-28T17:39:27.869Z,1422466767.869 [DataOverHttps](INFO): Moved sent file to Logs/20150128T173628/Courier0000.lzma.bak
2015-01-28T17:39:27.869Z,1422466767.869 [DataOverHttps](INFO): SBD MOMSN=1510303
2015-01-28T17:39:32.268Z,1422466772.268 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:37.221Z,1422466777.221 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150128T171220/Express0009.lzma
2015-01-28T17:39:37.225Z,1422466777.225 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:38.013Z,1422466778.013 [DataOverHttps](INFO): Moved sent file to Logs/20150128T171220/Express0009.lzma.bak
2015-01-28T17:39:38.014Z,1422466778.014 [DataOverHttps](INFO): SBD MOMSN=1510308
2015-01-28T17:39:38.969Z,1422466778.969 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:42.382Z,1422466782.382 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:43.977Z,1422466783.977 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:47.447Z,1422466787.447 [DataOverHttps](INFO): Sending 599 bytes from file Logs/20150128T173628/Express0001.lzma
2015-01-28T17:39:47.453Z,1422466787.453 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:55.289Z,1422466795.289 [DataOverHttps](INFO): Moved sent file to Logs/20150128T173628/Express0001.lzma.bak
2015-01-28T17:39:55.289Z,1422466795.289 [DataOverHttps](INFO): SBD MOMSN=1510310
2015-01-28T17:39:55.847Z,1422466795.847 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:55.904Z,1422466795.904 [Startup:StartupSatComms:B] Stopped
2015-01-28T17:39:55.904Z,1422466795.904 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-28T17:39:55.904Z,1422466795.904 [Startup:StartupSatComms] Stopped
2015-01-28T17:39:55.904Z,1422466795.904 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-28T17:39:55.905Z,1422466795.905 [Startup](INFO): Completed Startup
2015-01-28T17:39:55.905Z,1422466795.905 [Startup] Stopped
2015-01-28T17:39:55.905Z,1422466795.905 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-28T17:39:55.905Z,1422466795.905 [Startup:A.GoToSurface] Stopped
2015-01-28T17:39:55.905Z,1422466795.905 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-28T17:39:56.181Z,1422466796.181 [MissionManager](IMPORTANT): Started mission Default
2015-01-28T17:39:56.181Z,1422466796.181 [Default] Running Loop=1
2015-01-28T17:39:56.181Z,1422466796.181 [Default](INFO): Aggregate::initialize Default
2015-01-28T17:39:56.182Z,1422466796.182 [Default:B.GoToSurface] Running Loop=1
2015-01-28T17:39:56.182Z,1422466796.182 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-28T17:39:56.182Z,1422466796.182 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-28T17:39:56.182Z,1422466796.182 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-28T17:39:56.183Z,1422466796.183 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-28T17:39:56.183Z,1422466796.183 [Default:StartClock] Running Loop=1
2015-01-28T17:39:56.183Z,1422466796.183 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-28T17:39:56.183Z,1422466796.183 [Default:StartClock:A] Running Loop=1
2015-01-28T17:39:56.207Z,1422466796.207 [Default:StartClock:A] Stopped
2015-01-28T17:39:56.207Z,1422466796.207 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-28T17:39:56.207Z,1422466796.207 [Default:StartClock] Stopped
2015-01-28T17:39:56.207Z,1422466796.207 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-28T17:39:59.228Z,1422466799.228 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:39:59.259Z,1422466799.259 [Default:WaitAtTheSurface] Running Loop=1
2015-01-28T17:39:59.259Z,1422466799.259 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-28T17:39:59.259Z,1422466799.259 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-28T17:39:59.259Z,1422466799.259 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-28T17:39:59.408Z,1422466799.408 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-28T17:40:04.427Z,1422466804.427 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:40:04.428Z,1422466804.428 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-01-28T17:40:04.428Z,1422466804.428 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:40:04.467Z,1422466804.467 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:40:09.369Z,1422466809.369 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:40:09.462Z,1422466809.462 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:40:09.462Z,1422466809.462 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-01-28T17:40:14.414Z,1422466814.414 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:40:19.372Z,1422466819.372 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:40:19.440Z,1422466819.440 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:24.405Z,1422466824.405 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:29.359Z,1422466829.359 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:40:29.414Z,1422466829.414 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:34.442Z,1422466834.442 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:39.359Z,1422466839.359 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:40:39.378Z,1422466839.378 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:44.411Z,1422466844.411 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:40:49.358Z,1422466849.358 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:40:59.374Z,1422466859.374 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:41:12.156Z,1422466872.156 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:41:24.373Z,1422466884.373 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:41:34.369Z,1422466894.369 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:41:39.369Z,1422466899.369 [NAL9602](INFO): Requesting MT sbdi session.
2015-01-28T17:41:44.368Z,1422466904.368 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:41:49.360Z,1422466909.360 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:41:54.364Z,1422466914.364 [NAL9602](INFO): ************** SESSION MT QUEUE VERIFY **************

2015-01-28T17:41:54.365Z,1422466914.365 [NAL9602](INFO): SBD MO Status=2, MOMSN=5457, MT Status=2, MTMSN=0
2015-01-28T17:41:54.366Z,1422466914.366 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2015-01-28T17:41:59.363Z,1422466919.363 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:42:04.418Z,1422466924.418 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:42:04.418Z,1422466924.418 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:42:04.418Z,1422466924.418 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:42:04.420Z,1422466924.420 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:42:04.420Z,1422466924.420 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:42:09.367Z,1422466929.367 [NAL9602](INFO): MT Sig Qty requested
2015-01-28T17:42:09.440Z,1422466929.440 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 2.138822 min 
2015-01-28T17:42:09.447Z,1422466929.447 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:42:09.447Z,1422466929.447 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:42:09.447Z,1422466929.447 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:42:09.447Z,1422466929.447 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:42:19.362Z,1422466939.362 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-28T17:42:29.575Z,1422466949.575 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:42:34.367Z,1422466954.367 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:42:54.369Z,1422466974.369 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:42:59.369Z,1422466979.369 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:43:17.193Z,1422466997.193 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:43:17.193Z,1422466997.193 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-01-28T17:43:17.193Z,1422466997.193 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:43:17.227Z,1422466997.227 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:43:19.372Z,1422466999.372 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:43:19.432Z,1422466999.432 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:43:19.432Z,1422466999.432 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-01-28T17:43:24.381Z,1422467004.381 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:43:24.436Z,1422467004.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:43:29.442Z,1422467009.442 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:43:34.382Z,1422467014.382 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:43:34.382Z,1422467014.382 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:43:34.382Z,1422467014.382 [BPC1](ERROR): Communications Fault
2015-01-28T17:43:34.388Z,1422467014.388 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:43:34.399Z,1422467014.399 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:43:39.390Z,1422467019.390 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:43:44.367Z,1422467024.367 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:43:44.401Z,1422467024.401 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:43:49.363Z,1422467029.363 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:43:49.429Z,1422467029.429 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:43:49.449Z,1422467029.449 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:43:49.449Z,1422467029.449 [BPC1] No Fault, FailCount= 1
2015-01-28T17:43:54.466Z,1422467034.466 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:44:09.370Z,1422467049.370 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:44:17.169Z,1422467057.169 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:44:17.200Z,1422467057.200 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:44:17.200Z,1422467057.200 [BPC1] Communications Fault, FailCount= 2
2015-01-28T17:44:17.200Z,1422467057.200 [BPC1](ERROR): Communications Fault
2015-01-28T17:44:17.246Z,1422467057.246 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:44:29.403Z,1422467069.403 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:44:29.403Z,1422467069.403 [BPC1] No Fault, FailCount= 2
2015-01-28T17:44:34.373Z,1422467074.373 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:44:39.373Z,1422467079.373 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:44:59.372Z,1422467099.372 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:44:59.428Z,1422467099.428 [Default:CheckIn] Running Loop=1
2015-01-28T17:44:59.428Z,1422467099.428 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-28T17:44:59.428Z,1422467099.428 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T17:44:59.428Z,1422467099.428 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-28T17:44:59.428Z,1422467099.428 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-28T17:44:59.429Z,1422467099.429 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-28T17:44:59.431Z,1422467099.431 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-28T17:44:59.777Z,1422467099.777 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:01.785Z,1422467101.785 [BPC1](DEBUG): Received data from all battery sticks
2015-01-28T17:45:02.167Z,1422467102.167 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:02.569Z,1422467102.569 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:08.180Z,1422467108.180 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:08.739Z,1422467108.739 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:12.536Z,1422467112.536 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:13.766Z,1422467113.766 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:18.585Z,1422467118.585 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:19.656Z,1422467119.656 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:22.335Z,1422467122.335 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:22.773Z,1422467122.773 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:25.380Z,1422467125.380 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:26.198Z,1422467126.198 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:31.221Z,1422467131.221 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:32.135Z,1422467132.135 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:35.043Z,1422467135.043 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:35.444Z,1422467135.444 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:38.227Z,1422467138.227 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:38.629Z,1422467138.629 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:41.036Z,1422467141.036 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:41.426Z,1422467141.426 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:44.241Z,1422467144.241 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:44.623Z,1422467144.623 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:47.029Z,1422467147.029 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:47.463Z,1422467147.463 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:49.842Z,1422467149.842 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:50.235Z,1422467150.235 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:52.242Z,1422467152.242 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:52.627Z,1422467152.627 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:55.046Z,1422467155.046 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:55.431Z,1422467155.431 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:45:57.029Z,1422467157.029 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:45:57.431Z,1422467157.431 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:00.234Z,1422467160.234 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:00.644Z,1422467160.644 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:03.030Z,1422467163.030 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:03.444Z,1422467163.444 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:08.687Z,1422467168.687 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:09.093Z,1422467169.093 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:11.143Z,1422467171.143 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:11.549Z,1422467171.549 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:14.344Z,1422467174.344 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:14.891Z,1422467174.891 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:17.161Z,1422467177.161 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:17.546Z,1422467177.546 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:20.341Z,1422467180.341 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:20.747Z,1422467180.747 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:23.142Z,1422467183.142 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:23.543Z,1422467183.543 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:24.756Z,1422467184.756 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:46:24.756Z,1422467184.756 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2015-01-28T17:46:24.756Z,1422467184.756 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:46:24.783Z,1422467184.783 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:46:25.195Z,1422467185.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:46:25.195Z,1422467185.195 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2015-01-28T17:46:25.560Z,1422467185.560 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:46:25.955Z,1422467185.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:26.335Z,1422467186.335 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:26.390Z,1422467186.390 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:26.744Z,1422467186.744 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:26.797Z,1422467186.797 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:27.199Z,1422467187.199 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:27.559Z,1422467187.559 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:27.960Z,1422467187.960 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:46:29.143Z,1422467189.143 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:29.565Z,1422467189.565 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:32.348Z,1422467192.348 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:32.746Z,1422467192.746 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:35.324Z,1422467195.324 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:35.546Z,1422467195.546 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:38.341Z,1422467198.341 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:38.751Z,1422467198.751 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:41.150Z,1422467201.150 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:41.543Z,1422467201.543 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:44.374Z,1422467204.374 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:44.744Z,1422467204.744 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:47.143Z,1422467207.143 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:47.565Z,1422467207.565 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:50.349Z,1422467210.349 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:50.742Z,1422467210.742 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:53.144Z,1422467213.144 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:53.546Z,1422467213.546 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:56.369Z,1422467216.369 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:56.751Z,1422467216.751 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:46:59.150Z,1422467219.150 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:46:59.547Z,1422467219.547 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:02.367Z,1422467222.367 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:02.748Z,1422467222.748 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:04.802Z,1422467224.802 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:47:04.802Z,1422467224.802 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:47:04.803Z,1422467224.803 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:47:04.803Z,1422467224.803 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:47:04.803Z,1422467224.803 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:47:05.151Z,1422467225.151 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:05.205Z,1422467225.205 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 7.145208 min 
2015-01-28T17:47:05.206Z,1422467225.206 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:47:05.206Z,1422467225.206 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:47:05.206Z,1422467225.206 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:47:05.206Z,1422467225.206 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:47:08.364Z,1422467228.364 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:10.544Z,1422467230.544 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:11.151Z,1422467231.151 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:13.324Z,1422467233.324 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:13.725Z,1422467233.725 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:16.521Z,1422467236.521 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-28T17:47:16.521Z,1422467236.521 [NAL9602] Data Fault, FailCount= 1
2015-01-28T17:47:16.521Z,1422467236.521 [NAL9602](ERROR): Data Fault
2015-01-28T17:47:16.584Z,1422467236.584 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-28T17:47:16.917Z,1422467236.917 [NAL9602](INFO): Stop
2015-01-28T17:47:16.917Z,1422467236.917 [NAL9602](INFO): Uninitialize
2015-01-28T17:47:16.917Z,1422467236.917 [NAL9602](INFO): Powering down
2015-01-28T17:47:17.334Z,1422467237.334 [NAL9602](INFO): Stopping
2015-01-28T17:47:17.774Z,1422467237.774 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-28T17:47:17.774Z,1422467237.774 [NAL9602] No Fault, FailCount= 1
2015-01-28T17:47:18.123Z,1422467238.123 [NAL9602](INFO): Start
2015-01-28T17:47:18.540Z,1422467238.540 [NAL9602](INFO): Start
2015-01-28T17:47:18.952Z,1422467238.952 [NAL9602](INFO): Start
2015-01-28T17:47:19.313Z,1422467239.313 [NAL9602](INFO): Start
2015-01-28T17:47:19.709Z,1422467239.709 [NAL9602](INFO): Start
2015-01-28T17:47:20.114Z,1422467240.114 [NAL9602](INFO): Start
2015-01-28T17:47:20.537Z,1422467240.537 [NAL9602](INFO): Start
2015-01-28T17:47:20.915Z,1422467240.915 [NAL9602](INFO): Start
2015-01-28T17:47:21.408Z,1422467241.408 [NAL9602](INFO): Start
2015-01-28T17:47:21.715Z,1422467241.715 [NAL9602](INFO): Start
2015-01-28T17:47:22.109Z,1422467242.109 [NAL9602](INFO): Start
2015-01-28T17:47:22.109Z,1422467242.109 [NAL9602](INFO): Powering up NAL9602
2015-01-28T17:47:32.918Z,1422467252.918 [NAL9602](INFO): ************** CMDMODE **************

2015-01-28T17:47:32.919Z,1422467252.919 [NAL9602](INFO): NAL9602 initialized
2015-01-28T17:47:33.764Z,1422467253.764 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:34.141Z,1422467254.141 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:36.155Z,1422467256.155 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:36.781Z,1422467256.781 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:38.960Z,1422467258.960 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:39.381Z,1422467259.381 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:41.884Z,1422467261.884 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:42.181Z,1422467262.181 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:43.763Z,1422467263.763 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:44.173Z,1422467264.173 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:45.769Z,1422467265.769 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:46.183Z,1422467266.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:47.762Z,1422467267.762 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:48.159Z,1422467268.159 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:49.760Z,1422467269.760 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:50.182Z,1422467270.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:51.760Z,1422467271.760 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:52.185Z,1422467272.185 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:53.763Z,1422467273.763 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:54.164Z,1422467274.164 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:55.760Z,1422467275.760 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:56.183Z,1422467276.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:57.781Z,1422467277.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:47:58.182Z,1422467278.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:47:59.780Z,1422467279.780 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:00.181Z,1422467280.181 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:01.775Z,1422467281.775 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:02.361Z,1422467282.361 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:03.782Z,1422467283.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:04.184Z,1422467284.184 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:08.579Z,1422467288.579 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:08.783Z,1422467288.783 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:11.158Z,1422467291.158 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:11.563Z,1422467291.563 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:14.010Z,1422467294.010 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:14.380Z,1422467294.380 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:16.811Z,1422467296.811 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:17.216Z,1422467297.216 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:19.975Z,1422467299.975 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:20.385Z,1422467300.385 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:22.893Z,1422467302.893 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:23.206Z,1422467303.206 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:24.783Z,1422467304.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:25.180Z,1422467305.180 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:26.790Z,1422467306.790 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:27.207Z,1422467307.207 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:28.785Z,1422467308.785 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:29.179Z,1422467309.179 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:30.780Z,1422467310.780 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:31.182Z,1422467311.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:32.779Z,1422467312.779 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:33.176Z,1422467313.176 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:34.782Z,1422467314.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:35.211Z,1422467315.211 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:36.809Z,1422467316.809 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:37.210Z,1422467317.210 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:38.781Z,1422467318.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:39.182Z,1422467319.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:40.807Z,1422467320.807 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:41.181Z,1422467321.181 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:42.783Z,1422467322.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:43.369Z,1422467323.369 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:44.782Z,1422467324.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:45.183Z,1422467325.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:46.775Z,1422467326.775 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:47.182Z,1422467327.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:48.784Z,1422467328.784 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:49.176Z,1422467329.176 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:50.783Z,1422467330.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:51.185Z,1422467331.185 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:52.783Z,1422467332.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:53.180Z,1422467333.180 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:54.781Z,1422467334.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:55.183Z,1422467335.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:56.781Z,1422467336.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:57.182Z,1422467337.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:48:58.775Z,1422467338.775 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:48:59.209Z,1422467339.209 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:00.783Z,1422467340.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:01.180Z,1422467341.180 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:02.806Z,1422467342.806 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:03.183Z,1422467343.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:08.808Z,1422467348.808 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:08.980Z,1422467348.980 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:10.975Z,1422467350.975 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:11.380Z,1422467351.380 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:13.775Z,1422467353.775 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:14.176Z,1422467354.176 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:15.769Z,1422467355.769 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:16.176Z,1422467356.176 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:17.773Z,1422467357.773 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:18.168Z,1422467358.168 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:19.776Z,1422467359.776 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:20.182Z,1422467360.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:21.776Z,1422467361.776 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:22.185Z,1422467362.185 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:23.775Z,1422467363.775 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:24.336Z,1422467364.336 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:25.774Z,1422467365.774 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:25.836Z,1422467365.836 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-28T17:49:25.836Z,1422467365.836 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2015-01-28T17:49:25.836Z,1422467365.836 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-28T17:49:25.847Z,1422467365.847 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-28T17:49:26.175Z,1422467366.175 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:26.251Z,1422467366.251 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-28T17:49:26.251Z,1422467366.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2015-01-28T17:49:26.624Z,1422467366.624 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-28T17:49:27.029Z,1422467367.029 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:27.435Z,1422467367.435 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:27.773Z,1422467367.773 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:27.828Z,1422467367.828 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:28.178Z,1422467368.178 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:28.241Z,1422467368.241 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:28.611Z,1422467368.611 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:29.003Z,1422467369.003 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-28T17:49:29.780Z,1422467369.780 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:30.177Z,1422467370.177 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:31.795Z,1422467371.795 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:32.185Z,1422467372.185 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:33.770Z,1422467373.770 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:34.180Z,1422467374.180 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:35.777Z,1422467375.777 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:36.179Z,1422467376.179 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:37.781Z,1422467377.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:38.178Z,1422467378.178 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:39.780Z,1422467379.780 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:40.184Z,1422467380.184 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:41.782Z,1422467381.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:42.183Z,1422467382.183 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:43.794Z,1422467383.794 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:44.195Z,1422467384.195 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:46.969Z,1422467386.969 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:47.384Z,1422467387.384 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:49.932Z,1422467389.932 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:50.184Z,1422467390.184 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:51.782Z,1422467391.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:52.185Z,1422467392.185 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:53.781Z,1422467393.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:54.182Z,1422467394.182 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:55.781Z,1422467395.781 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:56.181Z,1422467396.181 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:57.783Z,1422467397.783 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:58.169Z,1422467398.169 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:49:59.782Z,1422467399.782 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:49:59.820Z,1422467399.820 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T17:44:59.4Z
2015-01-28T17:49:59.820Z,1422467399.820 [Default:CheckIn:Read_GPS] Stopped
2015-01-28T17:49:59.820Z,1422467399.820 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-28T17:50:00.172Z,1422467400.172 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:50:00.209Z,1422467400.209 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-28T17:50:04.382Z,1422467404.382 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20150128T173628/Courier0004.lzma
2015-01-28T17:50:04.766Z,1422467404.766 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:50:05.274Z,1422467405.274 [DataOverHttps](INFO): Moved sent file to Logs/20150128T173628/Courier0004.lzma.bak
2015-01-28T17:50:05.274Z,1422467405.274 [DataOverHttps](INFO): SBD MOMSN=1510326
2015-01-28T17:50:05.293Z,1422467405.293 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:50:09.918Z,1422467409.918 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:50:10.420Z,1422467410.420 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:50:20.961Z,1422467420.961 [DataOverHttps](INFO): Sending 551 bytes from file Logs/20150128T173628/Express0005.lzma
2015-01-28T17:50:21.184Z,1422467421.184 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:50:21.506Z,1422467421.506 [DataOverHttps](INFO): Moved sent file to Logs/20150128T173628/Express0005.lzma.bak
2015-01-28T17:50:21.506Z,1422467421.506 [DataOverHttps](INFO): SBD MOMSN=1510328
2015-01-28T17:50:21.518Z,1422467421.518 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:50:22.493Z,1422467422.493 [Default:CheckIn:Read_Iridium] Stopped
2015-01-28T17:50:22.494Z,1422467422.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-28T17:50:22.494Z,1422467422.494 [Default:CheckIn] Stopped
2015-01-28T17:50:22.494Z,1422467422.494 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-28T17:50:22.494Z,1422467422.494 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-28T17:50:22.494Z,1422467422.494 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-28T17:50:37.606Z,1422467437.606 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:50:42.619Z,1422467442.619 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:51:02.612Z,1422467462.612 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:51:07.605Z,1422467467.605 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:51:12.642Z,1422467472.642 [BPC1](FAULT): Failed to receive battery data
2015-01-28T17:51:12.642Z,1422467472.642 [BPC1] Communications Fault, FailCount= 1
2015-01-28T17:51:12.642Z,1422467472.642 [BPC1](ERROR): Communications Fault
2015-01-28T17:51:12.660Z,1422467472.660 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-28T17:51:27.603Z,1422467487.603 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:51:27.659Z,1422467487.659 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-28T17:51:27.659Z,1422467487.659 [BPC1] No Fault, FailCount= 1
2015-01-28T17:51:34.420Z,1422467494.420 [CommandLine](IMPORTANT): got command report
2015-01-28T17:51:35.457Z,1422467495.457 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:51:40.132Z,1422467500.132 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality
2015-01-28T17:51:42.650Z,1422467502.650 [Reporter](INFO): NAL9602.sigQuality 0 count
2015-01-28T17:51:52.803Z,1422467512.803 [NAL9602](INFO): ************** Request Fix **************

2015-01-28T17:51:57.603Z,1422467517.603 [NAL9602](INFO): ************** GetFix **************

2015-01-28T17:52:06.479Z,1422467526.479 [CommandLine](IMPORTANT): got command restart system
2015-01-28T17:52:07.658Z,1422467527.658 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-28T17:52:07.659Z,1422467527.659 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:52:07.659Z,1422467527.659 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-28T17:52:07.659Z,1422467527.659 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-28T17:52:07.659Z,1422467527.659 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-28T17:52:11.290Z,1422467531.290 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T17:52:11.291Z,1422467531.291 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.318Z,1422467531.318 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-28T17:52:11.318Z,1422467531.318 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.319Z,1422467531.319 [CommandLine](INFO): Join timeout helper Thread ID is 878
2015-01-28T17:52:11.330Z,1422467531.330 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-28T17:52:11.330Z,1422467531.330 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.330Z,1422467531.330 [NavChartDb](INFO): Join timeout helper Thread ID is 879
2015-01-28T17:52:11.691Z,1422467531.691 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T17:52:11.691Z,1422467531.691 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.710Z,1422467531.710 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-28T17:52:11.711Z,1422467531.711 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.711Z,1422467531.711 [Radio_Surface](INFO): Join timeout helper Thread ID is 880
2015-01-28T17:52:11.743Z,1422467531.743 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T17:52:11.743Z,1422467531.743 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.751Z,1422467531.751 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-28T17:52:11.751Z,1422467531.751 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.751Z,1422467531.751 [logger](INFO): Join timeout helper Thread ID is 881
2015-01-28T17:52:11.767Z,1422467531.767 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T17:52:11.767Z,1422467531.767 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.771Z,1422467531.771 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-28T17:52:11.771Z,1422467531.771 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.771Z,1422467531.771 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-28T17:52:11.771Z,1422467531.771 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:11.771Z,1422467531.771 [controlThread](INFO): Join timeout helper Thread ID is 882
2015-01-28T17:52:12.508Z,1422467532.508 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-28T17:52:12.508Z,1422467532.508 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-28T17:52:12.510Z,1422467532.510 [NAL9602](INFO): Uninitialize
2015-01-28T17:52:12.510Z,1422467532.510 [NAL9602](INFO): Powering down
2015-01-28T17:52:12.512Z,1422467532.512 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-28T17:52:12.513Z,1422467532.513 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-28T17:52:12.513Z,1422467532.513 [Default] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default](INFO): Aggregate::uninitialize Default
2015-01-28T17:52:12.514Z,1422467532.514 [Default:B.GoToSurface] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-28T17:52:12.514Z,1422467532.514 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-28T17:52:12.514Z,1422467532.514 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default:WaitAtTheSurface] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-01-28T17:52:12.514Z,1422467532.514 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-01-28T17:52:12.514Z,1422467532.514 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-01-28T17:52:12.519Z,1422467532.519 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-28T17:52:12.519Z,1422467532.519 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-28T17:52:12.519Z,1422467532.519 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-28T17:52:12.519Z,1422467532.519 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-28T17:52:12.519Z,1422467532.519 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-28T17:52:12.520Z,1422467532.520 [BuoyancyServo](INFO): Powering down
2015-01-28T17:52:12.532Z,1422467532.532 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-28T17:52:12.532Z,1422467532.532 [ElevatorServo](INFO): Powering down
2015-01-28T17:52:12.533Z,1422467532.533 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-28T17:52:12.533Z,1422467532.533 [RudderServo](INFO): Powering down
2015-01-28T17:52:12.534Z,1422467532.534 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-28T17:52:12.534Z,1422467532.534 [ThrusterServo](INFO): Powering down
2015-01-28T17:52:12.535Z,1422467532.535 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-28T17:52:12.535Z,1422467532.535 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-28T17:52:12.536Z,1422467532.536 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-28T17:52:12.568Z,1422467532.568 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:12.686Z,1422467532.686 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:12.732Z,1422467532.732 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-28T17:52:12.785Z,1422467532.785 [logger ThreadHandler](INFO): Thread cancelled.