2013-09-14T20:42:43.873Z,1379191363.873 [Supervisor](DEBUG): Initializing supervisor.
2013-09-14T20:42:43.875Z,1379191363.875 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-09-14T20:42:43.876Z,1379191363.876 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-09-14T20:42:43.877Z,1379191363.877 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-09-14T20:42:43.882Z,1379191363.882 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-09-14T20:42:43.894Z,1379191363.894 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-09-14T20:42:43.895Z,1379191363.895 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-09-14T20:42:43.896Z,1379191363.896 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-09-14T20:42:43.897Z,1379191363.897 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-09-14T20:42:43.897Z,1379191363.897 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-09-14T20:42:43.899Z,1379191363.899 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-09-14T20:42:44.217Z,1379191364.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-09-14T20:42:44.218Z,1379191364.218 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-09-14T20:42:44.417Z,1379191364.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-09-14T20:42:44.418Z,1379191364.418 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-09-14T20:42:44.576Z,1379191364.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-09-14T20:42:44.577Z,1379191364.577 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-09-14T20:42:44.690Z,1379191364.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-09-14T20:42:44.691Z,1379191364.691 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-09-14T20:42:44.921Z,1379191364.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-09-14T20:42:44.922Z,1379191364.922 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-09-14T20:42:45.256Z,1379191365.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-09-14T20:42:45.256Z,1379191365.256 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-09-14T20:42:45.451Z,1379191365.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-09-14T20:42:45.451Z,1379191365.451 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-09-14T20:42:45.825Z,1379191365.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-09-14T20:42:45.826Z,1379191365.826 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-09-14T20:42:45.971Z,1379191365.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-09-14T20:42:45.972Z,1379191365.972 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-09-14T20:42:46.578Z,1379191366.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-09-14T20:42:46.578Z,1379191366.578 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-09-14T20:42:46.702Z,1379191366.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-09-14T20:42:46.703Z,1379191366.703 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-09-14T20:42:46.831Z,1379191366.831 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-09-14T20:42:46.831Z,1379191366.831 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-09-14T20:42:46.965Z,1379191366.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-09-14T20:42:47.116Z,1379191367.116 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-09-14T20:42:47.268Z,1379191367.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-09-14T20:42:47.393Z,1379191367.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-09-14T20:42:47.515Z,1379191367.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-09-14T20:42:47.681Z,1379191367.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-09-14T20:42:47.801Z,1379191367.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-09-14T20:42:47.911Z,1379191367.911 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2013-09-14T20:42:47.912Z,1379191367.912 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-09-14T20:42:47.913Z,1379191367.913 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-09-14T20:42:48.144Z,1379191368.144 [InternalSim] Loaded
2013-09-14T20:42:48.144Z,1379191368.144 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-09-14T20:42:48.145Z,1379191368.145 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-09-14T20:42:48.145Z,1379191368.145 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-09-14T20:42:48.242Z,1379191368.242 [SBIT](DEBUG): Construct Startup Built In Test.
2013-09-14T20:42:48.291Z,1379191368.291 [SBIT] Loaded
2013-09-14T20:42:48.292Z,1379191368.292 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-09-14T20:42:48.292Z,1379191368.292 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-09-14T20:42:48.343Z,1379191368.343 [IBIT] Loaded
2013-09-14T20:42:48.343Z,1379191368.343 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-09-14T20:42:48.345Z,1379191368.345 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-09-14T20:42:48.516Z,1379191368.516 [CBIT] Loaded
2013-09-14T20:42:48.517Z,1379191368.517 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-09-14T20:42:48.517Z,1379191368.517 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-09-14T20:42:48.518Z,1379191368.518 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-09-14T20:42:48.702Z,1379191368.702 [BuoyancyServo] Loaded
2013-09-14T20:42:48.702Z,1379191368.702 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-09-14T20:42:48.716Z,1379191368.716 [ElevatorServo] Loaded
2013-09-14T20:42:48.716Z,1379191368.716 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-09-14T20:42:48.729Z,1379191368.729 [MassServo] Loaded
2013-09-14T20:42:48.729Z,1379191368.729 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-09-14T20:42:48.744Z,1379191368.744 [RudderServo] Loaded
2013-09-14T20:42:48.744Z,1379191368.744 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-09-14T20:42:48.756Z,1379191368.756 [ThrusterServo] Loaded
2013-09-14T20:42:48.757Z,1379191368.757 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-09-14T20:42:48.757Z,1379191368.757 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-09-14T20:42:48.758Z,1379191368.758 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-09-14T20:42:48.821Z,1379191368.821 [DepthRateCalculator] Loaded
2013-09-14T20:42:48.821Z,1379191368.821 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-09-14T20:42:53.067Z,1379191373.067 [HFRadarModelCalc] Loaded
2013-09-14T20:42:53.068Z,1379191373.068 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-09-14T20:42:53.087Z,1379191373.087 [NavChart] Loaded
2013-09-14T20:42:53.087Z,1379191373.087 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-09-14T20:42:53.093Z,1379191373.093 [PitchRateCalculator] Loaded
2013-09-14T20:42:53.093Z,1379191373.093 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-09-14T20:42:53.104Z,1379191373.104 [SpeedCalculator] Loaded
2013-09-14T20:42:53.105Z,1379191373.105 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-09-14T20:42:53.122Z,1379191373.122 [TempGradientCalculator] Loaded
2013-09-14T20:42:53.123Z,1379191373.123 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-09-14T20:42:53.129Z,1379191373.129 [YawRateCalculator] Loaded
2013-09-14T20:42:53.129Z,1379191373.129 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-09-14T20:42:53.180Z,1379191373.180 [Navigation] Loaded
2013-09-14T20:42:53.180Z,1379191373.180 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-09-14T20:42:53.181Z,1379191373.181 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-09-14T20:42:53.181Z,1379191373.181 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-09-14T20:42:53.430Z,1379191373.430 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-09-14T20:42:53.431Z,1379191373.431 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-09-14T20:42:53.454Z,1379191373.454 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-09-14T20:42:53.455Z,1379191373.455 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-09-14T20:42:53.506Z,1379191373.506 [VerticalControl](DEBUG): Construct VerticalControl.
2013-09-14T20:42:53.695Z,1379191373.695 [VerticalControl] Loaded
2013-09-14T20:42:53.695Z,1379191373.695 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-09-14T20:42:53.696Z,1379191373.696 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-09-14T20:42:53.764Z,1379191373.764 [HorizontalControl] Loaded
2013-09-14T20:42:53.765Z,1379191373.765 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-09-14T20:42:53.765Z,1379191373.765 [SpeedControl](DEBUG): Construct SpeedControl.
2013-09-14T20:42:53.767Z,1379191373.767 [SpeedControl] Loaded
2013-09-14T20:42:53.767Z,1379191373.767 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-09-14T20:42:53.768Z,1379191373.768 [LoopControl](DEBUG): Construct LoopControl.
2013-09-14T20:42:53.769Z,1379191373.769 [LoopControl] Loaded
2013-09-14T20:42:53.769Z,1379191373.769 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-09-14T20:42:53.769Z,1379191373.769 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-09-14T20:42:53.770Z,1379191373.770 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-09-14T20:42:53.776Z,1379191373.776 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-09-14T20:42:53.781Z,1379191373.781 [AsyncPiEstimator] Loaded
2013-09-14T20:42:53.781Z,1379191373.781 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-09-14T20:42:53.782Z,1379191373.782 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0
2013-09-14T20:42:53.783Z,1379191373.783 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-09-14T20:42:53.784Z,1379191373.784 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-09-14T20:42:54.087Z,1379191374.087 [AHRS_sp3003D] Loaded
2013-09-14T20:42:54.087Z,1379191374.087 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-09-14T20:42:54.430Z,1379191374.430 [Batt_Ocean_Server] Loaded
2013-09-14T20:42:54.430Z,1379191374.430 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-09-14T20:42:54.465Z,1379191374.465 [Depth_Keller] Loaded
2013-09-14T20:42:54.465Z,1379191374.465 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-09-14T20:42:54.470Z,1379191374.470 [DropWeight] Loaded
2013-09-14T20:42:54.470Z,1379191374.470 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-09-14T20:42:54.713Z,1379191374.713 [DVL_micro] Loaded
2013-09-14T20:42:54.713Z,1379191374.713 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-09-14T20:42:54.715Z,1379191374.715 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D54E0
2013-09-14T20:42:54.830Z,1379191374.830 [NAL9602] Loaded
2013-09-14T20:42:54.830Z,1379191374.830 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-09-14T20:42:54.895Z,1379191374.895 [Onboard] Loaded
2013-09-14T20:42:54.895Z,1379191374.895 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-09-14T20:42:54.902Z,1379191374.902 [Radio_Freewave] Loaded
2013-09-14T20:42:54.903Z,1379191374.903 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-09-14T20:42:55.111Z,1379191375.111 [DAT] Loaded
2013-09-14T20:42:55.111Z,1379191375.111 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-09-14T20:42:55.112Z,1379191375.112 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-09-14T20:42:55.112Z,1379191375.112 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-09-14T20:42:55.197Z,1379191375.197 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-09-14T20:42:55.200Z,1379191375.200 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-09-14T20:42:55.201Z,1379191375.201 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-09-14T20:42:55.208Z,1379191375.208 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-09-14T20:42:55.209Z,1379191375.209 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407324E0
2013-09-14T20:42:55.213Z,1379191375.213 [Supervisor](DEBUG): Running supervisor.
2013-09-14T20:42:55.214Z,1379191375.214 [CommandLine](INFO): Thread ID is 862
2013-09-14T20:42:55.219Z,1379191375.219 [controlThread](INFO): Thread ID is 861
2013-09-14T20:42:55.219Z,1379191375.219 [controlThread](DEBUG): Initializing ControlThread
2013-09-14T20:42:55.219Z,1379191375.219 [CycleStarter](INFO): Thread ID is 860
2013-09-14T20:42:55.220Z,1379191375.220 [InternalSim](DEBUG):  InternalSim initializing...
2013-09-14T20:42:55.265Z,1379191375.265 [logger](INFO): Thread ID is 863
2013-09-14T20:42:55.291Z,1379191375.291 [AsyncPiEstimator](INFO): Thread ID is 925
2013-09-14T20:42:55.291Z,1379191375.291 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-09-14T20:42:55.306Z,1379191375.306 [SBIT](INFO): Initialize SBIT Component.
2013-09-14T20:42:55.311Z,1379191375.311 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:10573
2013-09-14T20:42:55.312Z,1379191375.312 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-09-14T20:42:55.312Z,1379191375.312 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-09-14T20:42:55.313Z,1379191375.313 [IBIT](INFO): Initialize IBIT Component.
2013-09-14T20:42:55.315Z,1379191375.315 [DVL_micro](INFO): Thread ID is 926
2013-09-14T20:42:55.325Z,1379191375.325 [DVL_micro](INFO): Initializing
2013-09-14T20:42:55.325Z,1379191375.325 [DVL_micro](INFO): start:Powering up
2013-09-14T20:42:55.326Z,1379191375.326 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:42:55.327Z,1379191375.327 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:42:55.336Z,1379191375.336 [CBIT](DEBUG): Initialize CBIT Component.
2013-09-14T20:42:55.336Z,1379191375.336 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-09-14T20:42:55.336Z,1379191375.336 [CBIT](CRITICAL): Watchdog Timer failed to initialize.
2013-09-14T20:42:55.336Z,1379191375.336 [CBIT] Hardware Fault, FailCount= 1
2013-09-14T20:42:55.336Z,1379191375.336 [CBIT](ERROR): Hardware Fault
2013-09-14T20:42:55.343Z,1379191375.343 [NavChartDb](INFO): Thread ID is 927
2013-09-14T20:42:55.345Z,1379191375.345 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-09-14T20:42:55.347Z,1379191375.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-09-14T20:42:55.347Z,1379191375.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-09-14T20:42:55.347Z,1379191375.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-09-14T20:42:55.347Z,1379191375.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-09-14T20:42:55.348Z,1379191375.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-09-14T20:42:55.348Z,1379191375.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-09-14T20:42:55.348Z,1379191375.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-09-14T20:42:55.348Z,1379191375.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-09-14T20:42:55.372Z,1379191375.372 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-09-14T20:42:55.372Z,1379191375.372 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-09-14T20:42:55.373Z,1379191375.373 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-09-14T20:42:55.373Z,1379191375.373 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-09-14T20:42:55.373Z,1379191375.373 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-09-14T20:42:55.374Z,1379191375.374 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-09-14T20:42:55.375Z,1379191375.375 [Navigation](DEBUG): Initializing Navigation.
2013-09-14T20:42:55.375Z,1379191375.375 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-09-14T20:42:55.377Z,1379191375.377 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-09-14T20:42:55.377Z,1379191375.377 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-09-14T20:42:55.378Z,1379191375.378 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-09-14T20:42:57.426Z,1379191377.426 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:42:57.426Z,1379191377.426 [DVL_micro](INFO): Querying output modes
2013-09-14T20:42:57.426Z,1379191377.426 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:42:57.438Z,1379191377.438 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-09-14T20:42:57.438Z,1379191377.438 [DVL_micro](INFO): NQ1 output enabled
2013-09-14T20:42:57.438Z,1379191377.438 [DVL_micro](INFO): RSSI output enabled
2013-09-14T20:42:57.438Z,1379191377.438 [DVL_micro](INFO): ADCP output enabled
2013-09-14T20:42:57.438Z,1379191377.438 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:42:57.450Z,1379191377.450 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-09-14T20:42:57.455Z,1379191377.455 [DVL_micro](INFO): pause:Powering down
2013-09-14T20:43:01.952Z,1379191381.952 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-09-14T20:43:01.952Z,1379191381.952 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-09-14T20:43:01.952Z,1379191381.952 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2013-09-14T20:43:01.953Z,1379191381.953 [Batt_Ocean_Server](ERROR): Communications Fault
2013-09-14T20:43:01.964Z,1379191381.964 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-09-14T20:43:01.994Z,1379191381.994 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T20:43:02.028Z,1379191382.028 [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-14T20:43:02.033Z,1379191382.033 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-09-14T20:43:02.115Z,1379191382.115 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-09-14T20:43:02.121Z,1379191382.121 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-09-14T20:43:02.124Z,1379191382.124 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T20:43:02.144Z,1379191382.144 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-09-14T20:43:02.147Z,1379191382.147 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T20:43:02.166Z,1379191382.166 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-09-14T20:43:02.208Z,1379191382.208 [Default:D.SetSpeed](DEBUG): Construct.
2013-09-14T20:43:02.211Z,1379191382.211 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-09-14T20:43:02.238Z,1379191382.238 [Default:F.Wait](DEBUG): Construct Wait.
2013-09-14T20:43:02.241Z,1379191382.241 [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-14T20:43:02.246Z,1379191382.246 [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-14T20:43:02.337Z,1379191382.337 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-09-14T20:43:02.499Z,1379191382.499 [NAL9602](INFO): Powering up NAL9602
2013-09-14T20:43:02.661Z,1379191382.661 [Radio_Freewave](INFO): Powering up
2013-09-14T20:43:02.698Z,1379191382.698 [DAT](INFO): Powering up
2013-09-14T20:43:02.699Z,1379191382.699 [DAT](DEBUG): Initializing DAT.
2013-09-14T20:43:03.057Z,1379191383.057 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:03.082Z,1379191383.082 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-09-14T20:43:03.105Z,1379191383.105 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:03.118Z,1379191383.118 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-14T20:43:03.128Z,1379191383.128 [MassServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:03.135Z,1379191383.135 [MassServo](DEBUG): Initializing MassServo.
2013-09-14T20:43:03.152Z,1379191383.152 [RudderServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:03.159Z,1379191383.159 [RudderServo](DEBUG): Initializing RudderServo.
2013-09-14T20:43:03.213Z,1379191383.213 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:03.219Z,1379191383.219 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-09-14T20:43:03.252Z,1379191383.252 [CBIT](DEBUG): Uninitialize CBIT Component.
2013-09-14T20:43:03.791Z,1379191383.791 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-09-14T20:43:03.792Z,1379191383.792 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-09-14T20:43:03.792Z,1379191383.792 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-09-14T20:43:03.792Z,1379191383.792 [AHRS_sp3003D](ERROR): Hardware Fault
2013-09-14T20:43:03.920Z,1379191383.920 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:03.920Z,1379191383.920 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:03.920Z,1379191383.920 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:03.921Z,1379191383.921 [DVL_micro](INFO): resume:Powering up
2013-09-14T20:43:03.921Z,1379191383.921 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:43:04.488Z,1379191384.488 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2013-09-14T20:43:04.489Z,1379191384.489 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2013-09-14T20:43:04.489Z,1379191384.489 [BuoyancyServo] Communications Fault, FailCount= 1
2013-09-14T20:43:04.489Z,1379191384.489 [BuoyancyServo](ERROR): Communications Fault
2013-09-14T20:43:05.001Z,1379191385.001 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2013-09-14T20:43:05.001Z,1379191385.001 [ElevatorServo](FAULT): Elevator failed to initialize
2013-09-14T20:43:05.001Z,1379191385.001 [ElevatorServo] Communications Fault, FailCount= 1
2013-09-14T20:43:05.001Z,1379191385.001 [ElevatorServo](ERROR): Communications Fault
2013-09-14T20:43:05.538Z,1379191385.538 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2013-09-14T20:43:05.538Z,1379191385.538 [RudderServo](FAULT): Rudder failed to initialize
2013-09-14T20:43:05.538Z,1379191385.538 [RudderServo] Communications Fault, FailCount= 1
2013-09-14T20:43:05.538Z,1379191385.538 [RudderServo](ERROR): Communications Fault
2013-09-14T20:43:05.927Z,1379191385.927 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:05.927Z,1379191385.927 [DVL_micro](INFO): Querying output modes
2013-09-14T20:43:05.927Z,1379191385.927 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:43:06.059Z,1379191386.059 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2013-09-14T20:43:06.575Z,1379191386.575 [ThrusterServo](ERROR): Thruster initialization uart error serial timeout
2013-09-14T20:43:06.576Z,1379191386.576 [ThrusterServo](FAULT): Thruster failed to initialize
2013-09-14T20:43:06.576Z,1379191386.576 [ThrusterServo] Communications Fault, FailCount= 1
2013-09-14T20:43:06.576Z,1379191386.576 [ThrusterServo](ERROR): Communications Fault
2013-09-14T20:43:06.821Z,1379191386.821 [AHRS_sp3003D](INFO): Powering down
2013-09-14T20:43:06.971Z,1379191386.971 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-09-14T20:43:06.977Z,1379191386.977 [BuoyancyServo](INFO): Powering down
2013-09-14T20:43:07.125Z,1379191387.125 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-09-14T20:43:07.125Z,1379191387.125 [ElevatorServo](INFO): Powering down
2013-09-14T20:43:07.694Z,1379191387.694 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2013-09-14T20:43:07.694Z,1379191387.694 [MassServo] Communications Fault, FailCount= 1
2013-09-14T20:43:07.694Z,1379191387.694 [MassServo](ERROR): Communications Fault
2013-09-14T20:43:07.694Z,1379191387.694 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-09-14T20:43:07.695Z,1379191387.695 [RudderServo](INFO): Powering down
2013-09-14T20:43:07.723Z,1379191387.723 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-09-14T20:43:07.723Z,1379191387.723 [ThrusterServo](INFO): Powering down
2013-09-14T20:43:07.938Z,1379191387.938 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:07.938Z,1379191387.938 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:43:07.938Z,1379191387.938 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:43:08.057Z,1379191388.057 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-09-14T20:43:08.057Z,1379191388.057 [MassServo](INFO): Powering down
2013-09-14T20:43:08.348Z,1379191388.348 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:08.467Z,1379191388.467 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-09-14T20:43:08.469Z,1379191388.469 [RudderServo](DEBUG): Initializing EZServoServo.
2013-09-14T20:43:08.592Z,1379191388.592 [RudderServo](DEBUG): Initializing RudderServo.
2013-09-14T20:43:09.941Z,1379191389.941 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:09.942Z,1379191389.942 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:09.943Z,1379191389.943 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:09.943Z,1379191389.943 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:43:10.821Z,1379191390.821 [SBIT](IMPORTANT): Beginning Startup BIT
2013-09-14T20:43:11.948Z,1379191391.948 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:11.948Z,1379191391.948 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T20:43:13.961Z,1379191393.961 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:13.961Z,1379191393.961 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T20:43:13.962Z,1379191393.962 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T20:43:15.153Z,1379191395.153 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-09-14T20:43:15.153Z,1379191395.153 [NAL9602] Communications Fault, FailCount= 1
2013-09-14T20:43:15.153Z,1379191395.153 [NAL9602](ERROR): Communications Fault
2013-09-14T20:43:15.482Z,1379191395.482 [Depth_Keller](INFO): A/D timeout, 6 tries over 140 ms

2013-09-14T20:43:15.482Z,1379191395.482 [Depth_Keller] Data Fault, FailCount= 1
2013-09-14T20:43:15.482Z,1379191395.482 [Depth_Keller](ERROR): Data Fault
2013-09-14T20:43:15.484Z,1379191395.484 [NAL9602](INFO): Powering down
2013-09-14T20:43:15.974Z,1379191395.974 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:15.974Z,1379191395.974 [DVL_micro](INFO): Querying output modes
2013-09-14T20:43:15.975Z,1379191395.975 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:43:17.977Z,1379191397.977 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:17.978Z,1379191397.978 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:43:17.978Z,1379191397.978 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:43:19.988Z,1379191399.988 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:21.990Z,1379191401.990 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:21.990Z,1379191401.990 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:21.990Z,1379191401.990 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:43:22.180Z,1379191402.180 [DAT](INFO): Init failed - response: 
2013-09-14T20:43:22.180Z,1379191402.180 [DAT](FAULT): DAT failed to initialize
2013-09-14T20:43:22.180Z,1379191402.180 [DAT] Communications Fault, FailCount= 1
2013-09-14T20:43:22.180Z,1379191402.180 [DAT](ERROR): Communications Fault
2013-09-14T20:43:22.283Z,1379191402.283 [DAT](INFO): Powering down
2013-09-14T20:43:23.995Z,1379191403.995 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:23.995Z,1379191403.995 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T20:43:25.997Z,1379191405.997 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:25.998Z,1379191405.998 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T20:43:25.998Z,1379191405.998 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

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

2013-09-14T20:43:30.016Z,1379191410.016 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:30.016Z,1379191410.016 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:43:30.016Z,1379191410.016 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:43:32.027Z,1379191412.027 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:34.032Z,1379191414.032 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:34.032Z,1379191414.032 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:34.032Z,1379191414.032 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:43:36.038Z,1379191416.038 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:36.038Z,1379191416.038 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

2013-09-14T20:43:42.062Z,1379191422.062 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:42.063Z,1379191422.063 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:43:42.063Z,1379191422.063 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:43:44.065Z,1379191424.065 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:46.076Z,1379191426.076 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:46.076Z,1379191426.076 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:46.076Z,1379191426.076 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:43:48.080Z,1379191428.080 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:43:48.080Z,1379191428.080 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

2013-09-14T20:43:54.101Z,1379191434.101 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:54.101Z,1379191434.101 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:43:54.102Z,1379191434.102 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:43:56.104Z,1379191436.104 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:43:58.116Z,1379191438.116 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:43:58.116Z,1379191438.116 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:43:58.116Z,1379191438.116 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:44:00.119Z,1379191440.119 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:44:00.119Z,1379191440.119 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

2013-09-14T20:44:04.712Z,1379191444.712 [SBIT](IMPORTANT): SBIT PASSED
2013-09-14T20:44:05.080Z,1379191445.080 [MissionManager](IMPORTANT): Started mission Startup
2013-09-14T20:44:05.080Z,1379191445.080 [Startup] Running Loop=1
2013-09-14T20:44:05.080Z,1379191445.080 [Startup](INFO): Aggregate::initialize Startup
2013-09-14T20:44:05.080Z,1379191445.080 [Startup:A.GoToSurface] Running Loop=1
2013-09-14T20:44:05.081Z,1379191445.081 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-14T20:44:05.119Z,1379191445.119 [Startup:StartupSatComms] Running Loop=1
2013-09-14T20:44:05.120Z,1379191445.120 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-09-14T20:44:05.120Z,1379191445.120 [Startup:StartupSatComms:A] Running Loop=1
2013-09-14T20:44:05.505Z,1379191445.505 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-14T20:44:06.160Z,1379191446.160 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:06.160Z,1379191446.160 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:44:06.160Z,1379191446.160 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:44:08.167Z,1379191448.167 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:10.175Z,1379191450.175 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:44:10.175Z,1379191450.175 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:44:10.175Z,1379191450.175 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:44:12.177Z,1379191452.177 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:44:12.178Z,1379191452.178 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T20:44:14.184Z,1379191454.184 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:14.185Z,1379191454.185 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T20:44:14.185Z,1379191454.185 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T20:44:16.195Z,1379191456.195 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:16.196Z,1379191456.196 [DVL_micro](INFO): Querying output modes
2013-09-14T20:44:16.196Z,1379191456.196 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

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

2013-09-14T20:44:20.206Z,1379191460.206 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:22.210Z,1379191462.210 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:44:22.210Z,1379191462.210 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:44:22.210Z,1379191462.210 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:44:24.212Z,1379191464.212 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:44:24.213Z,1379191464.213 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

2013-09-14T20:44:28.246Z,1379191468.246 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:28.247Z,1379191468.247 [DVL_micro](INFO): Querying output modes
2013-09-14T20:44:28.247Z,1379191468.247 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

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

2013-09-14T20:44:32.265Z,1379191472.265 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:34.268Z,1379191474.268 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:44:34.269Z,1379191474.269 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:44:34.269Z,1379191474.269 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:44:36.271Z,1379191476.271 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:44:36.271Z,1379191476.271 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

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

2013-09-14T20:44:44.303Z,1379191484.303 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:46.315Z,1379191486.315 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:44:46.315Z,1379191486.315 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:44:46.315Z,1379191486.315 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:44:48.318Z,1379191488.318 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:44:48.318Z,1379191488.318 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

2013-09-14T20:44:52.327Z,1379191492.327 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:52.328Z,1379191492.328 [DVL_micro](INFO): Querying output modes
2013-09-14T20:44:52.328Z,1379191492.328 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

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

2013-09-14T20:44:56.338Z,1379191496.338 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:44:58.341Z,1379191498.341 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:44:58.341Z,1379191498.341 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:44:58.342Z,1379191498.342 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:45:00.344Z,1379191500.344 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:45:00.345Z,1379191500.345 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

2013-09-14T20:45:05.473Z,1379191505.473 [Startup:StartupSatComms:A](INFO): Timed out from 2013-09-14T20:44:05.1Z
2013-09-14T20:45:05.473Z,1379191505.473 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-09-14T20:45:05.473Z,1379191505.473 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-09-14T20:45:05.474Z,1379191505.474 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-09-14T20:45:05.474Z,1379191505.474 [Startup:StartupSatComms:A] Stopped
2013-09-14T20:45:05.474Z,1379191505.474 [Startup:StartupSatComms:B] Running Loop=1
2013-09-14T20:45:05.870Z,1379191505.870 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-14T20:45:06.366Z,1379191506.366 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:06.366Z,1379191506.366 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:45:06.366Z,1379191506.366 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:45:08.390Z,1379191508.390 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:10.393Z,1379191510.393 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:45:10.393Z,1379191510.393 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:45:10.393Z,1379191510.393 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:45:12.399Z,1379191512.399 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:45:12.399Z,1379191512.399 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

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

2013-09-14T20:45:20.439Z,1379191520.439 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:22.447Z,1379191522.447 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:45:22.447Z,1379191522.447 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:45:22.447Z,1379191522.447 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:45:24.454Z,1379191524.454 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:45:24.454Z,1379191524.454 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-09-14T20:45:26.456Z,1379191526.456 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:26.457Z,1379191526.457 [DVL_micro](INFO): Enabling NQ1 output
2013-09-14T20:45:26.457Z,1379191526.457 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-09-14T20:45:28.463Z,1379191528.463 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:28.464Z,1379191528.464 [DVL_micro](INFO): Querying output modes
2013-09-14T20:45:28.464Z,1379191528.464 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

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

2013-09-14T20:45:32.491Z,1379191532.491 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:34.502Z,1379191534.502 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:45:34.502Z,1379191534.502 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:45:34.502Z,1379191534.502 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:45:36.504Z,1379191536.504 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:45:36.505Z,1379191536.505 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

2013-09-14T20:45:40.518Z,1379191540.518 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:40.518Z,1379191540.518 [DVL_micro](INFO): Querying output modes
2013-09-14T20:45:40.519Z,1379191540.519 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:45:42.525Z,1379191542.525 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:42.526Z,1379191542.526 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:45:42.526Z,1379191542.526 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:45:44.533Z,1379191544.533 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:46.536Z,1379191546.536 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:45:46.536Z,1379191546.536 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:45:46.536Z,1379191546.536 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:45:48.539Z,1379191548.539 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:45:48.539Z,1379191548.539 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

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

2013-09-14T20:45:56.568Z,1379191556.568 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:45:58.571Z,1379191558.571 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:45:58.571Z,1379191558.571 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:45:58.571Z,1379191558.571 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:46:00.573Z,1379191560.573 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:46:00.574Z,1379191560.574 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

2013-09-14T20:46:04.583Z,1379191564.583 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:04.584Z,1379191564.584 [DVL_micro](INFO): Querying output modes
2013-09-14T20:46:04.584Z,1379191564.584 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms:B](INFO): Timed out from 2013-09-14T20:45:05.5Z
2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms:B] Stopped
2013-09-14T20:46:05.855Z,1379191565.855 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-09-14T20:46:05.856Z,1379191565.856 [Startup:StartupSatComms] Stopped
2013-09-14T20:46:05.856Z,1379191565.856 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-09-14T20:46:05.856Z,1379191565.856 [Startup](INFO): Completed Startup
2013-09-14T20:46:05.857Z,1379191565.857 [Startup] Stopped
2013-09-14T20:46:05.857Z,1379191565.857 [Startup](INFO): Aggregate::uninitialize Startup
2013-09-14T20:46:05.857Z,1379191565.857 [Startup:A.GoToSurface] Stopped
2013-09-14T20:46:05.857Z,1379191565.857 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-14T20:46:06.263Z,1379191566.263 [MissionManager](IMPORTANT): Started mission Default
2013-09-14T20:46:06.263Z,1379191566.263 [Default] Running Loop=1
2013-09-14T20:46:06.264Z,1379191566.264 [Default](INFO): Aggregate::initialize Default
2013-09-14T20:46:06.264Z,1379191566.264 [Default:D.SetSpeed] Running Loop=1
2013-09-14T20:46:06.264Z,1379191566.264 [Default:D.SetSpeed](DEBUG): Initialize.
2013-09-14T20:46:06.264Z,1379191566.264 [Default:E.GoToSurface] Running Loop=1
2013-09-14T20:46:06.264Z,1379191566.264 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-14T20:46:06.264Z,1379191566.264 [Default:Iridium] Running Loop=1
2013-09-14T20:46:06.264Z,1379191566.264 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-09-14T20:46:06.264Z,1379191566.264 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-14T20:46:06.264Z,1379191566.264 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-09-14T20:46:06.265Z,1379191566.265 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-09-14T20:46:06.265Z,1379191566.265 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-14T20:46:06.265Z,1379191566.265 [Default:E.GoToSurface] Running Loop=1
2013-09-14T20:46:06.273Z,1379191566.273 [Default:D.SetSpeed] Running Loop=1
2013-09-14T20:46:06.279Z,1379191566.279 [Default:CallIridium] Running Loop=1
2013-09-14T20:46:06.279Z,1379191566.279 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-09-14T20:46:06.279Z,1379191566.279 [Default:CallIridium:A] Running Loop=1
2013-09-14T20:46:06.281Z,1379191566.281 [Default:CallIridium:A] Stopped
2013-09-14T20:46:06.281Z,1379191566.281 [Default:CallIridium:B] Running Loop=1
2013-09-14T20:46:06.281Z,1379191566.281 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-09-14T20:46:06.307Z,1379191566.307 [Default:Iridium:B.GoToSurface] Stopped
2013-09-14T20:46:06.308Z,1379191566.307 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-14T20:46:06.308Z,1379191566.308 [Default:Iridium:Read_Iridium] Running Loop=1
2013-09-14T20:46:06.308Z,1379191566.308 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-09-14T20:46:06.336Z,1379191566.336 [Default:GPS] Running Loop=1
2013-09-14T20:46:06.337Z,1379191566.337 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-09-14T20:46:06.337Z,1379191566.337 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-14T20:46:06.337Z,1379191566.337 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-09-14T20:46:06.337Z,1379191566.337 [Default:GPS:B.GoToSurface] Running Loop=1
2013-09-14T20:46:06.337Z,1379191566.337 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-09-14T20:46:06.345Z,1379191566.345 [Default:GPS:B.GoToSurface] Stopped
2013-09-14T20:46:06.345Z,1379191566.345 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-09-14T20:46:06.345Z,1379191566.345 [Default:GPS:Read_GPS] Running Loop=1
2013-09-14T20:46:06.345Z,1379191566.345 [Default:GPS:A.SetSpeed] Running Loop=1
2013-09-14T20:46:06.591Z,1379191566.591 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:06.591Z,1379191566.591 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:46:06.591Z,1379191566.591 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:46:06.657Z,1379191566.657 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-09-14T20:46:06.660Z,1379191566.660 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-09-14T20:46:08.594Z,1379191568.594 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:10.597Z,1379191570.597 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:46:10.598Z,1379191570.598 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:46:10.598Z,1379191570.598 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:46:12.600Z,1379191572.600 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:46:12.601Z,1379191572.601 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

2013-09-14T20:46:18.629Z,1379191578.629 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:18.630Z,1379191578.630 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:46:18.630Z,1379191578.630 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-09-14T20:46:20.648Z,1379191580.648 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:22.652Z,1379191582.652 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:46:22.652Z,1379191582.652 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:46:22.652Z,1379191582.652 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:46:24.655Z,1379191584.655 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:46:24.655Z,1379191584.655 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

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

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

2013-09-14T20:46:32.707Z,1379191592.707 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:34.715Z,1379191594.715 [DVL_micro](INFO): RSSI unrequested
2013-09-14T20:46:34.715Z,1379191594.715 [DVL_micro](INFO): ADCP unrequested
2013-09-14T20:46:34.715Z,1379191594.715 [DVL_micro](INFO): Cycling power to configure device.
2013-09-14T20:46:36.717Z,1379191596.717 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-09-14T20:46:36.718Z,1379191596.718 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

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

2013-09-14T20:46:40.731Z,1379191600.731 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:40.732Z,1379191600.732 [DVL_micro](INFO): Querying output modes
2013-09-14T20:46:40.732Z,1379191600.732 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-09-14T20:46:42.735Z,1379191602.735 [DVL_micro](DEBUG): cmdResponse: 
2013-09-14T20:46:42.735Z,1379191602.735 [DVL_micro](INFO): Output Modes: No Response
2013-09-14T20:46:42.735Z,137919160