2013-08-13T04:45:44.583Z,1376369144.583 [Supervisor](DEBUG): Initializing supervisor. 2013-08-13T04:45:44.586Z,1376369144.586 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-08-13T04:45:44.586Z,1376369144.586 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-08-13T04:45:44.587Z,1376369144.588 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-08-13T04:45:44.592Z,1376369144.592 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-08-13T04:45:44.604Z,1376369144.604 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-08-13T04:45:44.605Z,1376369144.605 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-08-13T04:45:44.606Z,1376369144.606 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-08-13T04:45:44.607Z,1376369144.607 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-08-13T04:45:44.607Z,1376369144.607 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-08-13T04:45:44.609Z,1376369144.609 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-08-13T04:45:45.065Z,1376369145.065 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-08-13T04:45:45.066Z,1376369145.066 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-08-13T04:45:45.260Z,1376369145.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-08-13T04:45:45.260Z,1376369145.260 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-08-13T04:45:45.345Z,1376369145.345 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-08-13T04:45:45.345Z,1376369145.345 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-08-13T04:45:45.456Z,1376369145.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-08-13T04:45:45.457Z,1376369145.457 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-08-13T04:45:45.595Z,1376369145.595 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-08-13T04:45:45.596Z,1376369145.596 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-08-13T04:45:45.835Z,1376369145.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-08-13T04:45:45.836Z,1376369145.836 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-08-13T04:45:46.003Z,1376369146.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-08-13T04:45:46.004Z,1376369146.004 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-08-13T04:45:46.268Z,1376369146.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-08-13T04:45:46.268Z,1376369146.268 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-08-13T04:45:46.369Z,1376369146.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-08-13T04:45:46.370Z,1376369146.370 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-08-13T04:45:46.805Z,1376369146.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-08-13T04:45:46.805Z,1376369146.805 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-08-13T04:45:46.916Z,1376369146.916 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-08-13T04:45:46.917Z,1376369146.917 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-08-13T04:45:47.002Z,1376369147.002 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-08-13T04:45:47.003Z,1376369147.003 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-08-13T04:45:47.102Z,1376369147.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-08-13T04:45:47.227Z,1376369147.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-08-13T04:45:47.319Z,1376369147.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-08-13T04:45:47.423Z,1376369147.423 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-08-13T04:45:47.519Z,1376369147.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-08-13T04:45:47.633Z,1376369147.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-08-13T04:45:47.728Z,1376369147.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-08-13T04:45:47.813Z,1376369147.813 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2013-08-13T04:45:47.813Z,1376369147.813 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-08-13T04:45:47.815Z,1376369147.815 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-08-13T04:45:47.987Z,1376369147.987 [InternalSim] Loaded 2013-08-13T04:45:47.987Z,1376369147.987 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-08-13T04:45:47.988Z,1376369147.988 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-08-13T04:45:47.989Z,1376369147.989 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-08-13T04:45:48.080Z,1376369148.080 [SBIT](DEBUG): Construct Startup Built In Test. 2013-08-13T04:45:48.109Z,1376369148.109 [SBIT] Loaded 2013-08-13T04:45:48.109Z,1376369148.109 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-08-13T04:45:48.110Z,1376369148.110 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-08-13T04:45:48.140Z,1376369148.140 [IBIT] Loaded 2013-08-13T04:45:48.141Z,1376369148.141 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-08-13T04:45:48.143Z,1376369148.143 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-08-13T04:45:48.262Z,1376369148.262 [CBIT] Loaded 2013-08-13T04:45:48.262Z,1376369148.262 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-08-13T04:45:48.262Z,1376369148.262 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-08-13T04:45:48.263Z,1376369148.263 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-08-13T04:45:48.437Z,1376369148.437 [BuoyancyServo] Loaded 2013-08-13T04:45:48.437Z,1376369148.437 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-08-13T04:45:48.449Z,1376369148.449 [ElevatorServo] Loaded 2013-08-13T04:45:48.449Z,1376369148.449 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-08-13T04:45:48.461Z,1376369148.461 [MassServo] Loaded 2013-08-13T04:45:48.461Z,1376369148.461 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-08-13T04:45:48.473Z,1376369148.473 [RudderServo] Loaded 2013-08-13T04:45:48.473Z,1376369148.473 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-08-13T04:45:48.484Z,1376369148.484 [ThrusterServo] Loaded 2013-08-13T04:45:48.484Z,1376369148.484 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-08-13T04:45:48.485Z,1376369148.485 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-08-13T04:45:48.486Z,1376369148.486 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-08-13T04:45:48.509Z,1376369148.509 [DepthRateCalculator] Loaded 2013-08-13T04:45:48.509Z,1376369148.509 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-08-13T04:45:51.638Z,1376369151.638 [HFRadarModelCalc] Loaded 2013-08-13T04:45:51.639Z,1376369151.639 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-08-13T04:45:51.655Z,1376369151.655 [NavChart] Loaded 2013-08-13T04:45:51.655Z,1376369151.655 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-08-13T04:45:51.661Z,1376369151.661 [PitchRateCalculator] Loaded 2013-08-13T04:45:51.662Z,1376369151.662 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-08-13T04:45:51.672Z,1376369151.672 [SpeedCalculator] Loaded 2013-08-13T04:45:51.673Z,1376369151.673 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-08-13T04:45:51.691Z,1376369151.691 [TempGradientCalculator] Loaded 2013-08-13T04:45:51.692Z,1376369151.692 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-08-13T04:45:51.697Z,1376369151.697 [YawRateCalculator] Loaded 2013-08-13T04:45:51.698Z,1376369151.698 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-08-13T04:45:51.746Z,1376369151.746 [Navigation] Loaded 2013-08-13T04:45:51.746Z,1376369151.746 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-08-13T04:45:51.746Z,1376369151.746 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-08-13T04:45:51.747Z,1376369151.747 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-08-13T04:45:51.996Z,1376369151.996 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-08-13T04:45:51.996Z,1376369151.996 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-08-13T04:45:52.021Z,1376369152.021 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-08-13T04:45:52.021Z,1376369152.021 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-08-13T04:45:52.072Z,1376369152.072 [VerticalControl](DEBUG): Construct VerticalControl. 2013-08-13T04:45:52.168Z,1376369152.168 [VerticalControl] Loaded 2013-08-13T04:45:52.168Z,1376369152.168 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-08-13T04:45:52.169Z,1376369152.169 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-08-13T04:45:52.229Z,1376369152.229 [HorizontalControl] Loaded 2013-08-13T04:45:52.229Z,1376369152.229 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-08-13T04:45:52.230Z,1376369152.230 [SpeedControl](DEBUG): Construct SpeedControl. 2013-08-13T04:45:52.231Z,1376369152.231 [SpeedControl] Loaded 2013-08-13T04:45:52.232Z,1376369152.232 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-08-13T04:45:52.232Z,1376369152.232 [LoopControl](DEBUG): Construct LoopControl. 2013-08-13T04:45:52.233Z,1376369152.233 [LoopControl] Loaded 2013-08-13T04:45:52.233Z,1376369152.233 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-08-13T04:45:52.234Z,1376369152.234 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-08-13T04:45:52.234Z,1376369152.234 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-08-13T04:45:52.240Z,1376369152.240 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-08-13T04:45:52.245Z,1376369152.245 [AsyncPiEstimator] Loaded 2013-08-13T04:45:52.245Z,1376369152.245 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-08-13T04:45:52.247Z,1376369152.247 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406474E0 2013-08-13T04:45:52.247Z,1376369152.247 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-08-13T04:45:52.248Z,1376369152.248 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-08-13T04:45:52.450Z,1376369152.450 [AHRS_sp3003D] Loaded 2013-08-13T04:45:52.451Z,1376369152.451 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-08-13T04:45:52.711Z,1376369152.711 [Batt_Ocean_Server] Loaded 2013-08-13T04:45:52.711Z,1376369152.711 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-08-13T04:45:52.725Z,1376369152.725 [Depth_Keller] Loaded 2013-08-13T04:45:52.725Z,1376369152.725 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-08-13T04:45:52.731Z,1376369152.731 [DropWeight] Loaded 2013-08-13T04:45:52.731Z,1376369152.731 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-08-13T04:45:52.920Z,1376369152.920 [DVL_micro] Loaded 2013-08-13T04:45:52.921Z,1376369152.921 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-08-13T04:45:52.922Z,1376369152.922 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406D74E0 2013-08-13T04:45:53.013Z,1376369153.013 [NAL9602] Loaded 2013-08-13T04:45:53.013Z,1376369153.013 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-08-13T04:45:53.057Z,1376369153.057 [Onboard] Loaded 2013-08-13T04:45:53.057Z,1376369153.057 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-08-13T04:45:53.064Z,1376369153.064 [Radio_Freewave] Loaded 2013-08-13T04:45:53.064Z,1376369153.064 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-08-13T04:45:53.232Z,1376369153.232 [DAT] Loaded 2013-08-13T04:45:53.232Z,1376369153.232 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-08-13T04:45:53.239Z,1376369153.239 [SCPI] Loaded 2013-08-13T04:45:53.239Z,1376369153.239 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2013-08-13T04:45:53.239Z,1376369153.239 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-08-13T04:45:53.240Z,1376369153.240 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-08-13T04:45:53.308Z,1376369153.308 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-08-13T04:45:53.311Z,1376369153.311 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-08-13T04:45:53.312Z,1376369153.312 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-08-13T04:45:53.319Z,1376369153.319 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-08-13T04:45:53.320Z,1376369153.320 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407344E0 2013-08-13T04:45:53.324Z,1376369153.324 [Supervisor](DEBUG): Running supervisor. 2013-08-13T04:45:53.325Z,1376369153.325 [CommandLine](INFO): Thread ID is 3823 2013-08-13T04:45:53.328Z,1376369153.328 [controlThread](INFO): Thread ID is 3822 2013-08-13T04:45:53.328Z,1376369153.328 [controlThread](DEBUG): Initializing ControlThread 2013-08-13T04:45:53.329Z,1376369153.329 [CycleStarter](INFO): Thread ID is 3821 2013-08-13T04:45:53.329Z,1376369153.329 [InternalSim](DEBUG): InternalSim initializing... 2013-08-13T04:45:53.363Z,1376369153.363 [logger](INFO): Thread ID is 3824 2013-08-13T04:45:53.389Z,1376369153.389 [SBIT](INFO): Initialize SBIT Component. 2013-08-13T04:45:53.389Z,1376369153.389 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10506 2013-08-13T04:45:53.390Z,1376369153.390 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-08-13T04:45:53.390Z,1376369153.390 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-08-13T04:45:53.391Z,1376369153.391 [IBIT](INFO): Initialize IBIT Component. 2013-08-13T04:45:53.392Z,1376369153.392 [CBIT](DEBUG): Initialize CBIT Component. 2013-08-13T04:45:53.392Z,1376369153.392 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-08-13T04:45:53.403Z,1376369153.403 [AsyncPiEstimator](INFO): Thread ID is 3885 2013-08-13T04:45:53.403Z,1376369153.403 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-08-13T04:45:53.416Z,1376369153.416 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-08-13T04:45:53.416Z,1376369153.416 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-08-13T04:45:53.417Z,1376369153.417 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-08-13T04:45:53.417Z,1376369153.417 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-08-13T04:45:53.417Z,1376369153.417 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-08-13T04:45:53.418Z,1376369153.418 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-08-13T04:45:53.418Z,1376369153.418 [Navigation](DEBUG): Initializing Navigation. 2013-08-13T04:45:53.418Z,1376369153.418 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-08-13T04:45:53.420Z,1376369153.420 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-08-13T04:45:53.421Z,1376369153.421 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-08-13T04:45:53.421Z,1376369153.421 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-08-13T04:45:53.426Z,1376369153.426 [DVL_micro](INFO): Thread ID is 3886 2013-08-13T04:45:53.435Z,1376369153.435 [DVL_micro](INFO): Initializing 2013-08-13T04:45:53.435Z,1376369153.435 [DVL_micro](INFO): start:Powering up 2013-08-13T04:45:53.436Z,1376369153.436 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:45:53.437Z,1376369153.437 [DVL_micro](INFO): Cycling power to configure device. 2013-08-13T04:45:53.456Z,1376369153.456 [NavChartDb](INFO): Thread ID is 3887 2013-08-13T04:45:53.461Z,1376369153.461 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-08-13T04:45:53.461Z,1376369153.461 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-08-13T04:45:53.462Z,1376369153.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-08-13T04:45:53.462Z,1376369153.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-08-13T04:45:53.462Z,1376369153.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-08-13T04:45:53.462Z,1376369153.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-08-13T04:45:53.463Z,1376369153.463 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-08-13T04:45:53.463Z,1376369153.463 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-08-13T04:45:53.463Z,1376369153.463 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-08-13T04:45:55.439Z,1376369155.439 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-08-13T04:45:55.473Z,1376369155.473 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-08-13T04:45:55.501Z,1376369155.501 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-08-13T04:45:55.527Z,1376369155.527 [MissionManager](DEBUG): 2013-08-13T04:45:55.528Z,1376369155.528 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-08-13T04:45:55.530Z,1376369155.530 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:45:55.531Z,1376369155.531 [DVL_micro](INFO): Querying output modes 2013-08-13T04:45:55.531Z,1376369155.531 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-08-13T04:45:55.542Z,1376369155.542 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2013-08-13T04:45:55.542Z,1376369155.542 [DVL_micro](INFO): NQ1 output enabled 2013-08-13T04:45:55.542Z,1376369155.542 [DVL_micro](INFO): RSSI output enabled 2013-08-13T04:45:55.542Z,1376369155.542 [DVL_micro](INFO): ADCP output enabled 2013-08-13T04:45:55.543Z,1376369155.543 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-08-13T04:45:55.554Z,1376369155.554 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-08-13T04:45:55.559Z,1376369155.559 [DVL_micro](INFO): pause:Powering down 2013-08-13T04:45:55.624Z,1376369155.624 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-08-13T04:45:55.626Z,1376369155.626 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-08-13T04:45:55.629Z,1376369155.629 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-08-13T04:45:55.649Z,1376369155.649 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-08-13T04:45:55.652Z,1376369155.652 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-08-13T04:45:55.687Z,1376369155.687 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-08-13T04:45:55.711Z,1376369155.711 [Default:D.SetSpeed](DEBUG): Construct. 2013-08-13T04:45:55.726Z,1376369155.726 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-08-13T04:45:55.731Z,1376369155.731 [Default:F.Wait](DEBUG): Construct Wait. 2013-08-13T04:45:55.736Z,1376369155.736 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-08-13T04:45:55.743Z,1376369155.743 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,SCPI,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-08-13T04:45:55.802Z,1376369155.802 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-08-13T04:45:55.963Z,1376369155.963 [Radio_Freewave](INFO): Powering up 2013-08-13T04:45:56.004Z,1376369156.004 [DAT](INFO): Powering up 2013-08-13T04:45:56.004Z,1376369156.004 [DAT](DEBUG): Initializing DAT. 2013-08-13T04:45:56.218Z,1376369156.218 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-08-13T04:45:56.227Z,1376369156.227 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-08-13T04:45:56.233Z,1376369156.233 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-08-13T04:45:56.238Z,1376369156.238 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-08-13T04:45:56.255Z,1376369156.255 [MassServo](DEBUG): Initializing EZServoServo. 2013-08-13T04:45:56.263Z,1376369156.263 [MassServo](DEBUG): Initializing MassServo. 2013-08-13T04:45:56.285Z,1376369156.285 [RudderServo](DEBUG): Initializing EZServoServo. 2013-08-13T04:45:56.291Z,1376369156.291 [RudderServo](DEBUG): Initializing RudderServo. 2013-08-13T04:45:56.305Z,1376369156.305 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-08-13T04:45:56.311Z,1376369156.311 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-08-13T04:45:56.523Z,1376369156.523 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x42360D0AA4 2013-08-13T04:45:56.523Z,1376369156.523 [AHRS_sp3003D](ERROR): SP3003D failed to initialize 2013-08-13T04:45:56.524Z,1376369156.524 [AHRS_sp3003D] Hardware Fault, FailCount= 1 2013-08-13T04:45:56.524Z,1376369156.524 [AHRS_sp3003D](ERROR): Hardware Fault 2013-08-13T04:45:56.636Z,1376369156.636 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D 2013-08-13T04:45:56.764Z,1376369156.764 [DVL_micro](INFO): RSSI unrequested 2013-08-13T04:45:56.764Z,1376369156.764 [DVL_micro](INFO): ADCP unrequested 2013-08-13T04:45:56.765Z,1376369156.765 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:45:56.765Z,1376369156.765 [DVL_micro](INFO): resume:Powering up 2013-08-13T04:45:56.765Z,1376369156.765 [DVL_micro](INFO): Cycling power to configure device. 2013-08-13T04:45:56.780Z,1376369156.780 [AHRS_sp3003D](INFO): Powering down 2013-08-13T04:45:58.092Z,1376369158.092 [NAL9602](INFO): Powering up NAL9602 2013-08-13T04:45:58.220Z,1376369158.220 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2013-08-13T04:45:58.220Z,1376369158.220 [AHRS_sp3003D] No Fault, FailCount= 1 2013-08-13T04:45:58.486Z,1376369158.486 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-08-13T04:45:58.775Z,1376369158.775 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:45:58.775Z,1376369158.775 [DVL_micro](INFO): Querying output modes 2013-08-13T04:45:58.776Z,1376369158.776 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-08-13T04:45:58.788Z,1376369158.788 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2013-08-13T04:45:58.788Z,1376369158.788 [DVL_micro](INFO): NQ1 output enabled 2013-08-13T04:45:58.788Z,1376369158.788 [DVL_micro](INFO): RSSI output enabled 2013-08-13T04:45:58.788Z,1376369158.788 [DVL_micro](INFO): ADCP output enabled 2013-08-13T04:45:58.788Z,1376369158.788 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-08-13T04:45:58.799Z,1376369158.799 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-08-13T04:45:58.802Z,1376369158.802 [DVL_micro](INFO): pause:Powering down 2013-08-13T04:46:07.160Z,1376369167.160 [CommandLine](IMPORTANT): got command failComponent 2013-08-13T04:46:07.160Z,1376369167.160 [CommandLine](IMPORTANT): Failed components: 2013-08-13T04:46:07.161Z,1376369167.161 [CommandLine](IMPORTANT): No failed Components. 2013-08-13T04:46:08.723Z,1376369168.723 [NAL9602](INFO): NAL9602 initialized 2013-08-13T04:46:08.797Z,1376369168.797 [SBIT](IMPORTANT): Beginning Startup BIT 2013-08-13T04:46:08.800Z,1376369168.800 [CBIT](IMPORTANT): Beginning GF scan 2013-08-13T04:46:16.309Z,1376369176.309 [DAT](INFO): Powering down 2013-08-13T04:46:35.685Z,1376369195.685 [CBIT](IMPORTANT): No ground fault detected 2013-08-13T04:47:02.385Z,1376369222.385 [SBIT](IMPORTANT): SBIT PASSED 2013-08-13T04:47:02.791Z,1376369222.791 [MissionManager](IMPORTANT): Started mission Startup 2013-08-13T04:47:02.791Z,1376369222.791 [Startup] Running Loop=1 2013-08-13T04:47:02.792Z,1376369222.792 [Startup](INFO): Aggregate::initialize Startup 2013-08-13T04:47:02.792Z,1376369222.792 [Startup:A.GoToSurface] Running Loop=1 2013-08-13T04:47:02.792Z,1376369222.792 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:47:02.798Z,1376369222.798 [Startup:StartupSatComms] Running Loop=1 2013-08-13T04:47:02.798Z,1376369222.798 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-08-13T04:47:02.798Z,1376369222.798 [Startup:StartupSatComms:A] Running Loop=1 2013-08-13T04:47:03.159Z,1376369223.159 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-08-13T04:47:21.103Z,1376369241.103 [CommandLine](IMPORTANT): got command show stack 2013-08-13T04:47:21.103Z,1376369241.103 [CommandLine](INFO): Behavior Stack: 2013-08-13T04:47:21.103Z,1376369241.103 [Startup](INFO): Priority 0: Startup:A.GoToSurface 2013-08-13T04:47:21.104Z,1376369241.104 [Startup:StartupSatComms](INFO): Priority 1: Startup:StartupSatComms:A 2013-08-13T04:47:28.450Z,1376369248.450 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-08-13T04:47:37.369Z,1376369257.369 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree 2013-08-13T04:47:37.693Z,1376369257.693 [Startup:StartupSatComms:A] Stopped 2013-08-13T04:47:37.693Z,1376369257.693 [Startup:StartupSatComms:B] Running Loop=1 2013-08-13T04:47:38.025Z,1376369258.025 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-08-13T04:47:43.125Z,1376369263.125 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-08-13T04:47:46.930Z,1376369266.930 [Startup:StartupSatComms:B] Stopped 2013-08-13T04:47:46.931Z,1376369266.931 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-08-13T04:47:46.931Z,1376369266.931 [Startup:StartupSatComms] Stopped 2013-08-13T04:47:46.931Z,1376369266.931 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-08-13T04:47:46.932Z,1376369266.932 [Startup](INFO): Completed Startup 2013-08-13T04:47:46.932Z,1376369266.932 [Startup] Stopped 2013-08-13T04:47:46.932Z,1376369266.932 [Startup](INFO): Aggregate::uninitialize Startup 2013-08-13T04:47:46.932Z,1376369266.932 [Startup:A.GoToSurface] Stopped 2013-08-13T04:47:46.932Z,1376369266.932 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:47:47.389Z,1376369267.389 [MissionManager](IMPORTANT): Started mission Default 2013-08-13T04:47:47.389Z,1376369267.389 [Default] Running Loop=1 2013-08-13T04:47:47.389Z,1376369267.389 [Default](INFO): Aggregate::initialize Default 2013-08-13T04:47:47.390Z,1376369267.390 [Default:D.SetSpeed] Running Loop=1 2013-08-13T04:47:47.390Z,1376369267.390 [Default:D.SetSpeed](DEBUG): Initialize. 2013-08-13T04:47:47.390Z,1376369267.390 [Default:E.GoToSurface] Running Loop=1 2013-08-13T04:47:47.390Z,1376369267.390 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:47:47.390Z,1376369267.390 [Default:Iridium] Running Loop=1 2013-08-13T04:47:47.390Z,1376369267.390 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-08-13T04:47:47.390Z,1376369267.390 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-08-13T04:47:47.390Z,1376369267.390 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-08-13T04:47:47.391Z,1376369267.391 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-08-13T04:47:47.391Z,1376369267.391 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:47:47.391Z,1376369267.391 [Default:E.GoToSurface] Running Loop=1 2013-08-13T04:47:47.397Z,1376369267.397 [Default:D.SetSpeed] Running Loop=1 2013-08-13T04:47:47.407Z,1376369267.407 [Default:Iridium:B.GoToSurface] Stopped 2013-08-13T04:47:47.409Z,1376369267.409 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:47:47.410Z,1376369267.410 [Default:Iridium:Read_Iridium] Running Loop=1 2013-08-13T04:47:47.410Z,1376369267.410 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS] Running Loop=1 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS:A.SetSpeed] Running Loop=1 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS:B.GoToSurface] Running Loop=1 2013-08-13T04:47:47.416Z,1376369267.416 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:47:47.422Z,1376369267.422 [Default:GPS:B.GoToSurface] Stopped 2013-08-13T04:47:47.422Z,1376369267.422 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:47:47.422Z,1376369267.422 [Default:GPS:Read_GPS] Running Loop=1 2013-08-13T04:47:47.422Z,1376369267.422 [Default:GPS:A.SetSpeed] Running Loop=1 2013-08-13T04:47:48.283Z,1376369268.283 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-08-13T04:47:48.286Z,1376369268.286 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-08-13T04:47:53.236Z,1376369273.236 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/tank_weight.xml 2013-08-13T04:47:53.237Z,1376369273.237 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_weight.xml 2013-08-13T04:47:53.291Z,1376369273.291 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitHiCC = 0.000955 n/a 2013-08-13T04:47:53.299Z,1376369273.299 [MissionManager](INFO): DefineArg tank_weight.BuoyancyLimitLoCC = 0.000080 n/a 2013-08-13T04:47:53.305Z,1376369273.305 [tank_weight:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2013-08-13T04:47:53.333Z,1376369273.333 [tank_weight:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2013-08-13T04:47:53.354Z,1376369273.354 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2013-08-13T04:47:53.670Z,1376369273.670 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUS = 0 bool 2013-08-13T04:47:53.673Z,1376369273.673 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2013-08-13T04:47:53.676Z,1376369273.676 [MissionManager](INFO): DefineArg tank_weight:Science.SampleISUSminPitch = -60.000000 arcdeg 2013-08-13T04:47:53.679Z,1376369273.679 [MissionManager](INFO): DefineArg tank_weight:Science.SampleRSSI = 1 bool 2013-08-13T04:47:53.694Z,1376369273.694 [MissionManager](INFO): DefineArg tank_weight:Science.SampleADCP = 1 bool 2013-08-13T04:47:53.696Z,1376369273.696 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectChlActive = 0 bool 2013-08-13T04:47:53.699Z,1376369273.699 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectNO3Active = 0 bool 2013-08-13T04:47:53.702Z,1376369273.702 [MissionManager](INFO): DefineArg tank_weight:Science.PeakDetectRSSIActive = 0 bool 2013-08-13T04:47:53.704Z,1376369273.704 [MissionManager](INFO): DefineArg tank_weight:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2013-08-13T04:47:53.742Z,1376369273.742 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrent = 0 bool 2013-08-13T04:47:53.745Z,1376369273.745 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMinDepth = 2.000000 m 2013-08-13T04:47:53.757Z,1376369273.757 [MissionManager](INFO): DefineArg tank_weight:Science.ComputeWaterCurrentMaxDepth = 5.000000 m 2013-08-13T04:47:53.761Z,1376369273.761 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledAanderaaO2 = 0.000000 n/a 2013-08-13T04:47:53.764Z,1376369273.764 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledNeilBrown = 0.000000 n/a 2013-08-13T04:47:53.818Z,1376369273.818 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledTurbulence_NPS = 0.000000 n/a 2013-08-13T04:47:53.821Z,1376369273.821 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledWetLabsBB2FL = 0.000000 n/a 2013-08-13T04:47:53.844Z,1376369273.844 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledDVL = 1.000000 n/a 2013-08-13T04:47:53.848Z,1376369273.848 [MissionManager](INFO): DefineArg tank_weight:Science.EnabledISUS = 0.000000 n/a 2013-08-13T04:47:53.862Z,1376369273.862 [MissionManager](INFO): DefineArg tank_weight:Science.HFRadarModelActive = 0 bool 2013-08-13T04:47:53.886Z,1376369273.886 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChl = 0.000000 ug/l 2013-08-13T04:47:53.889Z,1376369273.889 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlDepth = 0.000000 m 2013-08-13T04:47:53.892Z,1376369273.892 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLatitude = nan arcdeg 2013-08-13T04:47:53.925Z,1376369273.925 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakChlLongitude = nan arcdeg 2013-08-13T04:47:53.928Z,1376369273.928 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3 = 0.000000 umol/l 2013-08-13T04:47:53.941Z,1376369273.941 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Depth = 0.000000 m 2013-08-13T04:47:53.956Z,1376369273.956 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Latitude = nan arcdeg 2013-08-13T04:47:53.963Z,1376369273.963 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakNO3Longitude = nan arcdeg 2013-08-13T04:47:53.983Z,1376369273.983 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSI = 0.000000 dB 2013-08-13T04:47:54.010Z,1376369274.010 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSIDepth = 0.000000 m 2013-08-13T04:47:54.022Z,1376369274.022 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILatitude = nan arcdeg 2013-08-13T04:47:54.025Z,1376369274.025 [MissionManager](INFO): DefineOutput tank_weight:Science.PeakRSSILongitude = nan arcdeg 2013-08-13T04:47:54.036Z,1376369274.036 [MissionManager](INFO): DefineOutput tank_weight:Science.eastwardSurfaceCurrent = nan m/s 2013-08-13T04:47:54.041Z,1376369274.041 [MissionManager](INFO): DefineOutput tank_weight:Science.northwardSurfaceCurrent = nan m/s 2013-08-13T04:47:54.061Z,1376369274.061 [tank_weight:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2013-08-13T04:47:54.099Z,1376369274.099 [tank_weight:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2013-08-13T04:47:54.121Z,1376369274.121 [tank_weight:Science:PeakDetectRSSI:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2013-08-13T04:47:54.133Z,1376369274.133 [MissionManager](INFO): RedefineArg tank_weight:Science.SampleISUS = 1 bool 2013-08-13T04:47:54.135Z,1376369274.135 [tank_weight:D:A.SetSpeed](DEBUG): Construct. 2013-08-13T04:47:54.139Z,1376369274.139 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Construct Buoyancy. 2013-08-13T04:47:54.143Z,1376369274.143 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Construct. 2013-08-13T04:47:54.149Z,1376369274.149 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Construct Wait. 2013-08-13T04:47:54.151Z,1376369274.151 [tank_weight:D:BuoyancyHi:A.Buoyancy](DEBUG): Construct Buoyancy. 2013-08-13T04:47:54.154Z,1376369274.155 [tank_weight:D:BuoyancyHi:B.Pitch](DEBUG): Construct. 2013-08-13T04:47:54.161Z,1376369274.161 [tank_weight:D:BuoyancyHi:C.Wait](DEBUG): Construct Wait. 2013-08-13T04:47:54.193Z,1376369274.193 [MissionManager](DEBUG): 0 0 15 0 0 15 65 0 15 5 2013-08-13T04:47:54.211Z,1376369274.211 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/tank_weight.xml 2013-08-13T04:47:54.233Z,1376369274.233 [Default] Stopped 2013-08-13T04:47:54.233Z,1376369274.233 [Default](INFO): Aggregate::uninitialize Default 2013-08-13T04:47:54.233Z,1376369274.233 [Default:GPS] Stopped 2013-08-13T04:47:54.233Z,1376369274.233 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-08-13T04:47:54.234Z,1376369274.234 [Default:GPS:A.SetSpeed] Stopped 2013-08-13T04:47:54.234Z,1376369274.234 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:47:54.234Z,1376369274.234 [Default:GPS:Read_GPS] Stopped 2013-08-13T04:47:54.234Z,1376369274.234 [Default:Iridium] Stopped 2013-08-13T04:47:54.234Z,1376369274.234 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-08-13T04:47:54.234Z,1376369274.234 [Default:Iridium:A.SetSpeed] Stopped 2013-08-13T04:47:54.234Z,1376369274.234 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:47:54.234Z,1376369274.234 [Default:Iridium:Read_Iridium] Stopped 2013-08-13T04:47:54.235Z,1376369274.235 [Default:D.SetSpeed] Stopped 2013-08-13T04:47:54.235Z,1376369274.235 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:47:54.235Z,1376369274.235 [Default:E.GoToSurface] Stopped 2013-08-13T04:47:54.235Z,1376369274.235 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:47:54.235Z,1376369274.235 [MissionManager](IMPORTANT): Started mission tank_weight 2013-08-13T04:47:54.235Z,1376369274.235 [tank_weight] Running Loop=1 2013-08-13T04:47:54.235Z,1376369274.235 [tank_weight](INFO): Aggregate::initialize tank_weight 2013-08-13T04:47:54.235Z,1376369274.235 [tank_weight:A.AltitudeEnvelope] Running Loop=1 2013-08-13T04:47:54.235Z,1376369274.235 [tank_weight:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2013-08-13T04:47:54.236Z,1376369274.236 [tank_weight:B.DepthEnvelope] Running Loop=1 2013-08-13T04:47:54.236Z,1376369274.236 [tank_weight:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science](INFO): Aggregate::initialize tank_weight:Science 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:A] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:B] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:C] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:D] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:E] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:F] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:G] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:H] Running Loop=1 2013-08-13T04:47:54.237Z,1376369274.237 [tank_weight:Science:I] Running Loop=1 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D] Running Loop=1 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D](INFO): Aggregate::initialize tank_weight:D 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D:A.SetSpeed] Running Loop=1 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D:A.SetSpeed](DEBUG): Initialize. 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D:BuoyancyLo] Running Loop=1 2013-08-13T04:47:54.238Z,1376369274.238 [tank_weight:D:BuoyancyLo](INFO): Aggregate::initialize tank_weight:D:BuoyancyLo 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:B.Pitch](DEBUG): Initialize. 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:C.Wait] Running Loop=1 2013-08-13T04:47:54.239Z,1376369274.239 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Initialize Wait Component. 2013-08-13T04:47:54.244Z,1376369274.244 [tank_weight:D:BuoyancyLo:B.Pitch] Running Loop=1 2013-08-13T04:47:54.249Z,1376369274.249 [tank_weight:D:BuoyancyLo:A.Buoyancy] Running Loop=1 2013-08-13T04:47:54.254Z,1376369274.254 [tank_weight:D:A.SetSpeed] Running Loop=1 2013-08-13T04:47:54.259Z,1376369274.259 [tank_weight:Science] Running Loop=1 2013-08-13T04:47:54.260Z,1376369274.260 [tank_weight:Science:H] Running Loop=1 2013-08-13T04:47:54.261Z,1376369274.261 [tank_weight:Science:H](DEBUG): Initialize ReadDataComponent to sense DVL_micro.Beam1RSSI 2013-08-13T04:47:54.262Z,1376369274.262 [tank_weight:Science:G] Running Loop=1 2013-08-13T04:47:54.263Z,1376369274.263 [tank_weight:Science:G](DEBUG): Initialize ReadDataComponent to sense DVL_micro.AdcpXWaterVelocity 2013-08-13T04:47:54.264Z,1376369274.264 [tank_weight:B.DepthEnvelope] Running Loop=1 2013-08-13T04:47:54.283Z,1376369274.283 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:47:54.283Z,1376369274.283 [DVL_micro](INFO): resume:Powering up 2013-08-13T04:47:54.283Z,1376369274.283 [DVL_micro](INFO): Cycling power to configure device. 2013-08-13T04:47:54.286Z,1376369274.286 [tank_weight:A.AltitudeEnvelope] Running Loop=1 2013-08-13T04:47:56.289Z,1376369276.289 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-08-13T04:47:56.290Z,1376369276.290 [DVL_micro](INFO): Querying output modes 2013-08-13T04:47:56.290Z,1376369276.290 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-08-13T04:47:56.301Z,1376369276.301 [DVL_micro](DEBUG): cmdResponse: 01 03 16 2013-08-13T04:47:56.301Z,1376369276.301 [DVL_micro](INFO): NQ1 output enabled 2013-08-13T04:47:56.302Z,1376369276.302 [DVL_micro](INFO): RSSI output enabled 2013-08-13T04:47:56.302Z,1376369276.302 [DVL_micro](INFO): ADCP output enabled 2013-08-13T04:47:56.302Z,1376369276.302 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-08-13T04:47:56.313Z,1376369276.313 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-08-13T04:47:56.378Z,1376369276.378 [CommandLine](IMPORTANT): got command show variable aand 2013-08-13T04:47:56.388Z,1376369276.388 [CommandLine](INFO): Aanderaa_O2.loadControl (none) 2013-08-13T04:47:56.389Z,1376369276.389 [CommandLine](INFO): Aanderaa_O2.uart (none) 2013-08-13T04:47:56.389Z,1376369276.389 [CommandLine](INFO): Aanderaa_O2.baud (bit_per_second) 2013-08-13T04:47:56.432Z,1376369276.432 [CommandLine](INFO): Aanderaa_O2.loadAtStartup (bool) 2013-08-13T04:47:56.433Z,1376369276.433 [CommandLine](INFO): Aanderaa_O2.simulateHardware (bool) 2013-08-13T04:47:56.433Z,1376369276.433 [CommandLine](INFO): Aanderaa_O2.power (watt) 2013-08-13T04:47:56.434Z,1376369276.434 [CommandLine](INFO): Aanderaa_O2.model (none) 2013-08-13T04:47:56.463Z,1376369276.463 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=232 2013-08-13T04:47:56.510Z,1376369276.510 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=156 2013-08-13T04:47:56.524Z,1376369276.524 [CommandLine](INFO): tank_weight:Science.EnabledAanderaaO2 (none) 2013-08-13T04:47:56.558Z,1376369276.558 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:47:56.618Z,1376369276.618 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:47:56.898Z,1376369276.898 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:47:56.995Z,1376369276.995 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:47:57.091Z,1376369277.091 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2013-08-13T04:47:57.199Z,1376369277.199 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:47:57.339Z,1376369277.339 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:47:57.399Z,1376369277.399 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=156 2013-08-13T04:47:57.447Z,1376369277.447 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2013-08-13T04:47:57.495Z,1376369277.495 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:47:57.780Z,1376369277.780 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2013-08-13T04:47:57.892Z,1376369277.892 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=188 2013-08-13T04:47:57.992Z,1376369277.992 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2013-08-13T04:47:58.096Z,1376369278.096 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:47:58.445Z,1376369278.445 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=152 2013-08-13T04:47:58.581Z,1376369278.581 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2013-08-13T04:47:58.729Z,1376369278.729 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=64 2013-08-13T04:47:58.870Z,1376369278.870 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:47:59.198Z,1376369279.198 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=124 2013-08-13T04:47:59.310Z,1376369279.310 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2013-08-13T04:47:59.418Z,1376369279.418 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2013-08-13T04:47:59.542Z,1376369279.542 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:00.063Z,1376369280.063 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2013-08-13T04:48:00.304Z,1376369280.304 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=100 2013-08-13T04:48:00.544Z,1376369280.544 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=108 2013-08-13T04:48:00.772Z,1376369280.772 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:01.698Z,1376369281.698 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2013-08-13T04:48:01.787Z,1376369281.787 [NAL9602](INFO): Powering down 2013-08-13T04:48:02.170Z,1376369282.170 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=36 2013-08-13T04:48:02.651Z,1376369282.651 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=108 2013-08-13T04:48:03.124Z,1376369283.124 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:48:03.997Z,1376369283.997 [DVL_micro](DEBUG): NQ1 2013-08-13T04:48:04.040Z,1376369284.040 [DVL_micro](DEBUG): ADCP 2013-08-13T04:48:04.863Z,1376369284.863 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=65 2013-08-13T04:48:05.696Z,1376369285.696 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=9 2013-08-13T04:48:06.545Z,1376369286.545 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=113 2013-08-13T04:48:07.379Z,1376369287.379 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:48:07.399Z,1376369287.399 [CommandLine](IMPORTANT): got command show variable aand 2013-08-13T04:48:07.413Z,1376369287.413 [CommandLine](INFO): Aanderaa_O2.loadControl (none) 2013-08-13T04:48:07.413Z,1376369287.413 [CommandLine](INFO): Aanderaa_O2.uart (none) 2013-08-13T04:48:07.413Z,1376369287.413 [CommandLine](INFO): Aanderaa_O2.baud (bit_per_second) 2013-08-13T04:48:07.453Z,1376369287.453 [CommandLine](INFO): Aanderaa_O2.loadAtStartup (bool) 2013-08-13T04:48:07.454Z,1376369287.454 [CommandLine](INFO): Aanderaa_O2.simulateHardware (bool) 2013-08-13T04:48:07.462Z,1376369287.462 [CommandLine](INFO): Aanderaa_O2.power (watt) 2013-08-13T04:48:07.463Z,1376369287.463 [CommandLine](INFO): Aanderaa_O2.model (none) 2013-08-13T04:48:07.635Z,1376369287.635 [CommandLine](INFO): tank_weight:Science.EnabledAanderaaO2 (none) 2013-08-13T04:48:07.859Z,1376369287.859 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=104 2013-08-13T04:48:07.919Z,1376369287.919 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=124 2013-08-13T04:48:07.970Z,1376369287.970 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80 2013-08-13T04:48:08.016Z,1376369288.016 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:08.298Z,1376369288.298 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2013-08-13T04:48:08.412Z,1376369288.412 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=220 2013-08-13T04:48:08.508Z,1376369288.508 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2013-08-13T04:48:08.605Z,1376369288.605 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:08.749Z,1376369288.749 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=104 2013-08-13T04:48:08.797Z,1376369288.797 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2013-08-13T04:48:08.849Z,1376369288.849 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:48:08.909Z,1376369288.909 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:09.189Z,1376369289.189 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2013-08-13T04:48:09.297Z,1376369289.297 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2013-08-13T04:48:09.394Z,1376369289.394 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2013-08-13T04:48:09.494Z,1376369289.494 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:09.847Z,1376369289.847 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=152 2013-08-13T04:48:09.995Z,1376369289.995 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=124 2013-08-13T04:48:10.127Z,1376369290.127 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=0 2013-08-13T04:48:10.275Z,1376369290.275 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:48:10.600Z,1376369290.600 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=124 2013-08-13T04:48:10.720Z,1376369290.720 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2013-08-13T04:48:10.836Z,1376369290.836 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=140 2013-08-13T04:48:10.944Z,1376369290.944 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:11.477Z,1376369291.477 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2013-08-13T04:48:11.705Z,1376369291.705 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:11.768Z,1376369291.768 [CommandLine](IMPORTANT): got command failComponent 2013-08-13T04:48:11.768Z,1376369291.768 [CommandLine](IMPORTANT): Failed components: 2013-08-13T04:48:11.768Z,1376369291.768 [CommandLine](IMPORTANT): No failed Components. 2013-08-13T04:48:11.942Z,1376369291.942 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2013-08-13T04:48:12.178Z,1376369292.178 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:13.103Z,1376369293.103 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=92 2013-08-13T04:48:13.584Z,1376369293.584 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=164 2013-08-13T04:48:14.057Z,1376369294.057 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=108 2013-08-13T04:48:14.530Z,1376369294.530 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:48:15.411Z,1376369295.411 [DVL_micro](DEBUG): NQ1 2013-08-13T04:48:15.440Z,1376369295.440 [DVL_micro](DEBUG): ADCP 2013-08-13T04:48:16.281Z,1376369296.281 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=201 2013-08-13T04:48:17.114Z,1376369297.114 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=81 2013-08-13T04:48:17.951Z,1376369297.951 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=57 2013-08-13T04:48:18.792Z,1376369298.792 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:48:19.089Z,1376369299.089 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2013-08-13T04:48:19.149Z,1376369299.149 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2013-08-13T04:48:19.213Z,1376369299.213 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2013-08-13T04:48:19.261Z,1376369299.261 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:19.541Z,1376369299.541 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2013-08-13T04:48:19.638Z,1376369299.638 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2013-08-13T04:48:19.746Z,1376369299.746 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=64 2013-08-13T04:48:19.846Z,1376369299.846 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:19.982Z,1376369299.982 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:48:20.042Z,1376369300.042 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=92 2013-08-13T04:48:20.094Z,1376369300.094 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80 2013-08-13T04:48:20.142Z,1376369300.142 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:20.427Z,1376369300.427 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2013-08-13T04:48:20.535Z,1376369300.535 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2013-08-13T04:48:20.631Z,1376369300.631 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2013-08-13T04:48:20.731Z,1376369300.731 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:21.080Z,1376369301.080 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=88 2013-08-13T04:48:21.224Z,1376369301.224 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2013-08-13T04:48:21.368Z,1376369301.368 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2013-08-13T04:48:21.532Z,1376369301.532 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:48:21.833Z,1376369301.833 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2013-08-13T04:48:21.949Z,1376369301.949 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:22.073Z,1376369302.073 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=108 2013-08-13T04:48:22.186Z,1376369302.186 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:22.706Z,1376369302.706 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=28 2013-08-13T04:48:22.947Z,1376369302.947 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=36 2013-08-13T04:48:23.191Z,1376369303.191 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=140 2013-08-13T04:48:23.423Z,1376369303.423 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:24.349Z,1376369304.349 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=124 2013-08-13T04:48:24.822Z,1376369304.822 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=132 2013-08-13T04:48:25.294Z,1376369305.294 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=76 2013-08-13T04:48:25.771Z,1376369305.771 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:48:26.648Z,1376369306.648 [DVL_micro](DEBUG): NQ1 2013-08-13T04:48:26.719Z,1376369306.719 [DVL_micro](DEBUG): ADCP 2013-08-13T04:48:27.514Z,1376369307.514 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=71 2013-08-13T04:48:28.351Z,1376369308.351 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=47 2013-08-13T04:48:29.196Z,1376369309.196 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=119 2013-08-13T04:48:30.022Z,1376369310.022 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:48:30.302Z,1376369310.302 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:48:30.362Z,1376369310.362 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2013-08-13T04:48:30.414Z,1376369310.414 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80 2013-08-13T04:48:30.475Z,1376369310.475 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:30.755Z,1376369310.755 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:48:30.851Z,1376369310.851 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2013-08-13T04:48:30.959Z,1376369310.959 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2013-08-13T04:48:31.055Z,1376369311.055 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:31.195Z,1376369311.195 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:48:31.248Z,1376369311.248 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2013-08-13T04:48:31.300Z,1376369311.300 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:48:31.360Z,1376369311.360 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:31.636Z,1376369311.636 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2013-08-13T04:48:31.744Z,1376369311.744 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:48:31.841Z,1376369311.841 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2013-08-13T04:48:31.953Z,1376369311.953 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:32.297Z,1376369312.297 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=88 2013-08-13T04:48:32.437Z,1376369312.437 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=60 2013-08-13T04:48:32.582Z,1376369312.582 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2013-08-13T04:48:32.730Z,1376369312.730 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:48:33.047Z,1376369313.047 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=92 2013-08-13T04:48:33.162Z,1376369313.162 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=36 2013-08-13T04:48:33.287Z,1376369313.287 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=108 2013-08-13T04:48:33.395Z,1376369313.395 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:33.928Z,1376369313.928 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=92 2013-08-13T04:48:34.166Z,1376369314.166 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=132 2013-08-13T04:48:34.409Z,1376369314.409 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=108 2013-08-13T04:48:34.629Z,1376369314.629 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:35.550Z,1376369315.550 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2013-08-13T04:48:36.031Z,1376369316.031 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=100 2013-08-13T04:48:36.500Z,1376369316.500 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=44 2013-08-13T04:48:36.976Z,1376369316.976 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:48:37.862Z,1376369317.862 [DVL_micro](DEBUG): NQ1 2013-08-13T04:48:37.902Z,1376369317.902 [DVL_micro](DEBUG): ADCP 2013-08-13T04:48:38.715Z,1376369318.715 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=37 2013-08-13T04:48:39.560Z,1376369319.560 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=109 2013-08-13T04:48:40.394Z,1376369320.394 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=53 2013-08-13T04:48:41.235Z,1376369321.235 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:48:41.522Z,1376369321.522 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:48:41.573Z,1376369321.573 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2013-08-13T04:48:41.632Z,1376369321.632 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2013-08-13T04:48:41.684Z,1376369321.684 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:41.972Z,1376369321.972 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:48:42.075Z,1376369322.075 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2013-08-13T04:48:42.172Z,1376369322.172 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=64 2013-08-13T04:48:42.281Z,1376369322.281 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:42.421Z,1376369322.421 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=200 2013-08-13T04:48:42.472Z,1376369322.472 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=188 2013-08-13T04:48:42.521Z,1376369322.521 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=80 2013-08-13T04:48:42.569Z,1376369322.569 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:42.858Z,1376369322.858 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=88 2013-08-13T04:48:42.958Z,1376369322.958 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2013-08-13T04:48:43.054Z,1376369323.054 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2013-08-13T04:48:43.162Z,1376369323.162 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:43.507Z,1376369323.507 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2013-08-13T04:48:43.651Z,1376369323.651 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2013-08-13T04:48:43.795Z,1376369323.795 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=64 2013-08-13T04:48:43.943Z,1376369323.943 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:48:44.264Z,1376369324.264 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=92 2013-08-13T04:48:44.384Z,1376369324.384 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2013-08-13T04:48:44.496Z,1376369324.496 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2013-08-13T04:48:44.618Z,1376369324.618 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:45.137Z,1376369325.137 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2013-08-13T04:48:45.369Z,1376369325.369 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:45.618Z,1376369325.618 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=76 2013-08-13T04:48:45.850Z,1376369325.850 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:46.776Z,1376369326.776 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=156 2013-08-13T04:48:47.244Z,1376369327.244 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=68 2013-08-13T04:48:47.717Z,1376369327.717 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=44 2013-08-13T04:48:48.186Z,1376369328.186 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:48:49.079Z,1376369329.079 [DVL_micro](DEBUG): NQ1 2013-08-13T04:48:49.107Z,1376369329.107 [DVL_micro](DEBUG): ADCP 2013-08-13T04:48:49.940Z,1376369329.940 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=103 2013-08-13T04:48:50.778Z,1376369330.778 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=111 2013-08-13T04:48:51.627Z,1376369331.627 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=215 2013-08-13T04:48:52.448Z,1376369332.448 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:48:52.733Z,1376369332.733 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=104 2013-08-13T04:48:52.781Z,1376369332.781 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=28 2013-08-13T04:48:52.833Z,1376369332.833 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:48:52.897Z,1376369332.897 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:53.178Z,1376369333.178 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=184 2013-08-13T04:48:53.274Z,1376369333.274 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2013-08-13T04:48:53.370Z,1376369333.370 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2013-08-13T04:48:53.490Z,1376369333.490 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:53.621Z,1376369333.621 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=168 2013-08-13T04:48:53.672Z,1376369333.672 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=124 2013-08-13T04:48:53.722Z,1376369333.722 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:48:53.782Z,1376369333.782 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:48:54.059Z,1376369334.059 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=56 2013-08-13T04:48:54.159Z,1376369334.159 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=28 2013-08-13T04:48:54.259Z,1376369334.259 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2013-08-13T04:48:54.363Z,1376369334.363 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:48:54.716Z,1376369334.716 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=88 2013-08-13T04:48:54.856Z,1376369334.856 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2013-08-13T04:48:55.004Z,1376369335.004 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=128 2013-08-13T04:48:55.145Z,1376369335.145 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:48:55.477Z,1376369335.477 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=188 2013-08-13T04:48:55.585Z,1376369335.585 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=68 2013-08-13T04:48:55.697Z,1376369335.697 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=12 2013-08-13T04:48:55.819Z,1376369335.819 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:48:56.342Z,1376369336.342 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=60 2013-08-13T04:48:56.583Z,1376369336.583 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=100 2013-08-13T04:48:56.811Z,1376369336.811 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=44 2013-08-13T04:48:57.056Z,1376369337.056 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:48:57.973Z,1376369337.973 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=28 2013-08-13T04:48:58.450Z,1376369338.450 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=68 2013-08-13T04:48:58.922Z,1376369338.922 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=44 2013-08-13T04:48:59.399Z,1376369339.399 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:49:00.289Z,1376369340.289 [DVL_micro](DEBUG): NQ1 2013-08-13T04:49:00.305Z,1376369340.305 [DVL_micro](DEBUG): ADCP 2013-08-13T04:49:01.142Z,1376369341.142 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=37 2013-08-13T04:49:01.987Z,1376369341.987 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=109 2013-08-13T04:49:02.817Z,1376369342.817 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=21 2013-08-13T04:49:03.662Z,1376369343.662 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:49:04.087Z,1376369344.087 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=1256 2013-08-13T04:49:04.088Z,1376369344.088 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=636 2013-08-13T04:49:04.089Z,1376369344.089 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:49:04.151Z,1376369344.151 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:04.427Z,1376369344.427 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:49:04.535Z,1376369344.535 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=124 2013-08-13T04:49:04.631Z,1376369344.631 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=32 2013-08-13T04:49:04.728Z,1376369344.728 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:04.877Z,1376369344.877 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:49:04.928Z,1376369344.928 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=92 2013-08-13T04:49:04.976Z,1376369344.976 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=16 2013-08-13T04:49:05.028Z,1376369345.028 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:05.320Z,1376369345.320 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:49:05.421Z,1376369345.421 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:49:05.525Z,1376369345.525 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2013-08-13T04:49:05.621Z,1376369345.621 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:05.977Z,1376369345.977 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=152 2013-08-13T04:49:06.122Z,1376369346.122 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=124 2013-08-13T04:49:06.254Z,1376369346.254 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=32 2013-08-13T04:49:06.414Z,1376369346.414 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:49:06.727Z,1376369346.727 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=60 2013-08-13T04:49:06.839Z,1376369346.839 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:49:06.959Z,1376369346.959 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=44 2013-08-13T04:49:07.079Z,1376369347.079 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:49:07.608Z,1376369347.608 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=220 2013-08-13T04:49:07.836Z,1376369347.836 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=68 2013-08-13T04:49:08.073Z,1376369348.073 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=76 2013-08-13T04:49:08.305Z,1376369348.305 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:49:09.227Z,1376369349.227 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=60 2013-08-13T04:49:09.707Z,1376369349.707 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=68 2013-08-13T04:49:10.184Z,1376369350.184 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=76 2013-08-13T04:49:10.653Z,1376369350.653 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:49:11.542Z,1376369351.542 [DVL_micro](DEBUG): NQ1 2013-08-13T04:49:11.573Z,1376369351.573 [DVL_micro](DEBUG): ADCP 2013-08-13T04:49:12.403Z,1376369352.403 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=71 2013-08-13T04:49:13.245Z,1376369353.245 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=111 2013-08-13T04:49:14.083Z,1376369354.083 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=87 2013-08-13T04:49:14.915Z,1376369354.915 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:49:15.200Z,1376369355.200 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2013-08-13T04:49:15.261Z,1376369355.261 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=92 2013-08-13T04:49:15.312Z,1376369355.312 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2013-08-13T04:49:15.372Z,1376369355.372 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:15.657Z,1376369355.657 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=248 2013-08-13T04:49:15.753Z,1376369355.753 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:49:15.853Z,1376369355.853 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=128 2013-08-13T04:49:15.953Z,1376369355.953 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:16.085Z,1376369356.085 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=8 2013-08-13T04:49:16.145Z,1376369356.145 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=60 2013-08-13T04:49:16.205Z,1376369356.205 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=112 2013-08-13T04:49:16.245Z,1376369356.245 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:16.538Z,1376369356.538 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:49:16.634Z,1376369356.634 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=60 2013-08-13T04:49:16.734Z,1376369356.734 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=0 2013-08-13T04:49:16.842Z,1376369356.842 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:17.187Z,1376369357.187 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=24 2013-08-13T04:49:17.331Z,1376369357.331 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=28 2013-08-13T04:49:17.492Z,1376369357.492 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=225 2013-08-13T04:49:17.623Z,1376369357.623 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:49:17.952Z,1376369357.952 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=156 2013-08-13T04:49:18.056Z,1376369358.056 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=36 2013-08-13T04:49:18.180Z,1376369358.180 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=76 2013-08-13T04:49:18.293Z,1376369358.293 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:49:18.825Z,1376369358.825 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=124 2013-08-13T04:49:19.054Z,1376369359.054 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=68 2013-08-13T04:49:19.290Z,1376369359.290 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=12 2013-08-13T04:49:19.535Z,1376369359.535 [DVL_micro](DEBUG): RSSI read bytes: 2712 of 2712, #buffered=4 2013-08-13T04:49:20.468Z,1376369360.468 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=156 2013-08-13T04:49:20.929Z,1376369360.929 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=68 2013-08-13T04:49:21.401Z,1376369361.401 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=44 2013-08-13T04:49:21.886Z,1376369361.886 [DVL_micro](DEBUG): RSSI read bytes: 5432 of 5432, #buffered=4 2013-08-13T04:49:22.763Z,1376369362.763 [DVL_micro](DEBUG): NQ1 2013-08-13T04:49:22.801Z,1376369362.801 [DVL_micro](DEBUG): ADCP 2013-08-13T04:49:23.621Z,1376369363.621 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=72 2013-08-13T04:49:24.454Z,1376369364.454 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=48 2013-08-13T04:49:25.295Z,1376369365.295 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=56 2013-08-13T04:49:26.141Z,1376369366.141 [DVL_micro](DEBUG): RSSI read bytes: 9592 of 9592, #buffered=4 2013-08-13T04:49:26.458Z,1376369366.458 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=40 2013-08-13T04:49:26.517Z,1376369366.517 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=92 2013-08-13T04:49:26.567Z,1376369366.567 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=48 2013-08-13T04:49:26.617Z,1376369366.617 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:26.898Z,1376369366.898 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=24 2013-08-13T04:49:27.006Z,1376369367.006 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:49:27.102Z,1376369367.102 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=64 2013-08-13T04:49:27.206Z,1376369367.206 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:27.347Z,1376369367.347 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=72 2013-08-13T04:49:27.407Z,1376369367.407 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=124 2013-08-13T04:49:27.455Z,1376369367.455 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=112 2013-08-13T04:49:27.503Z,1376369367.503 [DVL_micro](DEBUG): RSSI read bytes: 620 of 620, #buffered=4 2013-08-13T04:49:27.795Z,1376369367.795 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=120 2013-08-13T04:49:27.892Z,1376369367.892 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=92 2013-08-13T04:49:27.000Z,1376369368.000 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=96 2013-08-13T04:49:28.100Z,1376369368.100 [DVL_micro](DEBUG): RSSI read bytes: 1180 of 1180, #buffered=4 2013-08-13T04:49:28.308Z,1376369368.308 [CommandLine](IMPORTANT): got command quit 2013-08-13T04:49:28.444Z,1376369368.444 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=56 2013-08-13T04:49:28.592Z,1376369368.592 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=92 2013-08-13T04:49:28.741Z,1376369368.741 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=128 2013-08-13T04:49:28.873Z,1376369368.873 [DVL_micro](DEBUG): RSSI read bytes: 1660 of 1660, #buffered=4 2013-08-13T04:49:29.197Z,1376369369.197 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=28 2013-08-13T04:49:29.326Z,1376369369.326 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=196 2013-08-13T04:49:29.389Z,1376369369.389 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-08-13T04:49:29.389Z,1376369369.389 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-08-13T04:49:29.434Z,1376369369.434 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=108 2013-08-13T04:49:29.502Z,1376369369.502 [tank_weight] Stopped 2013-08-13T04:49:29.502Z,1376369369.502 [tank_weight](INFO): Aggregate::uninitialize tank_weight 2013-08-13T04:49:29.502Z,1376369369.502 [tank_weight:A.AltitudeEnvelope] Stopped 2013-08-13T04:49:29.502Z,1376369369.502 [tank_weight:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2013-08-13T04:49:29.502Z,1376369369.502 [tank_weight:B.DepthEnvelope] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:B.DepthEnvelope](DEBUG): Uninitialize. 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science](INFO): Aggregate::uninitialize tank_weight:Science 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:A] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:B] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:C] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:D] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:E] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:F] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:G] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:H] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:Science:I] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:D] Stopped 2013-08-13T04:49:29.503Z,1376369369.503 [tank_weight:D](INFO): Aggregate::uninitialize tank_weight:D 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:A.SetSpeed] Stopped 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:A.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo] Stopped 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo](INFO): Aggregate::uninitialize tank_weight:D:BuoyancyLo 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo:A.Buoyancy] Stopped 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo:B.Pitch] Stopped 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo:C.Wait] Stopped 2013-08-13T04:49:29.504Z,1376369369.504 [tank_weight:D:BuoyancyLo:C.Wait](DEBUG): Uninitialize Wait Component. 2013-08-13T04:49:29.514Z,1376369369.514 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-08-13T04:49:29.550Z,1376369369.550 [DVL_micro](DEBUG): RSSI read bytes: 1336 of 1336, #buffered=4 2013-08-13T04:49:29.552Z,1376369369.552 [DVL_micro](INFO): uninitialize:Powering down 2013-08-13T04:49:29.850Z,1376369369.850 [MissionManager](IMPORTANT): Started mission Default 2013-08-13T04:49:29.850Z,1376369369.850 [Default] Running Loop=1 2013-08-13T04:49:29.851Z,1376369369.851 [Default](INFO): Aggregate::initialize Default 2013-08-13T04:49:29.851Z,1376369369.851 [Default:D.SetSpeed] Running Loop=1 2013-08-13T04:49:29.851Z,1376369369.851 [Default:D.SetSpeed](DEBUG): Initialize. 2013-08-13T04:49:29.851Z,1376369369.851 [Default:E.GoToSurface] Running Loop=1 2013-08-13T04:49:29.851Z,1376369369.851 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:49:29.851Z,1376369369.851 [Default:Iridium] Running Loop=1 2013-08-13T04:49:29.852Z,1376369369.852 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-08-13T04:49:29.852Z,1376369369.852 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-08-13T04:49:29.852Z,1376369369.852 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-08-13T04:49:29.852Z,1376369369.852 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-08-13T04:49:29.852Z,1376369369.852 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:49:29.854Z,1376369369.854 [Default:Iridium:B.GoToSurface] Stopped 2013-08-13T04:49:29.854Z,1376369369.854 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:49:29.854Z,1376369369.854 [Default:Iridium:Read_Iridium] Running Loop=1 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS] Running Loop=1 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS:A.SetSpeed] Running Loop=1 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS:B.GoToSurface] Running Loop=1 2013-08-13T04:49:29.855Z,1376369369.855 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-08-13T04:49:29.856Z,1376369369.856 [Default:GPS:B.GoToSurface] Stopped 2013-08-13T04:49:29.856Z,1376369369.856 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:49:29.856Z,1376369369.856 [Default:GPS:Read_GPS] Running Loop=1 2013-08-13T04:49:29.955Z,1376369369.955 [DVL_micro](INFO): uninitialize:Powering down 2013-08-13T04:49:29.970Z,1376369369.970 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-08-13T04:49:30.071Z,1376369370.071 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-08-13T04:49:30.082Z,1376369370.082 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-08-13T04:49:30.182Z,1376369370.182 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-08-13T04:49:30.184Z,1376369370.184 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-08-13T04:49:30.332Z,1376369370.332 [controlThread](DEBUG): Uninitializing ControlThread 2013-08-13T04:49:30.333Z,1376369370.333 [AHRS_sp3003D](INFO): Powering down 2013-08-13T04:49:30.420Z,1376369370.420 [NAL9602](INFO): Powering down 2013-08-13T04:49:30.421Z,1376369370.421 [DAT](INFO): Powering down 2013-08-13T04:49:30.423Z,1376369370.423 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-08-13T04:49:30.423Z,1376369370.423 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-08-13T04:49:30.424Z,1376369370.424 [Default] Stopped 2013-08-13T04:49:30.424Z,1376369370.424 [Default](INFO): Aggregate::uninitialize Default 2013-08-13T04:49:30.425Z,1376369370.425 [Default:GPS] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-08-13T04:49:30.425Z,1376369370.425 [Default:GPS:A.SetSpeed] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:49:30.425Z,1376369370.425 [Default:GPS:Read_GPS] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:Iridium] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-08-13T04:49:30.425Z,1376369370.425 [Default:Iridium:A.SetSpeed] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:49:30.425Z,1376369370.425 [Default:Iridium:Read_Iridium] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:D.SetSpeed] Stopped 2013-08-13T04:49:30.425Z,1376369370.425 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-08-13T04:49:30.425Z,1376369370.425 [Default:E.GoToSurface] Stopped 2013-08-13T04:49:30.426Z,1376369370.426 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-08-13T04:49:30.430Z,1376369370.430 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-08-13T04:49:30.430Z,1376369370.430 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-08-13T04:49:30.430Z,1376369370.430 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-08-13T04:49:30.430Z,1376369370.430 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-08-13T04:49:30.431Z,1376369370.431 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-08-13T04:49:30.432Z,1376369370.432 [BuoyancyServo](INFO): Powering down 2013-08-13T04:49:30.447Z,1376369370.447 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-08-13T04:49:30.447Z,1376369370.447 [ElevatorServo](INFO): Powering down 2013-08-13T04:49:30.448Z,1376369370.448 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-08-13T04:49:30.448Z,1376369370.448 [MassServo](INFO): Powering down 2013-08-13T04:49:30.449Z,1376369370.449 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-08-13T04:49:30.450Z,1376369370.450 [RudderServo](INFO): Powering down 2013-08-13T04:49:30.450Z,1376369370.450 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-08-13T04:49:30.451Z,1376369370.451 [ThrusterServo](INFO): Powering down 2013-08-13T04:49:30.452Z,1376369370.452 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-08-13T04:49:30.452Z,1376369370.452 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-08-13T04:49:30.452Z,1376369370.452 [CBIT](DEBUG): Uninitialize CBIT Component.