2012-11-08T18:36:45.636Z,1352399805.636 [Supervisor](DEBUG): Initializing supervisor. 2012-11-08T18:36:45.642Z,1352399805.642 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2012-11-08T18:36:45.643Z,1352399805.643 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-11-08T18:36:45.646Z,1352399805.646 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2012-11-08T18:36:45.650Z,1352399805.650 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-11-08T18:36:45.662Z,1352399805.662 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-11-08T18:36:45.666Z,1352399805.666 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2012-11-08T18:36:45.667Z,1352399805.667 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2012-11-08T18:36:45.670Z,1352399805.670 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2012-11-08T18:36:45.671Z,1352399805.671 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-11-08T18:36:45.674Z,1352399805.674 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-11-08T18:36:46.011Z,1352399806.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-11-08T18:36:46.014Z,1352399806.014 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-11-08T18:36:46.227Z,1352399806.227 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-11-08T18:36:46.228Z,1352399806.228 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-11-08T18:36:46.326Z,1352399806.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-11-08T18:36:46.328Z,1352399806.328 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-11-08T18:36:46.567Z,1352399806.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-11-08T18:36:46.568Z,1352399806.568 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-11-08T18:36:46.728Z,1352399806.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-11-08T18:36:46.731Z,1352399806.731 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-11-08T18:36:47.006Z,1352399807.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-11-08T18:36:47.006Z,1352399807.006 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-11-08T18:36:47.206Z,1352399807.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-11-08T18:36:47.208Z,1352399807.208 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-11-08T18:36:47.512Z,1352399807.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-11-08T18:36:47.514Z,1352399807.514 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-11-08T18:36:47.631Z,1352399807.631 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-11-08T18:36:47.632Z,1352399807.632 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-11-08T18:36:48.123Z,1352399808.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-11-08T18:36:48.124Z,1352399808.124 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-11-08T18:36:48.274Z,1352399808.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-11-08T18:36:48.275Z,1352399808.274 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-11-08T18:36:48.371Z,1352399808.371 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-11-08T18:36:48.376Z,1352399808.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-11-08T18:36:48.491Z,1352399808.491 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-11-08T18:36:48.644Z,1352399808.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-11-08T18:36:48.742Z,1352399808.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-11-08T18:36:48.860Z,1352399808.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-11-08T18:36:48.974Z,1352399808.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-11-08T18:36:49.111Z,1352399809.111 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-11-08T18:36:49.220Z,1352399809.220 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-11-08T18:36:49.318Z,1352399809.318 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2012-11-08T18:36:49.352Z,1352399809.352 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-11-08T18:36:49.670Z,1352399809.670 [ExternalSim] Loaded 2012-11-08T18:36:49.670Z,1352399809.670 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread. 2012-11-08T18:36:49.731Z,1352399809.731 [InternalSim] Loaded 2012-11-08T18:36:49.732Z,1352399809.732 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-11-08T18:36:49.733Z,1352399809.733 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-11-08T18:36:49.733Z,1352399809.733 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-11-08T18:36:49.826Z,1352399809.826 [SBIT](DEBUG): Construct Startup Built In Test. 2012-11-08T18:36:49.840Z,1352399809.840 [SBIT] Loaded 2012-11-08T18:36:49.841Z,1352399809.841 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-11-08T18:36:49.842Z,1352399809.842 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-11-08T18:36:49.876Z,1352399809.876 [IBIT] Loaded 2012-11-08T18:36:49.877Z,1352399809.877 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-11-08T18:36:49.880Z,1352399809.880 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-11-08T18:36:50.019Z,1352399810.019 [CBIT] Loaded 2012-11-08T18:36:50.019Z,1352399810.019 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-11-08T18:36:50.020Z,1352399810.020 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-11-08T18:36:50.020Z,1352399810.020 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-11-08T18:36:50.196Z,1352399810.195 [BuoyancyServo] Loaded 2012-11-08T18:36:50.196Z,1352399810.196 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-11-08T18:36:50.205Z,1352399810.205 [ElevatorServo] Loaded 2012-11-08T18:36:50.205Z,1352399810.205 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2012-11-08T18:36:50.214Z,1352399810.214 [MassServo] Loaded 2012-11-08T18:36:50.215Z,1352399810.215 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-11-08T18:36:50.224Z,1352399810.224 [RudderServo] Loaded 2012-11-08T18:36:50.224Z,1352399810.224 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-11-08T18:36:50.237Z,1352399810.237 [ThrusterServo] Loaded 2012-11-08T18:36:50.237Z,1352399810.237 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2012-11-08T18:36:50.238Z,1352399810.238 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-11-08T18:36:50.238Z,1352399810.239 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-11-08T18:36:50.271Z,1352399810.271 [DepthRateCalculator] Loaded 2012-11-08T18:36:50.272Z,1352399810.272 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-11-08T18:36:56.269Z,1352399816.269 [HFRadarModelCalc] Loaded 2012-11-08T18:36:56.269Z,1352399816.269 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2012-11-08T18:36:56.286Z,1352399816.286 [NavChart] Loaded 2012-11-08T18:36:56.286Z,1352399816.286 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-11-08T18:36:56.293Z,1352399816.293 [PitchRateCalculator] Loaded 2012-11-08T18:36:56.293Z,1352399816.293 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-11-08T18:36:56.300Z,1352399816.300 [SpeedCalculator] Loaded 2012-11-08T18:36:56.300Z,1352399816.300 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-11-08T18:36:56.320Z,1352399816.320 [TempGradientCalculator] Loaded 2012-11-08T18:36:56.320Z,1352399816.320 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-11-08T18:36:56.327Z,1352399816.327 [YawRateCalculator] Loaded 2012-11-08T18:36:56.327Z,1352399816.327 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-11-08T18:36:56.348Z,1352399816.348 [Navigation] Loaded 2012-11-08T18:36:56.348Z,1352399816.348 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-11-08T18:36:56.349Z,1352399816.349 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-11-08T18:36:56.349Z,1352399816.349 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-11-08T18:36:56.660Z,1352399816.660 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-11-08T18:36:56.661Z,1352399816.661 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-11-08T18:36:56.707Z,1352399816.707 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-11-08T18:36:56.708Z,1352399816.708 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-11-08T18:36:56.776Z,1352399816.776 [VerticalControl](DEBUG): Construct VerticalControl. 2012-11-08T18:36:56.827Z,1352399816.827 [VerticalControl] Loaded 2012-11-08T18:36:56.827Z,1352399816.827 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-11-08T18:36:56.828Z,1352399816.828 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-11-08T18:36:56.854Z,1352399816.854 [HorizontalControl] Loaded 2012-11-08T18:36:56.855Z,1352399816.855 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-11-08T18:36:56.856Z,1352399816.856 [SpeedControl](DEBUG): Construct SpeedControl. 2012-11-08T18:36:56.857Z,1352399816.857 [SpeedControl] Loaded 2012-11-08T18:36:56.858Z,1352399816.858 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-11-08T18:36:56.859Z,1352399816.859 [LoopControl](DEBUG): Construct LoopControl. 2012-11-08T18:36:56.859Z,1352399816.859 [LoopControl] Loaded 2012-11-08T18:36:56.860Z,1352399816.860 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-11-08T18:36:56.860Z,1352399816.860 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-11-08T18:36:56.861Z,1352399816.861 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-11-08T18:36:56.869Z,1352399816.869 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-11-08T18:36:56.874Z,1352399816.874 [AsyncPiEstimator] Loaded 2012-11-08T18:36:56.874Z,1352399816.874 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-11-08T18:36:56.878Z,1352399816.878 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A14E0 2012-11-08T18:36:56.879Z,1352399816.879 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-11-08T18:36:56.880Z,1352399816.880 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-11-08T18:36:57.079Z,1352399817.079 [AHRS_sp3003D] Loaded 2012-11-08T18:36:57.079Z,1352399817.079 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-11-08T18:36:57.384Z,1352399817.384 [Batt_Ocean_Server] Loaded 2012-11-08T18:36:57.384Z,1352399817.384 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2012-11-08T18:36:57.402Z,1352399817.402 [Depth_Keller] Loaded 2012-11-08T18:36:57.402Z,1352399817.402 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2012-11-08T18:36:57.405Z,1352399817.405 [DropWeight] Loaded 2012-11-08T18:36:57.405Z,1352399817.405 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-11-08T18:36:57.549Z,1352399817.549 [DVL_micro] Loaded 2012-11-08T18:36:57.549Z,1352399817.549 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2012-11-08T18:36:57.550Z,1352399817.550 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407224E0 2012-11-08T18:36:57.646Z,1352399817.646 [NAL9602] Loaded 2012-11-08T18:36:57.646Z,1352399817.646 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2012-11-08T18:36:57.709Z,1352399817.709 [Onboard] Loaded 2012-11-08T18:36:57.709Z,1352399817.709 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-11-08T18:36:57.716Z,1352399817.716 [Radio_Freewave] Loaded 2012-11-08T18:36:57.716Z,1352399817.717 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-11-08T18:36:57.717Z,1352399817.717 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-11-08T18:36:57.718Z,1352399817.718 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-11-08T18:36:57.831Z,1352399817.831 [CTD_NeilBrown] Loaded 2012-11-08T18:36:57.832Z,1352399817.832 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2012-11-08T18:36:57.834Z,1352399817.834 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0 2012-11-08T18:36:57.845Z,1352399817.845 [PAR_Licor] Loaded 2012-11-08T18:36:57.846Z,1352399817.846 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2012-11-08T18:36:57.867Z,1352399817.867 [Turbulence_NPS] Loaded 2012-11-08T18:36:57.867Z,1352399817.867 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread. 2012-11-08T18:36:57.870Z,1352399817.870 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0 2012-11-08T18:36:57.906Z,1352399817.906 [WetLabsBB2FL] Loaded 2012-11-08T18:36:57.906Z,1352399817.906 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2012-11-08T18:36:57.910Z,1352399817.910 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0 2012-11-08T18:36:57.911Z,1352399817.911 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-11-08T18:36:57.914Z,1352399817.914 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-11-08T18:36:57.914Z,1352399817.914 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-11-08T18:36:57.925Z,1352399817.925 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-11-08T18:36:57.930Z,1352399817.930 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4080A4E0 2012-11-08T18:36:57.935Z,1352399817.935 [Supervisor](DEBUG): Running supervisor. 2012-11-08T18:36:57.936Z,1352399817.936 [CommandLine](INFO): Thread ID is 749 2012-11-08T18:36:57.939Z,1352399817.939 [controlThread](INFO): Thread ID is 748 2012-11-08T18:36:57.939Z,1352399817.939 [controlThread](DEBUG): Initializing ControlThread 2012-11-08T18:36:57.940Z,1352399817.940 [CycleStarter](INFO): Thread ID is 747 2012-11-08T18:36:57.940Z,1352399817.940 [ExternalSim](INFO): ExternalSim initializing... 2012-11-08T18:36:57.991Z,1352399817.991 [logger](INFO): Thread ID is 750 2012-11-08T18:36:58.031Z,1352399818.031 [AsyncPiEstimator](INFO): Thread ID is 816 2012-11-08T18:36:58.031Z,1352399818.031 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-11-08T18:36:58.040Z,1352399818.040 [ExternalSim](DEBUG): beaconLat = 36.81340 2012-11-08T18:36:58.040Z,1352399818.040 [ExternalSim](DEBUG): beaconLon = -121.82240 2012-11-08T18:36:58.040Z,1352399818.040 [ExternalSim](DEBUG): beaconDepth = 25.00 2012-11-08T18:36:58.123Z,1352399818.123 [DVL_micro](INFO): Thread ID is 817 2012-11-08T18:36:58.185Z,1352399818.185 [CTD_NeilBrown](INFO): Thread ID is 818 2012-11-08T18:36:58.186Z,1352399818.186 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2012-11-08T18:36:58.189Z,1352399818.188 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2012-11-08T18:36:58.315Z,1352399818.315 [Turbulence_NPS](INFO): Thread ID is 819 2012-11-08T18:36:58.315Z,1352399818.315 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS. 2012-11-08T18:36:58.316Z,1352399818.316 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1 2012-11-08T18:36:58.327Z,1352399818.327 [ExternalSim](DEBUG): Simulator initialized 2012-11-08T18:36:58.343Z,1352399818.343 [WetLabsBB2FL](INFO): Thread ID is 820 2012-11-08T18:36:58.344Z,1352399818.344 [WetLabsBB2FL](INFO): Powering down 2012-11-08T18:36:58.446Z,1352399818.446 [Turbulence_NPS](INFO): Pause powering down 2012-11-08T18:36:58.462Z,1352399818.462 [NavChartDb](INFO): Thread ID is 821 2012-11-08T18:36:58.463Z,1352399818.463 [InternalSim](DEBUG): InternalSim initializing... 2012-11-08T18:36:58.475Z,1352399818.475 [DVL_micro](INFO): Initializing 2012-11-08T18:36:58.475Z,1352399818.476 [DVL_micro](INFO): start:Powering up 2012-11-08T18:36:58.476Z,1352399818.476 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:36:58.477Z,1352399818.477 [DVL_micro](INFO): Cycling power to configure device. 2012-11-08T18:36:58.564Z,1352399818.565 [SBIT](INFO): Initialize SBIT Component. 2012-11-08T18:36:58.565Z,1352399818.565 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10047 2012-11-08T18:36:58.566Z,1352399818.566 [IBIT](INFO): Initialize IBIT Component. 2012-11-08T18:36:58.566Z,1352399818.566 [CBIT](DEBUG): Initialize CBIT Component. 2012-11-08T18:36:58.567Z,1352399818.567 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2012-11-08T18:36:58.715Z,1352399818.716 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-11-08T18:36:58.716Z,1352399818.716 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-11-08T18:36:58.716Z,1352399818.716 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-11-08T18:36:58.717Z,1352399818.717 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-11-08T18:36:58.717Z,1352399818.717 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-11-08T18:36:58.719Z,1352399818.719 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-11-08T18:36:58.719Z,1352399818.719 [Navigation](DEBUG): Initializing Navigation. 2012-11-08T18:36:58.719Z,1352399818.719 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-11-08T18:36:58.721Z,1352399818.721 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-11-08T18:36:58.722Z,1352399818.722 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-11-08T18:36:58.734Z,1352399818.734 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-11-08T18:36:58.788Z,1352399818.788 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-11-08T18:36:58.789Z,1352399818.789 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-11-08T18:36:58.789Z,1352399818.789 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-11-08T18:36:58.789Z,1352399818.789 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-11-08T18:36:58.789Z,1352399818.789 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-11-08T18:37:00.351Z,1352399820.351 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2012-11-08T18:37:00.351Z,1352399820.351 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2012-11-08T18:37:00.351Z,1352399820.351 [Batt_Ocean_Server] Communications Fault, FailCount= 1 2012-11-08T18:37:00.351Z,1352399820.351 [Batt_Ocean_Server](ERROR): Communications Fault 2012-11-08T18:37:00.361Z,1352399820.361 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-11-08T18:37:00.487Z,1352399820.487 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:37:00.497Z,1352399820.497 [MissionManager](DEBUG): 2012-11-08T18:37:00.498Z,1352399820.498 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-11-08T18:37:00.539Z,1352399820.539 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:37:00.539Z,1352399820.539 [DVL_micro](INFO): Querying output modes 2012-11-08T18:37:00.539Z,1352399820.539 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-11-08T18:37:00.543Z,1352399820.543 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2012-11-08T18:37:00.543Z,1352399820.543 [DVL_micro](INFO): NQ1 output enabled 2012-11-08T18:37:00.543Z,1352399820.543 [DVL_micro](INFO): RSSI output enabled 2012-11-08T18:37:00.543Z,1352399820.543 [DVL_micro](INFO): ADCP output enabled 2012-11-08T18:37:00.543Z,1352399820.543 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-11-08T18:37:00.550Z,1352399820.550 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-11-08T18:37:00.555Z,1352399820.555 [DVL_micro](INFO): pause:Powering down 2012-11-08T18:37:00.574Z,1352399820.574 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-11-08T18:37:00.577Z,1352399820.578 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-11-08T18:37:00.581Z,1352399820.580 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:37:00.590Z,1352399820.590 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-11-08T18:37:00.593Z,1352399820.593 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:37:00.600Z,1352399820.600 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-11-08T18:37:00.609Z,1352399820.609 [Default:D.SetSpeed](DEBUG): Construct. 2012-11-08T18:37:00.612Z,1352399820.612 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:37:00.621Z,1352399820.621 [Default:F.Wait](DEBUG): Construct Wait. 2012-11-08T18:37:00.625Z,1352399820.625 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2012-11-08T18:37:00.629Z,1352399820.629 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,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, 2012-11-08T18:37:00.696Z,1352399820.696 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-11-08T18:37:00.891Z,1352399820.891 [Radio_Freewave](INFO): Powering up 2012-11-08T18:37:01.076Z,1352399821.076 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-11-08T18:37:01.079Z,1352399821.079 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-11-08T18:37:01.085Z,1352399821.085 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2012-11-08T18:37:01.090Z,1352399821.090 [MassServo](DEBUG): Initializing EZServoServo. 2012-11-08T18:37:01.091Z,1352399821.091 [MassServo](DEBUG): Initializing MassServo. 2012-11-08T18:37:01.097Z,1352399821.097 [RudderServo](DEBUG): Initializing RudderServo. 2012-11-08T18:37:01.106Z,1352399821.106 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-11-08T18:37:01.111Z,1352399821.111 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-11-08T18:37:01.156Z,1352399821.156 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2012-11-08T18:37:01.156Z,1352399821.156 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server 2012-11-08T18:37:01.156Z,1352399821.156 [Batt_Ocean_Server] No Fault, FailCount= 1 2012-11-08T18:37:02.679Z,1352399822.679 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2012-11-08T18:37:02.679Z,1352399822.679 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2012-11-08T18:37:02.679Z,1352399822.679 [Batt_Ocean_Server] Communications Fault, FailCount= 2 2012-11-08T18:37:02.679Z,1352399822.679 [Batt_Ocean_Server](ERROR): Communications Fault 2012-11-08T18:37:03.272Z,1352399823.272 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2012-11-08T18:37:03.590Z,1352399823.590 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server 2012-11-08T18:37:03.614Z,1352399823.614 [Batt_Ocean_Server] No Fault, FailCount= 2 2012-11-08T18:37:05.271Z,1352399825.270 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2012-11-08T18:37:05.271Z,1352399825.271 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2012-11-08T18:37:05.271Z,1352399825.271 [Batt_Ocean_Server] Communications Fault, FailCount= 3 2012-11-08T18:37:05.271Z,1352399825.271 [Batt_Ocean_Server](ERROR): Communications Fault 2012-11-08T18:37:05.413Z,1352399825.413 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2012-11-08T18:37:05.414Z,1352399825.414 [CBIT](CRITICAL): Communications Fault in component: Batt_Ocean_Server 2012-11-08T18:37:09.201Z,1352399829.201 [NAL9602](IMPORTANT): GPS fix at: 1352399829.19 2012-11-08T18:37:14.756Z,1352399834.756 [SBIT](IMPORTANT): Beginning Startup BIT 2012-11-08T18:37:14.759Z,1352399834.759 [CBIT](IMPORTANT): Beginning GF scan 2012-11-08T18:37:17.155Z,1352399837.155 [NAL9602](INFO): Powering down 2012-11-08T18:37:45.176Z,1352399865.176 [CBIT](IMPORTANT): No ground fault detected 2012-11-08T18:38:11.011Z,1352399891.011 [SBIT](IMPORTANT): SBIT PASSED 2012-11-08T18:38:11.621Z,1352399891.621 [MissionManager](IMPORTANT): Started mission Startup 2012-11-08T18:38:11.621Z,1352399891.621 [Startup] Running Loop=1 2012-11-08T18:38:11.621Z,1352399891.621 [Startup](INFO): Aggregate::initialize Startup 2012-11-08T18:38:11.621Z,1352399891.621 [Startup:A.GoToSurface] Running Loop=1 2012-11-08T18:38:11.621Z,1352399891.621 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:38:11.649Z,1352399891.649 [Startup:StartupSatComms] Running Loop=1 2012-11-08T18:38:11.649Z,1352399891.649 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-11-08T18:38:11.649Z,1352399891.649 [Startup:StartupSatComms:A] Running Loop=1 2012-11-08T18:38:11.888Z,1352399891.888 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T18:38:12.251Z,1352399892.251 [NAL9602](INFO): Powering up 2012-11-08T18:38:21.128Z,1352399901.128 [NAL9602](IMPORTANT): GPS fix at: 1352399901.12 2012-11-08T18:38:21.143Z,1352399901.143 [Startup:StartupSatComms:A] Stopped 2012-11-08T18:38:21.144Z,1352399901.144 [Startup:StartupSatComms:B] Running Loop=1 2012-11-08T18:38:21.537Z,1352399901.537 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-11-08T18:38:23.918Z,1352399903.918 [NAL9602](INFO): Sent 121 bytes from file Logs/20121108T181339/shore0005.lzma 2012-11-08T18:38:23.918Z,1352399903.918 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:38:23.962Z,1352399903.962 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T181339/shore0005.lzma.parts/0000.sbd 2012-11-08T18:38:25.122Z,1352399905.122 [NAL9602](INFO): Sent 332 bytes from file Logs/20121108T183645/shore0000.lzma 2012-11-08T18:38:25.122Z,1352399905.122 [NAL9602](INFO): Packets left to send: 1 2012-11-08T18:38:25.133Z,1352399905.133 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0000.lzma.parts/0001.sbd 2012-11-08T18:38:26.332Z,1352399906.332 [NAL9602](INFO): Sent 321 bytes from file Logs/20121108T183645/shore0000.lzma 2012-11-08T18:38:26.332Z,1352399906.332 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:38:26.333Z,1352399906.333 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0000.lzma.parts/0000.sbd 2012-11-08T18:38:28.450Z,1352399908.450 [Startup:StartupSatComms:B] Stopped 2012-11-08T18:38:28.451Z,1352399908.451 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-11-08T18:38:28.451Z,1352399908.451 [Startup:StartupSatComms] Stopped 2012-11-08T18:38:28.451Z,1352399908.451 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-11-08T18:38:28.452Z,1352399908.452 [Startup](INFO): Completed Startup 2012-11-08T18:38:28.452Z,1352399908.452 [Startup] Stopped 2012-11-08T18:38:28.452Z,1352399908.452 [Startup](INFO): Aggregate::uninitialize Startup 2012-11-08T18:38:28.452Z,1352399908.452 [Startup:A.GoToSurface] Stopped 2012-11-08T18:38:28.452Z,1352399908.452 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:38:28.728Z,1352399908.728 [MissionManager](IMPORTANT): Started mission Default 2012-11-08T18:38:28.728Z,1352399908.728 [Default] Running Loop=1 2012-11-08T18:38:28.728Z,1352399908.728 [Default](INFO): Aggregate::initialize Default 2012-11-08T18:38:28.728Z,1352399908.728 [Default:D.SetSpeed] Running Loop=1 2012-11-08T18:38:28.728Z,1352399908.728 [Default:D.SetSpeed](DEBUG): Initialize. 2012-11-08T18:38:28.728Z,1352399908.728 [Default:E.GoToSurface] Running Loop=1 2012-11-08T18:38:28.728Z,1352399908.728 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:38:28.729Z,1352399908.728 [Default:Iridium] Running Loop=1 2012-11-08T18:38:28.729Z,1352399908.729 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-11-08T18:38:28.729Z,1352399908.729 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T18:38:28.729Z,1352399908.729 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:38:28.729Z,1352399908.729 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-11-08T18:38:28.729Z,1352399908.729 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:38:28.730Z,1352399908.730 [Default:E.GoToSurface] Running Loop=1 2012-11-08T18:38:28.739Z,1352399908.739 [Default:D.SetSpeed] Running Loop=1 2012-11-08T18:38:28.749Z,1352399908.749 [Default:Iridium:B.GoToSurface] Stopped 2012-11-08T18:38:28.749Z,1352399908.749 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:38:28.749Z,1352399908.749 [Default:Iridium:Read_Iridium] Running Loop=1 2012-11-08T18:38:28.749Z,1352399908.749 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS] Running Loop=1 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS:A.SetSpeed] Running Loop=1 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS:B.GoToSurface] Running Loop=1 2012-11-08T18:38:28.754Z,1352399908.754 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:38:28.760Z,1352399908.760 [Default:GPS:B.GoToSurface] Stopped 2012-11-08T18:38:28.760Z,1352399908.760 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:38:28.760Z,1352399908.760 [Default:GPS:Read_GPS] Running Loop=1 2012-11-08T18:38:28.760Z,1352399908.760 [Default:GPS:A.SetSpeed] Running Loop=1 2012-11-08T18:38:29.758Z,1352399909.758 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-11-08T18:38:29.765Z,1352399909.764 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T18:38:34.679Z,1352399914.680 [NAL9602](IMPORTANT): GPS fix at: 1352399914.67 2012-11-08T18:38:35.339Z,1352399915.339 [Default:GPS:Read_GPS] Stopped 2012-11-08T18:38:35.339Z,1352399915.339 [Default:GPS:D] Running Loop=1 2012-11-08T18:38:35.568Z,1352399915.568 [Default:GPS:D] Stopped 2012-11-08T18:38:35.568Z,1352399915.568 [Default:GPS](INFO): Completed Default:GPS 2012-11-08T18:38:35.568Z,1352399915.568 [Default:GPS] Stopped 2012-11-08T18:38:35.568Z,1352399915.568 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-11-08T18:38:35.568Z,1352399915.568 [Default:GPS:A.SetSpeed] Stopped 2012-11-08T18:38:35.568Z,1352399915.569 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:38:37.130Z,1352399917.130 [NAL9602](INFO): Sent 140 bytes from file Logs/20121108T183645/shore0001.lzma 2012-11-08T18:38:37.130Z,1352399917.130 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:38:37.141Z,1352399917.141 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0001.lzma.parts/0000.sbd 2012-11-08T18:38:37.948Z,1352399917.948 [Default:Iridium:Read_Iridium] Stopped 2012-11-08T18:38:37.949Z,1352399917.949 [Default:Iridium](INFO): Completed Default:Iridium 2012-11-08T18:38:37.949Z,1352399917.949 [Default:Iridium] Stopped 2012-11-08T18:38:37.949Z,1352399917.949 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-11-08T18:38:37.949Z,1352399917.949 [Default:Iridium:A.SetSpeed] Stopped 2012-11-08T18:38:37.949Z,1352399917.949 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:38:37.949Z,1352399917.949 [Default:F.Wait] Running Loop=1 2012-11-08T18:38:37.949Z,1352399917.949 [Default:F.Wait](DEBUG): Initialize Wait Component. 2012-11-08T18:38:48.408Z,1352399928.408 [NAL9602](INFO): Powering down 2012-11-08T18:43:38.432Z,1352400218.432 [Default:CallIridium] Running Loop=1 2012-11-08T18:43:38.432Z,1352400218.432 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-11-08T18:43:38.432Z,1352400218.432 [Default:CallIridium:A] Running Loop=1 2012-11-08T18:43:38.434Z,1352400218.434 [Default:CallIridium:A] Stopped 2012-11-08T18:43:38.434Z,1352400218.434 [Default:CallIridium:B] Running Loop=1 2012-11-08T18:43:38.434Z,1352400218.434 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-11-08T18:43:43.417Z,1352400223.417 [Default:Iridium] Running Loop=1 2012-11-08T18:43:43.417Z,1352400223.417 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-11-08T18:43:43.417Z,1352400223.417 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T18:43:43.417Z,1352400223.417 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:43:43.418Z,1352400223.418 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-11-08T18:43:43.418Z,1352400223.418 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:43:43.439Z,1352400223.439 [Default:Iridium:B.GoToSurface] Stopped 2012-11-08T18:43:43.439Z,1352400223.439 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:43:43.439Z,1352400223.439 [Default:Iridium:Read_Iridium] Running Loop=1 2012-11-08T18:43:43.439Z,1352400223.439 [Default:GPS] Running Loop=1 2012-11-08T18:43:43.439Z,1352400223.439 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-11-08T18:43:43.440Z,1352400223.440 [Default:GPS:A.SetSpeed] Running Loop=1 2012-11-08T18:43:43.440Z,1352400223.440 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:43:43.440Z,1352400223.440 [Default:GPS:B.GoToSurface] Running Loop=1 2012-11-08T18:43:43.440Z,1352400223.440 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:43:43.440Z,1352400223.441 [Default:GPS:B.GoToSurface] Stopped 2012-11-08T18:43:43.441Z,1352400223.441 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:43:43.441Z,1352400223.441 [Default:GPS:Read_GPS] Running Loop=1 2012-11-08T18:43:44.132Z,1352400224.132 [NAL9602](INFO): Powering up 2012-11-08T18:43:49.331Z,1352400229.331 [NAL9602](IMPORTANT): GPS fix at: 1352400229.32 2012-11-08T18:43:49.355Z,1352400229.355 [Default:GPS:Read_GPS] Stopped 2012-11-08T18:43:49.355Z,1352400229.355 [Default:GPS:D] Running Loop=1 2012-11-08T18:43:49.742Z,1352400229.742 [Default:GPS:D] Stopped 2012-11-08T18:43:49.743Z,1352400229.743 [Default:GPS](INFO): Completed Default:GPS 2012-11-08T18:43:49.743Z,1352400229.743 [Default:GPS] Stopped 2012-11-08T18:43:49.743Z,1352400229.743 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-11-08T18:43:49.743Z,1352400229.743 [Default:GPS:A.SetSpeed] Stopped 2012-11-08T18:43:49.743Z,1352400229.743 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:43:51.326Z,1352400231.326 [NAL9602](INFO): Sent 109 bytes from file Logs/20121108T183645/shore0002.lzma 2012-11-08T18:43:51.326Z,1352400231.326 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:43:51.337Z,1352400231.337 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0002.lzma.parts/0000.sbd 2012-11-08T18:43:52.148Z,1352400232.148 [Default:Iridium:Read_Iridium] Stopped 2012-11-08T18:43:52.149Z,1352400232.149 [Default:Iridium](INFO): Completed Default:Iridium 2012-11-08T18:43:52.149Z,1352400232.149 [Default:Iridium] Stopped 2012-11-08T18:43:52.149Z,1352400232.149 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-11-08T18:43:52.149Z,1352400232.149 [Default:Iridium:A.SetSpeed] Stopped 2012-11-08T18:43:52.149Z,1352400232.149 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:43:52.545Z,1352400232.545 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-11-08T18:43:52.545Z,1352400232.545 [Default:CallIridium:B] Stopped 2012-11-08T18:43:52.545Z,1352400232.545 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-11-08T18:43:52.545Z,1352400232.546 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-11-08T18:43:52.546Z,1352400232.546 [Default:CallIridium] Stopped 2012-11-08T18:43:52.546Z,1352400232.546 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-11-08T18:44:02.598Z,1352400242.598 [NAL9602](INFO): Powering down 2012-11-08T18:48:52.614Z,1352400532.614 [Default:CallIridium] Running Loop=1 2012-11-08T18:48:52.614Z,1352400532.614 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-11-08T18:48:52.614Z,1352400532.614 [Default:CallIridium:A] Running Loop=1 2012-11-08T18:48:52.615Z,1352400532.615 [Default:CallIridium:A] Stopped 2012-11-08T18:48:52.615Z,1352400532.615 [Default:CallIridium:B] Running Loop=1 2012-11-08T18:48:52.615Z,1352400532.615 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium] Running Loop=1 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-11-08T18:48:57.632Z,1352400537.632 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:48:57.633Z,1352400537.633 [Default:Iridium:B.GoToSurface] Stopped 2012-11-08T18:48:57.633Z,1352400537.633 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:48:57.633Z,1352400537.633 [Default:Iridium:Read_Iridium] Running Loop=1 2012-11-08T18:48:57.633Z,1352400537.633 [Default:GPS] Running Loop=1 2012-11-08T18:48:57.633Z,1352400537.633 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-11-08T18:48:57.633Z,1352400537.634 [Default:GPS:A.SetSpeed] Running Loop=1 2012-11-08T18:48:57.634Z,1352400537.634 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:48:57.634Z,1352400537.634 [Default:GPS:B.GoToSurface] Running Loop=1 2012-11-08T18:48:57.634Z,1352400537.634 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:48:57.635Z,1352400537.635 [Default:GPS:B.GoToSurface] Stopped 2012-11-08T18:48:57.635Z,1352400537.635 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:48:57.635Z,1352400537.635 [Default:GPS:Read_GPS] Running Loop=1 2012-11-08T18:48:58.329Z,1352400538.329 [NAL9602](INFO): Powering up 2012-11-08T18:49:03.586Z,1352400543.586 [NAL9602](IMPORTANT): GPS fix at: 1352400543.58 2012-11-08T18:49:03.603Z,1352400543.603 [Default:GPS:Read_GPS] Stopped 2012-11-08T18:49:03.604Z,1352400543.603 [Default:GPS:D] Running Loop=1 2012-11-08T18:49:04.006Z,1352400544.006 [Default:GPS:D] Stopped 2012-11-08T18:49:04.006Z,1352400544.006 [Default:GPS](INFO): Completed Default:GPS 2012-11-08T18:49:04.007Z,1352400544.007 [Default:GPS] Stopped 2012-11-08T18:49:04.007Z,1352400544.007 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-11-08T18:49:04.007Z,1352400544.007 [Default:GPS:A.SetSpeed] Stopped 2012-11-08T18:49:04.007Z,1352400544.007 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:49:05.592Z,1352400545.592 [NAL9602](INFO): Sent 111 bytes from file Logs/20121108T183645/shore0003.lzma 2012-11-08T18:49:05.592Z,1352400545.592 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:49:05.604Z,1352400545.604 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0003.lzma.parts/0000.sbd 2012-11-08T18:49:06.402Z,1352400546.402 [Default:Iridium:Read_Iridium] Stopped 2012-11-08T18:49:06.403Z,1352400546.403 [Default:Iridium](INFO): Completed Default:Iridium 2012-11-08T18:49:06.403Z,1352400546.403 [Default:Iridium] Stopped 2012-11-08T18:49:06.403Z,1352400546.403 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-11-08T18:49:06.403Z,1352400546.403 [Default:Iridium:A.SetSpeed] Stopped 2012-11-08T18:49:06.403Z,1352400546.403 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium:B] Stopped 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium] Stopped 2012-11-08T18:49:06.812Z,1352400546.812 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-11-08T18:49:16.872Z,1352400556.872 [NAL9602](INFO): Powering down 2012-11-08T18:52:06.882Z,1352400726.882 [CBIT](INFO): Clearing failed count for component Batt_Ocean_Server 2012-11-08T18:52:06.882Z,1352400726.882 [Batt_Ocean_Server] No Fault, FailCount= 3 2012-11-08T18:52:13.335Z,1352400733.335 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2012-11-08T18:54:06.972Z,1352400846.972 [Default:CallIridium] Running Loop=1 2012-11-08T18:54:06.972Z,1352400846.972 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-11-08T18:54:06.973Z,1352400846.973 [Default:CallIridium:A] Running Loop=1 2012-11-08T18:54:06.973Z,1352400846.973 [Default:CallIridium:A] Stopped 2012-11-08T18:54:06.973Z,1352400846.973 [Default:CallIridium:B] Running Loop=1 2012-11-08T18:54:06.973Z,1352400846.973 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-11-08T18:54:11.952Z,1352400851.952 [Default:Iridium] Running Loop=1 2012-11-08T18:54:11.952Z,1352400851.952 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-11-08T18:54:11.952Z,1352400851.952 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T18:54:11.952Z,1352400851.952 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:54:11.952Z,1352400851.952 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-11-08T18:54:11.952Z,1352400851.953 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:54:11.953Z,1352400851.953 [Default:Iridium:B.GoToSurface] Stopped 2012-11-08T18:54:11.953Z,1352400851.953 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:54:11.953Z,1352400851.953 [Default:Iridium:Read_Iridium] Running Loop=1 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS] Running Loop=1 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS:A.SetSpeed] Running Loop=1 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS:B.GoToSurface] Running Loop=1 2012-11-08T18:54:11.954Z,1352400851.954 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:54:11.955Z,1352400851.955 [Default:GPS:B.GoToSurface] Stopped 2012-11-08T18:54:11.955Z,1352400851.955 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:54:11.955Z,1352400851.955 [Default:GPS:Read_GPS] Running Loop=1 2012-11-08T18:54:12.587Z,1352400852.587 [NAL9602](INFO): Powering up 2012-11-08T18:54:17.951Z,1352400857.951 [NAL9602](IMPORTANT): GPS fix at: 1352400857.95 2012-11-08T18:54:17.968Z,1352400857.968 [Default:GPS:Read_GPS] Stopped 2012-11-08T18:54:17.968Z,1352400857.968 [Default:GPS:D] Running Loop=1 2012-11-08T18:54:18.360Z,1352400858.360 [Default:GPS:D] Stopped 2012-11-08T18:54:18.360Z,1352400858.360 [Default:GPS](INFO): Completed Default:GPS 2012-11-08T18:54:18.361Z,1352400858.361 [Default:GPS] Stopped 2012-11-08T18:54:18.361Z,1352400858.361 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2012-11-08T18:54:18.361Z,1352400858.361 [Default:GPS:A.SetSpeed] Stopped 2012-11-08T18:54:18.361Z,1352400858.361 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:54:19.948Z,1352400859.948 [NAL9602](INFO): Sent 277 bytes from file Logs/20121108T183645/shore0004.lzma 2012-11-08T18:54:19.948Z,1352400859.948 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:54:19.959Z,1352400859.959 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0004.lzma.parts/0000.sbd 2012-11-08T18:54:20.801Z,1352400860.801 [Default:Iridium:Read_Iridium] Stopped 2012-11-08T18:54:20.801Z,1352400860.801 [Default:Iridium](INFO): Completed Default:Iridium 2012-11-08T18:54:20.802Z,1352400860.802 [Default:Iridium] Stopped 2012-11-08T18:54:20.802Z,1352400860.802 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-11-08T18:54:20.802Z,1352400860.802 [Default:Iridium:A.SetSpeed] Stopped 2012-11-08T18:54:20.802Z,1352400860.802 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:54:21.158Z,1352400861.158 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2012-11-08T18:54:21.158Z,1352400861.158 [Default:CallIridium:B] Stopped 2012-11-08T18:54:21.158Z,1352400861.158 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2012-11-08T18:54:21.159Z,1352400861.159 [Default:CallIridium](INFO): Completed Default:CallIridium 2012-11-08T18:54:21.159Z,1352400861.159 [Default:CallIridium] Stopped 2012-11-08T18:54:21.159Z,1352400861.159 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2012-11-08T18:54:31.280Z,1352400871.280 [NAL9602](INFO): Powering down 2012-11-08T18:58:22.646Z,1352401102.647 [CommandLine](IMPORTANT): got command get distance_from_shore 2012-11-08T18:58:22.647Z,1352401102.647 [CommandLine](IMPORTANT): distance_from_shore 8.174262 kilometer 2012-11-08T18:58:53.203Z,1352401133.203 [CommandLine](IMPORTANT): got command run ./Missions/Science/turbulence_daphne.xml 2012-11-08T18:58:53.203Z,1352401133.203 [MissionManager](INFO): Loading Mission: ./Missions/Science/turbulence_daphne.xml 2012-11-08T18:58:53.394Z,1352401133.394 [MissionManager](INFO): DefineArg turbulence_daphne.ResumeEastward = 0 bool 2012-11-08T18:58:53.397Z,1352401133.397 [MissionManager](INFO): DefineArg turbulence_daphne.ResumeWestward = 0 bool 2012-11-08T18:58:53.400Z,1352401133.399 [MissionManager](INFO): DefineArg turbulence_daphne.MinAltitude = 2.000000 m 2012-11-08T18:58:53.402Z,1352401133.402 [MissionManager](INFO): DefineArg turbulence_daphne.MaxDepth = 105.000000 m 2012-11-08T18:58:53.405Z,1352401133.405 [MissionManager](INFO): DefineArg turbulence_daphne.MinOffshore = 2000.000000 m 2012-11-08T18:58:53.408Z,1352401133.408 [MissionManager](INFO): DefineArg turbulence_daphne.Speed = 1.000000 m/s 2012-11-08T18:58:53.411Z,1352401133.411 [MissionManager](INFO): DefineArg turbulence_daphne.MissionTimeout = 30.000000 h 2012-11-08T18:58:53.414Z,1352401133.414 [MissionManager](INFO): DefineArg turbulence_daphne.MassDefault = 0.010900 n/a 2012-11-08T18:58:53.417Z,1352401133.418 [MissionManager](INFO): DefineArg turbulence_daphne.BuoyancyNeutral = 0.000498 n/a 2012-11-08T18:58:53.421Z,1352401133.421 [MissionManager](INFO): DefineArg turbulence_daphne.WpWestLat = 36.716000 arcdeg 2012-11-08T18:58:53.423Z,1352401133.423 [MissionManager](INFO): DefineArg turbulence_daphne.WpWestLon = -121.903400 arcdeg 2012-11-08T18:58:53.426Z,1352401133.426 [MissionManager](INFO): DefineArg turbulence_daphne.InboundSurfLon = -121.884000 arcdeg 2012-11-08T18:58:53.429Z,1352401133.429 [MissionManager](INFO): DefineArg turbulence_daphne.WpMidwayLat = 36.716000 arcdeg 2012-11-08T18:58:53.432Z,1352401133.432 [MissionManager](INFO): DefineArg turbulence_daphne.WpMidwayLon = -121.860000 arcdeg 2012-11-08T18:58:53.435Z,1352401133.435 [MissionManager](INFO): DefineArg turbulence_daphne.WpEastLat = 36.716000 arcdeg 2012-11-08T18:58:53.474Z,1352401133.474 [MissionManager](INFO): DefineArg turbulence_daphne.WpEastLon = -121.836600 arcdeg 2012-11-08T18:58:53.477Z,1352401133.477 [MissionManager](INFO): DefineArg turbulence_daphne.OutboundSurfLon = -121.870000 arcdeg 2012-11-08T18:58:53.480Z,1352401133.480 [MissionManager](INFO): DefineArg turbulence_daphne.ApproachDepth = 20.000000 m 2012-11-08T18:58:53.483Z,1352401133.483 [MissionManager](INFO): DefineArg turbulence_daphne.ApproachTimeout = 5.000000 h 2012-11-08T18:58:53.490Z,1352401133.490 [MissionManager](INFO): DefineArg turbulence_daphne.ApproachNeedCommsTime = 60.000000 min 2012-11-08T18:58:53.493Z,1352401133.493 [MissionManager](INFO): DefineArg turbulence_daphne.Repeat = 999.000000 count 2012-11-08T18:58:53.496Z,1352401133.496 [MissionManager](INFO): DefineArg turbulence_daphne.InboundTimeout = 5.000000 h 2012-11-08T18:58:53.499Z,1352401133.499 [MissionManager](INFO): DefineArg turbulence_daphne.SurfaceGPSTimeout = 5.000000 h 2012-11-08T18:58:53.502Z,1352401133.502 [MissionManager](INFO): DefineArg turbulence_daphne.SurfFastPitch = 15.000000 arcdeg 2012-11-08T18:58:53.505Z,1352401133.505 [MissionManager](INFO): DefineArg turbulence_daphne.SurfFastFloatTime = 30.000000 s 2012-11-08T18:58:53.508Z,1352401133.508 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoMinDepth = 3.000000 m 2012-11-08T18:58:53.511Z,1352401133.511 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoMaxDepth = 100.000000 m 2012-11-08T18:58:53.514Z,1352401133.514 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoMinAltitude = 3.000000 m 2012-11-08T18:58:53.517Z,1352401133.517 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoUpPitch = 20.000000 arcdeg 2012-11-08T18:58:53.520Z,1352401133.520 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoDownPitch = -10.000000 arcdeg 2012-11-08T18:58:53.524Z,1352401133.524 [MissionManager](INFO): DefineArg turbulence_daphne.OutboundTimeout = 5.000000 h 2012-11-08T18:58:53.531Z,1352401133.531 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoMaxAltitude = 15.000000 m 2012-11-08T18:58:53.534Z,1352401133.534 [MissionManager](INFO): DefineArg turbulence_daphne.YoYoFollowPeriod = 12.000000 min 2012-11-08T18:58:53.537Z,1352401133.537 [MissionManager](INFO): DefineArg turbulence_daphne.BottomFollowingAltitude = 3.000000 m 2012-11-08T18:58:53.540Z,1352401133.540 [MissionManager](INFO): DefineArg turbulence_daphne.BottomFollowingMaxDepth = 100.000000 m 2012-11-08T18:58:53.543Z,1352401133.543 [MissionManager](INFO): DefineArg turbulence_daphne.kpAltitude = -0.060000 n/a 2012-11-08T18:58:53.546Z,1352401133.546 [MissionManager](INFO): DefineArg turbulence_daphne.kiAltitude = 0.000000 n/a 2012-11-08T18:58:53.549Z,1352401133.549 [MissionManager](INFO): DefineArg turbulence_daphne.kdAltitude = 0.000000 n/a 2012-11-08T18:58:53.552Z,1352401133.552 [MissionManager](INFO): DefineArg turbulence_daphne.YoRepeat = 1.000000 count 2012-11-08T18:58:53.555Z,1352401133.555 [MissionManager](INFO): DefineArg turbulence_daphne.SurfacedFast = 0 bool 2012-11-08T18:58:53.557Z,1352401133.557 [turbulence_daphne:A.Pitch](DEBUG): Construct. 2012-11-08T18:58:53.562Z,1352401133.562 [turbulence_daphne:B.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-11-08T18:58:53.570Z,1352401133.570 [turbulence_daphne:C.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-11-08T18:58:53.578Z,1352401133.578 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2012-11-08T18:58:53.612Z,1352401133.612 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceComms.SurfaceDepthRate = nan m/s 2012-11-08T18:58:53.615Z,1352401133.615 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceComms.SurfacePitch = nan arcdeg 2012-11-08T18:58:53.618Z,1352401133.618 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceComms.SurfaceSpeed = 0.500000 m/s 2012-11-08T18:58:53.621Z,1352401133.621 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceComms.IridiumTimeout = 30.000000 min 2012-11-08T18:58:53.627Z,1352401133.627 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceComms.UnpackSplitAtSurface = 0 bool 2012-11-08T18:58:53.628Z,1352401133.628 [turbulence_daphne:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:58:53.653Z,1352401133.653 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2012-11-08T18:58:53.684Z,1352401133.684 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.SurfaceDepthRate = nan m/s 2012-11-08T18:58:53.687Z,1352401133.687 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.SurfacePitch = nan arcdeg 2012-11-08T18:58:53.690Z,1352401133.690 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = 0.500000 m/s 2012-11-08T18:58:53.693Z,1352401133.693 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.IridiumTimeout = 30.000000 min 2012-11-08T18:58:53.697Z,1352401133.697 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = 0 bool 2012-11-08T18:58:53.698Z,1352401133.698 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:58:53.711Z,1352401133.711 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2012-11-08T18:58:53.713Z,1352401133.713 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2012-11-08T18:58:53.714Z,1352401133.714 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = 1 bool 2012-11-08T18:58:53.716Z,1352401133.716 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceNavUpdate.xml 2012-11-08T18:58:53.735Z,1352401133.735 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.SurfaceDepthRate = nan m/s 2012-11-08T18:58:53.738Z,1352401133.738 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.SurfacePitch = nan arcdeg 2012-11-08T18:58:53.778Z,1352401133.778 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.SurfaceSpeed = 0.500000 m/s 2012-11-08T18:58:53.781Z,1352401133.781 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.UnpackSplitAtSurface = 0 bool 2012-11-08T18:58:53.782Z,1352401133.782 [turbulence_daphne:SurfaceGPS:SurfaceNavUpdate:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:58:53.799Z,1352401133.799 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.SurfacePitch = 20.000000 arcdeg 2012-11-08T18:58:53.801Z,1352401133.801 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceGPS:SurfaceNavUpdate.SurfaceSpeed = 1.000000 m/s 2012-11-08T18:58:53.804Z,1352401133.804 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceNavUpdate.xml 2012-11-08T18:58:53.821Z,1352401133.821 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.SurfaceDepthRate = nan m/s 2012-11-08T18:58:53.824Z,1352401133.824 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.SurfacePitch = nan arcdeg 2012-11-08T18:58:53.827Z,1352401133.827 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.SurfaceSpeed = 0.500000 m/s 2012-11-08T18:58:53.830Z,1352401133.829 [MissionManager](INFO): DefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.UnpackSplitAtSurface = 0 bool 2012-11-08T18:58:53.831Z,1352401133.831 [turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:58:53.840Z,1352401133.840 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.SurfacePitch = 20.000000 arcdeg 2012-11-08T18:58:53.842Z,1352401133.842 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.SurfaceSpeed = 1.000000 m/s 2012-11-08T18:58:53.879Z,1352401133.879 [MissionManager](INFO): RedefineArg turbulence_daphne:SurfaceGPSSplit:SurfaceNavUpdate.UnpackSplitAtSurface = 1 bool 2012-11-08T18:58:53.882Z,1352401133.882 [turbulence_daphne:SurfaceFast:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-11-08T18:58:53.887Z,1352401133.887 [turbulence_daphne:SurfaceFast:B.Wait](DEBUG): Construct Wait. 2012-11-08T18:58:53.894Z,1352401133.894 [turbulence_daphne:I.Buoyancy](DEBUG): Construct Buoyancy. 2012-11-08T18:58:53.897Z,1352401133.897 [turbulence_daphne:J.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2012-11-08T18:58:53.909Z,1352401133.909 [turbulence_daphne:Approach:B.Pitch](DEBUG): Construct. 2012-11-08T18:58:53.914Z,1352401133.914 [turbulence_daphne:Approach:C.SetSpeed](DEBUG): Construct. 2012-11-08T18:58:53.917Z,1352401133.917 [turbulence_daphne:Approach:WpWestApproach.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:53.932Z,1352401133.932 [turbulence_daphne:ScienceOps:Inbound:A_Timeout:A.StopMission](DEBUG): Construct StopMission. 2012-11-08T18:58:53.933Z,1352401133.933 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2012-11-08T18:58:54.255Z,1352401134.255 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.SampleISUS = 0 bool 2012-11-08T18:58:54.258Z,1352401134.258 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.SampleRSSI = 1 bool 2012-11-08T18:58:54.261Z,1352401134.261 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.SampleADCP = 1 bool 2012-11-08T18:58:54.263Z,1352401134.263 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.PeakDetectChlActive = 0 bool 2012-11-08T18:58:54.266Z,1352401134.266 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.PeakDetectNO3Active = 0 bool 2012-11-08T18:58:54.269Z,1352401134.269 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.PeakDetectRSSIActive = 0 bool 2012-11-08T18:58:54.272Z,1352401134.272 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledAanderaaO2 = 0.000000 n/a 2012-11-08T18:58:54.276Z,1352401134.276 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledNeilBrown = 1.000000 n/a 2012-11-08T18:58:54.279Z,1352401134.279 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledTurbulence_NPS = 1.000000 n/a 2012-11-08T18:58:54.282Z,1352401134.282 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2012-11-08T18:58:54.286Z,1352401134.286 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledDVL = 1.000000 n/a 2012-11-08T18:58:54.289Z,1352401134.289 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Inbound:Science.EnabledISUS = 0.000000 n/a 2012-11-08T18:58:54.292Z,1352401134.292 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakChl = 0.000000 ug/l 2012-11-08T18:58:54.295Z,1352401134.295 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakChlDepth = 0.000000 m 2012-11-08T18:58:54.298Z,1352401134.298 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakChlLatitude = nan arcdeg 2012-11-08T18:58:54.301Z,1352401134.301 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakChlLongitude = nan arcdeg 2012-11-08T18:58:54.304Z,1352401134.304 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakNO3 = 0.000000 umol/l 2012-11-08T18:58:54.308Z,1352401134.307 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakNO3Depth = 0.000000 m 2012-11-08T18:58:54.311Z,1352401134.311 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakNO3Latitude = nan arcdeg 2012-11-08T18:58:54.313Z,1352401134.313 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakNO3Longitude = nan arcdeg 2012-11-08T18:58:54.317Z,1352401134.317 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakRSSI = 0.000000 dB 2012-11-08T18:58:54.320Z,1352401134.320 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakRSSIDepth = 0.000000 m 2012-11-08T18:58:54.323Z,1352401134.323 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakRSSILatitude = nan arcdeg 2012-11-08T18:58:54.326Z,1352401134.326 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Inbound:Science.PeakRSSILongitude = nan arcdeg 2012-11-08T18:58:54.338Z,1352401134.338 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.347Z,1352401134.347 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.357Z,1352401134.357 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.364Z,1352401134.364 [MissionManager](INFO): RedefineArg turbulence_daphne:ScienceOps:Inbound:Science.PeakDetectRSSIActive = 1 bool 2012-11-08T18:58:54.365Z,1352401134.365 [MissionManager](INFO): RedefineArg turbulence_daphne:ScienceOps:Inbound:Science.PeakDetectChlActive = 1 bool 2012-11-08T18:58:54.366Z,1352401134.366 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed](DEBUG): Construct. 2012-11-08T18:58:54.369Z,1352401134.369 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-11-08T18:58:54.378Z,1352401134.378 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-11-08T18:58:54.390Z,1352401134.390 [turbulence_daphne:ScienceOps:Inbound:F.YoYo](DEBUG): Construct YoYo. 2012-11-08T18:58:54.398Z,1352401134.398 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:54.403Z,1352401134.403 [turbulence_daphne:ScienceOps:Inbound:WpMidway.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:54.412Z,1352401134.412 [turbulence_daphne:ScienceOps:Inbound:WpEast.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:54.421Z,1352401134.421 [turbulence_daphne:ScienceOps:Outbound:A_Timeout:A.StopMission](DEBUG): Construct StopMission. 2012-11-08T18:58:54.422Z,1352401134.422 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2012-11-08T18:58:54.489Z,1352401134.489 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.SampleISUS = 0 bool 2012-11-08T18:58:54.492Z,1352401134.492 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.SampleRSSI = 1 bool 2012-11-08T18:58:54.495Z,1352401134.495 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.SampleADCP = 1 bool 2012-11-08T18:58:54.497Z,1352401134.497 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.PeakDetectChlActive = 0 bool 2012-11-08T18:58:54.500Z,1352401134.500 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.PeakDetectNO3Active = 0 bool 2012-11-08T18:58:54.503Z,1352401134.503 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.PeakDetectRSSIActive = 0 bool 2012-11-08T18:58:54.506Z,1352401134.506 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledAanderaaO2 = 0.000000 n/a 2012-11-08T18:58:54.509Z,1352401134.509 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledNeilBrown = 1.000000 n/a 2012-11-08T18:58:54.513Z,1352401134.513 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledTurbulence_NPS = 1.000000 n/a 2012-11-08T18:58:54.516Z,1352401134.516 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2012-11-08T18:58:54.519Z,1352401134.519 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledDVL = 1.000000 n/a 2012-11-08T18:58:54.523Z,1352401134.523 [MissionManager](INFO): DefineArg turbulence_daphne:ScienceOps:Outbound:Science.EnabledISUS = 0.000000 n/a 2012-11-08T18:58:54.526Z,1352401134.526 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakChl = 0.000000 ug/l 2012-11-08T18:58:54.529Z,1352401134.529 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakChlDepth = 0.000000 m 2012-11-08T18:58:54.532Z,1352401134.532 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakChlLatitude = nan arcdeg 2012-11-08T18:58:54.535Z,1352401134.535 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakChlLongitude = nan arcdeg 2012-11-08T18:58:54.538Z,1352401134.538 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakNO3 = 0.000000 umol/l 2012-11-08T18:58:54.541Z,1352401134.541 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakNO3Depth = 0.000000 m 2012-11-08T18:58:54.544Z,1352401134.544 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakNO3Latitude = nan arcdeg 2012-11-08T18:58:54.547Z,1352401134.547 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakNO3Longitude = nan arcdeg 2012-11-08T18:58:54.550Z,1352401134.550 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakRSSI = 0.000000 dB 2012-11-08T18:58:54.553Z,1352401134.553 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakRSSIDepth = 0.000000 m 2012-11-08T18:58:54.556Z,1352401134.556 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakRSSILatitude = nan arcdeg 2012-11-08T18:58:54.560Z,1352401134.560 [MissionManager](INFO): DefineOutput turbulence_daphne:ScienceOps:Outbound:Science.PeakRSSILongitude = nan arcdeg 2012-11-08T18:58:54.573Z,1352401134.573 [turbulence_daphne:ScienceOps:Outbound:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.581Z,1352401134.581 [turbulence_daphne:ScienceOps:Outbound:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.590Z,1352401134.590 [turbulence_daphne:ScienceOps:Outbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2012-11-08T18:58:54.598Z,1352401134.598 [MissionManager](INFO): RedefineArg turbulence_daphne:ScienceOps:Outbound:Science.SampleADCP = 0 bool 2012-11-08T18:58:54.599Z,1352401134.599 [MissionManager](INFO): RedefineArg turbulence_daphne:ScienceOps:Outbound:Science.SampleRSSI = 0 bool 2012-11-08T18:58:54.600Z,1352401134.600 [MissionManager](INFO): RedefineArg turbulence_daphne:ScienceOps:Outbound:Science.PeakDetectChlActive = 1 bool 2012-11-08T18:58:54.601Z,1352401134.601 [turbulence_daphne:ScienceOps:Outbound:B.SetSpeed](DEBUG): Construct. 2012-11-08T18:58:54.604Z,1352401134.604 [turbulence_daphne:ScienceOps:Outbound:C.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2012-11-08T18:58:54.623Z,1352401134.624 [turbulence_daphne:ScienceOps:Outbound:YoYoBottomFollow:Yo:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2012-11-08T18:58:54.632Z,1352401134.632 [turbulence_daphne:ScienceOps:Outbound:YoYoBottomFollow:Yo:B.YoYo](DEBUG): Construct YoYo. 2012-11-08T18:58:54.644Z,1352401134.644 [turbulence_daphne:ScienceOps:Outbound:YoYoBottomFollow:BottomFollow:A.PitchServo](DEBUG): Construct. 2012-11-08T18:58:54.652Z,1352401134.652 [turbulence_daphne:ScienceOps:Outbound:YoYoBottomFollow:BottomFollow:B.Wait](DEBUG): Construct Wait. 2012-11-08T18:58:54.653Z,1352401134.653 [turbulence_daphne:ScienceOps:Outbound:WpOutbound.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:54.661Z,1352401134.661 [turbulence_daphne:ScienceOps:Outbound:WpWestOutbound.Waypoint](DEBUG): Construct Waypoint. 2012-11-08T18:58:54.721Z,1352401134.721 [MissionManager](DEBUG): Daphne’s mission will have her running yoyos from West to East starting at the 120 isobath and ending at the 30 meter isobath. She will surface for a GPS fix at the 60 meter isobath and at the 30 meter isobath when she turns. The outbound leg will be a bottom following saw tooth. She will bottom follow at 3 meters altitude for 12 minutes then do a short up to 15 meter altitude and back down to 3 meters altitutude. There will be no surfacing on the outbound track until the western end point at which point she will surface and send back logs for the full East – West transit before commencing the next run. If true, skip approach and continue previously interrupted eastward science leg (if interrupted by WDT reset, for example). If true, skip approach and eastward leg and continue previously interrupted westward science leg (if interrupted by WDT reset, for example). Minimum altitude for the entire mission. 2 Maximum depth for the entire mission. 105 Minimum offshore distance for the entire mission. 2000 Vehicle speed. 1 Maximum duration of mission 30 Static setting for mass during the mission. Defaults to massDefault setting in the Config/Control.cfg file. Buoyancy bladder position while performing the YoYo behavior. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Latitude of deep waypoint. 36.7160 Longitude of deep waypoint. -121.9034 Do a quick surface when east of this Longitude. -121.8840 Latitude of midway waypoint - GPS update only, no Iridium! 36.7160 Longitude of midway waypoint - GPS update only, no Iridium! -121.8600 Latitude of shallowest waypoint - GPS update only, no Iridium! 36.7160 Longitude of shallowest waypoint - GPS update only, no Iridium! -121.8366 Do a quick surface when west of this Longitude. -121.8700 Depth for initial approach to WpWest. 20.0 Maximum duration of initial approach 5 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications. Only active during the approach. 60 Number of times to repeat the science loop 999 Maximum duration of inbound leg 5 Maximum duration to surface and get a GPS fix on inbound leg 5 Only initiate fast surfacing when pitch exceeds this value. 15 Float at the surface this long when doing a SurfaceFast. 30 Minimum depth during yo-yo's. 3.0 Maximum depth during yo-yo's. 100.0 Min altitude while in yo-yo mode. 3 Pitch when yo-yo's are ascending. 20.0 Pitch when yo-yo's are descending. -10.0 Maximum duration of outbound leg 5 Maximum altitude while yo-yo-ing in yo-yo and bottom following mode. 15 Period of yo-yo and bottom following cycle. 12.0 Altitude while following the bottom. 3 Maximum depth while following the bottom. 100.0 PID loop parameter for following the bottom. -0.06 PID loop parameter for following the bottom. 0 PID loop parameter for following the bottom. 0 Variable used internally within the mission 1 Variable used internally within the mission Note that we are setting massPosition at a higher priority than the the vertical safety behaviors. The intent is to ensure that the mass does not actuate near the sea floor, potentially failing and re-centering, which some imagine could cause a nose-dive into the sea floor. 20 1 20 1 20 1 ***** Get to start point ***** ***** Check in periodically, but do not split logs ****** Repeat the following loop a lot of times ****** Inbound, get science data, including RSSI and ADCP ****** Outbound, get science data, except for RSSI and ADCP 1 2 -1 2012-11-08T18:58:54.722Z,1352401134.722 [CommandLine](IMPORTANT): Running ./Missions/Science/turbulence_daphne.xml 2012-11-08T18:58:56.448Z,1352401136.448 [Default] Stopped 2012-11-08T18:58:56.448Z,1352401136.448 [Default](INFO): Aggregate::uninitialize Default 2012-11-08T18:58:56.448Z,1352401136.448 [Default:D.SetSpeed] Stopped 2012-11-08T18:58:56.448Z,1352401136.448 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-11-08T18:58:56.448Z,1352401136.448 [Default:E.GoToSurface] Stopped 2012-11-08T18:58:56.448Z,1352401136.448 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:58:56.448Z,1352401136.448 [Default:F.Wait] Stopped 2012-11-08T18:58:56.448Z,1352401136.448 [Default:F.Wait](DEBUG): Uninitialize Wait Component. 2012-11-08T18:58:56.449Z,1352401136.449 [MissionManager](IMPORTANT): Started mission turbulence_daphne 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne] Running Loop=1 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne](INFO): Aggregate::initialize turbulence_daphne 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne:A.Pitch] Running Loop=1 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne:A.Pitch](DEBUG): Initialize. 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne:B.AltitudeEnvelope] Running Loop=1 2012-11-08T18:58:56.449Z,1352401136.449 [turbulence_daphne:B.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-11-08T18:58:56.449Z,1352401136.450 [turbulence_daphne:C.DepthEnvelope] Running Loop=1 2012-11-08T18:58:56.450Z,1352401136.450 [turbulence_daphne:C.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:I.Buoyancy] Running Loop=1 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:I.Buoyancy](DEBUG): Initialize Buoyancy Component. 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:J.OffshoreEnvelope] Running Loop=1 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:J.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:SurfaceComms] Running Loop=1 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:SurfaceComms](INFO): Aggregate::initialize turbulence_daphne:SurfaceComms 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:SurfaceComms:A.GoToSurface] Running Loop=1 2012-11-08T18:58:56.454Z,1352401136.454 [turbulence_daphne:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T18:58:56.455Z,1352401136.455 [turbulence_daphne:J.OffshoreEnvelope] Running Loop=1 2012-11-08T18:58:56.460Z,1352401136.460 [turbulence_daphne:I.Buoyancy] Running Loop=1 2012-11-08T18:58:56.498Z,1352401136.499 [turbulence_daphne:SurfaceComms:B] Running Loop=1 2012-11-08T18:58:56.499Z,1352401136.499 [turbulence_daphne:SurfaceComms:B](INFO): Aggregate::initialize turbulence_daphne:SurfaceComms:B 2012-11-08T18:58:56.499Z,1352401136.499 [turbulence_daphne:SurfaceComms:B:A] Running Loop=1 2012-11-08T18:58:56.499Z,1352401136.499 [turbulence_daphne:C.DepthEnvelope] Running Loop=1 2012-11-08T18:58:56.504Z,1352401136.504 [turbulence_daphne:B.AltitudeEnvelope] Running Loop=1 2012-11-08T18:58:56.509Z,1352401136.509 [turbulence_daphne:A.Pitch] Running Loop=1 2012-11-08T18:58:56.587Z,1352401136.587 [DVL_micro](INFO): RSSI unrequested 2012-11-08T18:58:56.587Z,1352401136.587 [DVL_micro](INFO): ADCP unrequested 2012-11-08T18:58:56.587Z,1352401136.587 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:58:56.588Z,1352401136.588 [DVL_micro](INFO): resume:Powering up 2012-11-08T18:58:56.588Z,1352401136.588 [DVL_micro](INFO): Cycling power to configure device. 2012-11-08T18:58:56.747Z,1352401136.747 [turbulence_daphne:SurfaceComms:B] Stopped 2012-11-08T18:58:56.747Z,1352401136.747 [turbulence_daphne:SurfaceComms:B](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceComms:B 2012-11-08T18:58:56.747Z,1352401136.747 [turbulence_daphne:SurfaceComms:B:A] Stopped 2012-11-08T18:58:56.750Z,1352401136.750 [turbulence_daphne:SurfaceComms:C] Running Loop=1 2012-11-08T18:58:56.750Z,1352401136.750 [turbulence_daphne:SurfaceComms:C](INFO): Aggregate::initialize turbulence_daphne:SurfaceComms:C 2012-11-08T18:58:56.750Z,1352401136.750 [turbulence_daphne:SurfaceComms:C:A] Running Loop=1 2012-11-08T18:58:57.124Z,1352401137.124 [turbulence_daphne:J.OffshoreEnvelope] Preempted 2012-11-08T18:58:57.124Z,1352401137.124 [turbulence_daphne:I.Buoyancy] Preempted 2012-11-08T18:58:57.125Z,1352401137.125 [turbulence_daphne:SurfaceComms:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T18:58:57.526Z,1352401137.526 [NAL9602](INFO): Powering up 2012-11-08T18:58:58.595Z,1352401138.595 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:58:58.595Z,1352401138.595 [DVL_micro](INFO): Querying output modes 2012-11-08T18:58:58.595Z,1352401138.595 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-11-08T18:58:58.599Z,1352401138.599 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2012-11-08T18:58:58.599Z,1352401138.599 [DVL_micro](INFO): NQ1 output enabled 2012-11-08T18:58:58.599Z,1352401138.599 [DVL_micro](INFO): RSSI output enabled 2012-11-08T18:58:58.599Z,1352401138.599 [DVL_micro](INFO): ADCP output enabled 2012-11-08T18:58:58.599Z,1352401138.599 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-11-08T18:58:58.607Z,1352401138.606 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-11-08T18:58:58.608Z,1352401138.608 [DVL_micro](INFO): RSSI unrequested 2012-11-08T18:58:58.608Z,1352401138.608 [DVL_micro](INFO): ADCP unrequested 2012-11-08T18:58:58.609Z,1352401138.609 [DVL_micro](INFO): Cycling power to configure device. 2012-11-08T18:59:00.614Z,1352401140.615 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:59:00.615Z,1352401140.615 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0 2012-11-08T18:59:00.627Z,1352401140.627 [DVL_micro](DEBUG): cmdResponse: ‰«ââ“â²â‰â|â–âÊâ×âÅâºâŽâ|âoâ€âTâHâNâzânâÎâ§âmâMâ”â¾âãâÉââsâWâaâoâ^â_âmâxâ¡âÌâˆâfâZâvâ~â`â_â_âtâ] 2012-11-08T18:59:00.627Z,1352401140.627 [DVL_micro](INFO): Enabling NQ1 output 2012-11-08T18:59:00.627Z,1352401140.627 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1 2012-11-08T18:59:00.638Z,1352401140.638 [DVL_micro](DEBUG): cmdResponse: âžâµâŸâ˜â|âwârâ~âhâzâ‘âsâZâTâ]â@âQâ8âCârâmâ`â£â‹â«âÆâ«ââdâUâ\âjâYâDâ\âYâdâyâânâGâLâ¨â¯â—â‡âZâlâv 2012-11-08T18:59:00.638Z,1352401140.638 [DVL_micro](INFO): Querying output modes 2012-11-08T18:59:00.639Z,1352401140.639 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-11-08T18:59:00.651Z,1352401140.651 [DVL_micro](DEBUG): cmdResponse: â~âtâ›â¨âŽâ…â•âçâÓââ_ânââ¤â|â[âhâ–â€â âÃâ¦âZâTâ]âyâˆâsââ™âÁâxâ_âPâ^â_âRâvâkâ…âŸâ¼â«âŒâ`âbâsâ—⪠2012-11-08T18:59:00.651Z,1352401140.651 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-11-08T18:59:00.662Z,1352401140.662 [DVL_micro](DEBUG): cmdResponse: âkâUâŠâpâkânâ‰â„âƒâ`âbâ âÑâ¹â â‰âkâWâaâ\âTâfâ·âÖâ â¥âiâfâŸâ©ânâYâVâYâbâ`âgâXâ“â½âŸâ}â‚âoâ[âHâ9â[âj 2012-11-08T18:59:01.236Z,1352401141.236 [DVL_micro](INFO): NQ1 requested 2012-11-08T18:59:01.236Z,1352401141.236 [DVL_micro](INFO): Cycling power to configure device. 2012-11-08T18:59:02.733Z,1352401142.733 [NAL9602](IMPORTANT): GPS fix at: 1352401142.73 2012-11-08T18:59:02.750Z,1352401142.750 [turbulence_daphne:SurfaceComms:C:A] Stopped 2012-11-08T18:59:02.750Z,1352401142.750 [turbulence_daphne:SurfaceComms:C:B] Running Loop=1 2012-11-08T18:59:03.127Z,1352401143.127 [turbulence_daphne:SurfaceComms:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-11-08T18:59:03.243Z,1352401143.243 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T18:59:03.243Z,1352401143.243 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0 2012-11-08T18:59:03.426Z,1352401143.426 [DVL_micro](DEBUG): cmdResponse: 00 2012-11-08T18:59:03.426Z,1352401143.426 [DVL_micro](INFO): Enabling NQ1 output 2012-11-08T18:59:03.427Z,1352401143.427 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1 2012-11-08T18:59:03.611Z,1352401143.611 [DVL_micro](DEBUG): cmdResponse: 01 2012-11-08T18:59:03.611Z,1352401143.611 [DVL_micro](INFO): Querying output modes 2012-11-08T18:59:03.611Z,1352401143.611 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-11-08T18:59:03.615Z,1352401143.615 [DVL_micro](DEBUG): cmdResponse: 01 2012-11-08T18:59:03.615Z,1352401143.615 [DVL_micro](INFO): NQ1 output enabled 2012-11-08T18:59:03.615Z,1352401143.615 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-11-08T18:59:03.619Z,1352401143.619 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-11-08T18:59:05.511Z,1352401145.511 [NAL9602](INFO): Sent 300 bytes from file Logs/20121108T183645/shore0005.lzma 2012-11-08T18:59:05.511Z,1352401145.511 [NAL9602](INFO): Packets left to send: 0 2012-11-08T18:59:05.523Z,1352401145.523 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0005.lzma.parts/0000.sbd 2012-11-08T18:59:06.131Z,1352401146.131 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:06.383Z,1352401146.383 [turbulence_daphne:SurfaceComms:C:B] Stopped 2012-11-08T18:59:06.383Z,1352401146.383 [turbulence_daphne:SurfaceComms:C:C] Running Loop=1 2012-11-08T18:59:06.737Z,1352401146.737 [turbulence_daphne:SurfaceComms:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T18:59:08.662Z,1352401148.662 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:11.183Z,1352401151.183 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:11.519Z,1352401151.519 [NAL9602](IMPORTANT): GPS fix at: 1352401151.51 2012-11-08T18:59:11.537Z,1352401151.537 [turbulence_daphne:SurfaceComms:C:C] Stopped 2012-11-08T18:59:11.537Z,1352401151.537 [turbulence_daphne:SurfaceComms:C](INFO): Completed turbulence_daphne:SurfaceComms:C 2012-11-08T18:59:11.537Z,1352401151.537 [turbulence_daphne:SurfaceComms:C] Stopped 2012-11-08T18:59:11.537Z,1352401151.537 [turbulence_daphne:SurfaceComms:C](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceComms:C 2012-11-08T18:59:11.538Z,1352401151.538 [turbulence_daphne:SurfaceComms](INFO): Completed turbulence_daphne:SurfaceComms 2012-11-08T18:59:11.538Z,1352401151.538 [turbulence_daphne:SurfaceComms] Stopped 2012-11-08T18:59:11.538Z,1352401151.538 [turbulence_daphne:SurfaceComms](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceComms 2012-11-08T18:59:11.538Z,1352401151.538 [turbulence_daphne:SurfaceComms:A.GoToSurface] Stopped 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach] Running Loop=1 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach](INFO): Aggregate::initialize turbulence_daphne:Approach 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach:B.Pitch] Running Loop=1 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach:B.Pitch](DEBUG): Initialize. 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach:C.SetSpeed] Running Loop=1 2012-11-08T18:59:11.539Z,1352401151.539 [turbulence_daphne:Approach:C.SetSpeed](DEBUG): Initialize. 2012-11-08T18:59:11.540Z,1352401151.540 [turbulence_daphne:Approach:WpWestApproach.Waypoint] Running Loop=1 2012-11-08T18:59:11.540Z,1352401151.540 [turbulence_daphne:Approach:WpWestApproach.Waypoint](DEBUG): Initialize WaypointComponent. 2012-11-08T18:59:11.937Z,1352401151.937 [turbulence_daphne:Approach:C.SetSpeed] Running Loop=1 2012-11-08T18:59:11.942Z,1352401151.942 [turbulence_daphne:Approach:B.Pitch] Running Loop=1 2012-11-08T18:59:11.947Z,1352401151.947 [turbulence_daphne:J.OffshoreEnvelope] Running Loop=1 2012-11-08T18:59:11.948Z,1352401151.948 [turbulence_daphne:I.Buoyancy] Running Loop=1 2012-11-08T18:59:13.706Z,1352401153.706 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:16.010Z,1352401156.010 [Radio_Freewave](INFO): Powering down 2012-11-08T18:59:16.226Z,1352401156.226 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:17.520Z,1352401157.520 [NAL9602](INFO): Powering down 2012-11-08T18:59:18.750Z,1352401158.750 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:21.281Z,1352401161.281 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:23.798Z,1352401163.798 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:26.314Z,1352401166.314 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:28.838Z,1352401168.838 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:31.362Z,1352401171.362 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:33.878Z,1352401173.878 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:36.398Z,1352401176.398 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:38.918Z,1352401178.918 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:41.526Z,1352401181.526 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:44.054Z,1352401184.054 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:44.779Z,1352401184.779 [Radio_Freewave](INFO): Powering up 2012-11-08T18:59:46.562Z,1352401186.562 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:49.083Z,1352401189.083 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:51.590Z,1352401191.590 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:54.111Z,1352401194.111 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:56.627Z,1352401196.626 [DVL_micro](DEBUG): NQ1 2012-11-08T18:59:59.139Z,1352401199.139 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:01.654Z,1352401201.654 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:04.174Z,1352401204.174 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:06.682Z,1352401206.682 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:09.190Z,1352401209.190 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:11.806Z,1352401211.806 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:14.322Z,1352401214.322 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:15.283Z,1352401215.283 [turbulence_daphne:Approach:WpWestApproach.Waypoint](INFO): Reached Waypoint: 36.716000,-121.903400 2012-11-08T19:00:15.284Z,1352401215.284 [turbulence_daphne:Approach:WpWestApproach.Waypoint] Stopped 2012-11-08T19:00:15.284Z,1352401215.284 [turbulence_daphne:Approach:WpWestApproach.Waypoint](DEBUG): Uninitialize WaypointComponent. 2012-11-08T19:00:15.284Z,1352401215.284 [turbulence_daphne:Approach:E] Running Loop=1 2012-11-08T19:00:15.284Z,1352401215.284 [turbulence_daphne:Approach:E](INFO): Aggregate::initialize turbulence_daphne:Approach:E 2012-11-08T19:00:15.621Z,1352401215.621 [turbulence_daphne:SurfaceCommsSplit] Running Loop=1 2012-11-08T19:00:15.622Z,1352401215.622 [turbulence_daphne:SurfaceCommsSplit](INFO): Aggregate::initialize turbulence_daphne:SurfaceCommsSplit 2012-11-08T19:00:15.622Z,1352401215.622 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms] Running Loop=1 2012-11-08T19:00:15.622Z,1352401215.622 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms](INFO): Aggregate::initialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms 2012-11-08T19:00:15.622Z,1352401215.622 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:A.GoToSurface] Running Loop=1 2012-11-08T19:00:15.623Z,1352401215.622 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T19:00:15.628Z,1352401215.628 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B] Running Loop=1 2012-11-08T19:00:15.628Z,1352401215.628 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B](INFO): Aggregate::initialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B 2012-11-08T19:00:15.629Z,1352401215.629 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B:A] Running Loop=1 2012-11-08T19:00:16.017Z,1352401216.017 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B:A](INFO): ##UnpackSplit## 2012-11-08T19:00:16.019Z,1352401216.019 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B:A] Stopped 2012-11-08T19:00:16.019Z,1352401216.019 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B](INFO): Completed turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B 2012-11-08T19:00:16.019Z,1352401216.019 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B] Stopped 2012-11-08T19:00:16.020Z,1352401216.020 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms:B 2012-11-08T19:00:16.020Z,1352401216.020 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C] Running Loop=1 2012-11-08T19:00:16.020Z,1352401216.020 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C](INFO): Aggregate::initialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C 2012-11-08T19:00:16.020Z,1352401216.020 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:A] Running Loop=1 2012-11-08T19:00:16.415Z,1352401216.415 [turbulence_daphne:J.OffshoreEnvelope] Preempted 2012-11-08T19:00:16.415Z,1352401216.415 [turbulence_daphne:I.Buoyancy] Preempted 2012-11-08T19:00:16.416Z,1352401216.416 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T19:00:16.798Z,1352401216.798 [NAL9602](INFO): Powering up 2012-11-08T19:00:16.834Z,1352401216.834 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:19.350Z,1352401219.350 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:21.858Z,1352401221.858 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:22.020Z,1352401222.020 [NAL9602](IMPORTANT): GPS fix at: 1352401222.00 2012-11-08T19:00:22.040Z,1352401222.039 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:A] Stopped 2012-11-08T19:00:22.040Z,1352401222.040 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:B] Running Loop=1 2012-11-08T19:00:22.417Z,1352401222.417 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-11-08T19:00:24.363Z,1352401224.362 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:24.870Z,1352401224.870 [NAL9602](INFO): Sent 183 bytes from file Logs/20121108T183645/shore0006.lzma 2012-11-08T19:00:24.876Z,1352401224.876 [NAL9602](INFO): Packets left to send: 0 2012-11-08T19:00:24.919Z,1352401224.919 [NAL9602](INFO): Stored copy of sent data in Logs/20121108T183645/shore0006.lzma.parts/0000.sbd 2012-11-08T19:00:25.885Z,1352401225.885 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:B] Stopped 2012-11-08T19:00:25.885Z,1352401225.885 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:C] Running Loop=1 2012-11-08T19:00:26.285Z,1352401226.285 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-11-08T19:00:26.975Z,1352401226.975 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:29.495Z,1352401229.495 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:31.068Z,1352401231.068 [NAL9602](IMPORTANT): GPS fix at: 1352401231.00 2012-11-08T19:00:31.085Z,1352401231.085 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C:C] Stopped 2012-11-08T19:00:31.086Z,1352401231.086 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C](INFO): Completed turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C 2012-11-08T19:00:31.086Z,1352401231.086 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C] Stopped 2012-11-08T19:00:31.086Z,1352401231.086 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms:C 2012-11-08T19:00:31.087Z,1352401231.087 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms](INFO): Completed turbulence_daphne:SurfaceCommsSplit:SurfaceComms 2012-11-08T19:00:31.087Z,1352401231.087 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms] Stopped 2012-11-08T19:00:31.087Z,1352401231.087 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceCommsSplit:SurfaceComms 2012-11-08T19:00:31.087Z,1352401231.087 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:A.GoToSurface] Stopped 2012-11-08T19:00:31.087Z,1352401231.087 [turbulence_daphne:SurfaceCommsSplit:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T19:00:31.088Z,1352401231.088 [turbulence_daphne:SurfaceCommsSplit](INFO): Completed turbulence_daphne:SurfaceCommsSplit 2012-11-08T19:00:31.088Z,1352401231.088 [turbulence_daphne:SurfaceCommsSplit] Stopped 2012-11-08T19:00:31.088Z,1352401231.088 [turbulence_daphne:SurfaceCommsSplit](INFO): Aggregate::uninitialize turbulence_daphne:SurfaceCommsSplit 2012-11-08T19:00:31.501Z,1352401231.501 [Radio_Freewave](INFO): Powering down 2012-11-08T19:00:31.514Z,1352401231.514 [turbulence_daphne:Approach:E](INFO): Completed turbulence_daphne:Approach:E 2012-11-08T19:00:31.514Z,1352401231.514 [turbulence_daphne:Approach:E] Stopped 2012-11-08T19:00:31.514Z,1352401231.514 [turbulence_daphne:Approach:E](INFO): Aggregate::uninitialize turbulence_daphne:Approach:E 2012-11-08T19:00:31.515Z,1352401231.515 [turbulence_daphne:Approach](INFO): Completed turbulence_daphne:Approach 2012-11-08T19:00:31.515Z,1352401231.515 [turbulence_daphne:Approach] Stopped 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:Approach](INFO): Aggregate::uninitialize turbulence_daphne:Approach 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:Approach:B.Pitch] Stopped 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:Approach:C.SetSpeed] Stopped 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:Approach:C.SetSpeed](DEBUG): Uninitialize. 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:ScienceOps] Running Loop=1 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:ScienceOps](INFO): Aggregate::initialize turbulence_daphne:ScienceOps 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:ScienceOps:A] Running Loop=1 2012-11-08T19:00:31.516Z,1352401231.516 [turbulence_daphne:J.OffshoreEnvelope] Running Loop=1 2012-11-08T19:00:31.517Z,1352401231.517 [turbulence_daphne:I.Buoyancy] Running Loop=1 2012-11-08T19:00:31.886Z,1352401231.886 [turbulence_daphne:ScienceOps:A] Stopped 2012-11-08T19:00:31.886Z,1352401231.886 [turbulence_daphne:ScienceOps:Inbound] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound](INFO): Aggregate::initialize turbulence_daphne:ScienceOps:Inbound 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science](INFO): Aggregate::initialize turbulence_daphne:ScienceOps:Inbound:Science 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:A] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:B] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:C] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:D] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:E] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:F] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:Science:G] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed] Running Loop=1 2012-11-08T19:00:31.887Z,1352401231.887 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed](DEBUG): Initialize. 2012-11-08T19:00:31.888Z,1352401231.888 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope] Running Loop=1 2012-11-08T19:00:31.888Z,1352401231.888 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2012-11-08T19:00:31.889Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope] Running Loop=1 2012-11-08T19:00:31.889Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2012-11-08T19:00:31.889Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:F.YoYo] Running Loop=1 2012-11-08T19:00:31.889Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:F.YoYo](DEBUG): Initialize YoYoComponent. 2012-11-08T19:00:31.890Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint] Running Loop=1 2012-11-08T19:00:31.890Z,1352401231.889 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint](DEBUG): Initialize WaypointComponent. 2012-11-08T19:00:32.007Z,1352401232.007 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:32.301Z,1352401232.301 [turbulence_daphne:ScienceOps:Inbound:F.YoYo] Running Loop=1 2012-11-08T19:00:32.306Z,1352401232.306 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope] Running Loop=1 2012-11-08T19:00:32.311Z,1352401232.311 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope] Running Loop=1 2012-11-08T19:00:32.317Z,1352401232.317 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed] Running Loop=1 2012-11-08T19:00:32.321Z,1352401232.321 [turbulence_daphne:ScienceOps:Inbound:Science] Running Loop=1 2012-11-08T19:00:32.322Z,1352401232.322 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI] Running Loop=1 2012-11-08T19:00:32.322Z,1352401232.322 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI](INFO): Aggregate::initialize turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI 2012-11-08T19:00:32.322Z,1352401232.322 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth] Running Loop=1 2012-11-08T19:00:32.323Z,1352401232.323 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth](INFO): Initialize. 2012-11-08T19:00:32.329Z,1352401232.329 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl] Running Loop=1 2012-11-08T19:00:32.329Z,1352401232.329 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl](INFO): Aggregate::initialize turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl 2012-11-08T19:00:32.329Z,1352401232.329 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2012-11-08T19:00:32.330Z,1352401232.330 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl:A.PeakDetectVsDepth](INFO): Initialize. 2012-11-08T19:00:32.336Z,1352401232.336 [turbulence_daphne:ScienceOps:Inbound:Science:G] Running Loop=1 2012-11-08T19:00:32.337Z,1352401232.337 [turbulence_daphne:ScienceOps:Inbound:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2012-11-08T19:00:32.338Z,1352401232.338 [turbulence_daphne:ScienceOps:Inbound:Science:F] Running Loop=1 2012-11-08T19:00:32.339Z,1352401232.339 [turbulence_daphne:ScienceOps:Inbound:Science:F](DEBUG): Initialize ReadDataComponent to sense DVL_micro.Beam1RSSI 2012-11-08T19:00:32.340Z,1352401232.340 [turbulence_daphne:ScienceOps:Inbound:Science:E] Running Loop=1 2012-11-08T19:00:32.341Z,1352401232.341 [turbulence_daphne:ScienceOps:Inbound:Science:E](DEBUG): Initialize ReadDataComponent to sense DVL_micro.AdcpXWaterVelocity 2012-11-08T19:00:32.343Z,1352401232.343 [turbulence_daphne:ScienceOps:Inbound:Science:D] Running Loop=1 2012-11-08T19:00:32.343Z,1352401232.343 [turbulence_daphne:ScienceOps:Inbound:Science:D](DEBUG): Initialize ReadDataComponent to sense Turbulence_NPS.MicroCond 2012-11-08T19:00:32.345Z,1352401232.345 [turbulence_daphne:ScienceOps:Inbound:Science:C] Running Loop=1 2012-11-08T19:00:32.346Z,1352401232.346 [turbulence_daphne:ScienceOps:Inbound:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2012-11-08T19:00:32.347Z,1352401232.347 [turbulence_daphne:ScienceOps:Inbound:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2012-11-08T19:00:32.432Z,1352401232.432 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2012-11-08T19:00:32.432Z,1352401232.432 [WetLabsBB2FL](INFO): Powering up 2012-11-08T19:00:32.435Z,1352401232.435 [Turbulence_NPS](INFO): Resume powering up 2012-11-08T19:00:32.435Z,1352401232.435 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1 2012-11-08T19:00:32.512Z,1352401232.512 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2012-11-08T19:00:34.136Z,1352401234.136 [DVL_micro](INFO): RSSI requested 2012-11-08T19:00:34.136Z,1352401234.136 [DVL_micro](INFO): ADCP requested 2012-11-08T19:00:34.137Z,1352401234.136 [DVL_micro](INFO): Cycling power to configure device. 2012-11-08T19:00:36.143Z,1352401236.143 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-11-08T19:00:36.143Z,1352401236.143 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD1616 00 0 2012-11-08T19:00:36.327Z,1352401236.327 [DVL_micro](DEBUG): cmdResponse: 00 2012-11-08T19:00:36.327Z,1352401236.327 [DVL_micro](INFO): Enabling RSSI output 2012-11-08T19:00:36.327Z,1352401236.327 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 16 7 2012-11-08T19:00:36.511Z,1352401236.511 [DVL_micro](DEBUG): cmdResponse: 16 2012-11-08T19:00:36.511Z,1352401236.511 [DVL_micro](INFO): Enabling ADCP output 2012-11-08T19:00:36.511Z,1352401236.511 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 03 3 2012-11-08T19:00:36.695Z,1352401236.695 [DVL_micro](DEBUG): cmdResponse: 03 16 2012-11-08T19:00:36.695Z,1352401236.695 [DVL_micro](INFO): Enabling NQ1 output 2012-11-08T19:00:36.695Z,1352401236.695 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0505 01 1 2012-11-08T19:00:36.872Z,1352401236.872 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2012-11-08T19:00:36.872Z,1352401236.872 [DVL_micro](INFO): Querying output modes 2012-11-08T19:00:36.872Z,1352401236.872 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-11-08T19:00:36.901Z,1352401236.901 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2012-11-08T19:00:36.901Z,1352401236.901 [DVL_micro](INFO): NQ1 output enabled 2012-11-08T19:00:36.901Z,1352401236.901 [DVL_micro](INFO): RSSI output enabled 2012-11-08T19:00:36.901Z,1352401236.901 [DVL_micro](INFO): ADCP output enabled 2012-11-08T19:00:36.901Z,1352401236.901 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-11-08T19:00:36.907Z,1352401236.907 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-11-08T19:00:37.043Z,1352401237.043 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:00:37.099Z,1352401237.099 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:00:37.152Z,1352401237.151 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:00:37.175Z,1352401237.175 [NAL9602](INFO): Powering down 2012-11-08T19:00:37.211Z,1352401237.211 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:00:37.488Z,1352401237.488 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:00:37.587Z,1352401237.587 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:00:37.692Z,1352401237.692 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=33 2012-11-08T19:00:37.860Z,1352401237.861 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:00:37.913Z,1352401237.913 [CTD_NeilBrown](ERROR): Bad response: .13 2012-11-08T19:00:37.931Z,1352401237.931 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:00:37.999Z,1352401237.999 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=188 2012-11-08T19:00:38.039Z,1352401238.039 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:00:38.091Z,1352401238.091 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:00:38.392Z,1352401238.392 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=248 2012-11-08T19:00:38.481Z,1352401238.481 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:00:38.575Z,1352401238.575 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:00:38.690Z,1352401238.690 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:00:39.033Z,1352401239.033 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=88 2012-11-08T19:00:39.176Z,1352401239.176 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:00:39.315Z,1352401239.315 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=1 2012-11-08T19:00:39.483Z,1352401239.483 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:00:39.784Z,1352401239.784 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=29 2012-11-08T19:00:39.900Z,1352401239.900 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=37 2012-11-08T19:00:40.015Z,1352401240.015 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=13 2012-11-08T19:00:40.133Z,1352401240.133 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:00:40.655Z,1352401240.655 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2012-11-08T19:00:40.887Z,1352401240.887 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=6 2012-11-08T19:00:41.131Z,1352401241.131 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=79 2012-11-08T19:00:41.371Z,1352401241.371 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:00:42.284Z,1352401242.284 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2012-11-08T19:00:42.755Z,1352401242.755 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=36 2012-11-08T19:00:43.227Z,1352401243.227 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=13 2012-11-08T19:00:43.709Z,1352401243.708 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:00:44.575Z,1352401244.575 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:44.621Z,1352401244.621 [DVL_micro](DEBUG): ADCP 2012-11-08T19:00:45.435Z,1352401245.435 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=5 2012-11-08T19:00:46.275Z,1352401246.275 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=13 2012-11-08T19:00:47.124Z,1352401247.124 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=149 2012-11-08T19:00:47.980Z,1352401247.980 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:00:48.625Z,1352401248.625 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=3463 2012-11-08T19:00:48.626Z,1352401248.626 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=2843 2012-11-08T19:00:48.627Z,1352401248.627 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=2992 2012-11-08T19:00:48.627Z,1352401248.627 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=2372 2012-11-08T19:00:48.639Z,1352401248.639 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1304 2012-11-08T19:00:48.640Z,1352401248.640 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2012-11-08T19:00:48.731Z,1352401248.731 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:00:48.835Z,1352401248.835 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:00:48.971Z,1352401248.971 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:00:49.027Z,1352401249.027 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2012-11-08T19:00:49.100Z,1352401249.100 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=208 2012-11-08T19:00:49.131Z,1352401249.131 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:00:49.416Z,1352401249.416 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:00:49.516Z,1352401249.516 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:00:49.619Z,1352401249.619 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2012-11-08T19:00:49.719Z,1352401249.719 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:00:50.091Z,1352401250.092 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=281 2012-11-08T19:00:50.215Z,1352401250.216 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=61 2012-11-08T19:00:50.355Z,1352401250.355 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=2 2012-11-08T19:00:50.505Z,1352401250.505 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:00:50.824Z,1352401250.824 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:00:50.939Z,1352401250.939 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=36 2012-11-08T19:00:51.059Z,1352401251.059 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=76 2012-11-08T19:00:51.169Z,1352401251.169 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:00:51.696Z,1352401251.696 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=61 2012-11-08T19:00:51.931Z,1352401251.931 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=38 2012-11-08T19:00:52.052Z,1352401252.052 [CTD_NeilBrown](ERROR): Bad response: 8323 2012-11-08T19:00:52.169Z,1352401252.169 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=46 2012-11-08T19:00:52.403Z,1352401252.403 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:00:53.323Z,1352401253.323 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2012-11-08T19:00:53.795Z,1352401253.795 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=5 2012-11-08T19:00:54.271Z,1352401254.271 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=45 2012-11-08T19:00:54.743Z,1352401254.743 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:00:55.627Z,1352401255.627 [DVL_micro](DEBUG): NQ1 2012-11-08T19:00:55.692Z,1352401255.692 [DVL_micro](DEBUG): ADCP 2012-11-08T19:00:56.483Z,1352401256.483 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=7 2012-11-08T19:00:57.323Z,1352401257.323 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=15 2012-11-08T19:00:58.159Z,1352401258.159 [DVL_micro](DEBUG): RSSI read bytes: 7218 of 9592, #buffered=0 2012-11-08T19:00:58.239Z,1352401258.239 [DVL_micro](DEBUG): RSSI read bytes: 2374 of 2374, #buffered=922 2012-11-08T19:00:58.475Z,1352401258.475 [DVL_micro](DEBUG): RSSI read bytes: 1242 of 9592, #buffered=0 2012-11-08T19:00:58.581Z,1352401258.582 [CTD_NeilBrown](ERROR): Bad response: 0.13 2012-11-08T19:00:58.995Z,1352401258.995 [DVL_micro](DEBUG): RSSI read bytes: 8350 of 8350, #buffered=4 2012-11-08T19:00:59.361Z,1352401259.361 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:00:59.361Z,1352401259.361 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:00:59.362Z,1352401259.362 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:00:59.369Z,1352401259.369 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:00:59.575Z,1352401259.575 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:00:59.679Z,1352401259.679 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:00:59.781Z,1352401259.781 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2012-11-08T19:00:59.883Z,1352401259.883 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:00.020Z,1352401260.020 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:01:00.075Z,1352401260.075 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2012-11-08T19:01:00.128Z,1352401260.128 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:01:00.179Z,1352401260.179 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:00.463Z,1352401260.463 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:01:00.567Z,1352401260.567 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:01:00.683Z,1352401260.683 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=192 2012-11-08T19:01:00.767Z,1352401260.767 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:01.119Z,1352401261.119 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:01:01.263Z,1352401261.263 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:01:01.405Z,1352401261.405 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:01:01.552Z,1352401261.552 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:01.871Z,1352401261.871 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:01:01.987Z,1352401261.987 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=36 2012-11-08T19:01:02.104Z,1352401262.104 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:01:02.224Z,1352401262.224 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:02.744Z,1352401262.744 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2012-11-08T19:01:02.975Z,1352401262.975 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=5 2012-11-08T19:01:03.238Z,1352401263.238 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=269 2012-11-08T19:01:03.451Z,1352401263.451 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:04.369Z,1352401264.369 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=29 2012-11-08T19:01:04.840Z,1352401264.839 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=5 2012-11-08T19:01:05.324Z,1352401265.324 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=109 2012-11-08T19:01:05.787Z,1352401265.787 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:06.662Z,1352401266.662 [DVL_micro](DEBUG): NQ1 2012-11-08T19:01:06.689Z,1352401266.689 [DVL_micro](DEBUG): ADCP 2012-11-08T19:01:07.523Z,1352401267.523 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=6 2012-11-08T19:01:08.364Z,1352401268.364 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=47 2012-11-08T19:01:09.199Z,1352401269.199 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=26 2012-11-08T19:01:10.039Z,1352401270.039 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:01:10.393Z,1352401270.393 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:01:10.394Z,1352401270.394 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:01:10.401Z,1352401270.401 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:01:10.403Z,1352401270.403 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:10.619Z,1352401270.619 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2012-11-08T19:01:10.719Z,1352401270.719 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=61 2012-11-08T19:01:10.819Z,1352401270.819 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=33 2012-11-08T19:01:10.919Z,1352401270.919 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:11.055Z,1352401271.055 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:01:11.111Z,1352401271.111 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:01:11.169Z,1352401271.169 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:01:11.219Z,1352401271.219 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:11.499Z,1352401271.499 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:01:11.603Z,1352401271.603 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:01:11.704Z,1352401271.704 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:01:11.807Z,1352401271.807 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:12.156Z,1352401272.156 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:01:12.303Z,1352401272.303 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:01:12.443Z,1352401272.443 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:01:12.595Z,1352401272.595 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:12.911Z,1352401272.911 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=60 2012-11-08T19:01:13.023Z,1352401273.023 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:13.143Z,1352401273.143 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2012-11-08T19:01:13.259Z,1352401273.259 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:13.799Z,1352401273.799 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=252 2012-11-08T19:01:14.033Z,1352401274.033 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=197 2012-11-08T19:01:14.258Z,1352401274.258 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=46 2012-11-08T19:01:14.487Z,1352401274.487 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:15.403Z,1352401275.403 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:01:15.877Z,1352401275.876 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:16.351Z,1352401276.351 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=12 2012-11-08T19:01:16.827Z,1352401276.827 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:17.799Z,1352401277.799 [DVL_micro](DEBUG): NQ1 2012-11-08T19:01:17.838Z,1352401277.838 [DVL_micro](DEBUG): ADCP 2012-11-08T19:01:18.659Z,1352401278.659 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=8 2012-11-08T19:01:19.504Z,1352401279.504 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=80 2012-11-08T19:01:20.335Z,1352401280.335 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=25 2012-11-08T19:01:21.171Z,1352401281.171 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:01:21.559Z,1352401281.559 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:01:21.560Z,1352401281.560 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:01:21.561Z,1352401281.561 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:01:21.562Z,1352401281.562 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:21.748Z,1352401281.748 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:01:21.852Z,1352401281.852 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:01:21.951Z,1352401281.951 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:01:22.056Z,1352401282.056 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:22.195Z,1352401282.195 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:01:22.247Z,1352401282.247 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:01:22.303Z,1352401282.303 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:01:22.356Z,1352401282.356 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:22.635Z,1352401282.635 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:01:22.739Z,1352401282.739 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:01:22.839Z,1352401282.839 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:01:22.943Z,1352401282.943 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:23.294Z,1352401283.293 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:01:23.439Z,1352401283.439 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:01:23.580Z,1352401283.580 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2012-11-08T19:01:23.751Z,1352401283.751 [CTD_NeilBrown](ERROR): Bad response: 0.13 2012-11-08T19:01:23.753Z,1352401283.753 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:24.043Z,1352401284.043 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:01:24.159Z,1352401284.159 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:24.275Z,1352401284.276 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:01:24.392Z,1352401284.392 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:24.925Z,1352401284.925 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=124 2012-11-08T19:01:25.151Z,1352401285.151 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:25.387Z,1352401285.387 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=17 2012-11-08T19:01:25.627Z,1352401285.627 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:26.543Z,1352401286.543 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=29 2012-11-08T19:01:27.232Z,1352401287.232 [DVL_micro](DEBUG): RSSI read bytes: 5213 of 5432, #buffered=0 2012-11-08T19:01:27.257Z,1352401287.257 [DVL_micro](DEBUG): RSSI read bytes: 219 of 219, #buffered=2725 2012-11-08T19:01:27.492Z,1352401287.492 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=45 2012-11-08T19:01:27.967Z,1352401287.967 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:28.847Z,1352401288.847 [DVL_micro](DEBUG): NQ1 2012-11-08T19:01:28.877Z,1352401288.877 [DVL_micro](DEBUG): ADCP 2012-11-08T19:01:29.492Z,1352401289.492 [CTD_NeilBrown](ERROR): Bad response: 2.08017 2012-11-08T19:01:29.703Z,1352401289.703 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=10 2012-11-08T19:01:30.548Z,1352401290.547 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=84 2012-11-08T19:01:31.380Z,1352401291.380 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=28 2012-11-08T19:01:32.215Z,1352401292.215 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:01:32.601Z,1352401292.601 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:01:32.603Z,1352401292.603 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:01:32.604Z,1352401292.604 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:01:32.605Z,1352401292.605 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:32.795Z,1352401292.795 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:01:32.900Z,1352401292.900 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:01:32.999Z,1352401293.000 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=33 2012-11-08T19:01:33.104Z,1352401293.103 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:33.239Z,1352401293.239 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:01:33.295Z,1352401293.295 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2012-11-08T19:01:33.347Z,1352401293.347 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=17 2012-11-08T19:01:33.400Z,1352401293.400 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:33.683Z,1352401293.684 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:01:33.783Z,1352401293.783 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:01:33.887Z,1352401293.887 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2012-11-08T19:01:33.988Z,1352401293.988 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:34.335Z,1352401294.335 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:01:34.483Z,1352401294.483 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:01:34.623Z,1352401294.623 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:01:34.771Z,1352401294.771 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:35.091Z,1352401295.091 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=60 2012-11-08T19:01:35.203Z,1352401295.203 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:35.323Z,1352401295.323 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2012-11-08T19:01:35.439Z,1352401295.439 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:35.963Z,1352401295.963 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=93 2012-11-08T19:01:36.195Z,1352401296.195 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=37 2012-11-08T19:01:36.431Z,1352401296.431 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=13 2012-11-08T19:01:36.620Z,1352401296.620 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint](INFO): Reached Waypoint: 36.716000,-121.903400 2012-11-08T19:01:36.621Z,1352401296.621 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint] Stopped 2012-11-08T19:01:36.621Z,1352401296.621 [turbulence_daphne:ScienceOps:Inbound:WpWestAlign.Waypoint](DEBUG): Uninitialize WaypointComponent. 2012-11-08T19:01:36.621Z,1352401296.621 [turbulence_daphne:ScienceOps:Inbound:WpMidway.Waypoint] Running Loop=1 2012-11-08T19:01:36.621Z,1352401296.621 [turbulence_daphne:ScienceOps:Inbound:WpMidway.Waypoint](DEBUG): Initialize WaypointComponent. 2012-11-08T19:01:36.667Z,1352401296.667 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:36.985Z,1352401296.985 [CTD_NeilBrown](ERROR): Bad response: 0.10004 2012-11-08T19:01:37.591Z,1352401297.591 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:01:38.063Z,1352401298.063 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:38.539Z,1352401298.539 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=46 2012-11-08T19:01:39.016Z,1352401299.016 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:39.895Z,1352401299.895 [DVL_micro](DEBUG): NQ1 2012-11-08T19:01:39.952Z,1352401299.952 [DVL_micro](DEBUG): ADCP 2012-11-08T19:01:40.775Z,1352401300.775 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=272 2012-11-08T19:01:41.628Z,1352401301.628 [DVL_micro](DEBUG): RSSI read bytes: 8016 of 9592, #buffered=0 2012-11-08T19:01:41.739Z,1352401301.739 [DVL_micro](DEBUG): RSSI read bytes: 1576 of 1576, #buffered=1688 2012-11-08T19:01:42.015Z,1352401302.015 [DVL_micro](DEBUG): RSSI read bytes: 1912 of 9592, #buffered=0 2012-11-08T19:01:42.064Z,1352401302.063 [Turbulence_NPS](FAULT): Bytes before packet: 126 2012-11-08T19:01:42.275Z,1352401302.274 [DVL_micro](DEBUG): RSSI read bytes: 3713 of 7680, #buffered=0 2012-11-08T19:01:42.631Z,1352401302.631 [DVL_micro](DEBUG): RSSI read bytes: 3712 of 3967, #buffered=0 2012-11-08T19:01:42.652Z,1352401302.652 [CTD_NeilBrown](ERROR): Bad response: 02316 2012-11-08T19:01:42.707Z,1352401302.707 [DVL_micro](DEBUG): RSSI read bytes: 255 of 255, #buffered=3041 2012-11-08T19:01:42.911Z,1352401302.911 [DVL_micro](DEBUG): RSSI read bytes: 3393 of 9592, #buffered=0 2012-11-08T19:01:43.267Z,1352401303.267 [DVL_micro](DEBUG): RSSI read bytes: 6199 of 6199, #buffered=4 2012-11-08T19:01:43.459Z,1352401303.459 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=680 2012-11-08T19:01:43.460Z,1352401303.460 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2012-11-08T19:01:43.515Z,1352401303.515 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80 2012-11-08T19:01:43.567Z,1352401303.567 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:43.843Z,1352401303.843 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:01:43.951Z,1352401303.951 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:01:44.047Z,1352401304.047 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:01:44.151Z,1352401304.151 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:44.287Z,1352401304.287 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:01:44.343Z,1352401304.343 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:01:44.415Z,1352401304.415 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=240 2012-11-08T19:01:44.451Z,1352401304.451 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:44.764Z,1352401304.764 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=408 2012-11-08T19:01:44.837Z,1352401304.837 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:01:44.939Z,1352401304.939 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=64 2012-11-08T19:01:45.039Z,1352401305.039 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:45.387Z,1352401305.387 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=25 2012-11-08T19:01:45.532Z,1352401305.532 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=29 2012-11-08T19:01:45.675Z,1352401305.675 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=33 2012-11-08T19:01:45.823Z,1352401305.823 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:46.139Z,1352401306.139 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:01:46.255Z,1352401306.255 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:46.371Z,1352401306.371 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:01:46.487Z,1352401306.487 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:47.056Z,1352401307.056 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=348 2012-11-08T19:01:47.247Z,1352401307.247 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=36 2012-11-08T19:01:47.483Z,1352401307.483 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2012-11-08T19:01:47.719Z,1352401307.719 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:48.640Z,1352401308.639 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=29 2012-11-08T19:01:49.123Z,1352401309.123 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=133 2012-11-08T19:01:49.587Z,1352401309.587 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=13 2012-11-08T19:01:50.063Z,1352401310.063 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:01:50.943Z,1352401310.943 [DVL_micro](DEBUG): NQ1 2012-11-08T19:01:50.972Z,1352401310.972 [DVL_micro](DEBUG): ADCP 2012-11-08T19:01:51.803Z,1352401311.803 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=8 2012-11-08T19:01:52.639Z,1352401312.639 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=16 2012-11-08T19:01:53.479Z,1352401313.479 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=24 2012-11-08T19:01:54.315Z,1352401314.315 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:01:54.660Z,1352401314.660 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1481 2012-11-08T19:01:54.660Z,1352401314.660 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=861 2012-11-08T19:01:54.661Z,1352401314.661 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=241 2012-11-08T19:01:54.683Z,1352401314.683 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:54.710Z,1352401314.710 [ThrusterServo](FAULT): getVelocity uart error serial timeout 2012-11-08T19:01:54.711Z,1352401314.711 [ThrusterServo](FAULT): Thruster uart error: serial timeout 2012-11-08T19:01:54.711Z,1352401314.711 [ThrusterServo] Communications Fault, FailCount= 1 2012-11-08T19:01:54.711Z,1352401314.711 [ThrusterServo](ERROR): Communications Fault 2012-11-08T19:01:54.713Z,1352401314.713 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2012-11-08T19:01:54.900Z,1352401314.900 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2012-11-08T19:01:55.003Z,1352401315.003 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=125 2012-11-08T19:01:55.048Z,1352401315.048 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-11-08T19:01:55.048Z,1352401315.048 [ThrusterServo](INFO): Powering down 2012-11-08T19:01:55.053Z,1352401315.053 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-11-08T19:01:55.054Z,1352401315.053 [ThrusterServo] No Fault, FailCount= 1 2012-11-08T19:01:55.099Z,1352401315.099 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=33 2012-11-08T19:01:55.199Z,1352401315.199 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:55.336Z,1352401315.336 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:01:55.391Z,1352401315.391 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:01:55.447Z,1352401315.447 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:01:55.499Z,1352401315.499 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:01:55.779Z,1352401315.779 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:01:55.883Z,1352401315.883 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:01:55.913Z,1352401315.913 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-11-08T19:01:55.983Z,1352401315.983 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:01:56.036Z,1352401316.036 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-11-08T19:01:56.087Z,1352401316.087 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:01:56.436Z,1352401316.436 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:01:56.579Z,1352401316.579 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:01:56.723Z,1352401316.723 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2012-11-08T19:01:56.876Z,1352401316.876 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:01:57.187Z,1352401317.187 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:01:57.333Z,1352401317.333 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=324 2012-11-08T19:01:57.424Z,1352401317.424 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2012-11-08T19:01:57.536Z,1352401317.536 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:01:58.059Z,1352401318.059 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:01:58.297Z,1352401318.297 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=36 2012-11-08T19:01:58.531Z,1352401318.531 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2012-11-08T19:01:58.767Z,1352401318.767 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:01:59.690Z,1352401319.690 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=0 2012-11-08T19:02:00.164Z,1352401320.164 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=40 2012-11-08T19:02:00.639Z,1352401320.639 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=48 2012-11-08T19:02:01.111Z,1352401321.111 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:02.087Z,1352401322.087 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:02.126Z,1352401322.126 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:02.947Z,1352401322.947 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=2 2012-11-08T19:02:03.789Z,1352401323.789 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=43 2012-11-08T19:02:04.623Z,1352401324.623 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=19 2012-11-08T19:02:05.460Z,1352401325.460 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:02:05.702Z,1352401325.702 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1160 2012-11-08T19:02:05.702Z,1352401325.703 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=540 2012-11-08T19:02:05.719Z,1352401325.719 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=176 2012-11-08T19:02:05.760Z,1352401325.760 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:06.039Z,1352401326.039 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:02:06.143Z,1352401326.143 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:06.243Z,1352401326.243 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2012-11-08T19:02:06.343Z,1352401326.343 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:06.479Z,1352401326.479 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:02:06.535Z,1352401326.535 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:02:06.591Z,1352401326.591 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:02:06.643Z,1352401326.643 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:06.923Z,1352401326.923 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:02:07.034Z,1352401327.034 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:07.127Z,1352401327.127 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:02:07.231Z,1352401327.231 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:07.580Z,1352401327.580 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:02:07.801Z,1352401327.801 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=893 2012-11-08T19:02:07.867Z,1352401327.867 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=1 2012-11-08T19:02:08.011Z,1352401328.011 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:02:08.335Z,1352401328.335 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=60 2012-11-08T19:02:08.447Z,1352401328.447 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:08.568Z,1352401328.568 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2012-11-08T19:02:08.683Z,1352401328.683 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:09.244Z,1352401329.244 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=412 2012-11-08T19:02:09.253Z,1352401329.253 [Turbulence_NPS](FAULT): Bytes before packet: 78 2012-11-08T19:02:09.439Z,1352401329.439 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=5 2012-11-08T19:02:09.679Z,1352401329.679 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=45 2012-11-08T19:02:09.915Z,1352401329.915 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:10.851Z,1352401330.851 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=29 2012-11-08T19:02:11.323Z,1352401331.323 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=8 2012-11-08T19:02:11.799Z,1352401331.799 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=48 2012-11-08T19:02:12.271Z,1352401332.271 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:13.151Z,1352401333.151 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:13.189Z,1352401333.189 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:14.007Z,1352401334.007 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=11 2012-11-08T19:02:14.847Z,1352401334.847 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=19 2012-11-08T19:02:15.687Z,1352401335.687 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=60 2012-11-08T19:02:16.519Z,1352401336.519 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:02:16.905Z,1352401336.905 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:02:16.905Z,1352401336.905 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:02:16.931Z,1352401336.931 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:02:16.932Z,1352401336.931 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:17.100Z,1352401337.099 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:02:17.203Z,1352401337.203 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:17.306Z,1352401337.306 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:02:17.408Z,1352401337.408 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:17.543Z,1352401337.543 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=9 2012-11-08T19:02:17.599Z,1352401337.599 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=61 2012-11-08T19:02:17.651Z,1352401337.651 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=17 2012-11-08T19:02:17.715Z,1352401337.716 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:17.970Z,1352401337.970 [CTD_NeilBrown](ERROR): Bad response: 65 2012-11-08T19:02:17.990Z,1352401337.990 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:02:18.087Z,1352401338.087 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:02:18.192Z,1352401338.192 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=33 2012-11-08T19:02:18.295Z,1352401338.295 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:18.639Z,1352401338.639 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:02:18.787Z,1352401338.787 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:02:18.927Z,1352401338.927 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:02:19.079Z,1352401339.079 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:02:19.395Z,1352401339.395 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:02:19.515Z,1352401339.515 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2012-11-08T19:02:19.631Z,1352401339.631 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=76 2012-11-08T19:02:19.751Z,1352401339.750 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:20.299Z,1352401340.299 [DVL_micro](DEBUG): RSSI read bytes: 852 of 2712, #buffered=0 2012-11-08T19:02:20.380Z,1352401340.379 [DVL_micro](DEBUG): RSSI read bytes: 1860 of 1860, #buffered=1212 2012-11-08T19:02:20.668Z,1352401340.668 [DVL_micro](DEBUG): RSSI read bytes: 1564 of 2712, #buffered=0 2012-11-08T19:02:20.695Z,1352401340.695 [DVL_micro](DEBUG): RSSI read bytes: 1148 of 1148, #buffered=2116 2012-11-08T19:02:20.895Z,1352401340.895 [DVL_micro](DEBUG): RSSI read bytes: 2436 of 2712, #buffered=0 2012-11-08T19:02:20.917Z,1352401340.917 [CTD_NeilBrown](ERROR): Bad response: ,22.09399 2012-11-08T19:02:21.083Z,1352401341.083 [DVL_micro](DEBUG): RSSI read bytes: 276 of 276, #buffered=2716 2012-11-08T19:02:21.084Z,1352401341.084 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:21.896Z,1352401341.895 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:02:22.387Z,1352401342.387 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=229 2012-11-08T19:02:22.843Z,1352401342.843 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=13 2012-11-08T19:02:23.315Z,1352401343.315 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:24.199Z,1352401344.199 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:24.232Z,1352401344.232 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:25.083Z,1352401345.083 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=268 2012-11-08T19:02:25.899Z,1352401345.899 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=20 2012-11-08T19:02:26.739Z,1352401346.740 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=61 2012-11-08T19:02:27.575Z,1352401347.575 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:02:28.008Z,1352401348.008 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:02:28.009Z,1352401348.009 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:02:28.010Z,1352401348.010 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:02:28.020Z,1352401348.020 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:28.151Z,1352401348.151 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:02:28.255Z,1352401348.255 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=61 2012-11-08T19:02:28.355Z,1352401348.355 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=2 2012-11-08T19:02:28.459Z,1352401348.459 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:28.596Z,1352401348.596 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:02:28.651Z,1352401348.651 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:02:28.711Z,1352401348.711 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=112 2012-11-08T19:02:28.760Z,1352401348.760 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:29.039Z,1352401349.039 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:02:29.143Z,1352401349.143 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:29.243Z,1352401349.243 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:02:29.347Z,1352401349.347 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:29.696Z,1352401349.696 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:02:29.839Z,1352401349.839 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:02:29.983Z,1352401349.983 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2012-11-08T19:02:30.128Z,1352401350.128 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:02:30.447Z,1352401350.447 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:02:30.577Z,1352401350.577 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=196 2012-11-08T19:02:30.687Z,1352401350.687 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=108 2012-11-08T19:02:30.803Z,1352401350.803 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:31.323Z,1352401351.323 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=61 2012-11-08T19:02:31.559Z,1352401351.559 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=37 2012-11-08T19:02:31.809Z,1352401351.809 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=173 2012-11-08T19:02:32.099Z,1352401352.099 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:32.947Z,1352401352.947 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:02:33.424Z,1352401353.424 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=37 2012-11-08T19:02:33.895Z,1352401353.895 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=15 2012-11-08T19:02:34.375Z,1352401354.375 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:35.255Z,1352401355.255 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:35.291Z,1352401355.291 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:35.535Z,1352401355.535 [DVL_micro](DEBUG): RSSI read bytes: 697 of 9592, #buffered=0 2012-11-08T19:02:35.557Z,1352401355.557 [CTD_NeilBrown](ERROR): Bad response: 33 2012-11-08T19:02:35.639Z,1352401355.639 [Turbulence_NPS](FAULT): Bytes before packet: 126 2012-11-08T19:02:35.923Z,1352401355.923 [DVL_micro](DEBUG): RSSI read bytes: 3680 of 8895, #buffered=0 2012-11-08T19:02:35.959Z,1352401355.959 [Turbulence_NPS](FAULT): Bytes before packet: 30 2012-11-08T19:02:36.215Z,1352401356.215 [DVL_micro](DEBUG): RSSI read bytes: 3744 of 5215, #buffered=0 2012-11-08T19:02:36.275Z,1352401356.275 [DVL_micro](DEBUG): RSSI read bytes: 1471 of 1471, #buffered=1761 2012-11-08T19:02:36.482Z,1352401356.483 [DVL_micro](DEBUG): RSSI read bytes: 2017 of 9592, #buffered=0 2012-11-08T19:02:36.955Z,1352401356.955 [DVL_micro](DEBUG): RSSI read bytes: 7575 of 7575, #buffered=41 2012-11-08T19:02:37.791Z,1352401357.791 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=17 2012-11-08T19:02:38.627Z,1352401358.627 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:02:38.892Z,1352401358.892 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1288 2012-11-08T19:02:38.893Z,1352401358.893 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=668 2012-11-08T19:02:38.894Z,1352401358.894 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:02:38.909Z,1352401358.909 [ThrusterServo](FAULT): getVelocity uart error serial timeout 2012-11-08T19:02:38.909Z,1352401358.909 [ThrusterServo](FAULT): Thruster uart error: serial timeout 2012-11-08T19:02:38.910Z,1352401358.909 [ThrusterServo] Communications Fault, FailCount= 1 2012-11-08T19:02:38.910Z,1352401358.910 [ThrusterServo](ERROR): Communications Fault 2012-11-08T19:02:38.913Z,1352401358.913 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2012-11-08T19:02:38.927Z,1352401358.927 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:39.207Z,1352401359.207 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:02:39.208Z,1352401359.208 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-11-08T19:02:39.208Z,1352401359.208 [ThrusterServo](INFO): Powering down 2012-11-08T19:02:39.212Z,1352401359.211 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-11-08T19:02:39.212Z,1352401359.212 [ThrusterServo] No Fault, FailCount= 1 2012-11-08T19:02:39.311Z,1352401359.311 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:39.411Z,1352401359.411 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2012-11-08T19:02:39.511Z,1352401359.511 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:39.651Z,1352401359.651 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2012-11-08T19:02:39.707Z,1352401359.707 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2012-11-08T19:02:39.759Z,1352401359.759 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:02:39.811Z,1352401359.811 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:40.057Z,1352401360.057 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-11-08T19:02:40.091Z,1352401360.091 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=25 2012-11-08T19:02:40.172Z,1352401360.172 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-11-08T19:02:40.195Z,1352401360.195 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:02:40.295Z,1352401360.295 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:02:40.399Z,1352401360.399 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:40.747Z,1352401360.747 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:02:40.891Z,1352401360.891 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=30 2012-11-08T19:02:41.035Z,1352401361.035 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=3 2012-11-08T19:02:41.181Z,1352401361.181 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:02:41.499Z,1352401361.499 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:02:41.615Z,1352401361.615 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:41.731Z,1352401361.731 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:02:41.848Z,1352401361.848 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:42.371Z,1352401362.371 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:02:42.607Z,1352401362.607 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:42.843Z,1352401362.843 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2012-11-08T19:02:43.079Z,1352401363.079 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:44.003Z,1352401364.003 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2012-11-08T19:02:44.475Z,1352401364.475 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=36 2012-11-08T19:02:44.948Z,1352401364.948 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=14 2012-11-08T19:02:45.423Z,1352401365.423 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:46.299Z,1352401366.299 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:46.335Z,1352401366.335 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:47.159Z,1352401367.159 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=5 2012-11-08T19:02:47.995Z,1352401367.995 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=15 2012-11-08T19:02:48.831Z,1352401368.831 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=23 2012-11-08T19:02:49.676Z,1352401369.676 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:02:49.978Z,1352401369.978 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1448 2012-11-08T19:02:49.978Z,1352401369.978 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=828 2012-11-08T19:02:49.979Z,1352401369.979 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=208 2012-11-08T19:02:49.999Z,1352401369.999 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:50.248Z,1352401370.248 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:02:50.351Z,1352401370.351 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:02:50.452Z,1352401370.452 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:02:50.555Z,1352401370.556 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:50.691Z,1352401370.691 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=9 2012-11-08T19:02:50.747Z,1352401370.747 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=29 2012-11-08T19:02:50.799Z,1352401370.799 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=17 2012-11-08T19:02:50.851Z,1352401370.851 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:02:51.135Z,1352401371.135 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:02:51.239Z,1352401371.239 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2012-11-08T19:02:51.339Z,1352401371.339 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:02:51.444Z,1352401371.444 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:02:51.808Z,1352401371.808 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=216 2012-11-08T19:02:51.935Z,1352401371.935 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=29 2012-11-08T19:02:52.080Z,1352401372.080 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=33 2012-11-08T19:02:52.223Z,1352401372.223 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:02:52.548Z,1352401372.548 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=61 2012-11-08T19:02:52.659Z,1352401372.659 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=5 2012-11-08T19:02:52.779Z,1352401372.779 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=13 2012-11-08T19:02:52.895Z,1352401372.895 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:02:53.419Z,1352401373.419 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2012-11-08T19:02:53.655Z,1352401373.655 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=36 2012-11-08T19:02:53.891Z,1352401373.891 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=44 2012-11-08T19:02:54.127Z,1352401374.127 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:02:55.052Z,1352401375.053 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=93 2012-11-08T19:02:55.521Z,1352401375.521 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=38 2012-11-08T19:02:55.991Z,1352401375.991 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=15 2012-11-08T19:02:56.468Z,1352401376.468 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:02:57.355Z,1352401377.355 [DVL_micro](DEBUG): NQ1 2012-11-08T19:02:57.421Z,1352401377.421 [DVL_micro](DEBUG): ADCP 2012-11-08T19:02:58.215Z,1352401378.215 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=42 2012-11-08T19:02:59.051Z,1352401379.051 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=18 2012-11-08T19:02:59.891Z,1352401379.891 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=58 2012-11-08T19:03:00.723Z,1352401380.723 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:01.414Z,1352401381.414 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4330 2012-11-08T19:03:01.420Z,1352401381.420 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=3710 2012-11-08T19:03:01.421Z,1352401381.421 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=3186 2012-11-08T19:03:01.421Z,1352401381.421 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=2566 2012-11-08T19:03:01.505Z,1352401381.505 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=2330 2012-11-08T19:03:01.506Z,1352401381.506 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1150 2012-11-08T19:03:01.516Z,1352401381.516 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=98 2012-11-08T19:03:01.611Z,1352401381.611 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:01.837Z,1352401381.837 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=936 2012-11-08T19:03:01.838Z,1352401381.838 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=316 2012-11-08T19:03:01.855Z,1352401381.855 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:03:01.907Z,1352401381.907 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:02.191Z,1352401382.191 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=58 2012-11-08T19:03:02.295Z,1352401382.295 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=62 2012-11-08T19:03:02.396Z,1352401382.396 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=34 2012-11-08T19:03:02.503Z,1352401382.503 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:02.843Z,1352401382.843 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:03:02.991Z,1352401382.991 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:03:03.131Z,1352401383.131 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:03:03.283Z,1352401383.283 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:03.600Z,1352401383.600 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=60 2012-11-08T19:03:03.711Z,1352401383.711 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:03.831Z,1352401383.831 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2012-11-08T19:03:03.947Z,1352401383.947 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:04.471Z,1352401384.471 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2012-11-08T19:03:04.703Z,1352401384.703 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:03:04.943Z,1352401384.943 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=45 2012-11-08T19:03:05.179Z,1352401385.179 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:03:06.100Z,1352401386.100 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:03:06.571Z,1352401386.571 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=5 2012-11-08T19:03:07.047Z,1352401387.047 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=16 2012-11-08T19:03:07.519Z,1352401387.519 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:08.403Z,1352401388.403 [DVL_micro](DEBUG): NQ1 2012-11-08T19:03:08.447Z,1352401388.447 [DVL_micro](DEBUG): ADCP 2012-11-08T19:03:09.267Z,1352401389.267 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=69 2012-11-08T19:03:10.099Z,1352401390.099 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=13 2012-11-08T19:03:10.939Z,1352401390.939 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=53 2012-11-08T19:03:11.775Z,1352401391.775 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:12.148Z,1352401392.148 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:03:12.148Z,1352401392.148 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:03:12.149Z,1352401392.149 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:03:12.150Z,1352401392.150 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:12.372Z,1352401392.372 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=121 2012-11-08T19:03:12.455Z,1352401392.455 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:03:12.555Z,1352401392.555 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:03:12.659Z,1352401392.659 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:12.795Z,1352401392.795 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:03:12.851Z,1352401392.851 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:03:12.908Z,1352401392.908 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:03:12.959Z,1352401392.959 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:13.243Z,1352401393.243 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2012-11-08T19:03:13.343Z,1352401393.343 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:03:13.443Z,1352401393.443 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:03:13.569Z,1352401393.569 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:13.896Z,1352401393.896 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:03:14.039Z,1352401394.039 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=29 2012-11-08T19:03:14.183Z,1352401394.183 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=33 2012-11-08T19:03:14.327Z,1352401394.327 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:14.647Z,1352401394.647 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:03:14.767Z,1352401394.767 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2012-11-08T19:03:14.884Z,1352401394.884 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=45 2012-11-08T19:03:14.995Z,1352401394.995 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:15.519Z,1352401395.519 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:03:15.759Z,1352401395.759 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=69 2012-11-08T19:03:15.992Z,1352401395.991 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=13 2012-11-08T19:03:16.355Z,1352401396.355 [DVL_micro](DEBUG): RSSI read bytes: 1229 of 2712, #buffered=0 2012-11-08T19:03:16.391Z,1352401396.391 [DVL_micro](DEBUG): RSSI read bytes: 1483 of 1483, #buffered=4 2012-11-08T19:03:17.151Z,1352401397.151 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=61 2012-11-08T19:03:17.624Z,1352401397.624 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=38 2012-11-08T19:03:18.095Z,1352401398.095 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=14 2012-11-08T19:03:18.571Z,1352401398.571 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:19.447Z,1352401399.447 [DVL_micro](DEBUG): NQ1 2012-11-08T19:03:19.491Z,1352401399.491 [DVL_micro](DEBUG): ADCP 2012-11-08T19:03:20.307Z,1352401400.307 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=5 2012-11-08T19:03:21.147Z,1352401401.147 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=17 2012-11-08T19:03:21.983Z,1352401401.983 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=25 2012-11-08T19:03:22.823Z,1352401402.823 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:23.176Z,1352401403.176 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:03:23.177Z,1352401403.177 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:03:23.177Z,1352401403.177 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:03:23.178Z,1352401403.178 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:23.399Z,1352401403.399 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:03:23.503Z,1352401403.503 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=29 2012-11-08T19:03:23.603Z,1352401403.603 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:03:23.707Z,1352401403.707 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:23.840Z,1352401403.840 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:03:23.895Z,1352401403.895 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:03:23.951Z,1352401403.951 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2012-11-08T19:03:24.020Z,1352401404.020 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:24.283Z,1352401404.283 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:03:24.387Z,1352401404.387 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:03:24.487Z,1352401404.487 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1 2012-11-08T19:03:24.591Z,1352401404.591 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:24.944Z,1352401404.944 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:03:25.087Z,1352401405.087 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2012-11-08T19:03:25.227Z,1352401405.227 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2012-11-08T19:03:25.375Z,1352401405.375 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:25.697Z,1352401405.697 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:03:25.811Z,1352401405.811 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=36 2012-11-08T19:03:25.927Z,1352401405.927 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:03:26.044Z,1352401406.044 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:26.567Z,1352401406.567 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:03:26.803Z,1352401406.803 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=38 2012-11-08T19:03:27.040Z,1352401407.040 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=14 2012-11-08T19:03:27.275Z,1352401407.275 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:03:28.195Z,1352401408.195 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:03:28.667Z,1352401408.667 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:29.143Z,1352401409.143 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=12 2012-11-08T19:03:29.615Z,1352401409.615 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:30.498Z,1352401410.498 [DVL_micro](DEBUG): NQ1 2012-11-08T19:03:30.529Z,1352401410.529 [DVL_micro](DEBUG): ADCP 2012-11-08T19:03:30.779Z,1352401410.779 [DVL_micro](DEBUG): RSSI read bytes: 2109 of 9592, #buffered=0 2012-11-08T19:03:30.965Z,1352401410.965 [ThrusterServo](FAULT): getVelocity uart error serial timeout 2012-11-08T19:03:30.966Z,1352401410.966 [ThrusterServo](FAULT): Thruster uart error: serial timeout 2012-11-08T19:03:30.966Z,1352401410.966 [ThrusterServo] Communications Fault, FailCount= 1 2012-11-08T19:03:30.966Z,1352401410.966 [ThrusterServo](ERROR): Communications Fault 2012-11-08T19:03:30.968Z,1352401410.968 [CBIT](ERROR): Communications Fault in component: ThrusterServo 2012-11-08T19:03:31.295Z,1352401411.295 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-11-08T19:03:31.295Z,1352401411.295 [ThrusterServo](INFO): Powering down 2012-11-08T19:03:31.298Z,1352401411.298 [CBIT](INFO): Clearing failed state for component ThrusterServo 2012-11-08T19:03:31.298Z,1352401411.298 [ThrusterServo] No Fault, FailCount= 1 2012-11-08T19:03:31.359Z,1352401411.359 [DVL_micro](DEBUG): RSSI read bytes: 7483 of 7483, #buffered=69 2012-11-08T19:03:32.014Z,1352401412.014 [ThrusterServo](DEBUG): Initializing EZServoServo. 2012-11-08T19:03:32.133Z,1352401412.133 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2012-11-08T19:03:32.191Z,1352401412.191 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=13 2012-11-08T19:03:33.035Z,1352401413.035 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=85 2012-11-08T19:03:33.870Z,1352401413.870 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:34.584Z,1352401414.584 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4680 2012-11-08T19:03:34.585Z,1352401414.585 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4060 2012-11-08T19:03:34.585Z,1352401414.585 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=3440 2012-11-08T19:03:34.586Z,1352401414.586 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=2820 2012-11-08T19:03:34.624Z,1352401414.624 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=2072 2012-11-08T19:03:34.625Z,1352401414.625 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=892 2012-11-08T19:03:34.648Z,1352401414.648 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:03:34.751Z,1352401414.751 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:34.887Z,1352401414.887 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:03:34.943Z,1352401414.943 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=29 2012-11-08T19:03:34.995Z,1352401414.995 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=17 2012-11-08T19:03:35.054Z,1352401415.054 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:35.331Z,1352401415.331 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:03:35.436Z,1352401415.436 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:03:35.535Z,1352401415.535 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:03:35.640Z,1352401415.639 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:35.987Z,1352401415.987 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2012-11-08T19:03:36.131Z,1352401416.131 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:03:36.276Z,1352401416.276 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=33 2012-11-08T19:03:36.423Z,1352401416.423 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:36.739Z,1352401416.739 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:03:36.859Z,1352401416.859 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2012-11-08T19:03:36.972Z,1352401416.972 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:03:37.087Z,1352401417.087 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:37.611Z,1352401417.611 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:03:37.848Z,1352401417.848 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=38 2012-11-08T19:03:38.083Z,1352401418.083 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=14 2012-11-08T19:03:38.319Z,1352401418.319 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:03:39.239Z,1352401419.239 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:03:39.711Z,1352401419.711 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=40 2012-11-08T19:03:40.183Z,1352401420.183 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=16 2012-11-08T19:03:40.660Z,1352401420.660 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:41.635Z,1352401421.635 [DVL_micro](DEBUG): NQ1 2012-11-08T19:03:41.702Z,1352401421.702 [DVL_micro](DEBUG): ADCP 2012-11-08T19:03:42.495Z,1352401422.495 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=8 2012-11-08T19:03:43.335Z,1352401423.335 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=49 2012-11-08T19:03:43.843Z,1352401423.843 [DVL_micro](DEBUG): RSSI read bytes: 3025 of 9592, #buffered=0 2012-11-08T19:03:44.075Z,1352401424.075 [DVL_micro](DEBUG): RSSI read bytes: 3424 of 6567, #buffered=0 2012-11-08T19:03:44.194Z,1352401424.194 [DVL_micro](DEBUG): RSSI read bytes: 3143 of 3143, #buffered=89 2012-11-08T19:03:45.007Z,1352401425.007 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:45.264Z,1352401425.264 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1384 2012-11-08T19:03:45.265Z,1352401425.265 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=764 2012-11-08T19:03:45.265Z,1352401425.265 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=144 2012-11-08T19:03:45.303Z,1352401425.303 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:45.593Z,1352401425.593 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2012-11-08T19:03:45.687Z,1352401425.687 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:03:45.788Z,1352401425.788 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:03:45.891Z,1352401425.891 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:46.027Z,1352401426.027 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:03:46.083Z,1352401426.083 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:03:46.136Z,1352401426.136 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:03:46.191Z,1352401426.191 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:46.475Z,1352401426.475 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2012-11-08T19:03:46.575Z,1352401426.575 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2012-11-08T19:03:46.675Z,1352401426.675 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2012-11-08T19:03:46.779Z,1352401426.779 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:47.127Z,1352401427.127 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:03:47.271Z,1352401427.271 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:03:47.415Z,1352401427.415 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2012-11-08T19:03:47.571Z,1352401427.571 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:47.879Z,1352401427.879 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=29 2012-11-08T19:03:47.995Z,1352401427.995 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=5 2012-11-08T19:03:48.111Z,1352401428.111 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=13 2012-11-08T19:03:48.227Z,1352401428.227 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:48.751Z,1352401428.751 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:03:48.987Z,1352401428.987 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=36 2012-11-08T19:03:49.223Z,1352401429.223 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2012-11-08T19:03:49.459Z,1352401429.459 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:03:50.380Z,1352401430.380 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2012-11-08T19:03:50.851Z,1352401430.851 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=36 2012-11-08T19:03:51.450Z,1352401431.450 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=1420 2012-11-08T19:03:51.799Z,1352401431.799 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:03:52.679Z,1352401432.679 [DVL_micro](DEBUG): NQ1 2012-11-08T19:03:52.717Z,1352401432.717 [DVL_micro](DEBUG): ADCP 2012-11-08T19:03:53.539Z,1352401433.539 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=37 2012-11-08T19:03:54.427Z,1352401434.427 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=590 2012-11-08T19:03:55.215Z,1352401435.215 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=23 2012-11-08T19:03:56.051Z,1352401436.051 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2012-11-08T19:03:56.368Z,1352401436.368 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1864 2012-11-08T19:03:56.368Z,1352401436.368 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1244 2012-11-08T19:03:56.369Z,1352401436.369 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=624 2012-11-08T19:03:56.370Z,1352401436.369 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:56.627Z,1352401436.627 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2012-11-08T19:03:56.739Z,1352401436.739 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2012-11-08T19:03:56.841Z,1352401436.841 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2012-11-08T19:03:56.939Z,1352401436.939 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:57.071Z,1352401437.071 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2012-11-08T19:03:57.127Z,1352401437.127 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2012-11-08T19:03:57.180Z,1352401437.180 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2012-11-08T19:03:57.246Z,1352401437.246 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2012-11-08T19:03:57.560Z,1352401437.560 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=504 2012-11-08T19:03:57.807Z,1352401437.807 [DVL_micro](DEBUG): RSSI read bytes: 728 of 1180, #buffered=0 2012-11-08T19:03:57.923Z,1352401437.923 [DVL_micro](DEBUG): RSSI read bytes: 452 of 452, #buffered=2364 2012-11-08T19:03:57.924Z,1352401437.924 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=1184 2012-11-08T19:03:57.924Z,1352401437.924 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2012-11-08T19:03:58.171Z,1352401438.171 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2012-11-08T19:03:58.315Z,1352401438.315 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2012-11-08T19:03:58.459Z,1352401438.459 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2012-11-08T19:03:58.603Z,1352401438.603 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2012-11-08T19:03:58.923Z,1352401438.923 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2012-11-08T19:03:59.039Z,1352401439.039 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:59.155Z,1352401439.155 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2012-11-08T19:03:59.271Z,1352401439.271 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2012-11-08T19:03:59.799Z,1352401439.799 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2012-11-08T19:04:00.035Z,1352401440.035 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:04:00.271Z,1352401440.271 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=13 2012-11-08T19:04:00.517Z,1352401440.517 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2012-11-08T19:04:01.427Z,1352401441.427 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2012-11-08T19:04:01.900Z,1352401441.899 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=44 2012-11-08T19:04:02.207Z,1352401442.207 [CommandLine](IMPORTANT): got command quit 2012-11-08T19:04:02.371Z,1352401442.371 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=20 2012-11-08T19:04:02.847Z,1352401442.847 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2012-11-08T19:04:03.242Z,1352401443.242 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2012-11-08T19:04:03.243Z,1352401443.243 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne] Stopped 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne](INFO): Aggregate::uninitialize turbulence_daphne 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:A.Pitch] Stopped 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:B.AltitudeEnvelope] Stopped 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:B.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:C.DepthEnvelope] Stopped 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:C.DepthEnvelope](DEBUG): Uninitialize. 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:I.Buoyancy] Stopped 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:I.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2012-11-08T19:04:03.381Z,1352401443.381 [turbulence_daphne:J.OffshoreEnvelope] Stopped 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:J.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:ScienceOps] Stopped 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:ScienceOps](INFO): Aggregate::uninitialize turbulence_daphne:ScienceOps 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:ScienceOps:Inbound] Stopped 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:ScienceOps:Inbound](INFO): Aggregate::uninitialize turbulence_daphne:ScienceOps:Inbound 2012-11-08T19:04:03.382Z,1352401443.382 [turbulence_daphne:ScienceOps:Inbound:Science] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science](INFO): Aggregate::uninitialize turbulence_daphne:ScienceOps:Inbound:Science 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:A] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:B] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:C] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:D] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:E] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:F] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:G] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl](INFO): Aggregate::uninitialize turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2012-11-08T19:04:03.383Z,1352401443.383 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI](INFO): Aggregate::uninitialize turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:B.SetSpeed](DEBUG): Uninitialize. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:C.DepthEnvelope](DEBUG): Uninitialize. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:D.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:F.YoYo] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:F.YoYo](DEBUG): Uninitialize YoYoComponent. 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:WpMidway.Waypoint] Stopped 2012-11-08T19:04:03.384Z,1352401443.384 [turbulence_daphne:ScienceOps:Inbound:WpMidway.Waypoint](DEBUG): Uninitialize WaypointComponent. 2012-11-08T19:04:03.438Z,1352401443.438 [Turbulence_NPS](INFO): Pause powering down 2012-11-08T19:04:03.523Z,1352401443.523 [WetLabsBB2FL](INFO): Powering down 2012-11-08T19:04:03.566Z,1352401443.566 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2012-11-08T19:04:03.720Z,1352401443.720 [DVL_micro](DEBUG): NQ1 2012-11-08T19:04:03.764Z,1352401443.764 [DVL_micro](INFO): pause:Powering down 2012-11-08T19:04:03.786Z,1352401443.786 [MissionManager](IMPORTANT): Started mission Default 2012-11-08T19:04:03.786Z,1352401443.786 [Default] Running Loop=1 2012-11-08T19:04:03.786Z,1352401443.786 [Default](INFO): Aggregate::initialize Default 2012-11-08T19:04:03.786Z,1352401443.786 [Default:D.SetSpeed] Running Loop=1 2012-11-08T19:04:03.787Z,1352401443.787 [Default:D.SetSpeed](DEBUG): Initialize. 2012-11-08T19:04:03.787Z,1352401443.787 [Default:E.GoToSurface] Running Loop=1 2012-11-08T19:04:03.787Z,1352401443.787 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T19:04:03.787Z,1352401443.787 [Default:Iridium] Running Loop=1 2012-11-08T19:04:03.787Z,1352401443.787 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-11-08T19:04:03.787Z,1352401443.787 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-11-08T19:04:03.787Z,1352401443.787 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-11-08T19:04:03.788Z,1352401443.787 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-11-08T19:04:03.788Z,1352401443.787 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-11-08T19:04:03.927Z,1352401443.927 [WetLabsBB2FL](INFO): Powering down 2012-11-08T19:04:03.928Z,1352401443.928 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler 2012-11-08T19:04:04.250Z,1352401444.250 [Turbulence_NPS](INFO): Uninitialize Powering down 2012-11-08T19:04:04.266Z,1352401444.266 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2012-11-08T19:04:04.375Z,1352401444.375 [CTD_NeilBrown](INFO): Powering down 2012-11-08T19:04:04.386Z,1352401444.386 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2012-11-08T19:04:04.571Z,1352401444.571 [DVL_micro](INFO): uninitialize:Powering down 2012-11-08T19:04:04.587Z,1352401444.587 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2012-11-08T19:04:04.699Z,1352401444.699 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2012-11-08T19:04:04.707Z,1352401444.707 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2012-11-08T19:04:04.747Z,1352401444.747 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2012-11-08T19:04:04.749Z,1352401444.749 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2012-11-08T19:04:05.138Z,1352401445.138 [controlThread](DEBUG): Uninitializing ControlThread 2012-11-08T19:04:05.140Z,1352401445.140 [AHRS_sp3003D](INFO): Powering down 2012-11-08T19:04:05.227Z,1352401445.227 [NAL9602](INFO): Powering down 2012-11-08T19:04:05.228Z,1352401445.228 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-11-08T19:04:05.229Z,1352401445.229 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2012-11-08T19:04:05.230Z,1352401445.230 [Default] Stopped 2012-11-08T19:04:05.230Z,1352401445.230 [Default](INFO): Aggregate::uninitialize Default 2012-11-08T19:04:05.230Z,1352401445.230 [Default:Iridium] Stopped 2012-11-08T19:04:05.230Z,1352401445.230 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2012-11-08T19:04:05.230Z,1352401445.230 [Default:Iridium:A.SetSpeed] Stopped 2012-11-08T19:04:05.230Z,1352401445.230 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2012-11-08T19:04:05.231Z,1352401445.231 [Default:Iridium:B.GoToSurface] Stopped 2012-11-08T19:04:05.231Z,1352401445.231 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T19:04:05.231Z,1352401445.231 [Default:D.SetSpeed] Stopped 2012-11-08T19:04:05.231Z,1352401445.231 [Default:D.SetSpeed](DEBUG): Uninitialize. 2012-11-08T19:04:05.231Z,1352401445.231 [Default:E.GoToSurface] Stopped 2012-11-08T19:04:05.231Z,1352401445.231 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-11-08T19:04:05.235Z,1352401445.235 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2012-11-08T19:04:05.235Z,1352401445.235 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2012-11-08T19:04:05.235Z,1352401445.235 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2012-11-08T19:04:05.236Z,1352401445.236 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2012-11-08T19:04:05.236Z,1352401445.236 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2012-11-08T19:04:05.236Z,1352401445.236 [BuoyancyServo](INFO): Powering down 2012-11-08T19:04:05.238Z,1352401445.238 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2012-11-08T19:04:05.239Z,1352401445.239 [MassServo](DEBUG): Uninitialize Mass Servo. 2012-11-08T19:04:05.239Z,1352401445.239 [MassServo](INFO): Powering down 2012-11-08T19:04:05.240Z,1352401445.240 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2012-11-08T19:04:05.240Z,1352401445.240 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2012-11-08T19:04:05.240Z,1352401445.240 [ThrusterServo](INFO): Powering down 2012-11-08T19:04:05.241Z,1352401445.241 [SBIT](DEBUG): Uninitialize SBIT Component. 2012-11-08T19:04:05.241Z,1352401445.241 [IBIT](DEBUG): Uninitialize IBIT Component. 2012-11-08T19:04:05.241Z,1352401445.241 [CBIT](DEBUG): Uninitialize CBIT Component.