2014-04-18T22:11:05.014Z,1397859065.014 [Supervisor](DEBUG): Initializing supervisor. 2014-04-18T22:11:05.017Z,1397859065.017 [SyncHandler](DEBUG): Created PCaller Thread at 4033C4E0 2014-04-18T22:11:05.018Z,1397859065.018 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-18T22:11:05.021Z,1397859065.021 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036C4E0 2014-04-18T22:11:05.023Z,1397859065.023 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-18T22:11:05.035Z,1397859065.035 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-18T22:11:05.037Z,1397859065.037 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039C4E0 2014-04-18T22:11:05.038Z,1397859065.038 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-18T22:11:05.041Z,1397859065.041 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CC4E0 2014-04-18T22:11:05.043Z,1397859065.043 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-18T22:11:05.043Z,1397859065.043 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-18T22:11:05.048Z,1397859065.048 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-18T22:11:05.431Z,1397859065.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-18T22:11:05.431Z,1397859065.431 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-18T22:11:05.725Z,1397859065.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-18T22:11:05.726Z,1397859065.726 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-18T22:11:05.821Z,1397859065.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-18T22:11:05.824Z,1397859065.824 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-18T22:11:06.027Z,1397859066.027 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-18T22:11:06.028Z,1397859066.028 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-18T22:11:06.203Z,1397859066.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-18T22:11:06.206Z,1397859066.206 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-18T22:11:06.532Z,1397859066.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-18T22:11:06.533Z,1397859066.533 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-18T22:11:06.732Z,1397859066.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-18T22:11:06.734Z,1397859066.734 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-18T22:11:07.095Z,1397859067.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-18T22:11:07.098Z,1397859067.098 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-18T22:11:07.213Z,1397859067.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-18T22:11:07.214Z,1397859067.214 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-18T22:11:07.746Z,1397859067.746 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-18T22:11:07.747Z,1397859067.747 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-18T22:11:07.862Z,1397859067.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-18T22:11:07.863Z,1397859067.863 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-18T22:11:07.957Z,1397859067.957 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-18T22:11:08.070Z,1397859068.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-18T22:11:08.073Z,1397859068.073 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-18T22:11:08.193Z,1397859068.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-18T22:11:08.194Z,1397859068.194 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-18T22:11:09.553Z,1397859069.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-18T22:11:09.555Z,1397859069.555 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-18T22:11:09.586Z,1397859069.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-18T22:11:09.705Z,1397859069.705 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-18T22:11:09.849Z,1397859069.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-18T22:11:09.958Z,1397859069.958 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-18T22:11:10.062Z,1397859070.062 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-18T22:11:10.234Z,1397859070.234 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-18T22:11:10.366Z,1397859070.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-18T22:11:10.466Z,1397859070.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-18T22:11:10.579Z,1397859070.579 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-18T22:11:10.691Z,1397859070.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2014-04-18T22:11:10.799Z,1397859070.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2014-04-18T22:11:10.899Z,1397859070.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg 2014-04-18T22:11:11.007Z,1397859071.007 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2014-04-18T22:11:11.011Z,1397859071.011 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-18T22:11:11.625Z,1397859071.625 [AHRS_sp3003D] Loaded 2014-04-18T22:11:11.625Z,1397859071.625 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-18T22:11:11.950Z,1397859071.950 [Batt_Ocean_Server] Loaded 2014-04-18T22:11:11.951Z,1397859071.951 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-18T22:11:12.138Z,1397859072.138 [DataOverHttps] Loaded 2014-04-18T22:11:12.138Z,1397859072.138 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2014-04-18T22:11:12.152Z,1397859072.152 [Depth_Keller] Loaded 2014-04-18T22:11:12.152Z,1397859072.152 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-18T22:11:12.157Z,1397859072.157 [DropWeight] Loaded 2014-04-18T22:11:12.157Z,1397859072.157 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-18T22:11:12.314Z,1397859072.314 [DVL_micro] Loaded 2014-04-18T22:11:12.314Z,1397859072.314 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-18T22:11:12.426Z,1397859072.426 [NAL9602] Loaded 2014-04-18T22:11:12.426Z,1397859072.426 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-18T22:11:12.481Z,1397859072.481 [Onboard] Loaded 2014-04-18T22:11:12.482Z,1397859072.482 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-18T22:11:12.489Z,1397859072.489 [Radio_Freewave] Loaded 2014-04-18T22:11:12.489Z,1397859072.489 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-18T22:11:12.496Z,1397859072.496 [SCPI] Loaded 2014-04-18T22:11:12.496Z,1397859072.496 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-18T22:11:12.497Z,1397859072.497 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-18T22:11:12.497Z,1397859072.497 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-18T22:11:12.704Z,1397859072.704 [InternalSim] Loaded 2014-04-18T22:11:12.704Z,1397859072.704 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-18T22:11:12.709Z,1397859072.709 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-18T22:11:12.709Z,1397859072.709 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-18T22:11:13.019Z,1397859073.019 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-18T22:11:13.020Z,1397859073.020 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-18T22:11:13.029Z,1397859073.029 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-18T22:11:13.033Z,1397859073.033 [AsyncPiEstimator] Loaded 2014-04-18T22:11:13.034Z,1397859073.034 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-18T22:11:13.037Z,1397859073.037 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A24E0 2014-04-18T22:11:13.038Z,1397859073.038 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-18T22:11:13.038Z,1397859073.038 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-18T22:11:13.137Z,1397859073.137 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-18T22:11:13.137Z,1397859073.137 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-18T22:11:13.153Z,1397859073.153 [NavChart] Loaded 2014-04-18T22:11:13.154Z,1397859073.154 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-18T22:11:13.158Z,1397859073.158 [UniversalFixResidualReporter] Loaded 2014-04-18T22:11:13.158Z,1397859073.158 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-18T22:11:13.159Z,1397859073.159 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-18T22:11:13.159Z,1397859073.159 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-18T22:11:13.232Z,1397859073.232 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-18T22:11:13.354Z,1397859073.354 [VerticalControl] Loaded 2014-04-18T22:11:13.355Z,1397859073.355 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-18T22:11:13.355Z,1397859073.355 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-18T22:11:13.430Z,1397859073.430 [HorizontalControl] Loaded 2014-04-18T22:11:13.430Z,1397859073.430 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-18T22:11:13.431Z,1397859073.431 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-18T22:11:13.432Z,1397859073.432 [SpeedControl] Loaded 2014-04-18T22:11:13.433Z,1397859073.433 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-18T22:11:13.433Z,1397859073.433 [LoopControl](DEBUG): Construct LoopControl. 2014-04-18T22:11:13.434Z,1397859073.434 [LoopControl] Loaded 2014-04-18T22:11:13.434Z,1397859073.434 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-18T22:11:13.435Z,1397859073.435 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-18T22:11:13.435Z,1397859073.435 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-18T22:11:13.468Z,1397859073.468 [DepthRateCalculator] Loaded 2014-04-18T22:11:13.469Z,1397859073.469 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-18T22:11:13.474Z,1397859073.474 [PitchRateCalculator] Loaded 2014-04-18T22:11:13.475Z,1397859073.475 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-18T22:11:13.482Z,1397859073.482 [SpeedCalculator] Loaded 2014-04-18T22:11:13.482Z,1397859073.482 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-18T22:11:13.499Z,1397859073.499 [TempGradientCalculator] Loaded 2014-04-18T22:11:13.499Z,1397859073.499 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-18T22:11:13.504Z,1397859073.504 [YawRateCalculator] Loaded 2014-04-18T22:11:13.505Z,1397859073.505 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-18T22:11:13.505Z,1397859073.505 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-18T22:11:13.506Z,1397859073.506 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-18T22:11:14.355Z,1397859074.355 [CTD_NeilBrown] Loaded 2014-04-18T22:11:14.356Z,1397859074.356 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-18T22:11:14.359Z,1397859074.359 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407444E0 2014-04-18T22:11:14.372Z,1397859074.372 [ISUS] Loaded 2014-04-18T22:11:14.373Z,1397859074.373 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-18T22:11:14.392Z,1397859074.392 [PAR_Licor] Loaded 2014-04-18T22:11:14.392Z,1397859074.392 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-18T22:11:14.431Z,1397859074.431 [WetLabsBB2FL] Loaded 2014-04-18T22:11:14.432Z,1397859074.432 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-18T22:11:14.435Z,1397859074.435 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407744E0 2014-04-18T22:11:14.436Z,1397859074.436 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-18T22:11:14.438Z,1397859074.438 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-18T22:11:14.563Z,1397859074.563 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-18T22:11:14.579Z,1397859074.579 [SBIT] Loaded 2014-04-18T22:11:14.579Z,1397859074.579 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-18T22:11:14.580Z,1397859074.580 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-18T22:11:14.592Z,1397859074.592 [IBIT] Loaded 2014-04-18T22:11:14.593Z,1397859074.593 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-18T22:11:14.595Z,1397859074.595 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-18T22:11:14.672Z,1397859074.672 [CBIT] Loaded 2014-04-18T22:11:14.672Z,1397859074.672 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-18T22:11:14.672Z,1397859074.672 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-18T22:11:14.675Z,1397859074.675 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-18T22:11:14.749Z,1397859074.749 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-18T22:11:14.750Z,1397859074.750 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-18T22:11:14.880Z,1397859074.880 [BuoyancyServo] Loaded 2014-04-18T22:11:14.880Z,1397859074.880 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-18T22:11:14.896Z,1397859074.896 [ElevatorServo] Loaded 2014-04-18T22:11:14.897Z,1397859074.897 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-18T22:11:14.908Z,1397859074.908 [MassServo] Loaded 2014-04-18T22:11:14.909Z,1397859074.909 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-18T22:11:14.920Z,1397859074.920 [RudderServo] Loaded 2014-04-18T22:11:14.921Z,1397859074.921 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-18T22:11:14.936Z,1397859074.936 [ThrusterServo] Loaded 2014-04-18T22:11:14.937Z,1397859074.937 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-18T22:11:14.937Z,1397859074.937 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-18T22:11:14.938Z,1397859074.938 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-18T22:11:14.980Z,1397859074.980 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-18T22:11:14.982Z,1397859074.982 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-18T22:11:14.983Z,1397859074.983 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-18T22:11:14.989Z,1397859074.989 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-18T22:11:14.992Z,1397859074.992 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408424E0 2014-04-18T22:11:14.997Z,1397859074.997 [Supervisor](DEBUG): Running supervisor. 2014-04-18T22:11:14.998Z,1397859074.998 [CommandLine](INFO): Thread ID is 779 2014-04-18T22:11:15.005Z,1397859075.005 [controlThread](INFO): Thread ID is 778 2014-04-18T22:11:15.005Z,1397859075.005 [controlThread](DEBUG): Initializing ControlThread 2014-04-18T22:11:15.005Z,1397859075.005 [CycleStarter](INFO): Thread ID is 777 2014-04-18T22:11:15.009Z,1397859075.009 [logger](INFO): Thread ID is 780 2014-04-18T22:11:15.045Z,1397859075.045 [AsyncPiEstimator](INFO): Thread ID is 862 2014-04-18T22:11:15.045Z,1397859075.045 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-18T22:11:15.069Z,1397859075.069 [CTD_NeilBrown](INFO): Thread ID is 863 2014-04-18T22:11:15.069Z,1397859075.069 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-18T22:11:15.073Z,1397859075.073 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-18T22:11:15.085Z,1397859075.085 [WetLabsBB2FL](INFO): Thread ID is 864 2014-04-18T22:11:15.086Z,1397859075.086 [WetLabsBB2FL](INFO): Powering down 2014-04-18T22:11:15.105Z,1397859075.105 [NavChartDb](INFO): Thread ID is 865 2014-04-18T22:11:15.118Z,1397859075.118 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-18T22:11:15.125Z,1397859075.125 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-18T22:11:15.125Z,1397859075.125 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-18T22:11:15.125Z,1397859075.125 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-18T22:11:15.126Z,1397859075.126 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-18T22:11:15.126Z,1397859075.126 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-18T22:11:15.126Z,1397859075.126 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-18T22:11:15.126Z,1397859075.126 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-18T22:11:15.127Z,1397859075.127 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-18T22:11:16.876Z,1397859076.876 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-18T22:11:16.906Z,1397859076.906 [InternalSim](DEBUG): InternalSim initializing... 2014-04-18T22:11:17.436Z,1397859077.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-18T22:11:17.437Z,1397859077.437 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-18T22:11:17.437Z,1397859077.437 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-18T22:11:17.437Z,1397859077.437 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-18T22:11:17.439Z,1397859077.439 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-18T22:11:17.440Z,1397859077.440 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-18T22:11:17.440Z,1397859077.440 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-18T22:11:17.441Z,1397859077.441 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-18T22:11:17.441Z,1397859077.441 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-18T22:11:17.441Z,1397859077.441 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-18T22:11:17.442Z,1397859077.442 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-18T22:11:17.442Z,1397859077.442 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-18T22:11:17.448Z,1397859077.448 [SBIT](INFO): Initialize SBIT Component. 2014-04-18T22:11:17.449Z,1397859077.449 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11231 2014-04-18T22:11:17.449Z,1397859077.449 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-18T22:11:17.449Z,1397859077.449 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-18T22:11:17.450Z,1397859077.450 [IBIT](INFO): Initialize IBIT Component. 2014-04-18T22:11:17.451Z,1397859077.451 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-18T22:11:17.451Z,1397859077.451 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-18T22:11:17.478Z,1397859077.478 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-18T22:11:17.503Z,1397859077.503 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T22:11:17.531Z,1397859077.531 [MissionManager](DEBUG): 2014-04-18T22:11:17.532Z,1397859077.532 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-18T22:11:17.621Z,1397859077.621 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-18T22:11:17.623Z,1397859077.623 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-18T22:11:17.642Z,1397859077.642 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T22:11:17.671Z,1397859077.671 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-18T22:11:17.674Z,1397859077.674 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T22:11:17.690Z,1397859077.690 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-18T22:11:17.738Z,1397859077.738 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-18T22:11:17.742Z,1397859077.742 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T22:11:17.766Z,1397859077.766 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-18T22:11:17.785Z,1397859077.785 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2014-04-18T22:11:17.926Z,1397859077.926 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-18T22:11:18.131Z,1397859078.131 [DVL_micro](INFO): Initializing 2014-04-18T22:11:18.155Z,1397859078.155 [NAL9602](INFO): Powering up NAL9602 2014-04-18T22:11:18.249Z,1397859078.249 [Radio_Freewave](INFO): Powering up 2014-04-18T22:11:18.630Z,1397859078.630 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:18.638Z,1397859078.638 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-18T22:11:18.652Z,1397859078.652 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:18.654Z,1397859078.654 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-18T22:11:18.674Z,1397859078.674 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:18.686Z,1397859078.686 [MassServo](DEBUG): Initializing MassServo. 2014-04-18T22:11:18.706Z,1397859078.706 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:18.717Z,1397859078.717 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-18T22:11:18.738Z,1397859078.738 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:18.746Z,1397859078.746 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-18T22:11:19.475Z,1397859079.475 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2014-04-18T22:11:19.475Z,1397859079.475 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2014-04-18T22:11:19.475Z,1397859079.475 [BuoyancyServo] Communications Fault, FailCount= 1 2014-04-18T22:11:19.475Z,1397859079.476 [BuoyancyServo](ERROR): Communications Fault 2014-04-18T22:11:19.766Z,1397859079.766 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2014-04-18T22:11:21.713Z,1397859081.713 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-18T22:11:21.817Z,1397859081.817 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-18T22:11:21.818Z,1397859081.818 [BuoyancyServo](INFO): Powering down 2014-04-18T22:11:23.881Z,1397859083.881 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003406 2014-04-18T22:11:24.065Z,1397859084.065 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2014-04-18T22:11:24.065Z,1397859084.065 [BuoyancyServo] No Fault, FailCount= 1 2014-04-18T22:11:24.464Z,1397859084.464 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-18T22:11:24.464Z,1397859084.464 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-18T22:11:28.762Z,1397859088.762 [NAL9602](INFO): NAL9602 initialized 2014-04-18T22:11:33.352Z,1397859093.352 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-18T22:11:33.355Z,1397859093.355 [CBIT](IMPORTANT): Beginning GF scan 2014-04-18T22:11:51.764Z,1397859111.764 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=26708, MT Status=1, MTMSN=1772 2014-04-18T22:11:51.765Z,1397859111.765 [NAL9602](INFO): Data available in MT queue 2014-04-18T22:11:52.793Z,1397859112.793 [NAL9602](IMPORTANT): Initialized file: Config/lrauv-daphne/Sensor.cfg 2014-04-18T22:11:52.795Z,1397859112.795 [NAL9602](IMPORTANT): Executing cat Logs/latest/53519C76.part | gunzip -f -d | cat `cp Config/lrauv-daphne/.svn/text-base/Sensor.cfg.svn-base Config/lrauv-daphne/Sensor.cfg` | patch Config/lrauv-daphne/Sensor.cfg 2014-04-18T22:11:53.468Z,1397859113.468 [CommandLine](IMPORTANT): missing header for unified diff at line 3 of patch patching file Config/lrauv-daphne/Sensor.cfg 2014-04-18T22:11:53.809Z,1397859113.809 [CommandLine](IMPORTANT): 927afd7d58000cdf4628b98cf9a7e511 Config/lrauv-daphne/Sensor.cfg 2014-04-18T22:11:59.465Z,1397859119.465 [NAL9602](IMPORTANT): GPS fix at: 1397859117.00 2014-04-18T22:12:00.652Z,1397859120.652 [CBIT](IMPORTANT): No ground fault detected 2014-04-18T22:12:07.219Z,1397859127.219 [NAL9602](INFO): Powering down 2014-04-18T22:12:27.612Z,1397859147.612 [SBIT](IMPORTANT): SBIT PASSED 2014-04-18T22:12:27.988Z,1397859147.988 [MissionManager](IMPORTANT): Started mission Startup 2014-04-18T22:12:27.988Z,1397859147.988 [Startup] Running Loop=1 2014-04-18T22:12:27.988Z,1397859147.988 [Startup](INFO): Aggregate::initialize Startup 2014-04-18T22:12:27.988Z,1397859147.988 [Startup:A.GoToSurface] Running Loop=1 2014-04-18T22:12:27.988Z,1397859147.988 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T22:12:28.015Z,1397859148.015 [Startup:StartupSatComms] Running Loop=1 2014-04-18T22:12:28.015Z,1397859148.015 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-18T22:12:28.015Z,1397859148.015 [Startup:StartupSatComms:A] Running Loop=1 2014-04-18T22:12:28.436Z,1397859148.436 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-18T22:12:28.923Z,1397859148.923 [NAL9602](INFO): Powering up 2014-04-18T22:12:39.496Z,1397859159.496 [NAL9602](INFO): NAL9602 initialized 2014-04-18T22:12:57.479Z,1397859177.479 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=26709, MT Status=1, MTMSN=1773 2014-04-18T22:12:57.479Z,1397859177.479 [NAL9602](INFO): Data available in MT queue 2014-04-18T22:12:58.396Z,1397859178.396 [NAL9602](IMPORTANT): Initialized file: Config/logger.cfg 2014-04-18T22:12:58.397Z,1397859178.397 [NAL9602](IMPORTANT): More data left to go, at position 91 2014-04-18T22:13:05.822Z,1397859185.822 [NAL9602](IMPORTANT): GPS fix at: 1397859184.00 2014-04-18T22:13:05.839Z,1397859185.839 [Startup:StartupSatComms:A] Stopped 2014-04-18T22:13:05.839Z,1397859185.839 [Startup:StartupSatComms:B] Running Loop=1 2014-04-18T22:13:06.290Z,1397859186.290 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-18T22:13:09.459Z,1397859189.459 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20140418T212550/Courier0016.lzma 2014-04-18T22:13:10.411Z,1397859190.411 [DataOverHttps](INFO): Moved sent file to Logs/20140418T212550/Courier0016.lzma.bak 2014-04-18T22:13:10.411Z,1397859190.411 [DataOverHttps](INFO): SBD MOMSN=787485 2014-04-18T22:13:14.053Z,1397859194.053 [NAL9602](INFO): Powering down 2014-04-18T22:13:16.463Z,1397859196.463 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20140418T221104/Courier0000.lzma 2014-04-18T22:13:17.314Z,1397859197.314 [DataOverHttps](INFO): Moved sent file to Logs/20140418T221104/Courier0000.lzma.bak 2014-04-18T22:13:17.314Z,1397859197.314 [DataOverHttps](INFO): SBD MOMSN=787487 2014-04-18T22:13:22.756Z,1397859202.756 [DataOverHttps](INFO): Sending 385 bytes from file Logs/20140418T212550/Express0017.lzma 2014-04-18T22:13:23.612Z,1397859203.612 [DataOverHttps](INFO): Moved sent file to Logs/20140418T212550/Express0017.lzma.bak 2014-04-18T22:13:23.612Z,1397859203.612 [DataOverHttps](INFO): SBD MOMSN=787491 2014-04-18T22:13:29.021Z,1397859209.021 [DataOverHttps](INFO): Sending 1026 bytes from file Logs/20140418T221104/Express0001.lzma 2014-04-18T22:13:29.857Z,1397859209.857 [DataOverHttps](INFO): Moved sent file to Logs/20140418T221104/Express0001.lzma.bak 2014-04-18T22:13:29.857Z,1397859209.857 [DataOverHttps](INFO): SBD MOMSN=787499 2014-04-18T22:13:30.431Z,1397859210.431 [Startup:StartupSatComms:B] Stopped 2014-04-18T22:13:30.432Z,1397859210.432 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-18T22:13:30.432Z,1397859210.432 [Startup:StartupSatComms] Stopped 2014-04-18T22:13:30.432Z,1397859210.432 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-18T22:13:30.433Z,1397859210.433 [Startup](INFO): Completed Startup 2014-04-18T22:13:30.433Z,1397859210.433 [Startup] Stopped 2014-04-18T22:13:30.433Z,1397859210.433 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-18T22:13:30.433Z,1397859210.433 [Startup:A.GoToSurface] Stopped 2014-04-18T22:13:30.433Z,1397859210.433 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T22:13:30.886Z,1397859210.886 [MissionManager](IMPORTANT): Started mission Default 2014-04-18T22:13:30.886Z,1397859210.886 [Default] Running Loop=1 2014-04-18T22:13:30.886Z,1397859210.886 [Default](INFO): Aggregate::initialize Default 2014-04-18T22:13:30.886Z,1397859210.886 [Default:Iridium] Running Loop=1 2014-04-18T22:13:30.886Z,1397859210.886 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-18T22:13:30.887Z,1397859210.887 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-18T22:13:30.887Z,1397859210.887 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-18T22:13:30.887Z,1397859210.887 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-18T22:13:30.887Z,1397859210.887 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T22:13:30.893Z,1397859210.893 [Default:Iridium:B.GoToSurface] Stopped 2014-04-18T22:13:30.893Z,1397859210.893 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T22:13:30.893Z,1397859210.893 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-18T22:13:30.894Z,1397859210.894 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-18T22:13:30.915Z,1397859210.915 [Default:GPS] Running Loop=1 2014-04-18T22:13:30.915Z,1397859210.915 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-18T22:13:30.915Z,1397859210.915 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-18T22:13:30.915Z,1397859210.915 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-18T22:13:30.915Z,1397859210.915 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-18T22:13:30.916Z,1397859210.916 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T22:13:30.922Z,1397859210.922 [Default:GPS:B.GoToSurface] Stopped 2014-04-18T22:13:30.922Z,1397859210.922 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T22:13:30.922Z,1397859210.922 [Default:GPS:Read_GPS] Running Loop=1 2014-04-18T22:13:30.922Z,1397859210.922 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-18T22:13:32.029Z,1397859212.029 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-18T22:13:32.031Z,1397859212.031 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-18T22:13:32.700Z,1397859212.700 [NAL9602](INFO): Powering up 2014-04-18T22:13:35.859Z,1397859215.859 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140418T221104/Courier0004.lzma 2014-04-18T22:13:36.680Z,1397859216.680 [DataOverHttps](INFO): Moved sent file to Logs/20140418T221104/Courier0004.lzma.bak 2014-04-18T22:13:36.680Z,1397859216.680 [DataOverHttps](INFO): SBD MOMSN=787522 2014-04-18T22:13:42.083Z,1397859222.083 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20140418T221104/Express0005.lzma 2014-04-18T22:13:42.913Z,1397859222.913 [DataOverHttps](INFO): Moved sent file to Logs/20140418T221104/Express0005.lzma.bak 2014-04-18T22:13:42.914Z,1397859222.914 [DataOverHttps](INFO): SBD MOMSN=787524 2014-04-18T22:13:43.379Z,1397859223.379 [NAL9602](INFO): NAL9602 initialized 2014-04-18T22:13:43.412Z,1397859223.412 [Default:Iridium:Read_Iridium] Stopped 2014-04-18T22:13:43.413Z,1397859223.413 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-18T22:13:43.413Z,1397859223.413 [Default:Iridium] Stopped 2014-04-18T22:13:43.413Z,1397859223.413 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-18T22:13:43.413Z,1397859223.413 [Default:Iridium:A.SetSpeed] Stopped 2014-04-18T22:13:43.413Z,1397859223.413 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface] Running Loop=1 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-18T22:13:43.414Z,1397859223.414 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T22:13:43.822Z,1397859223.822 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-18T22:13:43.844Z,1397859223.844 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-18T22:14:10.831Z,1397859250.831 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=26710, MT Status=1, MTMSN=1774 2014-04-18T22:14:10.831Z,1397859250.831 [NAL9602](INFO): Data available in MT queue 2014-04-18T22:14:11.749Z,1397859251.749 [NAL9602](IMPORTANT): Added data to file: Config/logger.cfg 2014-04-18T22:14:11.750Z,1397859251.750 [NAL9602](IMPORTANT): More data left to go, at position 18A 2014-04-18T22:14:13.063Z,1397859253.063 [NAL9602](IMPORTANT): GPS fix at: 1397859251.00 2014-04-18T22:14:13.116Z,1397859253.116 [Default:GPS:Read_GPS] Stopped 2014-04-18T22:14:13.116Z,1397859253.116 [Default:GPS:D] Running Loop=1 2014-04-18T22:14:13.525Z,1397859253.525 [Default:GPS:D] Stopped 2014-04-18T22:14:13.526Z,1397859253.526 [Default:GPS](INFO): Completed Default:GPS 2014-04-18T22:14:13.526Z,1397859253.526 [Default:GPS] Stopped 2014-04-18T22:14:13.526Z,1397859253.526 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-18T22:14:13.526Z,1397859253.526 [Default:GPS:A.SetSpeed] Stopped 2014-04-18T22:14:13.526Z,1397859253.526 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T22:14:29.080Z,1397859269.080 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-18T22:14:29.080Z,1397859269.080 [DVL_micro] Data Fault, FailCount= 1 2014-04-18T22:14:29.080Z,1397859269.080 [DVL_micro](ERROR): Data Fault 2014-04-18T22:14:29.109Z,1397859269.109 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-18T22:14:34.092Z,1397859274.092 [DVL_micro](INFO): uninitialize:Powering down 2014-04-18T22:14:34.094Z,1397859274.094 [NAL9602](INFO): Powering down 2014-04-18T22:14:39.055Z,1397859279.055 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-18T22:14:39.056Z,1397859279.056 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-18T22:14:39.056Z,1397859279.056 [DVL_micro](ERROR): Hardware Fault 2014-04-18T22:14:44.122Z,1397859284.122 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-18T22:14:44.122Z,1397859284.122 [DVL_micro] No Fault, FailCount= 1 2014-04-18T22:14:49.068Z,1397859289.068 [DVL_micro](INFO): Initializing 2014-04-18T22:15:26.972Z,1397859326.972 [CommandLine](IMPORTANT): got command ibit 2014-04-18T22:15:29.142Z,1397859329.142 [IBIT](IMPORTANT): Beginning Initiated BIT 2014-04-18T22:15:29.142Z,1397859329.142 [IBIT](IMPORTANT): Beginning control surface checks. 2014-04-18T22:15:29.156Z,1397859329.156 [CBIT](IMPORTANT): Beginning GF scan 2014-04-18T22:15:34.081Z,1397859334.081 [NAL9602](INFO): Powering up 2014-04-18T22:15:45.031Z,1397859345.031 [NAL9602](INFO): NAL9602 initialized 2014-04-18T22:15:56.199Z,1397859356.199 [CBIT](IMPORTANT): No ground fault detected 2014-04-18T22:16:02.757Z,1397859362.757 [CommandLine](IMPORTANT): got command burn 300.000000 2014-04-18T22:16:03.867Z,1397859363.867 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=26711, MT Status=1, MTMSN=1775 2014-04-18T22:16:03.867Z,1397859363.867 [NAL9602](INFO): Data available in MT queue 2014-04-18T22:16:04.736Z,1397859364.736 [NAL9602](IMPORTANT): Added data to file: Config/logger.cfg 2014-04-18T22:16:04.737Z,1397859364.737 [NAL9602](IMPORTANT): More data left to go, at position 283 2014-04-18T22:16:06.189Z,1397859366.189 [NAL9602](IMPORTANT): GPS fix at: 1397859364.00 2014-04-18T22:16:08.900Z,1397859368.900 [NAL9602](IMPORTANT): GPS fix at: 1397859367.00 2014-04-18T22:16:11.967Z,1397859371.967 [NAL9602](IMPORTANT): GPS fix at: 1397859370.00 2014-04-18T22:16:15.043Z,1397859375.043 [NAL9602](IMPORTANT): GPS fix at: 1397859373.00 2014-04-18T22:16:15.127Z,1397859375.127 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 33.616573 Longitude: -117.917770 2014-04-18T22:16:15.599Z,1397859375.599 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 230.730011 Voltage: 16.093063 2014-04-18T22:16:15.599Z,1397859375.599 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2014-04-18T22:16:15.599Z,1397859375.599 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.500000 V 2014-04-18T22:16:16.071Z,1397859376.071 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2014-04-18T22:16:16.071Z,1397859376.071 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2014-04-18T22:16:16.071Z,1397859376.071 [IBIT](IMPORTANT): Pressure:11.265132 PSI 2014-04-18T22:16:16.072Z,1397859376.072 [IBIT](IMPORTANT): Humidity:9.758848 % 2014-04-18T22:16:16.486Z,1397859376.486 [IBIT](IMPORTANT): surfaceThreshold: 0.500000 m 2014-04-18T22:16:16.486Z,1397859376.486 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc 2014-04-18T22:16:16.486Z,1397859376.486 [IBIT](IMPORTANT): massDefault: 0.000000 cm 2014-04-18T22:16:16.487Z,1397859376.487 [IBIT](IMPORTANT): stopDepth: 112.000000 m 2014-04-18T22:16:16.487Z,1397859376.487 [IBIT](IMPORTANT): abortDepth: 130.000000 m 2014-04-18T22:16:16.487Z,1397859376.487 [IBIT](IMPORTANT): IBIT PASSED 2014-04-18T22:16:27.011Z,1397859387.011 [NAL9602](INFO): Powering down 2014-04-18T22:17:01.940Z,1397859421.940 [CommandLine](IMPORTANT): got command burn off 2014-04-18T22:17:01.940Z,1397859421.940 [CommandLine](IMPORTANT): Deactivating dropweight wire 2014-04-18T22:18:12.042Z,1397859492.042 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-18T22:18