2013-05-16T21:34:15.654Z,1368740055.654 [Supervisor](DEBUG): Initializing supervisor.
2013-05-16T21:34:15.657Z,1368740055.657 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-16T21:34:15.657Z,1368740055.657 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-16T21:34:15.658Z,1368740055.658 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-16T21:34:15.662Z,1368740055.662 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-16T21:34:15.673Z,1368740055.673 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-16T21:34:15.674Z,1368740055.674 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-16T21:34:15.675Z,1368740055.675 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-16T21:34:15.676Z,1368740055.676 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-16T21:34:15.676Z,1368740055.676 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-16T21:34:15.678Z,1368740055.678 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-16T21:34:15.965Z,1368740055.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-16T21:34:15.965Z,1368740055.965 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-16T21:34:16.158Z,1368740056.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-16T21:34:16.159Z,1368740056.159 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-16T21:34:16.244Z,1368740056.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-16T21:34:16.244Z,1368740056.244 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-16T21:34:16.449Z,1368740056.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-16T21:34:16.450Z,1368740056.450 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-16T21:34:16.590Z,1368740056.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-16T21:34:16.590Z,1368740056.590 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-16T21:34:16.829Z,1368740056.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-16T21:34:16.830Z,1368740056.830 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-16T21:34:17.003Z,1368740057.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-16T21:34:17.004Z,1368740057.004 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-16T21:34:17.264Z,1368740057.264 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-16T21:34:17.265Z,1368740057.265 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-16T21:34:17.365Z,1368740057.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-16T21:34:17.365Z,1368740057.365 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-16T21:34:17.776Z,1368740057.776 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-16T21:34:17.776Z,1368740057.776 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-16T21:34:17.892Z,1368740057.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-16T21:34:17.892Z,1368740057.892 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-16T21:34:17.979Z,1368740057.979 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-16T21:34:17.980Z,1368740057.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-16T21:34:18.086Z,1368740058.086 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-16T21:34:18.217Z,1368740058.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-16T21:34:18.304Z,1368740058.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-16T21:34:18.412Z,1368740058.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-16T21:34:18.515Z,1368740058.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-16T21:34:18.639Z,1368740058.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-16T21:34:18.737Z,1368740058.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-16T21:34:18.827Z,1368740058.827 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-05-16T21:34:18.827Z,1368740058.827 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-05-16T21:34:18.851Z,1368740058.851 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-16T21:34:19.002Z,1368740059.002 [InternalSim] Loaded
2013-05-16T21:34:19.003Z,1368740059.003 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-16T21:34:19.004Z,1368740059.004 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-16T21:34:19.004Z,1368740059.004 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-16T21:34:19.062Z,1368740059.062 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-16T21:34:19.091Z,1368740059.091 [SBIT] Loaded
2013-05-16T21:34:19.091Z,1368740059.091 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-16T21:34:19.092Z,1368740059.092 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-16T21:34:19.121Z,1368740059.121 [IBIT] Loaded
2013-05-16T21:34:19.122Z,1368740059.122 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-16T21:34:19.125Z,1368740059.125 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-16T21:34:19.245Z,1368740059.246 [CBIT] Loaded
2013-05-16T21:34:19.246Z,1368740059.246 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-16T21:34:19.246Z,1368740059.246 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-16T21:34:19.247Z,1368740059.247 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-16T21:34:19.396Z,1368740059.396 [BuoyancyServo] Loaded
2013-05-16T21:34:19.396Z,1368740059.396 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-16T21:34:19.409Z,1368740059.409 [ElevatorServo] Loaded
2013-05-16T21:34:19.409Z,1368740059.409 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-16T21:34:19.421Z,1368740059.421 [MassServo] Loaded
2013-05-16T21:34:19.421Z,1368740059.421 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-16T21:34:19.434Z,1368740059.434 [RudderServo] Loaded
2013-05-16T21:34:19.434Z,1368740059.434 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-16T21:34:19.446Z,1368740059.446 [ThrusterServo] Loaded
2013-05-16T21:34:19.446Z,1368740059.446 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-16T21:34:19.447Z,1368740059.447 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-16T21:34:19.447Z,1368740059.447 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-16T21:34:19.464Z,1368740059.464 [DepthRateCalculator] Loaded
2013-05-16T21:34:19.465Z,1368740059.465 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-16T21:34:22.490Z,1368740062.490 [HFRadarModelCalc] Loaded
2013-05-16T21:34:22.490Z,1368740062.490 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-16T21:34:22.507Z,1368740062.507 [NavChart] Loaded
2013-05-16T21:34:22.507Z,1368740062.507 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-16T21:34:22.513Z,1368740062.513 [PitchRateCalculator] Loaded
2013-05-16T21:34:22.513Z,1368740062.513 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-16T21:34:22.524Z,1368740062.524 [SpeedCalculator] Loaded
2013-05-16T21:34:22.524Z,1368740062.524 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-16T21:34:22.540Z,1368740062.540 [TempGradientCalculator] Loaded
2013-05-16T21:34:22.540Z,1368740062.540 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-16T21:34:22.546Z,1368740062.546 [YawRateCalculator] Loaded
2013-05-16T21:34:22.546Z,1368740062.546 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-16T21:34:22.593Z,1368740062.593 [Navigation] Loaded
2013-05-16T21:34:22.594Z,1368740062.594 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-16T21:34:22.594Z,1368740062.594 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-16T21:34:22.595Z,1368740062.595 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-16T21:34:22.804Z,1368740062.804 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-16T21:34:22.805Z,1368740062.805 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-16T21:34:22.827Z,1368740062.827 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-16T21:34:22.827Z,1368740062.827 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-16T21:34:22.868Z,1368740062.868 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-16T21:34:22.963Z,1368740062.963 [VerticalControl] Loaded
2013-05-16T21:34:22.963Z,1368740062.963 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-16T21:34:22.964Z,1368740062.964 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-16T21:34:23.021Z,1368740063.021 [HorizontalControl] Loaded
2013-05-16T21:34:23.022Z,1368740063.022 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-16T21:34:23.023Z,1368740063.023 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-16T21:34:23.024Z,1368740063.024 [SpeedControl] Loaded
2013-05-16T21:34:23.025Z,1368740063.025 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-16T21:34:23.026Z,1368740063.026 [LoopControl](DEBUG): Construct LoopControl.
2013-05-16T21:34:23.026Z,1368740063.026 [LoopControl] Loaded
2013-05-16T21:34:23.026Z,1368740063.026 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-16T21:34:23.027Z,1368740063.027 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-16T21:34:23.027Z,1368740063.027 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-16T21:34:23.033Z,1368740063.033 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-16T21:34:23.038Z,1368740063.038 [AsyncPiEstimator] Loaded
2013-05-16T21:34:23.038Z,1368740063.038 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-16T21:34:23.040Z,1368740063.040 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-16T21:34:23.040Z,1368740063.040 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-16T21:34:23.041Z,1368740063.041 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-16T21:34:23.166Z,1368740063.166 [AHRS_sp3003D] Loaded
2013-05-16T21:34:23.166Z,1368740063.166 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-16T21:34:23.426Z,1368740063.426 [Batt_Ocean_Server] Loaded
2013-05-16T21:34:23.426Z,1368740063.426 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-16T21:34:23.440Z,1368740063.441 [Depth_Keller] Loaded
2013-05-16T21:34:23.441Z,1368740063.441 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-16T21:34:23.447Z,1368740063.447 [DropWeight] Loaded
2013-05-16T21:34:23.447Z,1368740063.447 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-05-16T21:34:23.621Z,1368740063.621 [DVL_micro] Loaded
2013-05-16T21:34:23.621Z,1368740063.621 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-16T21:34:23.622Z,1368740063.622 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406BD4E0
2013-05-16T21:34:23.705Z,1368740063.705 [NAL9602] Loaded
2013-05-16T21:34:23.706Z,1368740063.706 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-16T21:34:23.757Z,1368740063.757 [Onboard] Loaded
2013-05-16T21:34:23.758Z,1368740063.758 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-16T21:34:23.764Z,1368740063.764 [Radio_Freewave] Loaded
2013-05-16T21:34:23.765Z,1368740063.765 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-16T21:34:23.887Z,1368740063.887 [DAT] Loaded
2013-05-16T21:34:23.888Z,1368740063.888 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-05-16T21:34:23.888Z,1368740063.888 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-16T21:34:23.889Z,1368740063.889 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-16T21:34:23.961Z,1368740063.961 [CTD_NeilBrown] Loaded
2013-05-16T21:34:23.961Z,1368740063.961 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-16T21:34:23.967Z,1368740063.967 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4070F4E0
2013-05-16T21:34:23.999Z,1368740063.999 [WetLabsBB2FL] Loaded
2013-05-16T21:34:23.000Z,1368740064.000 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-16T21:34:24.001Z,1368740064.001 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4073F4E0
2013-05-16T21:34:24.001Z,1368740064.001 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-16T21:34:24.004Z,1368740064.004 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-16T21:34:24.005Z,1368740064.005 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-16T21:34:24.011Z,1368740064.011 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-16T21:34:24.013Z,1368740064.013 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4076F4E0
2013-05-16T21:34:24.017Z,1368740064.017 [Supervisor](DEBUG): Running supervisor.
2013-05-16T21:34:24.018Z,1368740064.018 [CommandLine](INFO): Thread ID is 9684
2013-05-16T21:34:24.021Z,1368740064.021 [controlThread](INFO): Thread ID is 9683
2013-05-16T21:34:24.021Z,1368740064.021 [controlThread](DEBUG): Initializing ControlThread
2013-05-16T21:34:24.021Z,1368740064.021 [CycleStarter](INFO): Thread ID is 9682
2013-05-16T21:34:24.022Z,1368740064.022 [InternalSim](DEBUG):  InternalSim initializing...
2013-05-16T21:34:24.057Z,1368740064.057 [logger](INFO): Thread ID is 9685
2013-05-16T21:34:24.078Z,1368740064.078 [SBIT](INFO): Initialize SBIT Component.
2013-05-16T21:34:24.079Z,1368740064.079 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10359
2013-05-16T21:34:24.079Z,1368740064.079 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-16T21:34:24.079Z,1368740064.079 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-16T21:34:24.080Z,1368740064.080 [IBIT](INFO): Initialize IBIT Component.
2013-05-16T21:34:24.081Z,1368740064.081 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-16T21:34:24.081Z,1368740064.081 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-05-16T21:34:24.081Z,1368740064.081 [CBIT](CRITICAL): Watchdog Timer failed to initialize.
2013-05-16T21:34:24.081Z,1368740064.081 [CBIT] Hardware Fault, FailCount= 1
2013-05-16T21:34:24.081Z,1368740064.081 [CBIT](ERROR): Hardware Fault
2013-05-16T21:34:24.090Z,1368740064.090 [AsyncPiEstimator](INFO): Thread ID is 9746
2013-05-16T21:34:24.091Z,1368740064.091 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-16T21:34:24.100Z,1368740064.100 [DVL_micro](INFO): Thread ID is 9747
2013-05-16T21:34:24.109Z,1368740064.109 [DVL_micro](INFO): Initializing
2013-05-16T21:34:24.109Z,1368740064.109 [DVL_micro](INFO): start:Powering up
2013-05-16T21:34:24.110Z,1368740064.110 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:24.112Z,1368740064.112 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-16T21:34:24.112Z,1368740064.112 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-16T21:34:24.113Z,1368740064.113 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-16T21:34:24.113Z,1368740064.113 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-16T21:34:24.113Z,1368740064.113 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-16T21:34:24.115Z,1368740064.115 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:34:24.119Z,1368740064.119 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-16T21:34:24.120Z,1368740064.120 [Navigation](DEBUG): Initializing Navigation.
2013-05-16T21:34:24.120Z,1368740064.120 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-16T21:34:24.122Z,1368740064.122 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-16T21:34:24.127Z,1368740064.127 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-16T21:34:24.127Z,1368740064.127 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-16T21:34:24.139Z,1368740064.139 [CTD_NeilBrown](INFO): Thread ID is 9748
2013-05-16T21:34:24.140Z,1368740064.140 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-16T21:34:24.143Z,1368740064.143 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-16T21:34:24.148Z,1368740064.148 [WetLabsBB2FL](INFO): Thread ID is 9749
2013-05-16T21:34:24.149Z,1368740064.149 [WetLabsBB2FL](INFO): Powering down
2013-05-16T21:34:24.187Z,1368740064.187 [NavChartDb](INFO): Thread ID is 9750
2013-05-16T21:34:24.190Z,1368740064.190 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-16T21:34:24.191Z,1368740064.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-16T21:34:24.191Z,1368740064.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-16T21:34:24.191Z,1368740064.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-16T21:34:24.191Z,1368740064.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-16T21:34:24.192Z,1368740064.192 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-16T21:34:24.192Z,1368740064.192 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-16T21:34:24.192Z,1368740064.192 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-16T21:34:24.192Z,1368740064.193 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-16T21:34:25.886Z,1368740065.886 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-16T21:34:25.917Z,1368740065.917 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-16T21:34:25.939Z,1368740065.939 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T21:34:25.957Z,1368740065.957 [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-05-16T21:34:25.957Z,1368740065.957 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-16T21:34:26.058Z,1368740066.058 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-16T21:34:26.088Z,1368740066.088 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-16T21:34:26.100Z,1368740066.100 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T21:34:26.120Z,1368740066.120 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-16T21:34:26.123Z,1368740066.123 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T21:34:26.130Z,1368740066.130 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-16T21:34:26.150Z,1368740066.150 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-16T21:34:26.153Z,1368740066.153 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T21:34:26.179Z,1368740066.179 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:26.179Z,1368740066.179 [DVL_micro](INFO): Querying output modes
2013-05-16T21:34:26.179Z,1368740066.179 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:34:26.186Z,1368740066.186 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-16T21:34:26.190Z,1368740066.190 [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-05-16T21:34:26.191Z,1368740066.191 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-05-16T21:34:26.191Z,1368740066.191 [DVL_micro](INFO): NQ1 output enabled
2013-05-16T21:34:26.191Z,1368740066.191 [DVL_micro](INFO): RSSI output enabled
2013-05-16T21:34:26.191Z,1368740066.191 [DVL_micro](INFO): ADCP output enabled
2013-05-16T21:34:26.191Z,1368740066.191 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:34:26.203Z,1368740066.203 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-05-16T21:34:26.207Z,1368740066.207 [DVL_micro](INFO): pause:Powering down
2013-05-16T21:34:26.213Z,1368740066.213 [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-05-16T21:34:26.278Z,1368740066.277 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-16T21:34:26.315Z,1368740066.315 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar
2013-05-16T21:34:26.429Z,1368740066.429 [Radio_Freewave](INFO): Powering up
2013-05-16T21:34:26.438Z,1368740066.438 [DAT](INFO): Powering up
2013-05-16T21:34:26.438Z,1368740066.438 [DAT](DEBUG): Initializing DAT.
2013-05-16T21:34:26.640Z,1368740066.640 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:26.646Z,1368740066.647 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-16T21:34:26.653Z,1368740066.653 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:26.675Z,1368740066.675 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-16T21:34:26.688Z,1368740066.688 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:26.695Z,1368740066.695 [MassServo](DEBUG): Initializing MassServo.
2013-05-16T21:34:26.701Z,1368740066.701 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:26.706Z,1368740066.707 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-16T21:34:26.722Z,1368740066.722 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:26.730Z,1368740066.730 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-16T21:34:26.755Z,1368740066.755 [CBIT](DEBUG): Uninitialize CBIT Component.
2013-05-16T21:34:27.566Z,1368740067.566 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-05-16T21:34:27.566Z,1368740067.566 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-05-16T21:34:27.567Z,1368740067.566 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-05-16T21:34:27.567Z,1368740067.567 [AHRS_sp3003D](ERROR): Hardware Fault
2013-05-16T21:34:27.823Z,1368740067.823 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:34:27.823Z,1368740067.823 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:34:27.823Z,1368740067.823 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:27.824Z,1368740067.824 [DVL_micro](INFO): resume:Powering up
2013-05-16T21:34:27.824Z,1368740067.824 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:34:28.166Z,1368740068.166 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2013-05-16T21:34:28.167Z,1368740068.167 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2013-05-16T21:34:28.167Z,1368740068.167 [BuoyancyServo] Communications Fault, FailCount= 1
2013-05-16T21:34:28.167Z,1368740068.167 [BuoyancyServo](ERROR): Communications Fault
2013-05-16T21:34:28.679Z,1368740068.679 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2013-05-16T21:34:28.679Z,1368740068.679 [ElevatorServo](FAULT): Elevator failed to initialize
2013-05-16T21:34:28.679Z,1368740068.679 [ElevatorServo] Communications Fault, FailCount= 1
2013-05-16T21:34:28.679Z,1368740068.679 [ElevatorServo](ERROR): Communications Fault
2013-05-16T21:34:29.186Z,1368740069.186 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2013-05-16T21:34:29.186Z,1368740069.186 [RudderServo](FAULT): Rudder failed to initialize
2013-05-16T21:34:29.186Z,1368740069.187 [RudderServo] Communications Fault, FailCount= 1
2013-05-16T21:34:29.186Z,1368740069.187 [RudderServo](ERROR): Communications Fault
2013-05-16T21:34:29.710Z,1368740069.710 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2013-05-16T21:34:29.831Z,1368740069.831 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:29.831Z,1368740069.831 [DVL_micro](INFO): Querying output modes
2013-05-16T21:34:29.831Z,1368740069.831 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:34:30.226Z,1368740070.226 [ThrusterServo](ERROR): Thruster initialization uart error serial timeout
2013-05-16T21:34:30.226Z,1368740070.226 [ThrusterServo](FAULT): Thruster failed to initialize
2013-05-16T21:34:30.226Z,1368740070.226 [ThrusterServo] Communications Fault, FailCount= 1
2013-05-16T21:34:30.227Z,1368740070.227 [ThrusterServo](ERROR): Communications Fault
2013-05-16T21:34:30.344Z,1368740070.344 [AHRS_sp3003D](INFO): Powering down
2013-05-16T21:34:30.597Z,1368740070.597 [NAL9602](INFO): Powering up NAL9602
2013-05-16T21:34:30.649Z,1368740070.649 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-05-16T21:34:30.654Z,1368740070.654 [BuoyancyServo](INFO): Powering down
2013-05-16T21:34:30.739Z,1368740070.739 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-05-16T21:34:30.739Z,1368740070.739 [ElevatorServo](INFO): Powering down
2013-05-16T21:34:31.298Z,1368740071.298 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2013-05-16T21:34:31.298Z,1368740071.298 [MassServo] Communications Fault, FailCount= 1
2013-05-16T21:34:31.299Z,1368740071.299 [MassServo](ERROR): Communications Fault
2013-05-16T21:34:31.299Z,1368740071.299 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-05-16T21:34:31.299Z,1368740071.299 [RudderServo](INFO): Powering down
2013-05-16T21:34:31.323Z,1368740071.323 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-05-16T21:34:31.323Z,1368740071.323 [ThrusterServo](INFO): Powering down
2013-05-16T21:34:31.623Z,1368740071.623 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-05-16T21:34:31.623Z,1368740071.623 [MassServo](INFO): Powering down
2013-05-16T21:34:31.842Z,1368740071.842 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:31.842Z,1368740071.842 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:34:31.842Z,1368740071.842 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:34:31.957Z,1368740071.957 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:32.073Z,1368740072.073 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-16T21:34:32.075Z,1368740072.075 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-16T21:34:32.195Z,1368740072.195 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-16T21:34:33.846Z,1368740073.846 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:33.848Z,1368740073.848 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:34:33.848Z,1368740073.848 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:34:33.848Z,1368740073.848 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:34:35.855Z,1368740075.855 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:35.855Z,1368740075.855 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:34:37.859Z,1368740077.859 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:37.860Z,1368740077.860 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:34:37.860Z,1368740077.860 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:34:39.601Z,1368740079.601 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-16T21:34:39.862Z,1368740079.862 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:39.862Z,1368740079.862 [DVL_micro](INFO): Querying output modes
2013-05-16T21:34:39.863Z,1368740079.863 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:34:41.870Z,1368740081.870 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:41.870Z,1368740081.870 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:34:41.871Z,1368740081.871 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:34:43.218Z,1368740083.218 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-05-16T21:34:43.219Z,1368740083.218 [NAL9602] Communications Fault, FailCount= 1
2013-05-16T21:34:43.219Z,1368740083.219 [NAL9602](ERROR): Communications Fault
2013-05-16T21:34:43.432Z,1368740083.432 [NAL9602](INFO): Powering down
2013-05-16T21:34:43.879Z,1368740083.879 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:45.887Z,1368740085.887 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:34:45.887Z,1368740085.887 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:34:45.887Z,1368740085.887 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:34:46.038Z,1368740086.038 [DAT](INFO): Init failed - response: 
2013-05-16T21:34:46.038Z,1368740086.038 [DAT](FAULT): DAT failed to initialize
2013-05-16T21:34:46.038Z,1368740086.039 [DAT] Communications Fault, FailCount= 1
2013-05-16T21:34:46.039Z,1368740086.039 [DAT](ERROR): Communications Fault
2013-05-16T21:34:46.221Z,1368740086.221 [DAT](INFO): Powering down
2013-05-16T21:34:47.895Z,1368740087.895 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:47.895Z,1368740087.895 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:34:49.902Z,1368740089.902 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:49.902Z,1368740089.902 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:34:49.902Z,1368740089.902 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:34:51.906Z,1368740091.906 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:51.906Z,1368740091.906 [DVL_micro](INFO): Querying output modes
2013-05-16T21:34:51.907Z,1368740091.907 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:34:53.725Z,1368740093.725 [Radio_Freewave](INFO): Powering down
2013-05-16T21:34:53.918Z,1368740093.918 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:53.919Z,1368740093.918 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:34:53.919Z,1368740093.919 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:34:55.926Z,1368740095.926 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:34:57.931Z,1368740097.931 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:34:57.931Z,1368740097.931 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:34:57.931Z,1368740097.931 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:34:59.939Z,1368740099.939 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:34:59.939Z,1368740099.939 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:35:01.950Z,1368740101.950 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:01.950Z,1368740101.950 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:35:01.951Z,1368740101.951 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:35:02.495Z,1368740102.495 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-05-16T21:35:02.495Z,1368740102.495 [DropWeight] Hardware Fault, FailCount= 1
2013-05-16T21:35:02.495Z,1368740102.495 [DropWeight](ERROR): Hardware Fault
2013-05-16T21:35:03.962Z,1368740103.962 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:03.962Z,1368740103.962 [DVL_micro](INFO): Querying output modes
2013-05-16T21:35:03.962Z,1368740103.963 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:35:05.970Z,1368740105.970 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:05.970Z,1368740105.970 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:35:05.970Z,1368740105.970 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:35:07.978Z,1368740107.978 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:09.987Z,1368740109.987 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:35:09.987Z,1368740109.987 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:35:09.987Z,1368740109.987 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:35:11.995Z,1368740111.995 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:35:11.995Z,1368740111.995 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:35:14.002Z,1368740114.002 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:14.002Z,1368740114.002 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:35:14.002Z,1368740114.003 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:35:16.006Z,1368740116.006 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:16.006Z,1368740116.006 [DVL_micro](INFO): Querying output modes
2013-05-16T21:35:16.007Z,1368740116.007 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:35:18.010Z,1368740118.010 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:18.010Z,1368740118.010 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:35:18.010Z,1368740118.010 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:35:20.022Z,1368740120.022 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:22.035Z,1368740122.035 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:35:22.035Z,1368740122.035 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:35:22.035Z,1368740122.035 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:35:24.043Z,1368740124.043 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:35:24.043Z,1368740124.043 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:35:26.050Z,1368740126.050 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:26.050Z,1368740126.050 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:35:26.051Z,1368740126.050 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:35:28.054Z,1368740128.054 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:28.054Z,1368740128.054 [DVL_micro](INFO): Querying output modes
2013-05-16T21:35:28.054Z,1368740128.055 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:35:30.062Z,1368740130.062 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:30.062Z,1368740130.062 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:35:30.062Z,1368740130.062 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:35:32.074Z,1368740132.074 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:33.711Z,1368740133.711 [SBIT](IMPORTANT): SBIT PASSED
2013-05-16T21:35:34.093Z,1368740134.093 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:35:34.093Z,1368740134.093 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:35:34.093Z,1368740134.093 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:35:34.111Z,1368740134.111 [MissionManager](IMPORTANT): Started mission Startup
2013-05-16T21:35:34.111Z,1368740134.111 [Startup] Running Loop=1
2013-05-16T21:35:34.111Z,1368740134.111 [Startup](INFO): Aggregate::initialize Startup
2013-05-16T21:35:34.111Z,1368740134.111 [Startup:A.GoToSurface] Running Loop=1
2013-05-16T21:35:34.111Z,1368740134.111 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T21:35:36.103Z,1368740136.103 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:35:36.103Z,1368740136.103 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:35:38.114Z,1368740138.114 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:38.114Z,1368740138.114 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:35:38.115Z,1368740138.115 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:35:40.118Z,1368740140.118 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:40.119Z,1368740140.118 [DVL_micro](INFO): Querying output modes
2013-05-16T21:35:40.119Z,1368740140.119 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:35:42.130Z,1368740142.130 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:42.130Z,1368740142.130 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:35:42.131Z,1368740142.131 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:35:44.142Z,1368740144.142 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:46.155Z,1368740146.155 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:35:46.155Z,1368740146.155 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:35:46.155Z,1368740146.155 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:35:48.163Z,1368740148.163 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:35:48.163Z,1368740148.163 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:35:50.171Z,1368740150.171 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:50.172Z,1368740150.172 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:35:50.172Z,1368740150.172 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:35:52.175Z,1368740152.175 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:52.175Z,1368740152.175 [DVL_micro](INFO): Querying output modes
2013-05-16T21:35:52.175Z,1368740152.175 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:35:54.182Z,1368740154.182 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:54.182Z,1368740154.182 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:35:54.183Z,1368740154.182 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:35:56.194Z,1368740156.194 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:35:58.207Z,1368740158.207 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:35:58.207Z,1368740158.207 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:35:58.207Z,1368740158.207 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:36:00.215Z,1368740160.215 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:36:00.215Z,1368740160.215 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:36:02.218Z,1368740162.218 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:02.218Z,1368740162.218 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:36:02.219Z,1368740162.218 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:36:04.226Z,1368740164.226 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:04.226Z,1368740164.226 [DVL_micro](INFO): Querying output modes
2013-05-16T21:36:04.227Z,1368740164.227 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:36:06.230Z,1368740166.230 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:06.230Z,1368740166.230 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:36:06.230Z,1368740166.230 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:36:08.242Z,1368740168.242 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:10.247Z,1368740170.247 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:36:10.247Z,1368740170.247 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:36:10.247Z,1368740170.247 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:36:12.255Z,1368740172.255 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:36:12.255Z,1368740172.255 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:36:14.266Z,1368740174.266 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:14.266Z,1368740174.266 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:36:14.266Z,1368740174.266 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:36:16.270Z,1368740176.270 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:16.270Z,1368740176.270 [DVL_micro](INFO): Querying output modes
2013-05-16T21:36:16.271Z,1368740176.270 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:36:18.282Z,1368740178.282 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:18.282Z,1368740178.282 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:36:18.282Z,1368740178.283 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:36:20.290Z,1368740180.290 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:22.291Z,1368740182.291 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:36:22.291Z,1368740182.291 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:36:22.291Z,1368740182.291 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:36:24.299Z,1368740184.299 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:36:24.299Z,1368740184.299 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:36:26.306Z,1368740186.306 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:26.306Z,1368740186.306 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:36:26.306Z,1368740186.306 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:36:28.314Z,1368740188.314 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:28.314Z,1368740188.314 [DVL_micro](INFO): Querying output modes
2013-05-16T21:36:28.315Z,1368740188.315 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:36:30.318Z,1368740190.318 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:30.318Z,1368740190.318 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:36:30.319Z,1368740190.319 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:36:32.326Z,1368740192.326 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:34.339Z,1368740194.339 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:36:34.339Z,1368740194.339 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:36:34.339Z,1368740194.339 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:36:36.347Z,1368740196.347 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:36:36.347Z,1368740196.347 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:36:38.350Z,1368740198.350 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:38.350Z,1368740198.350 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:36:38.350Z,1368740198.351 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:36:40.354Z,1368740200.354 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:40.354Z,1368740200.354 [DVL_micro](INFO): Querying output modes
2013-05-16T21:36:40.354Z,1368740200.355 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:36:42.362Z,1368740202.362 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:42.362Z,1368740202.362 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:36:42.363Z,1368740202.362 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:36:44.374Z,1368740204.374 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:46.387Z,1368740206.387 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:36:46.387Z,1368740206.387 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:36:46.387Z,1368740206.387 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:36:48.394Z,1368740208.395 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:36:48.395Z,1368740208.395 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:36:50.398Z,1368740210.398 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:50.398Z,1368740210.398 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:36:50.398Z,1368740210.398 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:36:52.402Z,1368740212.402 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:52.402Z,1368740212.402 [DVL_micro](INFO): Querying output modes
2013-05-16T21:36:52.403Z,1368740212.402 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:36:54.410Z,1368740214.410 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:54.410Z,1368740214.410 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:36:54.410Z,1368740214.411 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:36:56.422Z,1368740216.422 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:36:58.435Z,1368740218.435 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:36:58.435Z,1368740218.435 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:36:58.435Z,1368740218.435 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:37:00.443Z,1368740220.443 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:37:00.443Z,1368740220.443 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:37:02.450Z,1368740222.450 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:02.450Z,1368740222.450 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:37:02.451Z,1368740222.451 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:37:04.458Z,1368740224.458 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:04.458Z,1368740224.458 [DVL_micro](INFO): Querying output modes
2013-05-16T21:37:04.458Z,1368740224.458 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:37:06.474Z,1368740226.474 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:06.474Z,1368740226.474 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:37:06.475Z,1368740226.474 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:37:08.493Z,1368740228.493 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:10.495Z,1368740230.495 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:37:10.495Z,1368740230.495 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:37:10.495Z,1368740230.495 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:37:12.503Z,1368740232.503 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:37:12.503Z,1368740232.503 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:37:14.506Z,1368740234.506 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:14.506Z,1368740234.506 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:37:14.507Z,1368740234.507 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:37:16.518Z,1368740236.518 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:16.518Z,1368740236.519 [DVL_micro](INFO): Querying output modes
2013-05-16T21:37:16.519Z,1368740236.519 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:37:18.530Z,1368740238.530 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:18.530Z,1368740238.530 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:37:18.531Z,1368740238.531 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:37:20.542Z,1368740240.542 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:22.555Z,1368740242.555 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:37:22.555Z,1368740242.555 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:37:22.555Z,1368740242.555 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:37:24.563Z,1368740244.563 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:37:24.563Z,1368740244.563 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:37:26.566Z,1368740246.566 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:26.566Z,1368740246.566 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:37:26.567Z,1368740246.567 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:37:28.582Z,1368740248.582 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:28.582Z,1368740248.582 [DVL_micro](INFO): Querying output modes
2013-05-16T21:37:28.582Z,1368740248.582 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:37:30.594Z,1368740250.594 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:30.594Z,1368740250.594 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:37:30.595Z,1368740250.595 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:37:32.598Z,1368740252.598 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:34.607Z,1368740254.607 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:37:34.607Z,1368740254.607 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:37:34.607Z,1368740254.607 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:37:36.615Z,1368740256.615 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:37:36.615Z,1368740256.615 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:37:38.618Z,1368740258.618 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:38.618Z,1368740258.618 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:37:38.618Z,1368740258.618 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:37:40.630Z,1368740260.630 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:40.630Z,1368740260.630 [DVL_micro](INFO): Querying output modes
2013-05-16T21:37:40.631Z,1368740260.631 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:37:42.642Z,1368740262.642 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:42.642Z,1368740262.642 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:37:42.643Z,1368740262.643 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:37:44.646Z,1368740264.646 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:46.655Z,1368740266.655 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:37:46.655Z,1368740266.655 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:37:46.655Z,1368740266.655 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:37:48.675Z,1368740268.675 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:37:48.675Z,1368740268.675 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:37:50.678Z,1368740270.678 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:50.678Z,1368740270.678 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:37:50.678Z,1368740270.678 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-05-16T21:37:52.690Z,1368740272.690 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:52.690Z,1368740272.690 [DVL_micro](INFO): Querying output modes
2013-05-16T21:37:52.691Z,1368740272.691 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T21:37:54.702Z,1368740274.702 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:54.702Z,1368740274.702 [DVL_micro](INFO): Output Modes: No Response
2013-05-16T21:37:54.702Z,1368740274.703 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T21:37:56.714Z,1368740276.714 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:37:58.719Z,1368740278.719 [DVL_micro](INFO): RSSI unrequested
2013-05-16T21:37:58.719Z,1368740278.719 [DVL_micro](INFO): ADCP unrequested
2013-05-16T21:37:58.719Z,1368740278.719 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T21:38:00.727Z,1368740280.727 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T21:38:00.727Z,1368740280.727 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-05-16T21:38:02.738Z,1368740282.738 [DVL_micro](DEBUG): cmdResponse: 
2013-05-16T21:38:02.738Z,1368740282.738 [DVL_micro](INFO): Enabling NQ1 output
2013-05-16T21:38:02.738Z,1368740282.739 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1