2013-03-11T23:00:17.550Z,1363042817.550 [Supervisor](DEBUG): Initializing supervisor.
2013-03-11T23:00:17.553Z,1363042817.553 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-03-11T23:00:17.553Z,1363042817.553 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-03-11T23:00:17.554Z,1363042817.554 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-03-11T23:00:17.558Z,1363042817.558 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-03-11T23:00:17.569Z,1363042817.569 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-03-11T23:00:17.570Z,1363042817.570 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-03-11T23:00:17.571Z,1363042817.571 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-03-11T23:00:17.572Z,1363042817.572 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-03-11T23:00:17.572Z,1363042817.572 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-03-11T23:00:17.573Z,1363042817.573 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-03-11T23:00:17.857Z,1363042817.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-03-11T23:00:17.857Z,1363042817.857 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-03-11T23:00:18.046Z,1363042818.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-03-11T23:00:18.046Z,1363042818.046 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-03-11T23:00:18.130Z,1363042818.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-03-11T23:00:18.131Z,1363042818.131 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-03-11T23:00:18.316Z,1363042818.316 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-03-11T23:00:18.316Z,1363042818.316 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-03-11T23:00:18.449Z,1363042818.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-03-11T23:00:18.450Z,1363042818.450 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-03-11T23:00:18.684Z,1363042818.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-03-11T23:00:18.684Z,1363042818.684 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-03-11T23:00:18.854Z,1363042818.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-03-11T23:00:18.854Z,1363042818.854 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-03-11T23:00:19.109Z,1363042819.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-03-11T23:00:19.109Z,1363042819.109 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-03-11T23:00:19.207Z,1363042819.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-03-11T23:00:19.208Z,1363042819.208 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-03-11T23:00:19.609Z,1363042819.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-03-11T23:00:19.609Z,1363042819.609 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-03-11T23:00:19.722Z,1363042819.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-03-11T23:00:19.723Z,1363042819.723 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-03-11T23:00:19.808Z,1363042819.807 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-03-11T23:00:19.808Z,1363042819.808 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-03-11T23:00:19.909Z,1363042819.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-03-11T23:00:20.038Z,1363042820.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-03-11T23:00:20.123Z,1363042820.123 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-03-11T23:00:20.224Z,1363042820.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-03-11T23:00:20.323Z,1363042820.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-03-11T23:00:20.441Z,1363042820.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-03-11T23:00:20.535Z,1363042820.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-03-11T23:00:20.620Z,1363042820.620 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-03-11T23:00:20.644Z,1363042820.644 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-03-11T23:00:20.800Z,1363042820.800 [InternalSim] Loaded
2013-03-11T23:00:20.800Z,1363042820.800 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-03-11T23:00:20.801Z,1363042820.801 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-03-11T23:00:20.801Z,1363042820.801 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-03-11T23:00:20.859Z,1363042820.859 [SBIT](DEBUG): Construct Startup Built In Test.
2013-03-11T23:00:20.887Z,1363042820.887 [SBIT] Loaded
2013-03-11T23:00:20.887Z,1363042820.887 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-03-11T23:00:20.888Z,1363042820.888 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-03-11T23:00:20.917Z,1363042820.917 [IBIT] Loaded
2013-03-11T23:00:20.917Z,1363042820.917 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-03-11T23:00:20.920Z,1363042820.920 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-03-11T23:00:21.037Z,1363042821.037 [CBIT] Loaded
2013-03-11T23:00:21.037Z,1363042821.037 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-03-11T23:00:21.038Z,1363042821.038 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-03-11T23:00:21.038Z,1363042821.038 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-03-11T23:00:21.188Z,1363042821.188 [BuoyancyServo] Loaded
2013-03-11T23:00:21.189Z,1363042821.189 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-03-11T23:00:21.201Z,1363042821.201 [ElevatorServo] Loaded
2013-03-11T23:00:21.201Z,1363042821.201 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-03-11T23:00:21.213Z,1363042821.213 [MassServo] Loaded
2013-03-11T23:00:21.213Z,1363042821.213 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-03-11T23:00:21.225Z,1363042821.225 [RudderServo] Loaded
2013-03-11T23:00:21.226Z,1363042821.226 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-03-11T23:00:21.237Z,1363042821.237 [ThrusterServo] Loaded
2013-03-11T23:00:21.238Z,1363042821.238 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-03-11T23:00:21.238Z,1363042821.238 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-03-11T23:00:21.239Z,1363042821.239 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-03-11T23:00:21.256Z,1363042821.256 [DepthRateCalculator] Loaded
2013-03-11T23:00:21.256Z,1363042821.256 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-03-11T23:00:25.359Z,1363042825.359 [HFRadarModelCalc] Loaded
2013-03-11T23:00:25.359Z,1363042825.359 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-03-11T23:00:25.375Z,1363042825.375 [NavChart] Loaded
2013-03-11T23:00:25.375Z,1363042825.375 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-03-11T23:00:25.381Z,1363042825.381 [PitchRateCalculator] Loaded
2013-03-11T23:00:25.382Z,1363042825.382 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-03-11T23:00:25.388Z,1363042825.388 [SpeedCalculator] Loaded
2013-03-11T23:00:25.389Z,1363042825.388 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-03-11T23:00:25.403Z,1363042825.403 [TempGradientCalculator] Loaded
2013-03-11T23:00:25.404Z,1363042825.404 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-03-11T23:00:25.410Z,1363042825.409 [YawRateCalculator] Loaded
2013-03-11T23:00:25.410Z,1363042825.410 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-03-11T23:00:25.450Z,1363042825.450 [Navigation] Loaded
2013-03-11T23:00:25.450Z,1363042825.450 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-03-11T23:00:25.451Z,1363042825.451 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-03-11T23:00:25.451Z,1363042825.451 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-03-11T23:00:25.673Z,1363042825.673 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-03-11T23:00:25.674Z,1363042825.674 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-03-11T23:00:25.696Z,1363042825.696 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-03-11T23:00:25.697Z,1363042825.697 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-03-11T23:00:25.737Z,1363042825.737 [VerticalControl](DEBUG): Construct VerticalControl.
2013-03-11T23:00:25.831Z,1363042825.831 [VerticalControl] Loaded
2013-03-11T23:00:25.831Z,1363042825.831 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-03-11T23:00:25.832Z,1363042825.832 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-03-11T23:00:25.888Z,1363042825.888 [HorizontalControl] Loaded
2013-03-11T23:00:25.889Z,1363042825.889 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-03-11T23:00:25.890Z,1363042825.890 [SpeedControl](DEBUG): Construct SpeedControl.
2013-03-11T23:00:25.891Z,1363042825.891 [SpeedControl] Loaded
2013-03-11T23:00:25.892Z,1363042825.892 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-03-11T23:00:25.893Z,1363042825.893 [LoopControl](DEBUG): Construct LoopControl.
2013-03-11T23:00:25.893Z,1363042825.893 [LoopControl] Loaded
2013-03-11T23:00:25.893Z,1363042825.893 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-03-11T23:00:25.894Z,1363042825.894 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-03-11T23:00:25.895Z,1363042825.895 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-03-11T23:00:25.900Z,1363042825.900 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-03-11T23:00:25.905Z,1363042825.905 [AsyncPiEstimator] Loaded
2013-03-11T23:00:25.905Z,1363042825.905 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-03-11T23:00:25.906Z,1363042825.906 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0
2013-03-11T23:00:25.907Z,1363042825.907 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-03-11T23:00:25.907Z,1363042825.907 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-03-11T23:00:26.034Z,1363042826.034 [AHRS_sp3003D] Loaded
2013-03-11T23:00:26.034Z,1363042826.034 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-03-11T23:00:26.291Z,1363042826.291 [Batt_Ocean_Server] Loaded
2013-03-11T23:00:26.291Z,1363042826.291 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-03-11T23:00:26.304Z,1363042826.304 [Depth_Keller] Loaded
2013-03-11T23:00:26.305Z,1363042826.305 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-03-11T23:00:26.310Z,1363042826.310 [DropWeight] Loaded
2013-03-11T23:00:26.310Z,1363042826.310 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-03-11T23:00:26.484Z,1363042826.484 [DVL_micro] Loaded
2013-03-11T23:00:26.485Z,1363042826.485 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-03-11T23:00:26.486Z,1363042826.486 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0
2013-03-11T23:00:26.569Z,1363042826.569 [NAL9602] Loaded
2013-03-11T23:00:26.569Z,1363042826.569 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-03-11T23:00:26.620Z,1363042826.620 [Onboard] Loaded
2013-03-11T23:00:26.620Z,1363042826.620 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-03-11T23:00:26.627Z,1363042826.627 [Radio_Freewave] Loaded
2013-03-11T23:00:26.627Z,1363042826.627 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-03-11T23:00:26.628Z,1363042826.628 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-03-11T23:00:26.628Z,1363042826.628 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-03-11T23:00:26.684Z,1363042826.684 [Aanderaa_O2] Loaded
2013-03-11T23:00:26.685Z,1363042826.685 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2013-03-11T23:00:26.718Z,1363042826.718 [CTD_NeilBrown] Loaded
2013-03-11T23:00:26.718Z,1363042826.718 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-03-11T23:00:26.719Z,1363042826.719 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2013-03-11T23:00:26.736Z,1363042826.736 [PAR_Licor] Loaded
2013-03-11T23:00:26.736Z,1363042826.736 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2013-03-11T23:00:26.766Z,1363042826.766 [WetLabsBB2FL] Loaded
2013-03-11T23:00:26.767Z,1363042826.767 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-03-11T23:00:26.768Z,1363042826.768 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2013-03-11T23:00:26.768Z,1363042826.769 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-03-11T23:00:26.771Z,1363042826.771 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-03-11T23:00:26.772Z,1363042826.772 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-03-11T23:00:26.778Z,1363042826.778 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-03-11T23:00:26.779Z,1363042826.779 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2013-03-11T23:00:26.784Z,1363042826.784 [Supervisor](DEBUG): Running supervisor.
2013-03-11T23:00:26.785Z,1363042826.785 [CommandLine](INFO): Thread ID is 1336
2013-03-11T23:00:26.787Z,1363042826.787 [controlThread](INFO): Thread ID is 1335
2013-03-11T23:00:26.788Z,1363042826.788 [controlThread](DEBUG): Initializing ControlThread
2013-03-11T23:00:26.788Z,1363042826.788 [CycleStarter](INFO): Thread ID is 1334
2013-03-11T23:00:26.789Z,1363042826.789 [InternalSim](DEBUG):  InternalSim initializing...
2013-03-11T23:00:26.823Z,1363042826.823 [logger](INFO): Thread ID is 1337
2013-03-11T23:00:26.848Z,1363042826.848 [SBIT](INFO): Initialize SBIT Component.
2013-03-11T23:00:26.849Z,1363042826.849 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 10234
2013-03-11T23:00:26.849Z,1363042826.849 [IBIT](INFO): Initialize IBIT Component.
2013-03-11T23:00:26.850Z,1363042826.850 [CBIT](DEBUG): Initialize CBIT Component.
2013-03-11T23:00:26.850Z,1363042826.851 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-03-11T23:00:26.851Z,1363042826.851 [CBIT](CRITICAL): Watchdog Timer failed to initialize.
2013-03-11T23:00:26.851Z,1363042826.851 [CBIT] Hardware Fault, FailCount= 1
2013-03-11T23:00:26.851Z,1363042826.851 [CBIT](ERROR): Hardware Fault
2013-03-11T23:00:26.863Z,1363042826.863 [AsyncPiEstimator](INFO): Thread ID is 1398
2013-03-11T23:00:26.863Z,1363042826.864 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-03-11T23:00:26.876Z,1363042826.876 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-03-11T23:00:26.877Z,1363042826.876 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-03-11T23:00:26.877Z,1363042826.877 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-03-11T23:00:26.877Z,1363042826.877 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-03-11T23:00:26.877Z,1363042826.878 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-03-11T23:00:26.879Z,1363042826.879 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-03-11T23:00:26.879Z,1363042826.879 [Navigation](DEBUG): Initializing Navigation.
2013-03-11T23:00:26.880Z,1363042826.880 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-03-11T23:00:26.881Z,1363042826.881 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-03-11T23:00:26.882Z,1363042826.882 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-03-11T23:00:26.883Z,1363042826.883 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-03-11T23:00:26.888Z,1363042826.888 [DVL_micro](INFO): Thread ID is 1399
2013-03-11T23:00:26.898Z,1363042826.898 [DVL_micro](INFO): Initializing
2013-03-11T23:00:26.898Z,1363042826.898 [DVL_micro](INFO): start:Powering up
2013-03-11T23:00:26.899Z,1363042826.899 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:26.900Z,1363042826.900 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:00:26.912Z,1363042826.912 [CTD_NeilBrown](INFO): Thread ID is 1400
2013-03-11T23:00:26.912Z,1363042826.912 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-03-11T23:00:26.915Z,1363042826.915 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-03-11T23:00:26.924Z,1363042826.924 [WetLabsBB2FL](INFO): Thread ID is 1401
2013-03-11T23:00:26.924Z,1363042826.924 [WetLabsBB2FL](INFO): Powering down
2013-03-11T23:00:26.966Z,1363042826.966 [NavChartDb](INFO): Thread ID is 1402
2013-03-11T23:00:26.969Z,1363042826.969 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-03-11T23:00:26.970Z,1363042826.970 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-03-11T23:00:26.970Z,1363042826.970 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-03-11T23:00:26.971Z,1363042826.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-03-11T23:00:26.971Z,1363042826.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-03-11T23:00:26.971Z,1363042826.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-03-11T23:00:26.971Z,1363042826.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-03-11T23:00:26.972Z,1363042826.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-03-11T23:00:26.972Z,1363042826.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-03-11T23:00:28.494Z,1363042828.494 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-03-11T23:00:28.539Z,1363042828.539 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-03-11T23:00:28.572Z,1363042828.572 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-11T23:00:28.595Z,1363042828.595 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="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-03-11T23:00:28.596Z,1363042828.596 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-03-11T23:00:28.680Z,1363042828.680 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-03-11T23:00:28.682Z,1363042828.682 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-03-11T23:00:28.699Z,1363042828.699 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-11T23:00:28.723Z,1363042828.723 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-03-11T23:00:28.743Z,1363042828.743 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-11T23:00:28.757Z,1363042828.757 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-03-11T23:00:28.782Z,1363042828.782 [Default:D.SetSpeed](DEBUG): Construct.
2013-03-11T23:00:28.785Z,1363042828.785 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-03-11T23:00:28.802Z,1363042828.802 [Default:F.Wait](DEBUG): Construct Wait.
2013-03-11T23:00:28.805Z,1363042828.805 [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-03-11T23:00:28.810Z,1363042828.810 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-03-11T23:00:28.878Z,1363042828.878 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-03-11T23:00:28.971Z,1363042828.971 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:28.971Z,1363042828.971 [DVL_micro](INFO): Querying output modes
2013-03-11T23:00:28.972Z,1363042828.972 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:00:28.983Z,1363042828.983 [DVL_micro](DEBUG): cmdResponse: 01 03
2013-03-11T23:00:28.983Z,1363042828.983 [DVL_micro](INFO): NQ1 output enabled
2013-03-11T23:00:28.983Z,1363042828.983 [DVL_micro](INFO): ADCP output enabled
2013-03-11T23:00:28.983Z,1363042828.983 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:00:28.995Z,1363042828.995 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-03-11T23:00:28.999Z,1363042829.000 [DVL_micro](INFO): pause:Powering down
2013-03-11T23:00:29.063Z,1363042829.063 [Radio_Freewave](INFO): Powering up
2013-03-11T23:00:29.448Z,1363042829.448 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:29.455Z,1363042829.455 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-03-11T23:00:29.469Z,1363042829.469 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:29.475Z,1363042829.475 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-11T23:00:29.483Z,1363042829.483 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:29.491Z,1363042829.491 [MassServo](DEBUG): Initializing MassServo.
2013-03-11T23:00:29.497Z,1363042829.497 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:29.503Z,1363042829.503 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-11T23:00:29.509Z,1363042829.509 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:29.515Z,1363042829.515 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-03-11T23:00:29.575Z,1363042829.575 [CBIT](DEBUG): Uninitialize CBIT Component.
2013-03-11T23:00:29.799Z,1363042829.799 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2013-03-11T23:00:29.799Z,1363042829.799 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0xA609A0
2013-03-11T23:00:29.799Z,1363042829.799 [AHRS_sp3003D](ERROR): SP3003D failed to initialize
2013-03-11T23:00:29.799Z,1363042829.799 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2013-03-11T23:00:29.799Z,1363042829.799 [AHRS_sp3003D](ERROR): Hardware Fault
2013-03-11T23:00:29.807Z,1363042829.807 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:00:29.808Z,1363042829.808 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:29.808Z,1363042829.808 [DVL_micro](INFO): resume:Powering up
2013-03-11T23:00:29.808Z,1363042829.808 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:00:30.041Z,1363042830.041 [AHRS_sp3003D](INFO): Powering down
2013-03-11T23:00:30.759Z,1363042830.759 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2013-03-11T23:00:30.759Z,1363042830.759 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2013-03-11T23:00:30.759Z,1363042830.759 [BuoyancyServo] Communications Fault, FailCount= 1
2013-03-11T23:00:30.759Z,1363042830.759 [BuoyancyServo](ERROR): Communications Fault
2013-03-11T23:00:31.271Z,1363042831.270 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2013-03-11T23:00:31.271Z,1363042831.271 [ElevatorServo](FAULT): Elevator failed to initialize
2013-03-11T23:00:31.271Z,1363042831.271 [ElevatorServo] Communications Fault, FailCount= 1
2013-03-11T23:00:31.271Z,1363042831.271 [ElevatorServo](ERROR): Communications Fault
2013-03-11T23:00:31.779Z,1363042831.779 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2013-03-11T23:00:31.779Z,1363042831.779 [RudderServo](FAULT): Rudder failed to initialize
2013-03-11T23:00:31.779Z,1363042831.779 [RudderServo] Communications Fault, FailCount= 1
2013-03-11T23:00:31.779Z,1363042831.779 [RudderServo](ERROR): Communications Fault
2013-03-11T23:00:31.816Z,1363042831.816 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:31.816Z,1363042831.816 [DVL_micro](INFO): Querying output modes
2013-03-11T23:00:31.816Z,1363042831.816 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:00:32.299Z,1363042832.299 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2013-03-11T23:00:32.819Z,1363042832.819 [ThrusterServo](ERROR): Thruster initialization uart error serial timeout
2013-03-11T23:00:32.819Z,1363042832.819 [ThrusterServo](FAULT): Thruster failed to initialize
2013-03-11T23:00:32.819Z,1363042832.819 [ThrusterServo] Communications Fault, FailCount= 1
2013-03-11T23:00:32.819Z,1363042832.819 [ThrusterServo](ERROR): Communications Fault
2013-03-11T23:00:32.993Z,1363042832.993 [NAL9602](INFO): Powering up NAL9602
2013-03-11T23:00:33.063Z,1363042833.063 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-03-11T23:00:33.065Z,1363042833.065 [BuoyancyServo](INFO): Powering down
2013-03-11T23:00:33.140Z,1363042833.140 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-03-11T23:00:33.140Z,1363042833.140 [ElevatorServo](INFO): Powering down
2013-03-11T23:00:33.702Z,1363042833.703 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2013-03-11T23:00:33.703Z,1363042833.703 [MassServo] Communications Fault, FailCount= 1
2013-03-11T23:00:33.703Z,1363042833.703 [MassServo](ERROR): Communications Fault
2013-03-11T23:00:33.703Z,1363042833.703 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-03-11T23:00:33.703Z,1363042833.703 [RudderServo](INFO): Powering down
2013-03-11T23:00:33.744Z,1363042833.744 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-03-11T23:00:33.745Z,1363042833.745 [ThrusterServo](INFO): Powering down
2013-03-11T23:00:33.826Z,1363042833.826 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:33.827Z,1363042833.827 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:00:33.827Z,1363042833.827 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:00:34.009Z,1363042834.009 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-03-11T23:00:34.009Z,1363042834.009 [MassServo](INFO): Powering down
2013-03-11T23:00:34.282Z,1363042834.282 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:34.400Z,1363042834.399 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-03-11T23:00:34.401Z,1363042834.401 [RudderServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:34.520Z,1363042834.520 [RudderServo](DEBUG): Initializing RudderServo.
2013-03-11T23:00:34.697Z,1363042834.697 [MassServo](DEBUG): Initializing EZServoServo.
2013-03-11T23:00:34.812Z,1363042834.812 [MassServo](DEBUG): Initializing MassServo.
2013-03-11T23:00:35.839Z,1363042835.839 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:35.840Z,1363042835.840 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:00:35.840Z,1363042835.840 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:00:37.851Z,1363042837.851 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:37.851Z,1363042837.851 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:00:39.154Z,1363042839.154 [Aanderaa_O2](FAULT): Timed out starting
2013-03-11T23:00:39.154Z,1363042839.154 [Aanderaa_O2] Communications Fault, FailCount= 1
2013-03-11T23:00:39.154Z,1363042839.154 [Aanderaa_O2](ERROR): Communications Fault
2013-03-11T23:00:39.607Z,1363042839.607 [Aanderaa_O2](INFO): Powering down
2013-03-11T23:00:39.854Z,1363042839.855 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:39.855Z,1363042839.855 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:00:39.855Z,1363042839.855 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:00:41.869Z,1363042841.869 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:41.869Z,1363042841.869 [DVL_micro](INFO): Querying output modes
2013-03-11T23:00:41.869Z,1363042841.869 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:00:42.309Z,1363042842.309 [SBIT](IMPORTANT): Beginning Startup BIT
2013-03-11T23:00:43.874Z,1363042843.875 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:43.875Z,1363042843.875 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:00:43.875Z,1363042843.875 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:00:45.482Z,1363042845.483 [NAL9602](ERROR): NAL9602 initialize uart error: serial timeout
2013-03-11T23:00:45.483Z,1363042845.483 [NAL9602] Communications Fault, FailCount= 1
2013-03-11T23:00:45.483Z,1363042845.483 [NAL9602](ERROR): Communications Fault
2013-03-11T23:00:45.792Z,1363042845.792 [NAL9602](INFO): Powering down
2013-03-11T23:00:45.883Z,1363042845.883 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:47.891Z,1363042847.891 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:00:47.891Z,1363042847.891 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:00:49.899Z,1363042849.899 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:00:49.899Z,1363042849.899 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:00:51.906Z,1363042851.907 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:51.907Z,1363042851.907 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:00:51.907Z,1363042851.907 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:00:53.914Z,1363042853.914 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:53.915Z,1363042853.915 [DVL_micro](INFO): Querying output modes
2013-03-11T23:00:53.915Z,1363042853.915 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:00:55.927Z,1363042855.927 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:55.927Z,1363042855.927 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:00:55.927Z,1363042855.927 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:00:57.938Z,1363042857.938 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:00:59.951Z,1363042859.951 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:00:59.951Z,1363042859.951 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:01:01.959Z,1363042861.959 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:01:01.959Z,1363042861.959 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:01:03.967Z,1363042863.967 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:03.967Z,1363042863.967 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:01:03.967Z,1363042863.967 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:01:05.979Z,1363042865.979 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:05.979Z,1363042865.979 [DVL_micro](INFO): Querying output modes
2013-03-11T23:01:05.979Z,1363042865.979 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:01:07.991Z,1363042867.991 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:07.991Z,1363042867.991 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:01:07.991Z,1363042867.991 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:01:09.994Z,1363042869.994 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:12.003Z,1363042872.003 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:01:12.003Z,1363042872.003 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:01:14.011Z,1363042874.011 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:01:14.011Z,1363042874.011 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:01:16.014Z,1363042876.014 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:16.015Z,1363042876.015 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:01:16.015Z,1363042876.015 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:01:18.019Z,1363042878.019 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:18.019Z,1363042878.019 [DVL_micro](INFO): Querying output modes
2013-03-11T23:01:18.019Z,1363042878.019 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:01:20.027Z,1363042880.027 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:20.027Z,1363042880.027 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:01:20.027Z,1363042880.027 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:01:22.039Z,1363042882.039 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:24.041Z,1363042884.041 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:01:24.041Z,1363042884.041 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:01:26.047Z,1363042886.047 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:01:26.047Z,1363042886.047 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:01:28.051Z,1363042888.050 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:28.051Z,1363042888.051 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:01:28.051Z,1363042888.051 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:01:30.062Z,1363042890.062 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:30.063Z,1363042890.063 [DVL_micro](INFO): Querying output modes
2013-03-11T23:01:30.063Z,1363042890.063 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:01:32.075Z,1363042892.075 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:32.075Z,1363042892.075 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:01:32.075Z,1363042892.075 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:01:34.087Z,1363042894.087 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:36.099Z,1363042896.099 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:01:36.099Z,1363042896.099 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:01:36.421Z,1363042896.421 [SBIT](IMPORTANT): SBIT PASSED
2013-03-11T23:01:36.780Z,1363042896.780 [MissionManager](IMPORTANT): Started mission Startup
2013-03-11T23:01:36.780Z,1363042896.780 [Startup] Running Loop=1
2013-03-11T23:01:36.780Z,1363042896.780 [Startup](INFO): Aggregate::initialize Startup
2013-03-11T23:01:36.780Z,1363042896.780 [Startup:A.GoToSurface] Running Loop=1
2013-03-11T23:01:36.780Z,1363042896.780 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-11T23:01:36.786Z,1363042896.786 [Startup:StartupSatComms] Running Loop=1
2013-03-11T23:01:36.786Z,1363042896.786 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-03-11T23:01:36.786Z,1363042896.786 [Startup:StartupSatComms:A] Running Loop=1
2013-03-11T23:01:37.186Z,1363042897.186 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-11T23:01:38.107Z,1363042898.107 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:01:38.107Z,1363042898.107 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:01:40.111Z,1363042900.111 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:40.111Z,1363042900.111 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:01:40.111Z,1363042900.111 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:01:42.123Z,1363042902.122 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:42.123Z,1363042902.123 [DVL_micro](INFO): Querying output modes
2013-03-11T23:01:42.123Z,1363042902.123 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:01:44.134Z,1363042904.135 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:44.135Z,1363042904.135 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:01:44.135Z,1363042904.135 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:01:46.147Z,1363042906.147 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:48.159Z,1363042908.159 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:01:48.159Z,1363042908.159 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:01:50.167Z,1363042910.167 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:01:50.167Z,1363042910.167 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:01:52.170Z,1363042912.171 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:52.171Z,1363042912.171 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:01:52.171Z,1363042912.171 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:01:54.183Z,1363042914.182 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:54.183Z,1363042914.183 [DVL_micro](INFO): Querying output modes
2013-03-11T23:01:54.183Z,1363042914.183 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:01:56.194Z,1363042916.194 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:01:56.195Z,1363042916.195 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:01:56.195Z,1363042916.195 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:01:58.206Z,1363042918.207 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:00.219Z,1363042920.219 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:02:00.219Z,1363042920.219 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:02:02.227Z,1363042922.227 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:02:02.227Z,1363042922.227 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:02:04.230Z,1363042924.230 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:04.231Z,1363042924.231 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:02:04.231Z,1363042924.231 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:02:06.243Z,1363042926.243 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:06.243Z,1363042926.243 [DVL_micro](INFO): Querying output modes
2013-03-11T23:02:06.243Z,1363042926.243 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:02:08.255Z,1363042928.254 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:08.255Z,1363042928.255 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:02:08.255Z,1363042928.255 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:02:10.266Z,1363042930.266 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:12.279Z,1363042932.279 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:02:12.279Z,1363042932.279 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:02:14.287Z,1363042934.287 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:02:14.287Z,1363042934.287 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:02:16.290Z,1363042936.290 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:16.291Z,1363042936.291 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:02:16.291Z,1363042936.291 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:02:18.303Z,1363042938.303 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:18.303Z,1363042938.303 [DVL_micro](INFO): Querying output modes
2013-03-11T23:02:18.303Z,1363042938.303 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:02:20.315Z,1363042940.315 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:20.315Z,1363042940.315 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:02:20.315Z,1363042940.315 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:02:22.327Z,1363042942.327 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:24.328Z,1363042944.328 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:02:24.328Z,1363042944.328 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:02:26.335Z,1363042946.335 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:02:26.335Z,1363042946.335 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:02:28.338Z,1363042948.339 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:28.339Z,1363042948.339 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:02:28.339Z,1363042948.339 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:02:30.350Z,1363042950.351 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:30.351Z,1363042950.351 [DVL_micro](INFO): Querying output modes
2013-03-11T23:02:30.351Z,1363042950.351 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:02:32.365Z,1363042952.365 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:32.365Z,1363042952.365 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:02:32.365Z,1363042952.365 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:02:34.367Z,1363042954.367 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:36.379Z,1363042956.379 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:02:36.379Z,1363042956.379 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:02:37.189Z,1363042957.189 [Startup:StartupSatComms:A](INFO): Timed out from 2013-03-11T23:01:36.8Z
2013-03-11T23:02:37.190Z,1363042957.190 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-03-11T23:02:37.190Z,1363042957.190 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-03-11T23:02:37.190Z,1363042957.190 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-03-11T23:02:37.190Z,1363042957.190 [Startup:StartupSatComms:A] Stopped
2013-03-11T23:02:37.190Z,1363042957.190 [Startup:StartupSatComms:B] Running Loop=1
2013-03-11T23:02:37.586Z,1363042957.586 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-11T23:02:38.387Z,1363042958.387 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:02:38.387Z,1363042958.387 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:02:40.391Z,1363042960.391 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:40.391Z,1363042960.391 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:02:40.391Z,1363042960.391 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:02:42.398Z,1363042962.398 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:42.399Z,1363042962.399 [DVL_micro](INFO): Querying output modes
2013-03-11T23:02:42.399Z,1363042962.399 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:02:44.407Z,1363042964.407 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:44.407Z,1363042964.407 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:02:44.407Z,1363042964.407 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:02:46.414Z,1363042966.414 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:48.440Z,1363042968.440 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:02:48.440Z,1363042968.440 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:02:50.447Z,1363042970.447 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:02:50.447Z,1363042970.447 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:02:52.451Z,1363042972.451 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:52.451Z,1363042972.451 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:02:52.451Z,1363042972.451 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:02:54.463Z,1363042974.463 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:54.463Z,1363042974.463 [DVL_micro](INFO): Querying output modes
2013-03-11T23:02:54.463Z,1363042974.463 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:02:56.475Z,1363042976.474 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:02:56.475Z,1363042976.475 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:02:56.475Z,1363042976.475 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:02:58.486Z,1363042978.487 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:00.491Z,1363042980.491 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:03:00.491Z,1363042980.491 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:03:02.499Z,1363042982.499 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:03:02.499Z,1363042982.499 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:03:04.511Z,1363042984.510 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:04.511Z,1363042984.511 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:03:04.511Z,1363042984.511 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:03:06.522Z,1363042986.523 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:06.523Z,1363042986.523 [DVL_micro](INFO): Querying output modes
2013-03-11T23:03:06.523Z,1363042986.523 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:03:08.535Z,1363042988.534 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:08.535Z,1363042988.535 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:03:08.535Z,1363042988.535 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:03:10.547Z,1363042990.546 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:12.559Z,1363042992.559 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:03:12.559Z,1363042992.559 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:03:14.567Z,1363042994.567 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:03:14.567Z,1363042994.567 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:03:16.571Z,1363042996.570 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:16.571Z,1363042996.571 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:03:16.571Z,1363042996.571 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:03:18.582Z,1363042998.582 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:18.583Z,1363042998.583 [DVL_micro](INFO): Querying output modes
2013-03-11T23:03:18.583Z,1363042998.583 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:03:20.595Z,1363043000.595 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:20.595Z,1363043000.595 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:03:20.595Z,1363043000.595 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:03:22.607Z,1363043002.606 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:24.619Z,1363043004.619 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:03:24.619Z,1363043004.619 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:03:26.627Z,1363043006.627 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:03:26.627Z,1363043006.627 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:03:28.631Z,1363043008.631 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:28.631Z,1363043008.631 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:03:28.631Z,1363043008.631 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:03:30.642Z,1363043010.642 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:30.643Z,1363043010.643 [DVL_micro](INFO): Querying output modes
2013-03-11T23:03:30.643Z,1363043010.643 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:03:32.655Z,1363043012.655 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:32.655Z,1363043012.655 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:03:32.655Z,1363043012.655 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-03-11T23:03:34.666Z,1363043014.667 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:36.679Z,1363043016.679 [DVL_micro](INFO): ADCP unrequested
2013-03-11T23:03:36.679Z,1363043016.679 [DVL_micro](INFO): Cycling power to configure device.
2013-03-11T23:03:37.247Z,1363043017.247 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-11T23:02:37.2Z
2013-03-11T23:03:37.247Z,1363043017.247 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-03-11T23:03:37.247Z,1363043017.247 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-03-11T23:03:37.248Z,1363043017.248 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-03-11T23:03:37.248Z,1363043017.248 [Startup:StartupSatComms:B] Stopped
2013-03-11T23:03:37.248Z,1363043017.248 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-03-11T23:03:37.248Z,1363043017.248 [Startup:StartupSatComms] Stopped
2013-03-11T23:03:37.248Z,1363043017.248 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-03-11T23:03:37.249Z,1363043017.249 [Startup](INFO): Completed Startup
2013-03-11T23:03:37.249Z,1363043017.249 [Startup] Stopped
2013-03-11T23:03:37.249Z,1363043017.249 [Startup](INFO): Aggregate::uninitialize Startup
2013-03-11T23:03:37.249Z,1363043017.249 [Startup:A.GoToSurface] Stopped
2013-03-11T23:03:37.249Z,1363043017.249 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-11T23:03:37.589Z,1363043017.589 [MissionManager](IMPORTANT): Started mission Default
2013-03-11T23:03:37.589Z,1363043017.589 [Default] Running Loop=1
2013-03-11T23:03:37.589Z,1363043017.589 [Default](INFO): Aggregate::initialize Default
2013-03-11T23:03:37.589Z,1363043017.589 [Default:D.SetSpeed] Running Loop=1
2013-03-11T23:03:37.589Z,1363043017.589 [Default:D.SetSpeed](DEBUG): Initialize.
2013-03-11T23:03:37.589Z,1363043017.589 [Default:E.GoToSurface] Running Loop=1
2013-03-11T23:03:37.590Z,1363043017.589 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-11T23:03:37.590Z,1363043017.590 [Default:Iridium] Running Loop=1
2013-03-11T23:03:37.590Z,1363043017.590 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-03-11T23:03:37.590Z,1363043017.590 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-11T23:03:37.590Z,1363043017.590 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-03-11T23:03:37.590Z,1363043017.590 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-03-11T23:03:37.591Z,1363043017.591 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-11T23:03:37.591Z,1363043017.591 [Default:E.GoToSurface] Running Loop=1
2013-03-11T23:03:37.596Z,1363043017.596 [Default:D.SetSpeed] Running Loop=1
2013-03-11T23:03:37.601Z,1363043017.601 [Default:CallIridium] Running Loop=1
2013-03-11T23:03:37.601Z,1363043017.601 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-03-11T23:03:37.601Z,1363043017.601 [Default:CallIridium:A] Running Loop=1
2013-03-11T23:03:37.603Z,1363043017.603 [Default:CallIridium:A] Stopped
2013-03-11T23:03:37.603Z,1363043017.603 [Default:CallIridium:B] Running Loop=1
2013-03-11T23:03:37.604Z,1363043017.603 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-03-11T23:03:37.609Z,1363043017.609 [Default:Iridium:B.GoToSurface] Stopped
2013-03-11T23:03:37.609Z,1363043017.609 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-11T23:03:37.609Z,1363043017.609 [Default:Iridium:Read_Iridium] Running Loop=1
2013-03-11T23:03:37.609Z,1363043017.609 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS] Running Loop=1
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS:B.GoToSurface] Running Loop=1
2013-03-11T23:03:37.614Z,1363043017.614 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-03-11T23:03:37.619Z,1363043017.619 [Default:GPS:B.GoToSurface] Stopped
2013-03-11T23:03:37.620Z,1363043017.620 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-03-11T23:03:37.620Z,1363043017.620 [Default:GPS:Read_GPS] Running Loop=1
2013-03-11T23:03:37.620Z,1363043017.620 [Default:GPS:A.SetSpeed] Running Loop=1
2013-03-11T23:03:37.983Z,1363043017.983 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-03-11T23:03:37.985Z,1363043017.985 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-03-11T23:03:38.687Z,1363043018.687 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-03-11T23:03:38.687Z,1363043018.687 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0

2013-03-11T23:03:40.695Z,1363043020.694 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:40.695Z,1363043020.695 [DVL_micro](INFO): Enabling NQ1 output
2013-03-11T23:03:40.695Z,1363043020.695 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1

2013-03-11T23:03:42.702Z,1363043022.703 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:42.703Z,1363043022.703 [DVL_micro](INFO): Querying output modes
2013-03-11T23:03:42.703Z,1363043022.703 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-03-11T23:03:44.715Z,1363043024.715 [DVL_micro](DEBUG): cmdResponse: 
2013-03-11T23:03:44.715Z,1363043024.715 [DVL_micro](INFO): Output Modes: No Response
2013-03-11T23:03:44.715Z,1363043024.715 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525