2013-09-14T23:42:20.909Z,1379202140.909 [Supervisor](DEBUG): Initializing supervisor.
2013-09-14T23:42:20.912Z,1379202140.912 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-09-14T23:42:20.913Z,1379202140.913 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-09-14T23:42:20.916Z,1379202140.916 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-09-14T23:42:20.920Z,1379202140.920 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-09-14T23:42:20.932Z,1379202140.932 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-09-14T23:42:20.936Z,1379202140.936 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-09-14T23:42:20.937Z,1379202140.937 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-09-14T23:42:20.940Z,1379202140.940 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-09-14T23:42:20.941Z,1379202140.941 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-09-14T23:42:20.945Z,1379202140.945 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-09-14T23:42:21.278Z,1379202141.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-09-14T23:42:21.279Z,1379202141.279 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-09-14T23:42:21.502Z,1379202141.502 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-09-14T23:42:21.503Z,1379202141.503 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-09-14T23:42:21.601Z,1379202141.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-09-14T23:42:21.603Z,1379202141.603 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-09-14T23:42:21.734Z,1379202141.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-09-14T23:42:21.735Z,1379202141.735 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-09-14T23:42:21.895Z,1379202141.895 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-09-14T23:42:21.897Z,1379202141.897 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-09-14T23:42:22.174Z,1379202142.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-09-14T23:42:22.175Z,1379202142.175 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-09-14T23:42:22.363Z,1379202142.363 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-09-14T23:42:22.366Z,1379202142.366 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-09-14T23:42:22.677Z,1379202142.677 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-09-14T23:42:22.679Z,1379202142.679 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-09-14T23:42:22.796Z,1379202142.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-09-14T23:42:22.797Z,1379202142.797 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-09-14T23:42:23.286Z,1379202143.286 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-09-14T23:42:23.286Z,1379202143.286 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-09-14T23:42:23.405Z,1379202143.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-09-14T23:42:23.406Z,1379202143.406 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-09-14T23:42:23.506Z,1379202143.506 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-09-14T23:42:23.509Z,1379202143.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-09-14T23:42:23.622Z,1379202143.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-09-14T23:42:23.770Z,1379202143.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-09-14T23:42:23.878Z,1379202143.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-09-14T23:42:23.998Z,1379202143.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-09-14T23:42:24.107Z,1379202144.107 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-09-14T23:42:24.241Z,1379202144.241 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-09-14T23:42:24.351Z,1379202144.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-09-14T23:42:24.449Z,1379202144.449 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-09-14T23:42:24.454Z,1379202144.454 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-09-14T23:42:24.695Z,1379202144.695 [InternalSim] Loaded
2013-09-14T23:42:24.695Z,1379202144.695 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-09-14T23:42:24.696Z,1379202144.696 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-09-14T23:42:24.697Z,1379202144.697 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-09-14T23:42:24.912Z,1379202144.912 [SBIT](DEBUG): Construct Startup Built In Test.
2013-09-14T23:42:24.943Z,1379202144.943 [SBIT] Loaded
2013-09-14T23:42:24.943Z,1379202144.943 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-09-14T23:42:24.944Z,1379202144.944 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-09-14T23:42:24.979Z,1379202144.979 [IBIT] Loaded
2013-09-14T23:42:24.979Z,1379202144.979 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-09-14T23:42:24.981Z,1379202144.981 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-09-14T23:42:25.120Z,1379202145.120 [CBIT] Loaded
2013-09-14T23:42:25.120Z,1379202145.120 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-09-14T23:42:25.121Z,1379202145.121 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-09-14T23:42:25.122Z,1379202145.122 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-09-14T23:42:25.334Z,1379202145.334 [BuoyancyServo] Loaded
2013-09-14T23:42:25.334Z,1379202145.334 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-09-14T23:42:25.346Z,1379202145.346 [ElevatorServo] Loaded
2013-09-14T23:42:25.346Z,1379202145.346 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-09-14T23:42:25.362Z,1379202145.362 [MassServo] Loaded
2013-09-14T23:42:25.362Z,1379202145.362 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-09-14T23:42:25.374Z,1379202145.374 [RudderServo] Loaded
2013-09-14T23:42:25.375Z,1379202145.375 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-09-14T23:42:25.386Z,1379202145.386 [ThrusterServo] Loaded
2013-09-14T23:42:25.386Z,1379202145.386 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-09-14T23:42:25.387Z,1379202145.387 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-09-14T23:42:25.388Z,1379202145.388 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-09-14T23:42:25.452Z,1379202145.452 [DepthRateCalculator] Loaded
2013-09-14T23:42:25.452Z,1379202145.452 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-09-14T23:42:29.443Z,1379202149.443 [HFRadarModelCalc] Loaded
2013-09-14T23:42:29.444Z,1379202149.444 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-09-14T23:42:29.461Z,1379202149.461 [NavChart] Loaded
2013-09-14T23:42:29.461Z,1379202149.461 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-09-14T23:42:29.467Z,1379202149.467 [PitchRateCalculator] Loaded
2013-09-14T23:42:29.467Z,1379202149.467 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-09-14T23:42:29.483Z,1379202149.483 [SpeedCalculator] Loaded
2013-09-14T23:42:29.483Z,1379202149.483 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-09-14T23:42:29.501Z,1379202149.501 [TempGradientCalculator] Loaded
2013-09-14T23:42:29.501Z,1379202149.501 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-09-14T23:42:29.507Z,1379202149.507 [YawRateCalculator] Loaded
2013-09-14T23:42:29.507Z,1379202149.507 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-09-14T23:42:29.561Z,1379202149.561 [Navigation] Loaded
2013-09-14T23:42:29.561Z,1379202149.561 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-09-14T23:42:29.561Z,1379202149.561 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-09-14T23:42:29.566Z,1379202149.566 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-09-14T23:42:29.902Z,1379202149.902 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-09-14T23:42:29.903Z,1379202149.903 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-09-14T23:42:29.952Z,1379202149.952 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-09-14T23:42:29.953Z,1379202149.953 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-09-14T23:42:30.037Z,1379202150.037 [VerticalControl](DEBUG): Construct VerticalControl.
2013-09-14T23:42:30.144Z,1379202150.144 [VerticalControl] Loaded
2013-09-14T23:42:30.145Z,1379202150.145 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-09-14T23:42:30.145Z,1379202150.145 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-09-14T23:42:30.215Z,1379202150.215 [HorizontalControl] Loaded
2013-09-14T23:42:30.215Z,1379202150.215 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-09-14T23:42:30.216Z,1379202150.216 [SpeedControl](DEBUG): Construct SpeedControl.
2013-09-14T23:42:30.218Z,1379202150.218 [SpeedControl] Loaded
2013-09-14T23:42:30.218Z,1379202150.218 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-09-14T23:42:30.223Z,1379202150.223 [LoopControl](DEBUG): Construct LoopControl.
2013-09-14T23:42:30.224Z,1379202150.224 [LoopControl] Loaded
2013-09-14T23:42:30.224Z,1379202150.224 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-09-14T23:42:30.224Z,1379202150.224 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-09-14T23:42:30.225Z,1379202150.225 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-09-14T23:42:30.234Z,1379202150.234 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-09-14T23:42:30.239Z,1379202150.239 [AsyncPiEstimator] Loaded
2013-09-14T23:42:30.239Z,1379202150.239 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-09-14T23:42:30.243Z,1379202150.243 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0
2013-09-14T23:42:30.244Z,1379202150.244 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-09-14T23:42:30.244Z,1379202150.244 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-09-14T23:42:30.525Z,1379202150.525 [AHRS_sp3003D] Loaded
2013-09-14T23:42:30.525Z,1379202150.525 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-09-14T23:42:30.825Z,1379202150.825 [Batt_Ocean_Server] Loaded
2013-09-14T23:42:30.825Z,1379202150.825 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-09-14T23:42:30.839Z,1379202150.839 [Depth_Keller] Loaded
2013-09-14T23:42:30.840Z,1379202150.840 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-09-14T23:42:30.845Z,1379202150.845 [DropWeight] Loaded
2013-09-14T23:42:30.845Z,1379202150.845 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-09-14T23:42:31.062Z,1379202151.062 [DVL_micro] Loaded
2013-09-14T23:42:31.062Z,1379202151.062 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-09-14T23:42:31.064Z,1379202151.064 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D54E0
2013-09-14T23:42:31.167Z,1379202151.167 [NAL9602] Loaded
2013-09-14T23:42:31.167Z,1379202151.167 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-09-14T23:42:31.221Z,1379202151.221 [Onboard] Loaded
2013-09-14T23:42:31.221Z,1379202151.221 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-09-14T23:42:31.229Z,1379202151.229 [Radio_Freewave] Loaded
2013-09-14T23:42:31.229Z,1379202151.229 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-09-14T23:42:31.395Z,1379202151.395 [DAT] Loaded
2013-09-14T23:42:31.395Z,1379202151.395 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-09-14T23:42:31.396Z,1379202151.396 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-09-14T23:42:31.397Z,1379202151.397 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-09-14T23:42:31.493Z,1379202151.493 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-09-14T23:42:31.496Z,1379202151.496 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-09-14T23:42:31.497Z,1379202151.497 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-09-14T23:42:31.510Z,1379202151.510 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-09-14T23:42:31.513Z,1379202151.513 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407324E0
2013-09-14T23:42:31.517Z,1379202151.517 [Supervisor](DEBUG): Running supervisor.
2013-09-14T23:42:31.518Z,1379202151.518 [CommandLine](INFO): Thread ID is 760
2013-09-14T23:42:31.522Z,1379202151.522 [controlThread](INFO): Thread ID is 759
2013-09-14T23:42:31.522Z,1379202151.522 [controlThread](DEBUG): Initializing ControlThread
2013-09-14T23:42:31.522Z,1379202151.522 [CycleStarter](INFO): Thread ID is 758
2013-09-14T23:42:31.523Z,1379202151.523 [InternalSim](DEBUG):  InternalSim initializing...
2013-09-14T23:42:31.599Z,1379202151.599 [logger](INFO): Thread ID is 761
2013-09-14T23:42:31.662Z,1379202151.662 [AsyncPiEstimator](INFO): Thread ID is 822
2013-09-14T23:42:31.662Z,1379202151.662 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-09-14T23:42:31.673Z,1379202151.673 [SBIT](INFO): Initialize SBIT Component.
2013-09-14T23:42:31.673Z,1379202151.673 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:10573
2013-09-14T23:42:31.673Z,1379202151.673 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-09-14T23:42:31.674Z,1379202151.674 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-09-14T23:42:31.675Z,1379202151.675 [DVL_micro](INFO): Thread ID is 823
2013-09-14T23:42:31.693Z,1379202151.693 [DVL_micro](INFO): Initializing
2013-09-14T23:42:31.693Z,1379202151.693 [DVL_micro](INFO): start:Powering up
2013-09-14T23:42:31.695Z,1379202151.695 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:31.695Z,1379202151.695 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:42:31.697Z,1379202151.697 [IBIT](INFO): Initialize IBIT Component.
2013-09-14T23:42:31.698Z,1379202151.698 [CBIT](DEBUG): Initialize CBIT Component.
2013-09-14T23:42:31.698Z,1379202151.698 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-09-14T23:42:31.699Z,1379202151.699 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-09-14T23:42:31.723Z,1379202151.723 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-09-14T23:42:31.723Z,1379202151.723 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-09-14T23:42:31.724Z,1379202151.724 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-09-14T23:42:31.724Z,1379202151.724 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-09-14T23:42:31.724Z,1379202151.724 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-09-14T23:42:31.725Z,1379202151.725 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-09-14T23:42:31.725Z,1379202151.725 [Navigation](DEBUG): Initializing Navigation.
2013-09-14T23:42:31.726Z,1379202151.726 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-09-14T23:42:31.728Z,1379202151.728 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-09-14T23:42:31.728Z,1379202151.728 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-09-14T23:42:31.729Z,1379202151.729 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-09-14T23:42:31.734Z,1379202151.734 [NavChartDb](INFO): Thread ID is 824
2013-09-14T23:42:31.744Z,1379202151.744 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-09-14T23:42:31.744Z,1379202151.744 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-09-14T23:42:31.745Z,1379202151.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-09-14T23:42:31.745Z,1379202151.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-09-14T23:42:31.745Z,1379202151.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-09-14T23:42:31.746Z,1379202151.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-09-14T23:42:31.746Z,1379202151.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-09-14T23:42:31.746Z,1379202151.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-09-14T23:42:31.746Z,1379202151.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-09-14T23:42:33.785Z,1379202153.785 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:33.785Z,1379202153.785 [DVL_micro](INFO): Querying output modes
2013-09-14T23:42:33.785Z,1379202153.785 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:42:35.796Z,1379202155.796 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:35.796Z,1379202155.796 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:42:35.796Z,1379202155.796 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:42:37.799Z,1379202157.799 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:37.820Z,1379202157.820 [DVL_micro](INFO): pause:Powering down
2013-09-14T23:42:38.320Z,1379202158.320 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-09-14T23:42:38.320Z,1379202158.320 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-09-14T23:42:38.320Z,1379202158.320 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2013-09-14T23:42:38.320Z,1379202158.320 [Batt_Ocean_Server](ERROR): Communications Fault
2013-09-14T23:42:38.338Z,1379202158.338 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-09-14T23:42:38.379Z,1379202158.379 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T23:42:38.401Z,1379202158.401 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2013-09-14T23:42:38.402Z,1379202158.402 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-09-14T23:42:38.467Z,1379202158.467 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-09-14T23:42:38.481Z,1379202158.481 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-09-14T23:42:38.484Z,1379202158.484 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T23:42:38.529Z,1379202158.529 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-09-14T23:42:38.547Z,1379202158.547 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T23:42:38.566Z,1379202158.566 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-09-14T23:42:38.574Z,1379202158.574 [Default:D.SetSpeed](DEBUG): Construct.
2013-09-14T23:42:38.586Z,1379202158.586 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T23:42:38.591Z,1379202158.591 [Default:F.Wait](DEBUG): Construct Wait.
2013-09-14T23:42:38.595Z,1379202158.595 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="Sequence">
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="CallIridium" >

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

        <Assign><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

    <Guidance:SetSpeed RunIn="Parallel">
        <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
    </Guidance:SetSpeed>

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-09-14T23:42:38.628Z,1379202158.628 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-09-14T23:42:38.672Z,1379202158.672 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:42:38.841Z,1379202158.841 [NAL9602](INFO): Powering up NAL9602
2013-09-14T23:42:38.972Z,1379202158.972 [DAT](INFO): Powering up
2013-09-14T23:42:38.973Z,1379202158.973 [DAT](DEBUG): Initializing DAT.
2013-09-14T23:42:39.185Z,1379202159.185 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:42:39.193Z,1379202159.193 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-09-14T23:42:39.200Z,1379202159.200 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:42:39.229Z,1379202159.229 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-14T23:42:39.235Z,1379202159.235 [MassServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:42:39.241Z,1379202159.241 [MassServo](DEBUG): Initializing MassServo.
2013-09-14T23:42:39.259Z,1379202159.259 [RudderServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:42:39.265Z,1379202159.265 [RudderServo](DEBUG): Initializing RudderServo.
2013-09-14T23:42:39.271Z,1379202159.271 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:42:39.277Z,1379202159.277 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-09-14T23:42:39.342Z,1379202159.342 [CBIT](FAULT): Main Battery Failure. Count: 1
2013-09-14T23:42:39.343Z,1379202159.343 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-09-14T23:42:39.343Z,1379202159.343 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2013-09-14T23:42:39.343Z,1379202159.343 [Batt_Ocean_Server] No Fault, FailCount= 1
2013-09-14T23:42:39.774Z,1379202159.774 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:42:39.774Z,1379202159.774 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:42:39.774Z,1379202159.774 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-14T23:42:39.774Z,1379202159.774 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:42:39.826Z,1379202159.826 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:42:39.827Z,1379202159.827 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:39.827Z,1379202159.827 [DVL_micro](INFO): resume:Powering up
2013-09-14T23:42:39.827Z,1379202159.827 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:42:41.837Z,1379202161.837 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:41.837Z,1379202161.837 [DVL_micro](INFO): Querying output modes
2013-09-14T23:42:41.838Z,1379202161.838 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:42:43.848Z,1379202163.848 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:43.848Z,1379202163.848 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:42:43.848Z,1379202163.848 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:42:45.859Z,1379202165.859 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:45.861Z,1379202165.861 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:42:45.861Z,1379202165.861 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:42:46.352Z,1379202166.352 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-09-14T23:42:46.352Z,1379202166.352 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-09-14T23:42:46.352Z,1379202166.352 [Batt_Ocean_Server] Communications Fault, FailCount= 2
2013-09-14T23:42:46.352Z,1379202166.352 [Batt_Ocean_Server](ERROR): Communications Fault
2013-09-14T23:42:46.718Z,1379202166.718 [CBIT](CRITICAL): ABORT DEPTH REACHED. ACTIVATING BURNWIRE.

2013-09-14T23:42:46.728Z,1379202166.728 [CBIT](CRITICAL): STOP DEPTH REACHED. Terminating Mission.

2013-09-14T23:42:46.729Z,1379202166.729 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:42:46.729Z,1379202166.729 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-09-14T23:42:46.924Z,1379202166.924 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:42:47.069Z,1379202167.069 [SBIT](IMPORTANT): Beginning Startup BIT
2013-09-14T23:42:47.071Z,1379202167.071 [CommandLine](FAULT): Scheduling is paused
2013-09-14T23:42:47.072Z,1379202167.072 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2013-09-14T23:42:47.072Z,1379202167.072 [Batt_Ocean_Server] No Fault, FailCount= 2
2013-09-14T23:42:47.072Z,1379202167.072 [CBIT](IMPORTANT): Beginning GF scan
2013-09-14T23:42:47.867Z,1379202167.867 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:47.867Z,1379202167.867 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:42:49.878Z,1379202169.878 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:49.878Z,1379202169.878 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:42:49.878Z,1379202169.878 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:42:51.896Z,1379202171.896 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:51.896Z,1379202171.896 [DVL_micro](INFO): Querying output modes
2013-09-14T23:42:51.897Z,1379202171.897 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:42:53.727Z,1379202173.727 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-09-14T23:42:53.728Z,1379202173.728 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-09-14T23:42:53.728Z,1379202173.728 [Batt_Ocean_Server] Communications Fault, FailCount= 3
2013-09-14T23:42:53.728Z,1379202173.728 [Batt_Ocean_Server](ERROR): Communications Fault
2013-09-14T23:42:53.794Z,1379202173.794 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-09-14T23:42:53.794Z,1379202173.794 [CBIT](CRITICAL): Communications Fault in component: Batt_Ocean_Server
2013-09-14T23:42:53.908Z,1379202173.908 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:53.908Z,1379202173.908 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:42:53.908Z,1379202173.908 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:42:54.092Z,1379202174.092 [NAL9602](INFO): NAL9602 initialized
2013-09-14T23:42:54.427Z,1379202174.427 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:42:54.427Z,1379202174.427 [AHRS_sp3003D] No Fault, FailCount= 1
2013-09-14T23:42:54.712Z,1379202174.712 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:42:55.912Z,1379202175.912 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:42:56.163Z,1379202176.163 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:42:56.163Z,1379202176.163 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:42:56.163Z,1379202176.163 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-09-14T23:42:56.163Z,1379202176.163 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:42:56.416Z,1379202176.416 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:42:56.450Z,1379202176.450 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:42:57.718Z,1379202177.718 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:42:57.718Z,1379202177.718 [AHRS_sp3003D] No Fault, FailCount= 2
2013-09-14T23:42:57.915Z,1379202177.915 [DVL_micro](INFO): pause:Powering down
2013-09-14T23:42:58.035Z,1379202178.035 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:42:58.378Z,1379202178.378 [DAT](INFO): Init failed - response: 
2013-09-14T23:42:58.379Z,1379202178.379 [DAT](FAULT): DAT failed to initialize
2013-09-14T23:42:58.379Z,1379202178.379 [DAT] Communications Fault, FailCount= 1
2013-09-14T23:42:58.379Z,1379202178.379 [DAT](ERROR): Communications Fault
2013-09-14T23:42:58.459Z,1379202178.459 [CBIT](ERROR): Communications Fault in component: DAT
2013-09-14T23:42:58.540Z,1379202178.540 [DAT](INFO): Powering down
2013-09-14T23:42:59.216Z,1379202179.216 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:42:59.216Z,1379202179.216 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:42:59.216Z,1379202179.216 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-09-14T23:42:59.216Z,1379202179.216 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:42:59.288Z,1379202179.288 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:42:59.362Z,1379202179.362 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:42:59.524Z,1379202179.524 [CBIT](INFO): Clearing failed state for component DAT
2013-09-14T23:42:59.524Z,1379202179.524 [DAT] No Fault, FailCount= 1
2013-09-14T23:42:59.529Z,1379202179.529 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:42:59.529Z,1379202179.529 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:42:59.530Z,1379202179.530 [DVL_micro](INFO): resume:Powering up
2013-09-14T23:42:59.530Z,1379202179.530 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:00.654Z,1379202180.654 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:43:00.654Z,1379202180.654 [AHRS_sp3003D] No Fault, FailCount= 3
2013-09-14T23:43:00.943Z,1379202180.943 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:43:01.536Z,1379202181.536 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:01.536Z,1379202181.536 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:01.536Z,1379202181.536 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:43:02.084Z,1379202182.084 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:43:02.084Z,1379202182.084 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:43:02.085Z,1379202182.085 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-09-14T23:43:02.085Z,1379202182.085 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:43:02.120Z,1379202182.120 [DAT](INFO): Powering up
2013-09-14T23:43:02.124Z,1379202182.124 [DAT](DEBUG): Initializing DAT.
2013-09-14T23:43:02.180Z,1379202182.180 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:43:02.194Z,1379202182.194 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:43:03.546Z,1379202183.546 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:43:03.546Z,1379202183.546 [AHRS_sp3003D] No Fault, FailCount= 4
2013-09-14T23:43:03.548Z,1379202183.548 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:03.548Z,1379202183.548 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:43:03.549Z,1379202183.549 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:43:03.795Z,1379202183.795 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:43:04.937Z,1379202184.937 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:43:04.937Z,1379202184.937 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:43:04.937Z,1379202184.937 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2013-09-14T23:43:04.937Z,1379202184.937 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:43:05.113Z,1379202185.113 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:43:05.114Z,1379202185.114 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:43:05.141Z,1379202185.141 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:43:05.550Z,1379202185.550 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:05.552Z,1379202185.552 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:43:05.552Z,1379202185.552 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:07.557Z,1379202187.557 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:07.558Z,1379202187.558 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:43:09.564Z,1379202189.564 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:09.564Z,1379202189.564 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:43:09.564Z,1379202189.564 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:43:11.571Z,1379202191.571 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:11.571Z,1379202191.571 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:11.571Z,1379202191.571 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:43:13.578Z,1379202193.578 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:13.578Z,1379202193.578 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:43:13.579Z,1379202193.579 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:43:15.185Z,1379202195.185 [CBIT](IMPORTANT): No ground fault detected
2013-09-14T23:43:15.582Z,1379202195.582 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:17.586Z,1379202197.586 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:43:17.586Z,1379202197.586 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:19.592Z,1379202199.592 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:19.592Z,1379202199.592 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:43:21.442Z,1379202201.442 [DAT](INFO): Init failed - response: 
2013-09-14T23:43:21.442Z,1379202201.442 [DAT](FAULT): DAT failed to initialize
2013-09-14T23:43:21.442Z,1379202201.442 [DAT] Communications Fault, FailCount= 2
2013-09-14T23:43:21.443Z,1379202201.443 [DAT](ERROR): Communications Fault
2013-09-14T23:43:21.491Z,1379202201.491 [CBIT](ERROR): Communications Fault in component: DAT
2013-09-14T23:43:21.556Z,1379202201.556 [DAT](INFO): Powering down
2013-09-14T23:43:21.594Z,1379202201.594 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:21.595Z,1379202201.595 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:43:21.595Z,1379202201.595 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:43:22.432Z,1379202202.432 [CBIT](INFO): Clearing failed state for component DAT
2013-09-14T23:43:22.432Z,1379202202.432 [DAT] No Fault, FailCount= 2
2013-09-14T23:43:23.602Z,1379202203.602 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:23.602Z,1379202203.602 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:23.602Z,1379202203.602 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:43:24.753Z,1379202204.753 [DAT](INFO): Powering up
2013-09-14T23:43:24.753Z,1379202204.753 [DAT](DEBUG): Initializing DAT.
2013-09-14T23:43:25.609Z,1379202205.609 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:25.609Z,1379202205.609 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:43:25.609Z,1379202205.609 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:43:27.636Z,1379202207.636 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:29.649Z,1379202209.649 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:43:29.649Z,1379202209.649 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:31.655Z,1379202211.655 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:31.656Z,1379202211.656 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:43:33.661Z,1379202213.661 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:33.661Z,1379202213.661 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:43:33.662Z,1379202213.662 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:43:35.664Z,1379202215.664 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:35.665Z,1379202215.665 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:35.665Z,1379202215.665 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:43:37.667Z,1379202217.667 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:37.668Z,1379202217.668 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:43:37.668Z,1379202217.668 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:43:39.678Z,1379202219.678 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:40.798Z,1379202220.798 [SBIT](IMPORTANT): SBIT PASSED
2013-09-14T23:43:41.147Z,1379202221.147 [MissionManager](IMPORTANT): Started mission Startup
2013-09-14T23:43:41.147Z,1379202221.147 [Startup] Running Loop=1
2013-09-14T23:43:41.147Z,1379202221.147 [Startup](INFO): Aggregate::initialize Startup
2013-09-14T23:43:41.147Z,1379202221.147 [Startup:A.GoToSurface] Running Loop=1
2013-09-14T23:43:41.148Z,1379202221.148 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-14T23:43:41.682Z,1379202221.682 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:43:41.682Z,1379202221.682 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:43.686Z,1379202223.686 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:43.687Z,1379202223.687 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:43:44.242Z,1379202224.242 [DAT](INFO): Init failed - response: 
2013-09-14T23:43:44.242Z,1379202224.242 [DAT](FAULT): DAT failed to initialize
2013-09-14T23:43:44.242Z,1379202224.242 [DAT] Communications Fault, FailCount= 3
2013-09-14T23:43:44.242Z,1379202224.242 [DAT](ERROR): Communications Fault
2013-09-14T23:43:44.320Z,1379202224.320 [CBIT](ERROR): Communications Fault in component: DAT
2013-09-14T23:43:44.320Z,1379202224.320 [CBIT](CRITICAL): Communications Fault in component: DAT
2013-09-14T23:43:44.361Z,1379202224.361 [DAT](INFO): Powering down
2013-09-14T23:43:45.692Z,1379202225.692 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:45.692Z,1379202225.692 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:43:45.692Z,1379202225.692 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:43:46.814Z,1379202226.814 [MassServo](FAULT): Failed to complete homing within timeout
2013-09-14T23:43:46.814Z,1379202226.814 [MassServo] Hardware Fault, FailCount= 1
2013-09-14T23:43:46.814Z,1379202226.814 [MassServo](ERROR): Hardware Fault
2013-09-14T23:43:46.844Z,1379202226.844 [CBIT](ERROR): Hardware Fault in component: MassServo
2013-09-14T23:43:47.160Z,1379202227.160 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-09-14T23:43:47.160Z,1379202227.160 [MassServo](INFO): Powering down
2013-09-14T23:43:47.704Z,1379202227.704 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:47.705Z,1379202227.705 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:47.705Z,1379202227.705 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:43:48.108Z,1379202228.108 [CBIT](INFO): Clearing failed state for component MassServo
2013-09-14T23:43:48.108Z,1379202228.108 [MassServo] No Fault, FailCount= 1
2013-09-14T23:43:48.366Z,1379202228.366 [MassServo](DEBUG): Initializing EZServoServo.
2013-09-14T23:43:48.367Z,1379202228.367 [MassServo](DEBUG): Initializing MassServo.
2013-09-14T23:43:49.714Z,1379202229.714 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:49.714Z,1379202229.714 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:43:49.714Z,1379202229.714 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:43:51.721Z,1379202231.721 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:53.725Z,1379202233.725 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:43:53.725Z,1379202233.725 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:43:55.728Z,1379202235.728 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:43:55.728Z,1379202235.728 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:43:57.738Z,1379202237.738 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:57.739Z,1379202237.739 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:43:57.739Z,1379202237.739 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:43:59.750Z,1379202239.750 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:43:59.750Z,1379202239.750 [DVL_micro](INFO): Querying output modes
2013-09-14T23:43:59.750Z,1379202239.750 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:44:01.757Z,1379202241.757 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:01.757Z,1379202241.757 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:44:01.757Z,1379202241.757 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:44:03.764Z,1379202243.764 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:05.776Z,1379202245.776 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:44:05.776Z,1379202245.776 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:44:07.779Z,1379202247.779 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:44:07.779Z,1379202247.779 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:44:09.781Z,1379202249.781 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:09.781Z,1379202249.781 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:44:09.781Z,1379202249.781 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:44:11.784Z,1379202251.784 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:11.784Z,1379202251.784 [DVL_micro](INFO): Querying output modes
2013-09-14T23:44:11.785Z,1379202251.785 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:44:13.791Z,1379202253.791 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:13.791Z,1379202253.791 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:44:13.792Z,1379202253.792 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:44:15.798Z,1379202255.798 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:17.804Z,1379202257.804 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:44:17.804Z,1379202257.804 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:44:19.809Z,1379202259.809 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:44:19.809Z,1379202259.809 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:44:21.812Z,1379202261.812 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:21.812Z,1379202261.812 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:44:21.812Z,1379202261.812 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:44:23.823Z,1379202263.823 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:23.823Z,1379202263.823 [DVL_micro](INFO): Querying output modes
2013-09-14T23:44:23.823Z,1379202263.823 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:44:25.826Z,1379202265.826 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:25.826Z,1379202265.826 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:44:25.826Z,1379202265.826 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:44:27.837Z,1379202267.837 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:29.849Z,1379202269.849 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:44:29.849Z,1379202269.849 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:44:31.852Z,1379202271.852 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:44:31.852Z,1379202271.852 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:44:33.858Z,1379202273.858 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:33.859Z,1379202273.859 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:44:33.859Z,1379202273.859 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:44:35.866Z,1379202275.866 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:35.866Z,1379202275.866 [DVL_micro](INFO): Querying output modes
2013-09-14T23:44:35.866Z,1379202275.866 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:44:37.869Z,1379202277.869 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:37.869Z,1379202277.869 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:44:37.869Z,1379202277.869 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:44:39.872Z,1379202279.872 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:41.876Z,1379202281.876 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:44:41.876Z,1379202281.876 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:44:43.878Z,1379202283.878 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:44:43.879Z,1379202283.879 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:44:45.881Z,1379202285.881 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:45.881Z,1379202285.881 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:44:45.881Z,1379202285.881 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:44:47.892Z,1379202287.892 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:47.892Z,1379202287.892 [DVL_micro](INFO): Querying output modes
2013-09-14T23:44:47.893Z,1379202287.893 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:44:49.896Z,1379202289.896 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:49.896Z,1379202289.896 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:44:49.896Z,1379202289.896 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:44:51.906Z,1379202291.906 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:53.918Z,1379202293.918 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:44:53.918Z,1379202293.918 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:44:55.921Z,1379202295.921 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:44:55.921Z,1379202295.921 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:44:57.932Z,1379202297.932 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:57.932Z,1379202297.932 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:44:57.932Z,1379202297.932 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:44:59.941Z,1379202299.941 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:44:59.941Z,1379202299.941 [DVL_micro](INFO): Querying output modes
2013-09-14T23:44:59.941Z,1379202299.941 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:45:01.946Z,1379202301.946 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:01.946Z,1379202301.946 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:45:01.946Z,1379202301.946 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:45:03.957Z,1379202303.957 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:05.969Z,1379202305.969 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:45:05.969Z,1379202305.969 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:45:07.972Z,1379202307.972 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:45:07.972Z,1379202307.972 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:45:09.978Z,1379202309.978 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:09.979Z,1379202309.979 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:45:09.979Z,1379202309.979 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:45:11.982Z,1379202311.982 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:11.982Z,1379202311.982 [DVL_micro](INFO): Querying output modes
2013-09-14T23:45:11.982Z,1379202311.982 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:45:13.993Z,1379202313.993 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:13.993Z,1379202313.993 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:45:13.993Z,1379202313.993 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:45:15.000Z,1379202316.000 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:18.020Z,1379202318.020 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:45:18.020Z,1379202318.020 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:45:20.023Z,1379202320.023 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:45:20.023Z,1379202320.023 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:45:22.033Z,1379202322.033 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:22.033Z,1379202322.033 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:45:22.033Z,1379202322.033 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:45:24.040Z,1379202324.040 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:24.040Z,1379202324.040 [DVL_micro](INFO): Querying output modes
2013-09-14T23:45:24.041Z,1379202324.041 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:45:26.051Z,1379202326.051 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:26.052Z,1379202326.052 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:45:26.052Z,1379202326.052 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:45:28.055Z,1379202328.055 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:30.058Z,1379202330.058 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:45:30.058Z,1379202330.058 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:45:32.061Z,1379202332.061 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:45:32.061Z,1379202332.061 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:45:34.064Z,1379202334.064 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:34.064Z,1379202334.064 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:45:34.064Z,1379202334.064 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:45:36.067Z,1379202336.067 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:36.067Z,1379202336.067 [DVL_micro](INFO): Querying output modes
2013-09-14T23:45:36.067Z,1379202336.067 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:45:38.078Z,1379202338.078 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:38.078Z,1379202338.078 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:45:38.078Z,1379202338.078 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:45:40.089Z,1379202340.089 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:42.105Z,1379202342.105 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:45:42.105Z,1379202342.105 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:45:44.108Z,1379202344.108 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:45:44.108Z,1379202344.108 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:45:46.115Z,1379202346.115 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:46.115Z,1379202346.115 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:45:46.115Z,1379202346.115 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:45:48.126Z,1379202348.126 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:48.126Z,1379202348.126 [DVL_micro](INFO): Querying output modes
2013-09-14T23:45:48.126Z,1379202348.126 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:45:50.133Z,1379202350.133 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:50.133Z,1379202350.133 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:45:50.133Z,1379202350.133 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:45:52.144Z,1379202352.144 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:54.152Z,1379202354.152 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:45:54.152Z,1379202354.152 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:45:56.154Z,1379202356.154 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:45:56.155Z,1379202356.155 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:45:58.165Z,1379202358.165 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:45:58.165Z,1379202358.165 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:45:58.165Z,1379202358.165 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:46:00.176Z,1379202360.176 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:00.176Z,1379202360.176 [DVL_micro](INFO): Querying output modes
2013-09-14T23:46:00.177Z,1379202360.177 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:46:02.179Z,1379202362.179 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:02.180Z,1379202362.180 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:46:02.180Z,1379202362.180 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:46:04.183Z,1379202364.183 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:06.195Z,1379202366.195 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:46:06.195Z,1379202366.195 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:46:08.197Z,1379202368.197 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:46:08.197Z,1379202368.197 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:46:10.208Z,1379202370.208 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:10.208Z,1379202370.208 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:46:10.208Z,1379202370.208 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:46:12.219Z,1379202372.219 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:12.219Z,1379202372.219 [DVL_micro](INFO): Querying output modes
2013-09-14T23:46:12.219Z,1379202372.219 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:46:14.226Z,1379202374.226 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:14.226Z,1379202374.226 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:46:14.226Z,1379202374.226 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:46:16.233Z,1379202376.233 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:18.245Z,1379202378.245 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:46:18.245Z,1379202378.245 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:46:20.248Z,1379202380.248 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:46:20.248Z,1379202380.248 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:46:22.259Z,1379202382.259 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:22.259Z,1379202382.259 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:46:22.259Z,1379202382.259 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:46:24.270Z,1379202384.270 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:24.270Z,1379202384.270 [DVL_micro](INFO): Querying output modes
2013-09-14T23:46:24.270Z,1379202384.270 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:46:26.277Z,1379202386.277 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:26.277Z,1379202386.277 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:46:26.277Z,1379202386.277 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:46:28.288Z,1379202388.288 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:30.296Z,1379202390.296 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:46:30.296Z,1379202390.296 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:46:32.299Z,1379202392.299 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:46:32.299Z,1379202392.299 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:46:34.308Z,1379202394.308 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:34.308Z,1379202394.308 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:46:34.308Z,1379202394.308 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:46:36.318Z,1379202396.318 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:36.318Z,1379202396.318 [DVL_micro](INFO): Querying output modes
2013-09-14T23:46:36.318Z,1379202396.318 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:46:38.319Z,1379202398.319 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:38.320Z,1379202398.320 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:46:38.320Z,1379202398.320 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:46:40.327Z,1379202400.327 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:42.334Z,1379202402.334 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:46:42.335Z,1379202402.335 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:46:44.337Z,1379202404.337 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:46:44.337Z,1379202404.337 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:46:46.348Z,1379202406.348 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:46.348Z,1379202406.348 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:46:46.348Z,1379202406.348 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:46:48.355Z,1379202408.355 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:48.355Z,1379202408.355 [DVL_micro](INFO): Querying output modes
2013-09-14T23:46:48.355Z,1379202408.355 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:46:50.358Z,1379202410.358 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:50.358Z,1379202410.358 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:46:50.358Z,1379202410.358 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:46:52.369Z,1379202412.369 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:54.377Z,1379202414.377 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:46:54.377Z,1379202414.377 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:46:56.380Z,1379202416.380 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:46:56.380Z,1379202416.380 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:46:58.391Z,1379202418.391 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:46:58.391Z,1379202418.391 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:46:58.391Z,1379202418.391 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:47:00.398Z,1379202420.398 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:00.398Z,1379202420.398 [DVL_micro](INFO): Querying output modes
2013-09-14T23:47:00.398Z,1379202420.398 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:47:02.405Z,1379202422.405 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:02.405Z,1379202422.405 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:47:02.405Z,1379202422.405 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:47:04.408Z,1379202424.408 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:06.416Z,1379202426.416 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:47:06.416Z,1379202426.416 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:47:08.419Z,1379202428.419 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:47:08.419Z,1379202428.419 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:47:10.429Z,1379202430.429 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:10.429Z,1379202430.429 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:47:10.430Z,1379202430.430 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:47:12.432Z,1379202432.432 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:12.432Z,1379202432.432 [DVL_micro](INFO): Querying output modes
2013-09-14T23:47:12.433Z,1379202432.433 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:47:14.464Z,1379202434.464 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:14.464Z,1379202434.464 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:47:14.464Z,1379202434.464 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:47:16.471Z,1379202436.471 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:18.478Z,1379202438.478 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:47:18.479Z,1379202438.479 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:47:20.481Z,1379202440.481 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:47:20.482Z,1379202440.482 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:47:22.488Z,1379202442.488 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:22.488Z,1379202442.488 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:47:22.488Z,1379202442.488 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:47:24.500Z,1379202444.500 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:24.501Z,1379202444.501 [DVL_micro](INFO): Querying output modes
2013-09-14T23:47:24.503Z,1379202444.503 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:47:26.538Z,1379202446.538 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:26.538Z,1379202446.538 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:47:26.539Z,1379202446.539 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:47:28.549Z,1379202448.549 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:30.557Z,1379202450.557 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:47:30.557Z,1379202450.557 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:47:32.560Z,1379202452.560 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:47:32.560Z,1379202452.560 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:47:34.567Z,1379202454.567 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:34.567Z,1379202454.567 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:47:34.567Z,1379202454.567 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:47:36.574Z,1379202456.574 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:36.574Z,1379202456.574 [DVL_micro](INFO): Querying output modes
2013-09-14T23:47:36.574Z,1379202456.574 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:47:38.581Z,1379202458.581 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:38.581Z,1379202458.581 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:47:38.581Z,1379202458.581 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:47:40.592Z,1379202460.592 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:42.600Z,1379202462.600 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:47:42.600Z,1379202462.600 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:47:44.603Z,1379202464.603 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:47:44.603Z,1379202464.603 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:47:46.609Z,1379202466.609 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:46.609Z,1379202466.609 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:47:46.610Z,1379202466.610 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:47:48.616Z,1379202468.616 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:48.617Z,1379202468.617 [DVL_micro](INFO): Querying output modes
2013-09-14T23:47:48.617Z,1379202468.617 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:47:50.628Z,1379202470.628 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:50.628Z,1379202470.628 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:47:50.628Z,1379202470.628 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:47:52.639Z,1379202472.639 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:54.650Z,1379202474.650 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:47:54.650Z,1379202474.650 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:47:56.653Z,1379202476.653 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:47:56.654Z,1379202476.654 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:47:58.664Z,1379202478.664 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:47:58.664Z,1379202478.664 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:47:58.664Z,1379202478.664 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:48:00.671Z,1379202480.671 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:00.671Z,1379202480.671 [DVL_micro](INFO): Querying output modes
2013-09-14T23:48:00.671Z,1379202480.671 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:48:02.678Z,1379202482.678 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:02.678Z,1379202482.678 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:48:02.679Z,1379202482.679 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:48:04.681Z,1379202484.681 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:05.173Z,1379202485.173 [CBIT](INFO): Clearing failed count for component AHRS_sp3003D
2013-09-14T23:48:05.173Z,1379202485.173 [AHRS_sp3003D] No Fault, FailCount= 5
2013-09-14T23:48:05.511Z,1379202485.511 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:48:06.432Z,1379202486.432 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:48:06.432Z,1379202486.432 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x240800
2013-09-14T23:48:06.432Z,1379202486.432 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:48:06.433Z,1379202486.433 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-14T23:48:06.433Z,1379202486.433 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:48:06.511Z,1379202486.511 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:06.689Z,1379202486.689 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:48:06.689Z,1379202486.689 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:48:06.721Z,1379202486.721 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:48:07.973Z,1379202487.973 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:48:07.973Z,1379202487.973 [AHRS_sp3003D] No Fault, FailCount= 1
2013-09-14T23:48:08.311Z,1379202488.311 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:48:08.692Z,1379202488.692 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:48:08.692Z,1379202488.692 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:48:09.228Z,1379202489.228 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:48:09.229Z,1379202489.229 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x040000
2013-09-14T23:48:09.229Z,1379202489.229 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:48:09.229Z,1379202489.229 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2013-09-14T23:48:09.229Z,1379202489.229 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:48:09.311Z,1379202489.311 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:09.514Z,1379202489.514 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:48:10.695Z,1379202490.695 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:10.695Z,1379202490.695 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:48:10.695Z,1379202490.695 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:48:10.793Z,1379202490.793 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:48:10.793Z,1379202490.793 [AHRS_sp3003D] No Fault, FailCount= 2
2013-09-14T23:48:11.112Z,1379202491.112 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:48:12.017Z,1379202492.017 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:48:12.017Z,1379202492.017 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x00
2013-09-14T23:48:12.017Z,1379202492.017 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:48:12.017Z,1379202492.017 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2013-09-14T23:48:12.017Z,1379202492.017 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:48:12.095Z,1379202492.095 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:12.312Z,1379202492.312 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:48:12.720Z,1379202492.720 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:12.720Z,1379202492.720 [DVL_micro](INFO): Querying output modes
2013-09-14T23:48:12.721Z,1379202492.721 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:48:13.574Z,1379202493.574 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:48:13.574Z,1379202493.574 [AHRS_sp3003D] No Fault, FailCount= 3
2013-09-14T23:48:13.912Z,1379202493.912 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:48:14.733Z,1379202494.733 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:14.733Z,1379202494.733 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:48:14.733Z,1379202494.733 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:48:15.049Z,1379202495.049 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:48:15.050Z,1379202495.050 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:48:15.050Z,1379202495.050 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2013-09-14T23:48:15.050Z,1379202495.050 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:48:15.128Z,1379202495.128 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:15.148Z,1379202495.148 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:48:16.398Z,1379202496.398 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2013-09-14T23:48:16.398Z,1379202496.398 [AHRS_sp3003D] No Fault, FailCount= 4
2013-09-14T23:48:16.744Z,1379202496.744 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T23:48:16.745Z,1379202496.745 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:17.882Z,1379202497.882 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T23:48:17.882Z,1379202497.882 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T23:48:17.882Z,1379202497.882 [AHRS_sp3003D] Hardware Fault, FailCount= 5
2013-09-14T23:48:17.882Z,1379202497.882 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T23:48:17.945Z,1379202497.945 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:17.945Z,1379202497.945 [CBIT](CRITICAL): Hardware Fault in component: AHRS_sp3003D
2013-09-14T23:48:17.959Z,1379202497.959 [AHRS_sp3003D](INFO): Powering down
2013-09-14T23:48:18.760Z,1379202498.760 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:48:18.760Z,1379202498.760 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:48:20.763Z,1379202500.763 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:48:20.763Z,1379202500.763 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:48:22.766Z,1379202502.766 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:22.766Z,1379202502.766 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:48:22.766Z,1379202502.766 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:48:24.772Z,1379202504.772 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:24.773Z,1379202504.773 [DVL_micro](INFO): Querying output modes
2013-09-14T23:48:24.773Z,1379202504.773 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:48:26.780Z,1379202506.780 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:26.780Z,1379202506.780 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:48:26.780Z,1379202506.780 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:48:28.787Z,1379202508.787 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:30.795Z,1379202510.795 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:48:30.795Z,1379202510.795 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:48:32.797Z,1379202512.797 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:48:32.798Z,1379202512.798 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:48:34.808Z,1379202514.808 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:34.808Z,1379202514.808 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:48:34.808Z,1379202514.808 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:48:36.811Z,1379202516.811 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:36.811Z,1379202516.811 [DVL_micro](INFO): Querying output modes
2013-09-14T23:48:36.812Z,1379202516.812 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T23:48:38.823Z,1379202518.823 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:38.823Z,1379202518.823 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T23:48:38.824Z,1379202518.824 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T23:48:40.833Z,1379202520.833 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:42.841Z,1379202522.841 [DVL_micro](INFO): NQ1 requested
2013-09-14T23:48:42.841Z,1379202522.841 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T23:48:44.402Z,1379202524.402 [CBIT](INFO): Clearing failed count for component DAT
2013-09-14T23:48:44.402Z,1379202524.402 [DAT] No Fault, FailCount= 3
2013-09-14T23:48:44.727Z,1379202524.727 [DAT](INFO): Powering up
2013-09-14T23:48:44.727Z,1379202524.727 [DAT](DEBUG): Initializing DAT.
2013-09-14T23:48:44.844Z,1379202524.844 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T23:48:44.844Z,1379202524.844 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T23:48:46.847Z,1379202526.847 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:46.847Z,1379202526.847 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T23:48:46.847Z,1379202526.847 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T23:48:48.854Z,1379202528.854 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T23:48:48.854Z,1379202528.854 [DVL_micro](INFO): Querying output modes
2013-09-14T23:48:48.854Z,1379202528.854 [DVL_micro](DEBUG): commandDVL: