2015-01-28T00:16:08.710Z,1422404168.710 [Supervisor](DEBUG): Initializing supervisor. 2015-01-28T00:16:08.713Z,1422404168.713 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-01-28T00:16:08.713Z,1422404168.713 [SyncHandler](INFO): Protected caller Thread ID is 3222 2015-01-28T00:16:08.714Z,1422404168.714 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-01-28T00:16:08.715Z,1422404168.715 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-01-28T00:16:08.715Z,1422404168.715 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3223 2015-01-28T00:16:08.718Z,1422404168.718 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-01-28T00:16:08.729Z,1422404168.729 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-01-28T00:16:08.730Z,1422404168.730 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-01-28T00:16:08.731Z,1422404168.731 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3224 2015-01-28T00:16:08.732Z,1422404168.732 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-01-28T00:16:08.733Z,1422404168.733 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-01-28T00:16:08.733Z,1422404168.733 [logger ThreadHandler](INFO): Protected caller Thread ID is 3225 2015-01-28T00:16:08.735Z,1422404168.735 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-01-28T00:16:08.735Z,1422404168.735 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-01-28T00:16:08.737Z,1422404168.737 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-01-28T00:16:09.058Z,1422404169.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-01-28T00:16:09.059Z,1422404169.059 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-01-28T00:16:09.214Z,1422404169.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-01-28T00:16:09.215Z,1422404169.215 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-01-28T00:16:09.321Z,1422404169.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-01-28T00:16:09.322Z,1422404169.322 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-01-28T00:16:09.442Z,1422404169.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-01-28T00:16:09.443Z,1422404169.443 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-01-28T00:16:09.527Z,1422404169.527 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-01-28T00:16:09.685Z,1422404169.685 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-01-28T00:16:09.686Z,1422404169.686 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-01-28T00:16:09.771Z,1422404169.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-01-28T00:16:09.772Z,1422404169.772 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-01-28T00:16:09.975Z,1422404169.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-01-28T00:16:09.976Z,1422404169.976 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-01-28T00:16:10.339Z,1422404170.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-01-28T00:16:10.339Z,1422404170.339 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-01-28T00:16:10.648Z,1422404170.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-01-28T00:16:10.649Z,1422404170.649 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-01-28T00:16:11.133Z,1422404171.133 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-01-28T00:16:11.134Z,1422404171.134 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-01-28T00:16:11.323Z,1422404171.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-01-28T00:16:11.324Z,1422404171.324 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-01-28T00:16:11.426Z,1422404171.426 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-01-28T00:16:11.427Z,1422404171.427 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-01-28T00:16:11.870Z,1422404171.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-01-28T00:16:11.871Z,1422404171.871 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-01-28T00:16:11.979Z,1422404171.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-01-28T00:16:11.981Z,1422404171.981 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-01-28T00:16:11.982Z,1422404171.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-01-28T00:16:12.217Z,1422404172.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-01-28T00:16:12.218Z,1422404172.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-01-28T00:16:12.331Z,1422404172.331 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg 2015-01-28T00:16:12.457Z,1422404172.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-01-28T00:16:12.553Z,1422404172.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-01-28T00:16:12.666Z,1422404172.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-01-28T00:16:12.804Z,1422404172.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-01-28T00:16:12.971Z,1422404172.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-01-28T00:16:13.071Z,1422404173.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-01-28T00:16:13.160Z,1422404173.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-01-28T00:16:13.259Z,1422404173.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-01-28T00:16:13.382Z,1422404173.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-01-28T00:16:13.560Z,1422404173.560 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2015-01-28T00:16:13.561Z,1422404173.561 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2015-01-28T00:16:13.574Z,1422404173.574 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-01-28T00:16:13.624Z,1422404173.624 [VerticalControl](DEBUG): Construct VerticalControl. 2015-01-28T00:16:13.740Z,1422404173.740 [VerticalControl] Loaded 2015-01-28T00:16:13.740Z,1422404173.740 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-01-28T00:16:13.741Z,1422404173.741 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-01-28T00:16:13.811Z,1422404173.811 [HorizontalControl] Loaded 2015-01-28T00:16:13.811Z,1422404173.811 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-01-28T00:16:13.812Z,1422404173.812 [SpeedControl](DEBUG): Construct SpeedControl. 2015-01-28T00:16:13.818Z,1422404173.818 [SpeedControl] Loaded 2015-01-28T00:16:13.818Z,1422404173.818 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-01-28T00:16:13.819Z,1422404173.819 [LoopControl](DEBUG): Construct LoopControl. 2015-01-28T00:16:13.819Z,1422404173.819 [LoopControl] Loaded 2015-01-28T00:16:13.819Z,1422404173.819 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-01-28T00:16:13.820Z,1422404173.820 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-01-28T00:16:13.820Z,1422404173.820 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-01-28T00:16:13.914Z,1422404173.914 [SBIT](DEBUG): Construct Startup Built In Test. 2015-01-28T00:16:13.925Z,1422404173.925 [SBIT] Loaded 2015-01-28T00:16:13.926Z,1422404173.926 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-01-28T00:16:13.926Z,1422404173.926 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-01-28T00:16:13.955Z,1422404173.955 [IBIT] Loaded 2015-01-28T00:16:13.955Z,1422404173.955 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-01-28T00:16:13.957Z,1422404173.957 [CBIT](DEBUG): Construct CBIT Built In Test. 2015-01-28T00:16:14.075Z,1422404174.075 [CBIT] Loaded 2015-01-28T00:16:14.076Z,1422404174.076 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-01-28T00:16:14.076Z,1422404174.076 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-01-28T00:16:14.077Z,1422404174.077 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-01-28T00:16:14.094Z,1422404174.094 [DepthRateCalculator] Loaded 2015-01-28T00:16:14.095Z,1422404174.095 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-01-28T00:16:14.100Z,1422404174.100 [PitchRateCalculator] Loaded 2015-01-28T00:16:14.101Z,1422404174.101 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-01-28T00:16:14.112Z,1422404174.112 [SpeedCalculator] Loaded 2015-01-28T00:16:14.112Z,1422404174.112 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-01-28T00:16:14.128Z,1422404174.128 [TempGradientCalculator] Loaded 2015-01-28T00:16:14.129Z,1422404174.129 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-01-28T00:16:14.134Z,1422404174.134 [YawRateCalculator] Loaded 2015-01-28T00:16:14.134Z,1422404174.134 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-01-28T00:16:14.135Z,1422404174.135 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-01-28T00:16:14.135Z,1422404174.135 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-01-28T00:16:14.211Z,1422404174.211 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-01-28T00:16:14.212Z,1422404174.212 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-01-28T00:16:14.450Z,1422404174.450 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-01-28T00:16:14.451Z,1422404174.451 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-01-28T00:16:14.535Z,1422404174.535 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-01-28T00:16:14.536Z,1422404174.536 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-01-28T00:16:14.553Z,1422404174.553 [NavChart] Loaded 2015-01-28T00:16:14.553Z,1422404174.553 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-01-28T00:16:14.557Z,1422404174.557 [UniversalFixResidualReporter] Loaded 2015-01-28T00:16:14.557Z,1422404174.557 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-01-28T00:16:14.558Z,1422404174.558 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-01-28T00:16:14.558Z,1422404174.558 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-01-28T00:16:14.564Z,1422404174.564 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-01-28T00:16:14.565Z,1422404174.565 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-01-28T00:16:14.649Z,1422404174.649 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-01-28T00:16:14.649Z,1422404174.649 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-01-28T00:16:14.944Z,1422404174.944 [DataOverHttps] Loaded 2015-01-28T00:16:14.945Z,1422404174.945 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-01-28T00:16:15.028Z,1422404175.028 [Depth_Keller] Loaded 2015-01-28T00:16:15.028Z,1422404175.028 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-01-28T00:16:15.121Z,1422404175.121 [NAL9602] Loaded 2015-01-28T00:16:15.121Z,1422404175.121 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-01-28T00:16:15.178Z,1422404175.178 [Onboard] Loaded 2015-01-28T00:16:15.178Z,1422404175.178 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-01-28T00:16:15.185Z,1422404175.185 [Radio_Surface] Loaded 2015-01-28T00:16:15.186Z,1422404175.186 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-01-28T00:16:15.187Z,1422404175.187 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0 2015-01-28T00:16:15.187Z,1422404175.187 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3307 2015-01-28T00:16:15.235Z,1422404175.235 [PNI_TCM] Loaded 2015-01-28T00:16:15.235Z,1422404175.235 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-01-28T00:16:17.071Z,1422404177.071 [BPC1] Loaded 2015-01-28T00:16:17.071Z,1422404177.071 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-01-28T00:16:17.072Z,1422404177.072 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-01-28T00:16:17.072Z,1422404177.072 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-01-28T00:16:17.170Z,1422404177.170 [BuoyancyServo] Loaded 2015-01-28T00:16:17.170Z,1422404177.170 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-01-28T00:16:17.182Z,1422404177.182 [ElevatorServo] Loaded 2015-01-28T00:16:17.182Z,1422404177.182 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-01-28T00:16:17.194Z,1422404177.194 [RudderServo] Loaded 2015-01-28T00:16:17.194Z,1422404177.194 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-01-28T00:16:17.205Z,1422404177.205 [ThrusterServo] Loaded 2015-01-28T00:16:17.206Z,1422404177.206 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-01-28T00:16:17.206Z,1422404177.206 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-01-28T00:16:17.207Z,1422404177.207 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-01-28T00:16:17.439Z,1422404177.439 [ExternalSim] Loaded 2015-01-28T00:16:17.439Z,1422404177.439 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread. 2015-01-28T00:16:17.440Z,1422404177.440 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-01-28T00:16:17.441Z,1422404177.441 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-01-28T00:16:17.465Z,1422404177.465 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-01-28T00:16:17.467Z,1422404177.467 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-01-28T00:16:17.468Z,1422404177.468 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-01-28T00:16:17.474Z,1422404177.474 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-01-28T00:16:17.476Z,1422404177.476 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0 2015-01-28T00:16:17.476Z,1422404177.476 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3308 2015-01-28T00:16:17.481Z,1422404177.481 [Supervisor](INFO): Main Thread ID is 3087 2015-01-28T00:16:17.481Z,1422404177.481 [Supervisor](DEBUG): Running supervisor. 2015-01-28T00:16:17.482Z,1422404177.482 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3309 2015-01-28T00:16:17.486Z,1422404177.486 [controlThread ThreadHandler](INFO): Handler Thread ID is 3310 2015-01-28T00:16:17.486Z,1422404177.486 [controlThread](DEBUG): Initializing ControlThread 2015-01-28T00:16:17.487Z,1422404177.487 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-01-28T00:16:17.489Z,1422404177.489 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-01-28T00:16:17.489Z,1422404177.489 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-01-28T00:16:17.490Z,1422404177.490 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-01-28T00:16:17.490Z,1422404177.490 [SBIT](INFO): Initialize SBIT Component. 2015-01-28T00:16:17.491Z,1422404177.491 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963 2015-01-28T00:16:17.491Z,1422404177.491 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-01-28T00:16:17.491Z,1422404177.491 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-01-28T00:16:17.492Z,1422404177.492 [IBIT](INFO): Initialize IBIT Component. 2015-01-28T00:16:17.493Z,1422404177.493 [CBIT](DEBUG): Initialize CBIT Component. 2015-01-28T00:16:17.493Z,1422404177.493 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-01-28T00:16:17.494Z,1422404177.494 [logger ThreadHandler](INFO): Handler Thread ID is 3311 2015-01-28T00:16:17.513Z,1422404177.513 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3312 2015-01-28T00:16:17.517Z,1422404177.517 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-01-28T00:16:17.517Z,1422404177.517 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-01-28T00:16:17.518Z,1422404177.518 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-01-28T00:16:17.518Z,1422404177.518 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-01-28T00:16:17.519Z,1422404177.519 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-01-28T00:16:17.519Z,1422404177.519 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:16:17.519Z,1422404177.519 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-01-28T00:16:17.520Z,1422404177.520 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-01-28T00:16:17.523Z,1422404177.523 [ExternalSim](INFO): ExternalSim initializing... 2015-01-28T00:16:17.537Z,1422404177.537 [Radio_Surface](INFO): Powering up 2015-01-28T00:16:17.553Z,1422404177.553 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3313 2015-01-28T00:16:17.556Z,1422404177.556 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-01-28T00:16:17.557Z,1422404177.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-01-28T00:16:17.557Z,1422404177.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-01-28T00:16:17.558Z,1422404177.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-01-28T00:16:17.558Z,1422404177.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-01-28T00:16:17.558Z,1422404177.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-01-28T00:16:17.558Z,1422404177.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-01-28T00:16:17.559Z,1422404177.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-01-28T00:16:17.559Z,1422404177.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-01-28T00:16:17.860Z,1422404177.860 [ExternalSim](DEBUG): beaconLat = 36.80340 2015-01-28T00:16:17.860Z,1422404177.860 [ExternalSim](DEBUG): beaconLon = -121.82230 2015-01-28T00:16:17.860Z,1422404177.860 [ExternalSim](DEBUG): beaconDepth = 25.00 2015-01-28T00:16:17.968Z,1422404177.968 [ExternalSim](DEBUG): Simulator initialized 2015-01-28T00:16:17.974Z,1422404177.974 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-01-28T00:16:17.984Z,1422404177.984 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-01-28T00:16:18.010Z,1422404178.010 [MissionManager](DEBUG): 2015-01-28T00:16:18.011Z,1422404178.011 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-01-28T00:16:18.099Z,1422404178.099 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h 2015-01-28T00:16:18.122Z,1422404178.122 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h 2015-01-28T00:16:18.126Z,1422404178.126 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2015-01-28T00:16:18.155Z,1422404178.155 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-01-28T00:16:18.177Z,1422404178.177 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-01-28T00:16:18.201Z,1422404178.201 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-01-28T00:16:18.215Z,1422404178.215 [MissionManager](DEBUG): 0 0 5.0 1.0 400 Burn 300 Dropped drop weight due to communications timeout 5.0 Default mission has been running for 5 2015-01-28T00:16:18.219Z,1422404178.219 [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-28T00:16:18.454Z,1422404178.454 [NAL9602](INFO): Start 2015-01-28T00:16:18.792Z,1422404178.792 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:18.907Z,1422404178.907 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-01-28T00:16:18.915Z,1422404178.915 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-01-28T00:16:18.945Z,1422404178.945 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-01-28T00:16:18.951Z,1422404178.951 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-01-28T00:16:18.961Z,1422404178.961 [RudderServo](DEBUG): Initializing EZServoServo. 2015-01-28T00:16:18.967Z,1422404178.967 [RudderServo](DEBUG): Initializing RudderServo. 2015-01-28T00:16:18.989Z,1422404178.989 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-01-28T00:16:18.995Z,1422404178.995 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-01-28T00:16:19.231Z,1422404179.231 [NAL9602](INFO): Start 2015-01-28T00:16:19.258Z,1422404179.258 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:28.487Z,1422404188.487 [NAL9602](INFO): Start 2015-01-28T00:16:28.487Z,1422404188.487 [NAL9602](INFO): Powering up NAL9602 2015-01-28T00:16:28.545Z,1422404188.545 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:28.996Z,1422404188.996 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:29.404Z,1422404189.404 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:29.739Z,1422404189.739 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003506 2015-01-28T00:16:29.819Z,1422404189.819 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:16:32.076Z,1422404192.076 [CommandLine](IMPORTANT): got command report mod NAL9602.sigQuality 2015-01-28T00:16:32.601Z,1422404192.601 [Reporter](INFO): NAL9602.sigQuality no_value 2015-01-28T00:16:32.837Z,1422404192.837 [SBIT](IMPORTANT): Beginning Startup BIT 2015-01-28T00:16:32.840Z,1422404192.840 [CBIT](IMPORTANT): Beginning GF scan 2015-01-28T00:16:35.943Z,1422404195.943 [CommandLine](IMPORTANT): got command report 2015-01-28T00:16:35.944Z,1422404195.944 [Reporter](INFO): NAL9602.sigQuality reporting changes 2015-01-28T00:16:39.588Z,1422404199.588 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-28T00:16:39.589Z,1422404199.589 [NAL9602](INFO): NAL9602 initialized 2015-01-28T00:16:42.790Z,1422404202.790 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:16:43.390Z,1422404203.390 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-28T00:16:43.591Z,1422404203.591 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:16:46.115Z,1422404206.115 [SBIT](ERROR): Could not read massPosReader_. 2015-01-28T00:16:47.990Z,1422404207.990 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:16:48.811Z,1422404208.811 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:16:52.929Z,1422404212.929 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:16:59.483Z,1422404219.483 [CBIT](IMPORTANT): No ground fault detected 2015-01-28T00:17:02.124Z,1422404222.124 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:06.531Z,1422404226.531 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:10.921Z,1422404230.921 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:11.731Z,1422404231.731 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:12.869Z,1422404232.869 [SBIT](ERROR): Could not read massPosReader_. 2015-01-28T00:17:12.869Z,1422404232.869 [SBIT](FAULT): Control surface position failure. 2015-01-28T00:17:15.765Z,1422404235.765 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:16.630Z,1422404236.630 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:23.021Z,1422404243.021 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:23.761Z,1422404243.761 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:26.173Z,1422404246.173 [SBIT](ERROR): Could not read massPosReader_. 2015-01-28T00:17:26.173Z,1422404246.173 [SBIT](FAULT): Control surface position failure. 2015-01-28T00:17:26.574Z,1422404246.574 [SBIT](CRITICAL): SBIT FAILED 2015-01-28T00:17:26.575Z,1422404246.575 [CommandLine](FAULT): Scheduling is paused 2015-01-28T00:17:26.963Z,1422404246.963 [MissionManager](IMPORTANT): Started mission Startup 2015-01-28T00:17:26.963Z,1422404246.963 [Startup] Running Loop=1 2015-01-28T00:17:26.963Z,1422404246.963 [Startup](INFO): Aggregate::initialize Startup 2015-01-28T00:17:26.963Z,1422404246.963 [Startup:A.GoToSurface] Running Loop=1 2015-01-28T00:17:26.963Z,1422404246.963 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-01-28T00:17:26.964Z,1422404246.964 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-01-28T00:17:26.964Z,1422404246.964 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-01-28T00:17:26.964Z,1422404246.964 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-01-28T00:17:26.970Z,1422404246.970 [Startup:StartupSatComms] Running Loop=1 2015-01-28T00:17:26.970Z,1422404246.970 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2015-01-28T00:17:26.970Z,1422404246.970 [Startup:StartupSatComms:A] Running Loop=1 2015-01-28T00:17:27.408Z,1422404247.408 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-01-28T00:17:32.527Z,1422404252.527 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:36.519Z,1422404256.519 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:36.728Z,1422404256.728 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:17:36.729Z,1422404256.729 [CommandLine](FAULT): Element has no value 2015-01-28T00:17:40.928Z,1422404260.928 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:41.766Z,1422404261.766 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:45.727Z,1422404265.727 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:46.529Z,1422404266.529 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:50.507Z,1422404270.507 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:51.324Z,1422404271.324 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:55.747Z,1422404275.747 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:17:56.548Z,1422404276.548 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:00.932Z,1422404280.932 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:01.704Z,1422404281.704 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:05.731Z,1422404285.731 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:09.329Z,1422404289.329 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:14.192Z,1422404294.192 [BPC1](ERROR): Failed to parse message. 2015-01-28T00:18:14.192Z,1422404294.192 [BPC1](FAULT): Failed to parse bank A battery data 2015-01-28T00:18:14.193Z,1422404294.193 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:18:14.193Z,1422404294.193 [BPC1](ERROR): Data Fault 2015-01-28T00:18:14.209Z,1422404294.209 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:18:15.362Z,1422404295.362 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:18:15.362Z,1422404295.362 [BPC1] No Fault, FailCount= 1 2015-01-28T00:18:18.134Z,1422404298.134 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:22.737Z,1422404302.737 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:26.735Z,1422404306.735 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:27.160Z,1422404307.160 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-28T00:17:26.0Z 2015-01-28T00:18:27.160Z,1422404307.160 [Startup:StartupSatComms:A] Stopped 2015-01-28T00:18:27.160Z,1422404307.160 [Startup:StartupSatComms:B] Running Loop=1 2015-01-28T00:18:27.562Z,1422404307.562 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-01-28T00:18:31.780Z,1422404311.780 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150127T230557/Courier0028.lzma 2015-01-28T00:18:32.586Z,1422404312.586 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Courier0028.lzma.bak 2015-01-28T00:18:32.586Z,1422404312.586 [DataOverHttps](INFO): SBD MOMSN=1509012 2015-01-28T00:18:36.735Z,1422404316.735 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:41.814Z,1422404321.814 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150128T001608/Courier0000.lzma 2015-01-28T00:18:41.842Z,1422404321.842 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:42.656Z,1422404322.656 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Courier0000.lzma.bak 2015-01-28T00:18:42.656Z,1422404322.656 [DataOverHttps](INFO): SBD MOMSN=1509014 2015-01-28T00:18:48.194Z,1422404328.194 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:51.965Z,1422404331.965 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20150127T230557/Express0029.lzma 2015-01-28T00:18:52.359Z,1422404332.359 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:18:52.741Z,1422404332.741 [DataOverHttps](INFO): Moved sent file to Logs/20150127T230557/Express0029.lzma.bak 2015-01-28T00:18:52.741Z,1422404332.741 [DataOverHttps](INFO): SBD MOMSN=1509018 2015-01-28T00:18:57.019Z,1422404337.019 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:02.050Z,1422404342.050 [DataOverHttps](INFO): Sending 629 bytes from file Logs/20150128T001608/Express0001.lzma 2015-01-28T00:19:02.062Z,1422404342.062 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:02.847Z,1422404342.847 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Express0001.lzma.bak 2015-01-28T00:19:02.847Z,1422404342.847 [DataOverHttps](INFO): SBD MOMSN=1509026 2015-01-28T00:19:03.677Z,1422404343.677 [Startup:StartupSatComms:B] Stopped 2015-01-28T00:19:03.677Z,1422404343.677 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2015-01-28T00:19:03.677Z,1422404343.677 [Startup:StartupSatComms] Stopped 2015-01-28T00:19:03.677Z,1422404343.677 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2015-01-28T00:19:03.678Z,1422404343.678 [Startup](INFO): Completed Startup 2015-01-28T00:19:03.678Z,1422404343.678 [Startup] Stopped 2015-01-28T00:19:03.678Z,1422404343.678 [Startup](INFO): Aggregate::uninitialize Startup 2015-01-28T00:19:03.678Z,1422404343.678 [Startup:A.GoToSurface] Stopped 2015-01-28T00:19:03.678Z,1422404343.678 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-01-28T00:19:03.874Z,1422404343.874 [MissionManager](IMPORTANT): Started mission Default 2015-01-28T00:19:03.874Z,1422404343.874 [Default] Running Loop=1 2015-01-28T00:19:03.874Z,1422404343.874 [Default](INFO): Aggregate::initialize Default 2015-01-28T00:19:03.874Z,1422404343.874 [Default:B.GoToSurface] Running Loop=1 2015-01-28T00:19:03.874Z,1422404343.874 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-01-28T00:19:03.875Z,1422404343.875 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-01-28T00:19:03.875Z,1422404343.875 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-01-28T00:19:03.876Z,1422404343.876 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-01-28T00:19:03.876Z,1422404343.876 [Default:StartClock] Running Loop=1 2015-01-28T00:19:03.876Z,1422404343.876 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock 2015-01-28T00:19:03.876Z,1422404343.876 [Default:StartClock:A] Running Loop=1 2015-01-28T00:19:03.884Z,1422404343.884 [Default:StartClock:A] Stopped 2015-01-28T00:19:03.885Z,1422404343.885 [Default:StartClock](INFO): Completed Default:StartClock 2015-01-28T00:19:03.885Z,1422404343.885 [Default:StartClock] Stopped 2015-01-28T00:19:03.885Z,1422404343.885 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock 2015-01-28T00:19:07.072Z,1422404347.072 [Default:WaitAtTheSurface] Running Loop=1 2015-01-28T00:19:07.072Z,1422404347.072 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2015-01-28T00:19:07.072Z,1422404347.072 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-01-28T00:19:07.072Z,1422404347.072 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize. 2015-01-28T00:19:07.178Z,1422404347.178 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:07.215Z,1422404347.215 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-01-28T00:19:22.186Z,1422404362.186 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:22.273Z,1422404362.273 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:19:22.273Z,1422404362.273 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2015-01-28T00:19:22.273Z,1422404362.273 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:19:22.310Z,1422404362.310 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:19:26.034Z,1422404366.034 [CommandLine](IMPORTANT): got command get platform_orientation 2015-01-28T00:19:26.035Z,1422404366.035 [CommandLine](IMPORTANT): platform_orientation 0.050989 rad 2015-01-28T00:19:27.245Z,1422404367.245 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:19:27.245Z,1422404367.245 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2015-01-28T00:19:29.201Z,1422404369.201 [CommandLine](IMPORTANT): got command get platform_orientation degree 2015-01-28T00:19:29.201Z,1422404369.201 [CommandLine](IMPORTANT): platform_orientation 2.961892 arcdeg 2015-01-28T00:19:32.185Z,1422404372.185 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:32.248Z,1422404372.248 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:19:37.236Z,1422404377.236 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:19:42.200Z,1422404382.200 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:42.272Z,1422404382.272 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:19:47.263Z,1422404387.263 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:19:48.146Z,1422404388.146 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:19:48.146Z,1422404388.146 [CommandLine](FAULT): Element has no value 2015-01-28T00:19:52.190Z,1422404392.190 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:19:52.209Z,1422404392.209 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:19:57.227Z,1422404397.227 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:20:02.189Z,1422404402.189 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:20:02.274Z,1422404402.274 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:20:12.183Z,1422404412.183 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:20:22.175Z,1422404422.175 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:20:32.403Z,1422404432.403 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:20:42.182Z,1422404442.182 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:20:52.178Z,1422404452.178 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:21:02.197Z,1422404462.197 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:21:12.181Z,1422404472.181 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:21:20.082Z,1422404480.082 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:21:20.082Z,1422404480.082 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:21:20.082Z,1422404480.082 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:21:20.088Z,1422404480.088 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:21:20.088Z,1422404480.088 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:21:22.180Z,1422404482.180 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:21:22.226Z,1422404482.226 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 2.222633 min 2015-01-28T00:21:22.228Z,1422404482.228 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:21:22.228Z,1422404482.228 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:21:22.228Z,1422404482.228 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:21:22.228Z,1422404482.228 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:21:32.180Z,1422404492.180 [NAL9602](INFO): MT Sig Qty requested 2015-01-28T00:21:47.183Z,1422404507.183 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2015-01-28T00:22:37.280Z,1422404557.280 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:22:37.280Z,1422404557.280 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2015-01-28T00:22:37.281Z,1422404557.281 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:22:37.300Z,1422404557.300 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:22:42.237Z,1422404562.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:22:42.237Z,1422404562.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2015-01-28T00:22:47.267Z,1422404567.267 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:22:52.234Z,1422404572.234 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:22:57.268Z,1422404577.268 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:23:02.244Z,1422404582.244 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:23:07.198Z,1422404587.198 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:23:12.230Z,1422404592.230 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:23:17.284Z,1422404597.284 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:23:47.211Z,1422404627.211 [BPC1](DEBUG): Received data from all battery sticks 2015-01-28T00:24:07.538Z,1422404647.538 [Default:CheckIn] Running Loop=1 2015-01-28T00:24:07.538Z,1422404647.538 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-01-28T00:24:07.538Z,1422404647.538 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-01-28T00:24:07.538Z,1422404647.538 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-01-28T00:24:07.538Z,1422404647.538 [Default:CheckIn:Read_GPS] Running Loop=1 2015-01-28T00:24:07.539Z,1422404647.539 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-01-28T00:24:07.541Z,1422404647.541 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-01-28T00:24:34.749Z,1422404674.749 [BPC1](FAULT): B bank: No match for serial number:5911 was found in the onboard configuration. 2015-01-28T00:24:34.750Z,1422404674.750 [BPC1](FAULT): Failed to parse bank B battery data 2015-01-28T00:24:34.750Z,1422404674.750 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:24:34.750Z,1422404674.750 [BPC1](ERROR): Data Fault 2015-01-28T00:24:34.767Z,1422404674.767 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:24:35.962Z,1422404675.962 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:24:35.963Z,1422404675.963 [BPC1] No Fault, FailCount= 1 2015-01-28T00:25:06.355Z,1422404706.355 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:25:06.355Z,1422404706.355 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:25:06.355Z,1422404706.355 [BPC1](ERROR): Communications Fault 2015-01-28T00:25:06.402Z,1422404706.402 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:25:07.548Z,1422404707.548 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:25:07.548Z,1422404707.548 [BPC1] No Fault, FailCount= 1 2015-01-28T00:25:47.477Z,1422404747.477 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:25:47.477Z,1422404747.477 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2015-01-28T00:25:47.477Z,1422404747.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:25:47.488Z,1422404747.488 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:25:47.882Z,1422404747.882 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:25:47.882Z,1422404747.882 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2015-01-28T00:25:48.284Z,1422404748.284 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:25:48.642Z,1422404748.642 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:25:49.076Z,1422404749.076 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:25:49.439Z,1422404749.439 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:25:49.983Z,1422404749.983 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:25:50.296Z,1422404750.296 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:25:50.641Z,1422404750.641 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:26:21.441Z,1422404781.441 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:26:21.441Z,1422404781.441 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:26:21.441Z,1422404781.441 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:26:21.442Z,1422404781.442 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:26:21.442Z,1422404781.442 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:26:21.587Z,1422404781.587 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 7.246299 min 2015-01-28T00:26:21.587Z,1422404781.587 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:26:21.587Z,1422404781.587 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:26:21.587Z,1422404781.587 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:26:21.588Z,1422404781.588 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:26:43.148Z,1422404803.148 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-01-28T00:26:43.148Z,1422404803.148 [NAL9602] Data Fault, FailCount= 1 2015-01-28T00:26:43.148Z,1422404803.148 [NAL9602](ERROR): Data Fault 2015-01-28T00:26:43.250Z,1422404803.250 [CBIT](ERROR): Data Fault in component: NAL9602 2015-01-28T00:26:43.251Z,1422404803.251 [Reporter](INFO): NAL9602.sigQuality no_value 2015-01-28T00:26:43.540Z,1422404803.540 [NAL9602](INFO): Stop 2015-01-28T00:26:43.540Z,1422404803.540 [NAL9602](INFO): Uninitialize 2015-01-28T00:26:43.540Z,1422404803.540 [NAL9602](INFO): Powering down 2015-01-28T00:26:43.942Z,1422404803.942 [NAL9602](INFO): Stopping 2015-01-28T00:26:44.423Z,1422404804.423 [CBIT](INFO): Clearing failed state for component NAL9602 2015-01-28T00:26:44.423Z,1422404804.423 [NAL9602] No Fault, FailCount= 1 2015-01-28T00:26:44.745Z,1422404804.745 [NAL9602](INFO): Start 2015-01-28T00:26:45.146Z,1422404805.146 [NAL9602](INFO): Start 2015-01-28T00:26:45.555Z,1422404805.555 [NAL9602](INFO): Start 2015-01-28T00:26:46.176Z,1422404806.176 [NAL9602](INFO): Start 2015-01-28T00:26:46.354Z,1422404806.354 [NAL9602](INFO): Start 2015-01-28T00:26:46.741Z,1422404806.741 [NAL9602](INFO): Start 2015-01-28T00:26:47.145Z,1422404807.145 [NAL9602](INFO): Start 2015-01-28T00:26:47.541Z,1422404807.541 [NAL9602](INFO): Start 2015-01-28T00:26:47.959Z,1422404807.959 [NAL9602](INFO): Start 2015-01-28T00:26:48.355Z,1422404808.355 [NAL9602](INFO): Start 2015-01-28T00:26:48.741Z,1422404808.741 [NAL9602](INFO): Start 2015-01-28T00:26:48.741Z,1422404808.741 [NAL9602](INFO): Powering up NAL9602 2015-01-28T00:26:58.797Z,1422404818.797 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-28T00:26:59.569Z,1422404819.569 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-28T00:26:59.569Z,1422404819.569 [NAL9602](INFO): NAL9602 initialized 2015-01-28T00:28:48.477Z,1422404928.477 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:28:48.477Z,1422404928.477 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2015-01-28T00:28:48.477Z,1422404928.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:28:48.523Z,1422404928.523 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:28:49.121Z,1422404929.121 [BPC1](FAULT): A bank: No match for serial number:5911 was found in the onboard configuration. 2015-01-28T00:28:49.122Z,1422404929.122 [BPC1](FAULT): Failed to parse bank A battery data 2015-01-28T00:28:49.122Z,1422404929.122 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:28:49.122Z,1422404929.122 [BPC1](ERROR): Data Fault 2015-01-28T00:28:49.138Z,1422404929.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:28:49.138Z,1422404929.138 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2015-01-28T00:28:49.174Z,1422404929.174 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:28:49.319Z,1422404929.319 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:28:49.714Z,1422404929.714 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:28:50.119Z,1422404930.119 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:28:50.130Z,1422404930.130 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:28:50.130Z,1422404930.130 [BPC1] No Fault, FailCount= 1 2015-01-28T00:28:50.576Z,1422404930.576 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:28:50.926Z,1422404930.926 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:28:51.289Z,1422404931.289 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:28:51.711Z,1422404931.711 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:29:07.740Z,1422404947.740 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T00:24:07.5Z 2015-01-28T00:29:07.740Z,1422404947.740 [Default:CheckIn:Read_GPS] Stopped 2015-01-28T00:29:07.740Z,1422404947.740 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-01-28T00:29:08.122Z,1422404948.122 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-01-28T00:29:12.547Z,1422404952.547 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20150128T001608/Courier0004.lzma 2015-01-28T00:29:13.318Z,1422404953.318 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Courier0004.lzma.bak 2015-01-28T00:29:13.319Z,1422404953.319 [DataOverHttps](INFO): SBD MOMSN=1509044 2015-01-28T00:29:28.965Z,1422404968.965 [DataOverHttps](INFO): Sending 738 bytes from file Logs/20150128T001608/Express0005.lzma 2015-01-28T00:29:29.794Z,1422404969.794 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Express0005.lzma.bak 2015-01-28T00:29:29.794Z,1422404969.794 [DataOverHttps](INFO): SBD MOMSN=1509046 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn:Read_Iridium] Stopped 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn](INFO): Completed Default:CheckIn 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn] Stopped 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn:A.SetSpeed] Stopped 2015-01-28T00:29:30.501Z,1422404970.501 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-01-28T00:29:36.940Z,1422404976.940 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:29:36.940Z,1422404976.940 [CommandLine](FAULT): Element has no value 2015-01-28T00:31:25.663Z,1422405085.663 [BPC1](DEBUG): Received data from all battery sticks 2015-01-28T00:31:25.688Z,1422405085.688 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:31:25.688Z,1422405085.688 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:31:25.688Z,1422405085.688 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:31:25.689Z,1422405085.689 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:31:25.689Z,1422405085.689 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:31:30.684Z,1422405090.684 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 12.363392 min 2015-01-28T00:31:30.684Z,1422405090.684 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:31:30.684Z,1422405090.684 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:31:30.684Z,1422405090.684 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:31:30.685Z,1422405090.685 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:31:50.691Z,1422405110.691 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:31:50.691Z,1422405110.691 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2015-01-28T00:31:50.691Z,1422405110.691 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:31:50.702Z,1422405110.702 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:31:55.702Z,1422405115.702 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:31:55.702Z,1422405115.702 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2015-01-28T00:32:00.707Z,1422405120.707 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:32:05.658Z,1422405125.658 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:32:10.661Z,1422405130.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:32:15.791Z,1422405135.791 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:32:15.997Z,1422405135.997 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:32:15.998Z,1422405135.998 [CommandLine](FAULT): Element has no value 2015-01-28T00:32:20.662Z,1422405140.662 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:32:25.695Z,1422405145.695 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:32:30.661Z,1422405150.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:34:30.675Z,1422405270.675 [Default:CheckIn] Running Loop=1 2015-01-28T00:34:30.675Z,1422405270.675 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-01-28T00:34:30.675Z,1422405270.675 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-01-28T00:34:30.675Z,1422405270.675 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-01-28T00:34:30.675Z,1422405270.675 [Default:CheckIn:Read_GPS] Running Loop=1 2015-01-28T00:34:46.878Z,1422405286.878 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:34:46.878Z,1422405286.878 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:34:46.878Z,1422405286.878 [BPC1](ERROR): Communications Fault 2015-01-28T00:34:46.919Z,1422405286.919 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:34:48.072Z,1422405288.072 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:34:48.072Z,1422405288.072 [BPC1] No Fault, FailCount= 1 2015-01-28T00:35:00.846Z,1422405300.846 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:35:00.846Z,1422405300.846 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2015-01-28T00:35:00.846Z,1422405300.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:35:00.882Z,1422405300.882 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:35:01.284Z,1422405301.284 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:35:01.284Z,1422405301.284 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2015-01-28T00:35:01.676Z,1422405301.676 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:35:02.073Z,1422405302.073 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:02.443Z,1422405302.443 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:02.881Z,1422405302.881 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:03.242Z,1422405303.242 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:03.641Z,1422405303.641 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:04.079Z,1422405304.079 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:35:35.266Z,1422405335.266 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:35:35.266Z,1422405335.266 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:35:35.266Z,1422405335.266 [BPC1](ERROR): Communications Fault 2015-01-28T00:35:35.312Z,1422405335.312 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:35:36.510Z,1422405336.510 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:35:36.510Z,1422405336.510 [BPC1] No Fault, FailCount= 1 2015-01-28T00:36:25.928Z,1422405385.928 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:36:25.928Z,1422405385.928 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:36:25.928Z,1422405385.928 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:36:25.929Z,1422405385.929 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:36:25.929Z,1422405385.929 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:36:26.312Z,1422405386.312 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 17.367176 min 2015-01-28T00:36:26.313Z,1422405386.313 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:36:26.313Z,1422405386.313 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:36:26.313Z,1422405386.313 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:36:26.313Z,1422405386.313 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:37:00.616Z,1422405420.616 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-01-28T00:37:00.616Z,1422405420.616 [NAL9602] Data Fault, FailCount= 2 2015-01-28T00:37:00.616Z,1422405420.616 [NAL9602](ERROR): Data Fault 2015-01-28T00:37:00.645Z,1422405420.645 [CBIT](ERROR): Data Fault in component: NAL9602 2015-01-28T00:37:00.646Z,1422405420.646 [Reporter](INFO): NAL9602.sigQuality no_value 2015-01-28T00:37:00.891Z,1422405420.891 [NAL9602](INFO): Stop 2015-01-28T00:37:00.891Z,1422405420.891 [NAL9602](INFO): Uninitialize 2015-01-28T00:37:00.891Z,1422405420.891 [NAL9602](INFO): Powering down 2015-01-28T00:37:01.297Z,1422405421.297 [NAL9602](INFO): Stopping 2015-01-28T00:37:01.739Z,1422405421.739 [CBIT](INFO): Clearing failed state for component NAL9602 2015-01-28T00:37:01.739Z,1422405421.739 [NAL9602] No Fault, FailCount= 2 2015-01-28T00:37:02.118Z,1422405422.118 [NAL9602](INFO): Start 2015-01-28T00:37:02.499Z,1422405422.499 [NAL9602](INFO): Start 2015-01-28T00:37:02.891Z,1422405422.891 [NAL9602](INFO): Start 2015-01-28T00:37:03.292Z,1422405423.292 [NAL9602](INFO): Start 2015-01-28T00:37:03.696Z,1422405423.696 [NAL9602](INFO): Start 2015-01-28T00:37:04.117Z,1422405424.117 [NAL9602](INFO): Start 2015-01-28T00:37:04.494Z,1422405424.494 [NAL9602](INFO): Start 2015-01-28T00:37:04.886Z,1422405424.886 [NAL9602](INFO): Start 2015-01-28T00:37:05.287Z,1422405425.287 [NAL9602](INFO): Start 2015-01-28T00:37:05.719Z,1422405425.719 [NAL9602](INFO): Start 2015-01-28T00:37:06.088Z,1422405426.088 [NAL9602](INFO): Start 2015-01-28T00:37:06.088Z,1422405426.088 [NAL9602](INFO): Powering up NAL9602 2015-01-28T00:37:16.140Z,1422405436.140 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-28T00:37:16.885Z,1422405436.885 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-28T00:37:16.885Z,1422405436.885 [NAL9602](INFO): NAL9602 initialized 2015-01-28T00:38:02.089Z,1422405482.089 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:38:02.089Z,1422405482.089 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2015-01-28T00:38:02.089Z,1422405482.089 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:38:02.101Z,1422405482.101 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:38:02.348Z,1422405482.348 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:38:02.349Z,1422405482.349 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2015-01-28T00:38:02.739Z,1422405482.739 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:38:03.144Z,1422405483.144 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:03.512Z,1422405483.512 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:03.896Z,1422405483.896 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:04.338Z,1422405484.338 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:04.702Z,1422405484.702 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:05.139Z,1422405485.139 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:38:11.128Z,1422405491.128 [BPC1](DEBUG): Received data from all battery sticks 2015-01-28T00:39:30.922Z,1422405570.922 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T00:34:30.7Z 2015-01-28T00:39:30.923Z,1422405570.923 [Default:CheckIn:Read_GPS] Stopped 2015-01-28T00:39:30.923Z,1422405570.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-01-28T00:39:35.513Z,1422405575.513 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150128T001608/Courier0008.lzma 2015-01-28T00:39:36.315Z,1422405576.315 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Courier0008.lzma.bak 2015-01-28T00:39:36.315Z,1422405576.315 [DataOverHttps](INFO): SBD MOMSN=1509068 2015-01-28T00:39:45.640Z,1422405585.640 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20150128T001608/Express0009.lzma 2015-01-28T00:39:46.421Z,1422405586.421 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Express0009.lzma.bak 2015-01-28T00:39:46.421Z,1422405586.421 [DataOverHttps](INFO): SBD MOMSN=1509070 2015-01-28T00:39:47.266Z,1422405587.266 [Default:CheckIn:Read_Iridium] Stopped 2015-01-28T00:39:47.267Z,1422405587.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2015-01-28T00:39:47.267Z,1422405587.267 [Default:CheckIn] Stopped 2015-01-28T00:39:47.267Z,1422405587.267 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-01-28T00:39:47.267Z,1422405587.267 [Default:CheckIn:A.SetSpeed] Stopped 2015-01-28T00:39:47.267Z,1422405587.267 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-01-28T00:41:07.428Z,1422405667.428 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:41:07.429Z,1422405667.429 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2015-01-28T00:41:07.429Z,1422405667.429 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:41:07.440Z,1422405667.440 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:41:12.439Z,1422405672.439 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:41:12.439Z,1422405672.439 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2015-01-28T00:41:17.409Z,1422405677.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:41:22.392Z,1422405682.392 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:41:27.494Z,1422405687.494 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:41:27.496Z,1422405687.496 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:41:27.496Z,1422405687.496 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:41:27.496Z,1422405687.496 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:41:27.497Z,1422405687.497 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:41:27.497Z,1422405687.497 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:41:32.400Z,1422405692.400 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:41:32.403Z,1422405692.403 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 22.392527 min 2015-01-28T00:41:32.403Z,1422405692.403 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:41:32.403Z,1422405692.403 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:41:32.403Z,1422405692.403 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:41:32.403Z,1422405692.403 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:41:37.431Z,1422405697.431 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:41:42.427Z,1422405702.427 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:41:47.461Z,1422405707.461 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:43:48.002Z,1422405828.002 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:43:48.003Z,1422405828.003 [CommandLine](FAULT): Element has no value 2015-01-28T00:44:15.369Z,1422405855.369 [CommandLine](IMPORTANT): got command failComponent 2015-01-28T00:44:15.370Z,1422405855.370 [CommandLine](IMPORTANT): Failed components: 2015-01-28T00:44:15.370Z,1422405855.370 [CommandLine](IMPORTANT): No failed Components. 2015-01-28T00:44:17.440Z,1422405857.440 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:44:17.440Z,1422405857.440 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2015-01-28T00:44:17.440Z,1422405857.440 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:44:17.451Z,1422405857.451 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:44:22.448Z,1422405862.448 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:44:22.448Z,1422405862.448 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2015-01-28T00:44:27.445Z,1422405867.445 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:44:32.470Z,1422405872.470 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:44:37.425Z,1422405877.425 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:44:42.426Z,1422405882.426 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:44:47.425Z,1422405887.425 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:44:47.427Z,1422405887.427 [Default:CheckIn] Running Loop=1 2015-01-28T00:44:47.428Z,1422405887.428 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-01-28T00:44:47.428Z,1422405887.428 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-01-28T00:44:47.428Z,1422405887.428 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-01-28T00:44:47.428Z,1422405887.428 [Default:CheckIn:Read_GPS] Running Loop=1 2015-01-28T00:44:47.806Z,1422405887.806 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:44:48.239Z,1422405888.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:45:33.588Z,1422405933.588 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:45:33.588Z,1422405933.588 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:45:33.588Z,1422405933.588 [BPC1](ERROR): Communications Fault 2015-01-28T00:45:33.645Z,1422405933.645 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:45:34.829Z,1422405934.829 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:45:34.829Z,1422405934.829 [BPC1] No Fault, FailCount= 1 2015-01-28T00:45:49.209Z,1422405949.209 [BPC1](DEBUG): Received data from all battery sticks 2015-01-28T00:46:27.851Z,1422405987.851 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:46:27.851Z,1422405987.851 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:46:27.851Z,1422405987.851 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:46:27.852Z,1422405987.852 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:46:27.852Z,1422405987.852 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:46:28.228Z,1422405988.228 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 27.399249 min 2015-01-28T00:46:28.228Z,1422405988.228 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:46:28.228Z,1422405988.228 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:46:28.228Z,1422405988.228 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:46:28.229Z,1422405988.229 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:47:20.144Z,1422406040.144 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-01-28T00:47:20.144Z,1422406040.144 [NAL9602] Data Fault, FailCount= 3 2015-01-28T00:47:20.144Z,1422406040.144 [NAL9602](ERROR): Data Fault 2015-01-28T00:47:20.217Z,1422406040.217 [CBIT](ERROR): Data Fault in component: NAL9602 2015-01-28T00:47:20.222Z,1422406040.222 [Reporter](INFO): NAL9602.sigQuality no_value 2015-01-28T00:47:20.396Z,1422406040.396 [NAL9602](INFO): Stop 2015-01-28T00:47:20.396Z,1422406040.396 [NAL9602](INFO): Uninitialize 2015-01-28T00:47:20.396Z,1422406040.396 [NAL9602](INFO): Powering down 2015-01-28T00:47:20.784Z,1422406040.784 [NAL9602](INFO): Stopping 2015-01-28T00:47:21.211Z,1422406041.211 [CBIT](INFO): Clearing failed state for component NAL9602 2015-01-28T00:47:21.211Z,1422406041.211 [NAL9602] No Fault, FailCount= 3 2015-01-28T00:47:21.581Z,1422406041.581 [NAL9602](INFO): Start 2015-01-28T00:47:21.982Z,1422406041.982 [NAL9602](INFO): Start 2015-01-28T00:47:22.380Z,1422406042.380 [NAL9602](INFO): Start 2015-01-28T00:47:22.780Z,1422406042.780 [NAL9602](INFO): Start 2015-01-28T00:47:23.168Z,1422406043.168 [NAL9602](INFO): Start 2015-01-28T00:47:23.582Z,1422406043.582 [NAL9602](INFO): Start 2015-01-28T00:47:23.982Z,1422406043.982 [NAL9602](INFO): Start 2015-01-28T00:47:24.386Z,1422406044.386 [NAL9602](INFO): Start 2015-01-28T00:47:24.784Z,1422406044.784 [NAL9602](INFO): Start 2015-01-28T00:47:25.207Z,1422406045.207 [NAL9602](INFO): Start 2015-01-28T00:47:25.572Z,1422406045.572 [NAL9602](INFO): Start 2015-01-28T00:47:25.573Z,1422406045.573 [NAL9602](INFO): Powering up NAL9602 2015-01-28T00:47:27.606Z,1422406047.606 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:47:27.606Z,1422406047.606 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2015-01-28T00:47:27.606Z,1422406047.606 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:47:27.633Z,1422406047.633 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:47:28.013Z,1422406048.013 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:47:28.013Z,1422406048.013 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2015-01-28T00:47:28.409Z,1422406048.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:47:28.805Z,1422406048.805 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:29.216Z,1422406049.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:29.606Z,1422406049.606 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:30.006Z,1422406050.006 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:30.382Z,1422406050.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:30.814Z,1422406050.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:47:36.015Z,1422406056.015 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-28T00:47:36.777Z,1422406056.777 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-28T00:47:36.777Z,1422406056.777 [NAL9602](INFO): NAL9602 initialized 2015-01-28T00:49:09.243Z,1422406149.243 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X $S,01,270F,02,00,04,5D%56 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,0A,0000%33 $B12,0A,FFFB%34 $B13,0A,FFFC%34 $B14,0A,FFFC%33 $B15,0A,0000%37 $B16,0A,0000%34 $B17,0A,0000%35 $B18,0A,FFE8%47 $S,01,270F,02,00,04,5D%56 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,02,000A,01,026C,03,0001,08,0B8E,09,3C20,0A,0000,0B,0000%3A $B11,0C,0001,0D,0064,0E,005B,0F,15E2,10,1641,11,FFFF,12,FFFF%41 $B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F $B11,1A,0031,1B,4357,1C,009D%49 $B12,02,000A,01,026C,03,0001,08,0B93,09,3C48,0A,FFFC,0B,FFFB%41 $B12,0C,0001,0D,0053,0E,0051,0F,1379,10,17B2,11,FFFF,12,E9AC%40 $B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42 $B12,1A,0031,1B,4357,1C,0093%3D $B13,02,000A,01,026C,03,0001,08,0B9B,09,3C48,0A,FFFC,0B,FFFC%30 $B13,0C,0001,0D,005C,0E,004E,0F,12CD,10,16D7,11,FFFF,12,FFFF%30 $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,0B93,09,3C48,0A,FFFB,0B,FFFC%47 $B14,0C,0001,0D,0053,0E,004D,0F,127F,10,168C,11,DDF4,12,FFFF%4A $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,0B95,09,3C13,0A,0000,0B,0000%4F $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,0B90,09,3C19,0A,0000,0B,0000%43 $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,0B94,09,3C15,0A,0000,0B,0000%4A $B17,0C,0001,0D,0064,0E,005F,0F,16DB,10,1701,11,FFFF,12,FFFF%34 $B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A $B17,1A,0031,1B,4357,1C,00A5%46 $B18,02,000A,01,026C,03,0001,08,0B96,09,3C19,0A,FFE8,0B,FFE8%4B $B18,0C,0001,0D,0058,0E,0050,0F,135E,10,16A5,11,306B,12,306B%45 $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-28T00:49:09.243Z,1422406149.243 [BPC1](FAULT): Failed to parse bank B battery data 2015-01-28T00:49:09.243Z,1422406149.243 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:49:09.243Z,1422406149.243 [BPC1](ERROR): Data Fault 2015-01-28T00:49:09.261Z,1422406149.261 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:49:10.434Z,1422406150.434 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:49:10.434Z,1422406150.434 [BPC1] No Fault, FailCount= 1 2015-01-28T00:49:22.965Z,1422406162.965 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read: 2015-01-28T00:49:22.965Z,1422406162.965 [BPC1](FAULT): Failed to parse bank A battery data 2015-01-28T00:49:22.965Z,1422406162.965 [BPC1] Data Fault, FailCount= 2 2015-01-28T00:49:22.965Z,1422406162.965 [BPC1](ERROR): Data Fault 2015-01-28T00:49:23.034Z,1422406163.034 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:49:24.064Z,1422406164.064 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:49:24.065Z,1422406164.065 [BPC1] No Fault, FailCount= 2 2015-01-28T00:49:47.630Z,1422406187.630 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-28T00:44:47.4Z 2015-01-28T00:49:47.630Z,1422406187.630 [Default:CheckIn:Read_GPS] Stopped 2015-01-28T00:49:47.630Z,1422406187.630 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-01-28T00:49:52.337Z,1422406192.337 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150128T001608/Courier0012.lzma 2015-01-28T00:49:53.124Z,1422406193.124 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Courier0012.lzma.bak 2015-01-28T00:49:53.125Z,1422406193.125 [DataOverHttps](INFO): SBD MOMSN=1509084 2015-01-28T00:50:02.694Z,1422406202.694 [DataOverHttps](INFO): Sending 385 bytes from file Logs/20150128T001608/Express0013.lzma 2015-01-28T00:50:03.492Z,1422406203.492 [DataOverHttps](INFO): Moved sent file to Logs/20150128T001608/Express0013.lzma.bak 2015-01-28T00:50:03.493Z,1422406203.493 [DataOverHttps](INFO): SBD MOMSN=1509086 2015-01-28T00:50:04.443Z,1422406204.443 [Default:CheckIn:Read_Iridium] Stopped 2015-01-28T00:50:04.444Z,1422406204.444 [Default:CheckIn](INFO): Completed Default:CheckIn 2015-01-28T00:50:04.444Z,1422406204.444 [Default:CheckIn] Stopped 2015-01-28T00:50:04.444Z,1422406204.444 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-01-28T00:50:04.444Z,1422406204.444 [Default:CheckIn:A.SetSpeed] Stopped 2015-01-28T00:50:04.444Z,1422406204.444 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-01-28T00:50:29.610Z,1422406229.610 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:50:29.610Z,1422406229.610 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2015-01-28T00:50:29.611Z,1422406229.611 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:50:29.621Z,1422406229.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:50:34.729Z,1422406234.729 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:50:34.729Z,1422406234.729 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2015-01-28T00:50:39.768Z,1422406239.768 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:50:44.605Z,1422406244.605 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:50:49.658Z,1422406249.658 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:50:54.606Z,1422406254.606 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:50:59.605Z,1422406259.605 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:51:04.576Z,1422406264.576 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:51:09.627Z,1422406269.627 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:51:29.633Z,1422406289.633 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:51:29.633Z,1422406289.633 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:51:29.633Z,1422406289.633 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:51:29.633Z,1422406289.633 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:51:29.633Z,1422406289.633 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:51:34.601Z,1422406294.601 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 32.428806 min 2015-01-28T00:51:34.601Z,1422406294.601 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:51:34.601Z,1422406294.601 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:51:34.601Z,1422406294.601 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:51:34.602Z,1422406294.602 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:53:44.597Z,1422406424.597 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:53:44.597Z,1422406424.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2015-01-28T00:53:44.597Z,1422406424.597 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:53:44.644Z,1422406424.644 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:53:49.638Z,1422406429.638 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:53:49.638Z,1422406429.638 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2015-01-28T00:53:54.593Z,1422406434.593 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:53:59.567Z,1422406439.567 [BPC1](DEBUG): Received data from all battery sticks 2015-01-28T00:53:59.593Z,1422406439.593 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:04.600Z,1422406444.600 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:09.711Z,1422406449.711 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:54:09.711Z,1422406449.711 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:54:09.711Z,1422406449.711 [BPC1](ERROR): Communications Fault 2015-01-28T00:54:09.718Z,1422406449.718 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:09.765Z,1422406449.765 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:54:14.888Z,1422406454.888 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:22.374Z,1422406462.374 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:24.591Z,1422406464.591 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:54:24.610Z,1422406464.610 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:54:24.610Z,1422406464.610 [BPC1] No Fault, FailCount= 1 2015-01-28T00:55:04.604Z,1422406504.604 [Default:CheckIn] Running Loop=1 2015-01-28T00:55:04.604Z,1422406504.604 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-01-28T00:55:04.605Z,1422406504.605 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-01-28T00:55:04.605Z,1422406504.605 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-01-28T00:55:04.605Z,1422406504.605 [Default:CheckIn:Read_GPS] Running Loop=1 2015-01-28T00:55:21.367Z,1422406521.367 [BPC1](FAULT): Failed to receive battery data 2015-01-28T00:55:21.367Z,1422406521.367 [BPC1] Communications Fault, FailCount= 1 2015-01-28T00:55:21.367Z,1422406521.367 [BPC1](ERROR): Communications Fault 2015-01-28T00:55:21.384Z,1422406521.384 [CBIT](ERROR): Communications Fault in component: BPC1 2015-01-28T00:55:22.423Z,1422406522.423 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:55:22.423Z,1422406522.423 [BPC1] No Fault, FailCount= 1 2015-01-28T00:56:29.834Z,1422406589.834 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1 2015-01-28T00:56:29.834Z,1422406589.834 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:56:29.835Z,1422406589.835 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1 2015-01-28T00:56:29.835Z,1422406589.835 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped 2015-01-28T00:56:29.835Z,1422406589.835 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1 2015-01-28T00:56:30.238Z,1422406590.238 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 37.432523 min 2015-01-28T00:56:30.238Z,1422406590.238 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped 2015-01-28T00:56:30.239Z,1422406590.239 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:56:30.239Z,1422406590.239 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped 2015-01-28T00:56:30.239Z,1422406590.239 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted 2015-01-28T00:56:54.649Z,1422406614.649 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:56:54.649Z,1422406614.649 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2015-01-28T00:56:54.650Z,1422406614.650 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:56:54.660Z,1422406614.660 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:56:55.056Z,1422406615.056 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:56:55.057Z,1422406615.057 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2015-01-28T00:56:55.459Z,1422406615.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:56:55.860Z,1422406615.860 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:56:56.257Z,1422406616.257 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:56:56.657Z,1422406616.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:56:57.102Z,1422406617.102 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:56:57.431Z,1422406617.431 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:56:57.873Z,1422406617.873 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:57:39.271Z,1422406659.271 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-01-28T00:57:39.271Z,1422406659.271 [NAL9602] Data Fault, FailCount= 4 2015-01-28T00:57:39.271Z,1422406659.271 [NAL9602](ERROR): Data Fault 2015-01-28T00:57:39.353Z,1422406659.353 [CBIT](ERROR): Data Fault in component: NAL9602 2015-01-28T00:57:39.354Z,1422406659.354 [Reporter](INFO): NAL9602.sigQuality no_value 2015-01-28T00:57:39.683Z,1422406659.683 [NAL9602](INFO): Stop 2015-01-28T00:57:39.683Z,1422406659.683 [NAL9602](INFO): Uninitialize 2015-01-28T00:57:39.683Z,1422406659.683 [NAL9602](INFO): Powering down 2015-01-28T00:57:40.064Z,1422406660.064 [NAL9602](INFO): Stopping 2015-01-28T00:57:40.493Z,1422406660.493 [CBIT](INFO): Clearing failed state for component NAL9602 2015-01-28T00:57:40.494Z,1422406660.494 [NAL9602] No Fault, FailCount= 4 2015-01-28T00:57:40.873Z,1422406660.873 [NAL9602](INFO): Start 2015-01-28T00:57:41.273Z,1422406661.273 [NAL9602](INFO): Start 2015-01-28T00:57:41.670Z,1422406661.670 [NAL9602](INFO): Start 2015-01-28T00:57:42.067Z,1422406662.067 [NAL9602](INFO): Start 2015-01-28T00:57:42.468Z,1422406662.468 [NAL9602](INFO): Start 2015-01-28T00:57:42.864Z,1422406662.864 [NAL9602](INFO): Start 2015-01-28T00:57:43.269Z,1422406663.269 [NAL9602](INFO): Start 2015-01-28T00:57:43.685Z,1422406663.685 [NAL9602](INFO): Start 2015-01-28T00:57:44.070Z,1422406664.070 [NAL9602](INFO): Start 2015-01-28T00:57:44.768Z,1422406664.768 [NAL9602](INFO): Start 2015-01-28T00:57:44.768Z,1422406664.768 [NAL9602](INFO): Powering up NAL9602 2015-01-28T00:57:54.994Z,1422406674.994 [Reporter](INFO): NAL9602.sigQuality 0 count 2015-01-28T00:57:55.736Z,1422406675.736 [NAL9602](INFO): ************** CMDMODE ************** 2015-01-28T00:57:55.736Z,1422406675.736 [NAL9602](INFO): NAL9602 initialized 2015-01-28T00:58:27.250Z,1422406707.250 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X $S,01,270F,02,00,04,5D%56 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,0A,0000%33 $B12,0A,FFFB%34 $B13,0A,FFFB%35 $B14,0A,FFFB%32 $B15,0A,0000%37 $B16,0A,0000%34 $B17,0A,0000%35 $B18,0A,FFE8%47 $S,01,270F,02,00,04,5D%56 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,02,000A,01,026C,03,0001,08,0B8E,09,3C20,0A,0000,0B,0000%3A $B11,0C,0001,0D,0064,0E,005B,0F,15E2,10,1641,11,FFFF,12,FFFF%41 $B11,13,FFFF,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4F $B11,1A,0031,1B,4357,1C,009D%49 $B12,02,000A,01,026C,03,0001,08,0B94,09,3C48,0A,FFFC,0B,FFFB%46 $B12,0C,0001,0D,0053,0E,0051,0F,1379,10,17B2,11,FFFF,12,E9AC%40 $B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42 $B12,1A,0031,1B,4357,1C,0093%3D $B13,02,000A,01,026C,03,0001,08,0B9B,09,3C48,0A,FFFC,0B,FFFC%30 $B13,0C,0001,0D,005C,0E,004E,0F,12CD,10,16D7,11,FFFF,12,FFFF%30 $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,0B93,09,3C48,0A,FFFC,0B,FFFC%46 $B14,0C,0001,0D,0053,0E,004D,0F,127F,10,168C,11,FFFF,12,FFFF%38 $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,0B95,09,3C12,0A,0000,0B,0000%4E $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,0B90,09,3C19,0A,0000,0B,0000%43 $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,0B94,09,3C15,0A,0000,0B,0000%4A $B17,0C,0001,0D,0064,0E,005F,0F,16DB,10,1701,11,FFFF,12,FFFF%34 $B17,13,FFFF,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4A $B17,1A,0031,1B,4357,1C,00A5%46 $B18,02,000A,01,026C,03,0001,08,0B97,09,3C16,0A,FFE7,0B,FFE8%4A $B18,0C,0001,0D,0058,0E,0050,0F,135A,10,16A5,11,2E72,12,3061%37 $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-28T00:58:27.250Z,1422406707.250 [BPC1](FAULT): Failed to parse bank A battery data 2015-01-28T00:58:27.250Z,1422406707.250 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:58:27.250Z,1422406707.250 [BPC1](ERROR): Data Fault 2015-01-28T00:58:27.267Z,1422406707.267 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:58:28.491Z,1422406708.491 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:58:28.491Z,1422406708.491 [BPC1] No Fault, FailCount= 1 2015-01-28T00:59:25.074Z,1422406765.074 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X $S,01,270F,02,00,04,5E%57 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,0A,FFFC%36 $B12,0A,0000%30 $B13,0A,FFFB%35 $B14,0A,FFFB%32 $B15,0A,0000%37 $B16,0A,0000%34 $B17,0A,0000%35 $B18,0A,FFE7%48 $S,01,270F,02,00,04,5E%57 $C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72 $B11,02,000A,01,026C,03,0001,08,0B95,09,3C51,0A,FFFC,0B,FFFD%4A $B11,0C,0001,0D,005A,0E,0056,0F,14AF,10,1787,11,FFFF,12,FFFF%39 $B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%41 $B11,1A,0031,1B,4357,1C,00A7%42 $B12,02,000A,01,026C,03,0001,08,0B93,09,3C23,0A,0000,0B,0001%4C $B12,0C,0001,0D,0064,0E,0060,0F,170F,10,170F,11,FFFF,12,FFFF%42 $B12,13,0000,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4F $B12,1A,0031,1B,4357,1C,009E%4B $B13,02,000A,01,026C,03,0001,08,0B99,09,3C54,0A,FFFB,0B,FFFD%40 $B13,0C,0001,0D,0060,0E,0054,0F,1454,10,17AC,11,F3F0,12,FFFF%43 $B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43 $B13,1A,0031,1B,4357,1C,0089%37 $B14,02,000A,01,026C,03,0001,08,0B9D,09,3C55,0A,FFFB,0B,FFFC%3C $B14,0C,0001,0D,0059,0E,0054,0F,1437,10,16F6,11,F294,12,FFFF%42 $B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44 $B14,1A,0031,1B,4357,1C,00A6%46 $B15,02,000A,01,026C,03,0001,08,0B97,09,3C14,0A,0000,0B,0001%4B $B15,0C,0001,0D,0064,0E,005C,0F,162F,10,171F,11,FFFF,12,FFFF%37 $B15,13,3840,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%47 $B15,1A,0031,1B,4357,1C,00A9%48 $B16,02,000A,01,026C,03,0001,08,0B91,09,3C59,0A,0000,0B,0000%46 $B16,0C,0001,0D,0061,0E,0057,0F,1501,10,1698,11,FFFF,12,FFFF%44 $B16,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%45 $B16,1A,0031,1B,4357,1C,00A8%4A $B17,02,000A,01,026C,03,0001,08,0B92,09,3C53,0A,0000,0B,0001%4F $B17,0C,0001,0D,005E,0E,0057,0F,14E4,10,16E3,11,FFFF,12,FFFF%34 $B17,13,77C4,14,0BB8,15,41A0,16,00C0,17,0001,18,1838,19,3840%33 $B17,1A,0031,1B,4357,1C,0096%3D $B18,02,000A,01,026C,03,0001,08,0B95,09,3C16,0A,FFE7,0B,FFE6%46 $B18,0C,0001,0D,0058,0E,0055,0F,1468,10,17BE,11,30FA,12,2F17%3D $B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48 $B18,1A,0031,1B,4357,1C,009B%46 2015-01-28T00:59:25.074Z,1422406765.074 [BPC1](FAULT): Failed to parse bank B battery data 2015-01-28T00:59:25.074Z,1422406765.074 [BPC1] Data Fault, FailCount= 1 2015-01-28T00:59:25.074Z,1422406765.074 [BPC1](ERROR): Data Fault 2015-01-28T00:59:25.091Z,1422406765.091 [CBIT](ERROR): Data Fault in component: BPC1 2015-01-28T00:59:26.312Z,1422406766.312 [CBIT](INFO): Clearing failed state for component BPC1 2015-01-28T00:59:26.312Z,1422406766.312 [BPC1] No Fault, FailCount= 1 2015-01-28T00:59:48.318Z,1422406788.318 [CommandLine](IMPORTANT): got command get latitude 2015-01-28T00:59:48.319Z,1422406788.319 [CommandLine](FAULT): Element has no value 2015-01-28T00:59:51.723Z,1422406791.723 [CommandLine](IMPORTANT): got command restart system 2015-01-28T00:59:55.591Z,1422406795.591 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-01-28T00:59:55.591Z,1422406795.591 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2015-01-28T00:59:55.592Z,1422406795.592 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-01-28T00:59:55.603Z,1422406795.603 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-01-28T00:59:55.984Z,1422406795.984 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-01-28T00:59:55.984Z,1422406795.984 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2015-01-28T00:59:56.326Z,1422406796.326 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-01-28T00:59:56.752Z,1422406796.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:57.138Z,1422406797.138 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:57.538Z,1422406797.538 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:57.946Z,1422406797.946 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:58.382Z,1422406798.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:58.750Z,1422406798.750 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles. 2015-01-28T00:59:59.326Z,1422406799.326 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-28T00:59:59.327Z,1422406799.327 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.395Z,1422406799.395 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2015-01-28T00:59:59.395Z,1422406799.395 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.396Z,1422406799.396 [CommandLine](INFO): Join timeout helper Thread ID is 3339 2015-01-28T00:59:59.396Z,1422406799.396 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2015-01-28T00:59:59.397Z,1422406799.397 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.397Z,1422406799.397 [NavChartDb](INFO): Join timeout helper Thread ID is 3340 2015-01-28T00:59:59.640Z,1422406799.640 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-28T00:59:59.640Z,1422406799.640 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.656Z,1422406799.656 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2015-01-28T00:59:59.656Z,1422406799.656 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.656Z,1422406799.656 [Radio_Surface](INFO): Join timeout helper Thread ID is 3341 2015-01-28T00:59:59.884Z,1422406799.884 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-28T00:59:59.884Z,1422406799.884 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.899Z,1422406799.899 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2015-01-28T00:59:59.899Z,1422406799.899 [logger ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.900Z,1422406799.900 [logger](INFO): Join timeout helper Thread ID is 3342 2015-01-28T00:59:59.920Z,1422406799.920 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-28T00:59:59.920Z,1422406799.920 [logger ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.924Z,1422406799.924 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2015-01-28T00:59:59.924Z,1422406799.924 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.924Z,1422406799.924 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2015-01-28T00:59:59.924Z,1422406799.924 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-01-28T00:59:59.925Z,1422406799.925 [controlThread](INFO): Join timeout helper Thread ID is 3343 2015-01-28T00:59:59.950Z,1422406799.950 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2015-01-28T00:59:59.951Z,1422406799.951 [controlThread](DEBUG): Uninitializing ControlThread 2015-01-28T00:59:59.952Z,1422406799.952 [NAL9602](INFO): Uninitialize 2015-01-28T00:59:59.952Z,1422406799.952 [NAL9602](INFO): Powering down 2015-01-28T00:59:59.954Z,1422406799.954 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-01-28T00:59:59.955Z,1422406799.955 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2015-01-28T00:59:59.956Z,1422406799.956 [Default] Stopped 2015-01-28T00:59:59.956Z,1422406799.956 [Default](INFO): Aggregate::uninitialize Default 2015-01-28T00:59:59.956Z,1422406799.956 [Default:B.GoToSurface] Stopped 2015-01-28T00:59:59.956Z,1422406799.956 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-01-28T00:59:59.956Z,1422406799.956 [Default:CheckIn] Stopped 2015-01-28T00:59:59.957Z,1422406799.957 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-01-28T00:59:59.957Z,1422406799.957 [Default:CheckIn:A.SetSpeed] Stopped 2015-01-28T00:59:59.957Z,1422406799.957 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-01-28T00:59:59.957Z,1422406799.957 [Default:CheckIn:Read_GPS] Stopped 2015-01-28T00:59:59.957Z,1422406799.957 [Default:WaitAtTheSurface] Stopped 2015-01-28T00:59:59.957Z,1422406799.957 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2015-01-28T00:59:59.957Z,1422406799.957 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped 2015-01-28T00:59:59.957Z,1422406799.957 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2015-01-28T00:59:59.961Z,1422406799.961 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2015-01-28T00:59:59.961Z,1422406799.961 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2015-01-28T00:59:59.962Z,1422406799.962 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2015-01-28T00:59:59.962Z,1422406799.962 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2015-01-28T00:59:59.962Z,1422406799.962 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2015-01-28T00:59:59.962Z,1422406799.962 [BuoyancyServo](INFO): Powering down 2015-01-28T00:59:59.976Z,1422406799.976 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2015-01-28T00:59:59.976Z,1422406799.976 [ElevatorServo](INFO): Powering down 2015-01-28T00:59:59.977Z,1422406799.977 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2015-01-28T00:59:59.977Z,1422406799.977 [RudderServo](INFO): Powering down 2015-01-28T00:59:59.978Z,1422406799.978 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2015-01-28T00:59:59.978Z,1422406799.978 [ThrusterServo](INFO): Powering down 2015-01-28T00:59:59.979Z,1422406799.979 [SBIT](DEBUG): Uninitialize SBIT Component. 2015-01-28T00:59:59.979Z,1422406799.979 [IBIT](DEBUG): Uninitialize IBIT Component. 2015-01-28T00:59:59.980Z,1422406799.980 [CBIT](DEBUG): Uninitialize CBIT Component. 2015-01-28T01:00:00.013Z,1422406800.013 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-01-28T01:00:00.118Z,1422406800.118 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-01-28T01:00:00.163Z,1422406800.163 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-01-28T01:00:00.212Z,1422406800.212 [logger ThreadHandler](INFO): Thread cancelled.