2013-06-04T00:47:53.148Z,1370306873.148 [Supervisor](DEBUG): Initializing supervisor. 2013-06-04T00:47:53.151Z,1370306873.151 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-06-04T00:47:53.151Z,1370306873.151 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-06-04T00:47:53.153Z,1370306873.153 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-06-04T00:47:53.157Z,1370306873.158 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-06-04T00:47:53.169Z,1370306873.169 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-06-04T00:47:53.170Z,1370306873.170 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-06-04T00:47:53.171Z,1370306873.171 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-06-04T00:47:53.172Z,1370306873.172 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-06-04T00:47:53.172Z,1370306873.172 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-06-04T00:47:53.174Z,1370306873.174 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-06-04T00:47:53.462Z,1370306873.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-06-04T00:47:53.463Z,1370306873.463 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-06-04T00:47:53.659Z,1370306873.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-06-04T00:47:53.660Z,1370306873.659 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-06-04T00:47:53.744Z,1370306873.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-06-04T00:47:53.744Z,1370306873.744 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-06-04T00:47:53.887Z,1370306873.887 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-06-04T00:47:53.887Z,1370306873.887 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-06-04T00:47:54.025Z,1370306874.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-06-04T00:47:54.026Z,1370306874.026 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-06-04T00:47:54.275Z,1370306874.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-06-04T00:47:54.275Z,1370306874.275 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-06-04T00:47:54.446Z,1370306874.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-06-04T00:47:54.446Z,1370306874.446 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-06-04T00:47:54.703Z,1370306874.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-06-04T00:47:54.704Z,1370306874.704 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-06-04T00:47:54.803Z,1370306874.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-06-04T00:47:54.803Z,1370306874.803 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-06-04T00:47:55.205Z,1370306875.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-06-04T00:47:55.206Z,1370306875.205 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-06-04T00:47:55.319Z,1370306875.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-06-04T00:47:55.319Z,1370306875.319 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-06-04T00:47:55.405Z,1370306875.405 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-06-04T00:47:55.406Z,1370306875.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-06-04T00:47:55.510Z,1370306875.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-06-04T00:47:55.644Z,1370306875.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-06-04T00:47:55.735Z,1370306875.735 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-06-04T00:47:55.848Z,1370306875.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-06-04T00:47:55.976Z,1370306875.976 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-06-04T00:47:56.094Z,1370306876.095 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-06-04T00:47:56.188Z,1370306876.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-06-04T00:47:56.275Z,1370306876.274 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2013-06-04T00:47:56.275Z,1370306876.275 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-06-04T00:47:56.280Z,1370306876.280 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-06-04T00:47:56.432Z,1370306876.432 [InternalSim] Loaded 2013-06-04T00:47:56.432Z,1370306876.432 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-06-04T00:47:56.433Z,1370306876.433 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-06-04T00:47:56.433Z,1370306876.433 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-06-04T00:47:56.493Z,1370306876.493 [SBIT](DEBUG): Construct Startup Built In Test. 2013-06-04T00:47:56.522Z,1370306876.522 [SBIT] Loaded 2013-06-04T00:47:56.522Z,1370306876.522 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-06-04T00:47:56.523Z,1370306876.523 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-06-04T00:47:56.552Z,1370306876.552 [IBIT] Loaded 2013-06-04T00:47:56.552Z,1370306876.552 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-06-04T00:47:56.555Z,1370306876.555 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-06-04T00:47:56.670Z,1370306876.670 [CBIT] Loaded 2013-06-04T00:47:56.670Z,1370306876.671 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-06-04T00:47:56.671Z,1370306876.671 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-06-04T00:47:56.672Z,1370306876.671 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-06-04T00:47:56.824Z,1370306876.824 [BuoyancyServo] Loaded 2013-06-04T00:47:56.824Z,1370306876.824 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-06-04T00:47:56.836Z,1370306876.836 [ElevatorServo] Loaded 2013-06-04T00:47:56.836Z,1370306876.836 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-06-04T00:47:56.848Z,1370306876.848 [MassServo] Loaded 2013-06-04T00:47:56.849Z,1370306876.849 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-06-04T00:47:56.861Z,1370306876.861 [RudderServo] Loaded 2013-06-04T00:47:56.861Z,1370306876.861 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-06-04T00:47:56.873Z,1370306876.873 [ThrusterServo] Loaded 2013-06-04T00:47:56.873Z,1370306876.873 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-06-04T00:47:56.874Z,1370306876.874 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-06-04T00:47:56.874Z,1370306876.874 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-06-04T00:47:56.893Z,1370306876.893 [DepthRateCalculator] Loaded 2013-06-04T00:47:56.893Z,1370306876.893 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-06-04T00:47:59.934Z,1370306879.934 [HFRadarModelCalc] Loaded 2013-06-04T00:47:59.934Z,1370306879.934 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-06-04T00:47:59.950Z,1370306879.950 [NavChart] Loaded 2013-06-04T00:47:59.950Z,1370306879.950 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-06-04T00:47:59.956Z,1370306879.956 [PitchRateCalculator] Loaded 2013-06-04T00:47:59.956Z,1370306879.956 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-06-04T00:47:59.967Z,1370306879.967 [SpeedCalculator] Loaded 2013-06-04T00:47:59.967Z,1370306879.967 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-06-04T00:47:59.982Z,1370306879.982 [TempGradientCalculator] Loaded 2013-06-04T00:47:59.982Z,1370306879.982 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-06-04T00:47:59.988Z,1370306879.988 [YawRateCalculator] Loaded 2013-06-04T00:47:59.988Z,1370306879.988 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-06-04T00:48:00.033Z,1370306880.033 [Navigation] Loaded 2013-06-04T00:48:00.033Z,1370306880.033 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-06-04T00:48:00.034Z,1370306880.034 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-06-04T00:48:00.034Z,1370306880.034 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-06-04T00:48:00.252Z,1370306880.252 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-06-04T00:48:00.252Z,1370306880.253 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-06-04T00:48:00.276Z,1370306880.276 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-06-04T00:48:00.276Z,1370306880.276 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-06-04T00:48:00.319Z,1370306880.319 [VerticalControl](DEBUG): Construct VerticalControl. 2013-06-04T00:48:00.411Z,1370306880.411 [VerticalControl] Loaded 2013-06-04T00:48:00.411Z,1370306880.411 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-06-04T00:48:00.412Z,1370306880.412 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-06-04T00:48:00.467Z,1370306880.467 [HorizontalControl] Loaded 2013-06-04T00:48:00.467Z,1370306880.467 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-06-04T00:48:00.468Z,1370306880.468 [SpeedControl](DEBUG): Construct SpeedControl. 2013-06-04T00:48:00.470Z,1370306880.470 [SpeedControl] Loaded 2013-06-04T00:48:00.470Z,1370306880.470 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-06-04T00:48:00.471Z,1370306880.471 [LoopControl](DEBUG): Construct LoopControl. 2013-06-04T00:48:00.472Z,1370306880.472 [LoopControl] Loaded 2013-06-04T00:48:00.472Z,1370306880.472 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-06-04T00:48:00.472Z,1370306880.472 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-06-04T00:48:00.473Z,1370306880.473 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-06-04T00:48:00.478Z,1370306880.478 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-06-04T00:48:00.483Z,1370306880.483 [AsyncPiEstimator] Loaded 2013-06-04T00:48:00.483Z,1370306880.483 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-06-04T00:48:00.484Z,1370306880.484 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0 2013-06-04T00:48:00.485Z,1370306880.485 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-06-04T00:48:00.486Z,1370306880.486 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-06-04T00:48:00.633Z,1370306880.633 [AHRS_sp3003D] Loaded 2013-06-04T00:48:00.633Z,1370306880.634 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-06-04T00:48:00.886Z,1370306880.886 [Batt_Ocean_Server] Loaded 2013-06-04T00:48:00.886Z,1370306880.886 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-06-04T00:48:00.899Z,1370306880.899 [Depth_Keller] Loaded 2013-06-04T00:48:00.899Z,1370306880.899 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-06-04T00:48:00.905Z,1370306880.905 [DropWeight] Loaded 2013-06-04T00:48:00.905Z,1370306880.905 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-06-04T00:48:01.074Z,1370306881.074 [DVL_micro] Loaded 2013-06-04T00:48:01.075Z,1370306881.075 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-06-04T00:48:01.076Z,1370306881.076 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406C34E0 2013-06-04T00:48:01.157Z,1370306881.157 [NAL9602] Loaded 2013-06-04T00:48:01.157Z,1370306881.157 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-06-04T00:48:01.206Z,1370306881.206 [Onboard] Loaded 2013-06-04T00:48:01.206Z,1370306881.207 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-06-04T00:48:01.213Z,1370306881.213 [Radio_Freewave] Loaded 2013-06-04T00:48:01.213Z,1370306881.214 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-06-04T00:48:01.368Z,1370306881.368 [DAT] Loaded 2013-06-04T00:48:01.369Z,1370306881.369 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-06-04T00:48:01.375Z,1370306881.375 [SCPI] Loaded 2013-06-04T00:48:01.376Z,1370306881.376 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2013-06-04T00:48:01.376Z,1370306881.376 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-06-04T00:48:01.377Z,1370306881.377 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-06-04T00:48:01.469Z,1370306881.469 [CTD_NeilBrown] Loaded 2013-06-04T00:48:01.470Z,1370306881.470 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-06-04T00:48:01.471Z,1370306881.471 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407154E0 2013-06-04T00:48:01.501Z,1370306881.501 [WetLabsBB2FL] Loaded 2013-06-04T00:48:01.501Z,1370306881.501 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-06-04T00:48:01.502Z,1370306881.502 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407454E0 2013-06-04T00:48:01.503Z,1370306881.503 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-06-04T00:48:01.505Z,1370306881.505 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-06-04T00:48:01.506Z,1370306881.506 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-06-04T00:48:01.513Z,1370306881.513 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-06-04T00:48:01.514Z,1370306881.514 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407754E0 2013-06-04T00:48:01.519Z,1370306881.519 [Supervisor](DEBUG): Running supervisor. 2013-06-04T00:48:01.520Z,1370306881.520 [CommandLine](INFO): Thread ID is 3732 2013-06-04T00:48:01.523Z,1370306881.523 [controlThread](INFO): Thread ID is 3731 2013-06-04T00:48:01.523Z,1370306881.523 [controlThread](DEBUG): Initializing ControlThread 2013-06-04T00:48:01.524Z,1370306881.524 [CycleStarter](INFO): Thread ID is 3730 2013-06-04T00:48:01.524Z,1370306881.524 [InternalSim](DEBUG): InternalSim initializing... 2013-06-04T00:48:01.559Z,1370306881.559 [logger](INFO): Thread ID is 3733 2013-06-04T00:48:01.584Z,1370306881.584 [SBIT](INFO): Initialize SBIT Component. 2013-06-04T00:48:01.585Z,1370306881.585 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10402 2013-06-04T00:48:01.585Z,1370306881.585 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-06-04T00:48:01.586Z,1370306881.586 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 2013-06-04T00:48:01.586Z,1370306881.586 [IBIT](INFO): Initialize IBIT Component. 2013-06-04T00:48:01.587Z,1370306881.587 [CBIT](DEBUG): Initialize CBIT Component. 2013-06-04T00:48:01.587Z,1370306881.587 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-06-04T00:48:01.599Z,1370306881.599 [AsyncPiEstimator](INFO): Thread ID is 3795 2013-06-04T00:48:01.599Z,1370306881.599 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-06-04T00:48:01.611Z,1370306881.611 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-06-04T00:48:01.612Z,1370306881.612 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-06-04T00:48:01.612Z,1370306881.612 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-06-04T00:48:01.613Z,1370306881.613 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-06-04T00:48:01.613Z,1370306881.613 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-06-04T00:48:01.615Z,1370306881.615 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-06-04T00:48:01.615Z,1370306881.615 [Navigation](DEBUG): Initializing Navigation. 2013-06-04T00:48:01.615Z,1370306881.615 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-06-04T00:48:01.617Z,1370306881.617 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-06-04T00:48:01.618Z,1370306881.618 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-06-04T00:48:01.618Z,1370306881.618 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-06-04T00:48:01.624Z,1370306881.624 [DVL_micro](INFO): Thread ID is 3796 2013-06-04T00:48:01.633Z,1370306881.633 [DVL_micro](INFO): Initializing 2013-06-04T00:48:01.633Z,1370306881.633 [DVL_micro](INFO): start:Powering up 2013-06-04T00:48:01.635Z,1370306881.635 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:48:01.635Z,1370306881.635 [DVL_micro](INFO): Cycling power to configure device. 2013-06-04T00:48:01.647Z,1370306881.647 [CTD_NeilBrown](INFO): Thread ID is 3797 2013-06-04T00:48:01.648Z,1370306881.648 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-06-04T00:48:01.650Z,1370306881.650 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-06-04T00:48:01.660Z,1370306881.660 [WetLabsBB2FL](INFO): Thread ID is 3798 2013-06-04T00:48:01.660Z,1370306881.660 [WetLabsBB2FL](INFO): Powering down 2013-06-04T00:48:01.703Z,1370306881.703 [NavChartDb](INFO): Thread ID is 3799 2013-06-04T00:48:01.710Z,1370306881.710 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-06-04T00:48:01.711Z,1370306881.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-06-04T00:48:01.711Z,1370306881.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-06-04T00:48:01.711Z,1370306881.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-06-04T00:48:01.712Z,1370306881.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-06-04T00:48:01.712Z,1370306881.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-06-04T00:48:01.712Z,1370306881.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-06-04T00:48:01.713Z,1370306881.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-06-04T00:48:01.713Z,1370306881.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-06-04T00:48:03.450Z,1370306883.450 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-06-04T00:48:03.505Z,1370306883.505 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-06-04T00:48:03.529Z,1370306883.529 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-06-04T00:48:03.552Z,1370306883.552 [MissionManager](DEBUG): 2013-06-04T00:48:03.553Z,1370306883.553 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-06-04T00:48:03.636Z,1370306883.636 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-06-04T00:48:03.639Z,1370306883.639 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:48:03.642Z,1370306883.642 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-06-04T00:48:03.687Z,1370306883.687 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:48:03.690Z,1370306883.690 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-06-04T00:48:03.712Z,1370306883.712 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-06-04T00:48:03.714Z,1370306883.714 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:48:03.715Z,1370306883.715 [DVL_micro](INFO): Querying output modes 2013-06-04T00:48:03.715Z,1370306883.715 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-06-04T00:48:03.726Z,1370306883.726 [DVL_micro](DEBUG): cmdResponse: 01 2013-06-04T00:48:03.726Z,1370306883.726 [DVL_micro](INFO): NQ1 output enabled 2013-06-04T00:48:03.727Z,1370306883.727 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-06-04T00:48:03.739Z,1370306883.739 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-06-04T00:48:03.744Z,1370306883.744 [DVL_micro](INFO): pause:Powering down 2013-06-04T00:48:03.748Z,1370306883.748 [Default:D.SetSpeed](DEBUG): Construct. 2013-06-04T00:48:03.776Z,1370306883.776 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-06-04T00:48:03.785Z,1370306883.786 [Default:F.Wait](DEBUG): Construct Wait. 2013-06-04T00:48:03.789Z,1370306883.789 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-06-04T00:48:03.814Z,1370306883.814 [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-06-04T00:48:03.886Z,1370306883.886 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-06-04T00:48:04.142Z,1370306884.142 [Radio_Freewave](INFO): Powering up 2013-06-04T00:48:04.148Z,1370306884.148 [DAT](INFO): Powering up 2013-06-04T00:48:04.148Z,1370306884.148 [DAT](DEBUG): Initializing DAT. 2013-06-04T00:48:04.380Z,1370306884.380 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-06-04T00:48:04.386Z,1370306884.386 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-06-04T00:48:04.414Z,1370306884.414 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-06-04T00:48:04.423Z,1370306884.422 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-06-04T00:48:04.428Z,1370306884.428 [MassServo](DEBUG): Initializing EZServoServo. 2013-06-04T00:48:04.434Z,1370306884.434 [MassServo](DEBUG): Initializing MassServo. 2013-06-04T00:48:04.440Z,1370306884.440 [RudderServo](DEBUG): Initializing EZServoServo. 2013-06-04T00:48:04.446Z,1370306884.446 [RudderServo](DEBUG): Initializing RudderServo. 2013-06-04T00:48:04.452Z,1370306884.452 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-06-04T00:48:04.458Z,1370306884.458 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-06-04T00:48:06.439Z,1370306886.439 [NAL9602](INFO): Powering up NAL9602 2013-06-04T00:48:17.158Z,1370306897.158 [NAL9602](INFO): NAL9602 initialized 2013-06-04T00:48:17.260Z,1370306897.260 [SBIT](IMPORTANT): Beginning Startup BIT 2013-06-04T00:48:17.287Z,1370306897.287 [CBIT](IMPORTANT): Beginning GF scan 2013-06-04T00:48:24.158Z,1370306904.158 [DAT](INFO): Powering down 2013-06-04T00:48:43.659Z,1370306923.659 [CBIT](IMPORTANT): No ground fault detected 2013-06-04T00:49:08.387Z,1370306948.386 [CommandLine](IMPORTANT): got command report touch homing_target_range 2013-06-04T00:49:08.388Z,1370306948.388 [CommandLine](IMPORTANT): got command report touch homing_target_azimuth 2013-06-04T00:49:10.000Z,1370306951.000 [SBIT](IMPORTANT): SBIT PASSED 2013-06-04T00:49:11.425Z,1370306951.425 [MissionManager](IMPORTANT): Started mission Startup 2013-06-04T00:49:11.425Z,1370306951.425 [Startup] Running Loop=1 2013-06-04T00:49:11.425Z,1370306951.425 [Startup](INFO): Aggregate::initialize Startup 2013-06-04T00:49:11.425Z,1370306951.425 [Startup:A.GoToSurface] Running Loop=1 2013-06-04T00:49:11.425Z,1370306951.425 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:49:11.431Z,1370306951.431 [Startup:StartupSatComms] Running Loop=1 2013-06-04T00:49:11.431Z,1370306951.431 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-06-04T00:49:11.432Z,1370306951.432 [Startup:StartupSatComms:A] Running Loop=1 2013-06-04T00:49:11.782Z,1370306951.782 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-06-04T00:49:25.543Z,1370306965.543 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-06-04T00:49:25.544Z,1370306965.544 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree 2013-06-04T00:49:25.545Z,1370306965.545 [CommandLine](IMPORTANT): got command set NAL9602.longitude_fix -121.820000 degree 2013-06-04T00:49:28.923Z,1370306968.923 [Startup:StartupSatComms:A] Stopped 2013-06-04T00:49:28.923Z,1370306968.923 [Startup:StartupSatComms:B] Running Loop=1 2013-06-04T00:49:29.246Z,1370306969.246 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-06-04T00:49:32.029Z,1370306972.029 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:36.332Z,1370306976.332 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:38.672Z,1370306978.672 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:41.783Z,1370306981.783 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-06-04T00:49:45.832Z,1370306985.832 [Startup:StartupSatComms:B] Stopped 2013-06-04T00:49:45.832Z,1370306985.832 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-06-04T00:49:45.832Z,1370306985.832 [Startup:StartupSatComms] Stopped 2013-06-04T00:49:45.832Z,1370306985.832 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-06-04T00:49:45.833Z,1370306985.833 [Startup](INFO): Completed Startup 2013-06-04T00:49:45.833Z,1370306985.833 [Startup] Stopped 2013-06-04T00:49:45.833Z,1370306985.833 [Startup](INFO): Aggregate::uninitialize Startup 2013-06-04T00:49:45.834Z,1370306985.833 [Startup:A.GoToSurface] Stopped 2013-06-04T00:49:45.834Z,1370306985.834 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:49:46.780Z,1370306986.780 [MissionManager](IMPORTANT): Started mission Default 2013-06-04T00:49:46.780Z,1370306986.780 [Default] Running Loop=1 2013-06-04T00:49:46.780Z,1370306986.780 [Default](INFO): Aggregate::initialize Default 2013-06-04T00:49:46.780Z,1370306986.780 [Default:D.SetSpeed] Running Loop=1 2013-06-04T00:49:46.780Z,1370306986.780 [Default:D.SetSpeed](DEBUG): Initialize. 2013-06-04T00:49:46.780Z,1370306986.780 [Default:E.GoToSurface] Running Loop=1 2013-06-04T00:49:46.781Z,1370306986.781 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium] Running Loop=1 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-06-04T00:49:46.781Z,1370306986.781 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:49:46.782Z,1370306986.782 [Default:E.GoToSurface] Running Loop=1 2013-06-04T00:49:46.787Z,1370306986.787 [Default:D.SetSpeed] Running Loop=1 2013-06-04T00:49:46.798Z,1370306986.798 [Default:Iridium:B.GoToSurface] Stopped 2013-06-04T00:49:46.798Z,1370306986.798 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:49:46.799Z,1370306986.799 [Default:Iridium:Read_Iridium] Running Loop=1 2013-06-04T00:49:46.799Z,1370306986.799 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-06-04T00:49:46.804Z,1370306986.804 [Default:GPS] Running Loop=1 2013-06-04T00:49:46.804Z,1370306986.804 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-06-04T00:49:46.804Z,1370306986.804 [Default:GPS:A.SetSpeed] Running Loop=1 2013-06-04T00:49:46.804Z,1370306986.804 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:49:46.805Z,1370306986.805 [Default:GPS:B.GoToSurface] Running Loop=1 2013-06-04T00:49:46.805Z,1370306986.805 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:49:46.810Z,1370306986.810 [Default:GPS:B.GoToSurface] Stopped 2013-06-04T00:49:46.810Z,1370306986.810 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:49:46.810Z,1370306986.810 [Default:GPS:Read_GPS] Running Loop=1 2013-06-04T00:49:46.811Z,1370306986.810 [Default:GPS:A.SetSpeed] Running Loop=1 2013-06-04T00:49:47.068Z,1370306987.068 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:47.085Z,1370306987.085 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-06-04T00:49:47.088Z,1370306987.088 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-06-04T00:49:51.012Z,1370306991.012 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:53.463Z,1370306993.464 [CommandLine](IMPORTANT): got command run ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:49:53.464Z,1370306993.464 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:49:53.526Z,1370306993.526 [MissionManager](INFO): DefineArg homing_pursuit.Speed = 1.000000 m/s 2013-06-04T00:49:53.529Z,1370306993.529 [MissionManager](INFO): DefineArg homing_pursuit.MassDefault = -0.006000 n/a 2013-06-04T00:49:53.533Z,1370306993.533 [MissionManager](INFO): DefineArg homing_pursuit.BuoyancyNeutral = 0.000560 n/a 2013-06-04T00:49:53.536Z,1370306993.536 [MissionManager](INFO): DefineArg homing_pursuit.MinRange = 0.200000 m 2013-06-04T00:49:53.539Z,1370306993.539 [MissionManager](INFO): DefineArg homing_pursuit.OnewayRange = 40.000000 m 2013-06-04T00:49:53.543Z,1370306993.543 [MissionManager](INFO): DefineArg homing_pursuit.TimeoutDuration = 40.000000 min 2013-06-04T00:49:53.546Z,1370306993.546 [MissionManager](INFO): DefineArg homing_pursuit.PowerOnDATTimeoutDuration = 1.000000 min 2013-06-04T00:49:53.549Z,1370306993.549 [MissionManager](INFO): DefineArg homing_pursuit.ClosePursuitTimeout = 180.000000 s 2013-06-04T00:49:53.589Z,1370306993.589 [MissionManager](INFO): DefineArg homing_pursuit.RolloutTimeout = 7.000000 min 2013-06-04T00:49:53.592Z,1370306993.592 [MissionManager](INFO): DefineArg homing_pursuit.HomingDepth = 7.000000 m 2013-06-04T00:49:53.600Z,1370306993.600 [MissionManager](INFO): DefineArg homing_pursuit.MaxDepth = 45.000000 m 2013-06-04T00:49:53.608Z,1370306993.608 [MissionManager](INFO): DefineArg homing_pursuit.EnabledNeilBrown = 1.000000 n/a 2013-06-04T00:49:53.610Z,1370306993.610 [homing_pursuit:A.Pitch](DEBUG): Construct. 2013-06-04T00:49:53.620Z,1370306993.620 [homing_pursuit:B.Buoyancy](DEBUG): Construct Buoyancy. 2013-06-04T00:49:53.628Z,1370306993.628 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:49:53.632Z,1370306993.632 [homing_pursuit:PowerOnDAT:B.Pitch](DEBUG): Construct. 2013-06-04T00:49:53.639Z,1370306993.639 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Construct Wait. 2013-06-04T00:49:53.642Z,1370306993.642 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:49:53.645Z,1370306993.645 [homing_pursuit:InitialPursuit:B.Pitch](DEBUG): Construct. 2013-06-04T00:49:53.651Z,1370306993.651 [homing_pursuit:InitialPursuit:C.Point](DEBUG): Construct. 2013-06-04T00:49:53.659Z,1370306993.659 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Construct Wait. 2013-06-04T00:49:53.683Z,1370306993.683 [homing_pursuit:ClosePursuit:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:49:53.690Z,1370306993.690 [homing_pursuit:ClosePursuit:B.Pitch](DEBUG): Construct. 2013-06-04T00:49:53.700Z,1370306993.700 [homing_pursuit:ClosePursuit:C.Point](DEBUG): Construct. 2013-06-04T00:49:53.716Z,1370306993.716 [homing_pursuit:ClosePursuit:D.Wait](DEBUG): Construct Wait. 2013-06-04T00:49:53.719Z,1370306993.719 [homing_pursuit:Rollout:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:49:53.723Z,1370306993.723 [homing_pursuit:Rollout:B.Pitch](DEBUG): Construct. 2013-06-04T00:49:53.728Z,1370306993.728 [homing_pursuit:Rollout:C.Wait](DEBUG): Construct Wait. 2013-06-04T00:49:53.758Z,1370306993.758 [MissionManager](DEBUG): 1 Minimum range to continue to update heading being driven. 0.2 Minimum range to continue to update heading being driven. Max is 120 meters due to maximum sample output from modem in oneway mode. 40.0 Maximum length of mission 40 Wait this long after turning on DAT before starting any behaviors that require DAT output. 1 Run in OneWayMode for this long. 180 Drive on your last heading for this long after approaching within minimum range. 7 Depth for initial approach. 7 Maximum depth for the entire mission. 45 Set either this or PeakDetectChlActive to True in order to sample from the Neil Brown CTD. Give the DAT some time to start up before you ask for ranges from it. 30 Move toward the target using normal two-way queries. (These will also provide the heading of the compass attached to the acoustic modem.) Update the commanded heading with *Universal:homing_target_azimuth* each cycle. Continue until you approach within *OnewayRange*, then move on to the next aggregate. Move toward the target using fast one-way queries. (These will *NOT* provide the heading of the compass attached to the acoustic modem.) Update the commanded heading with *Universal:homing_target_azimuth* each cycle. Continue until you approach within *MinRange*, then move on to the next aggregate. Move away from the target at the last commanded heading until *RolloutTimeout* has passed. (DAT should still be reporting. Target acoustic modem may still be in Oneway mode.) 2013-06-04T00:49:53.759Z,1370306993.759 [CommandLine](IMPORTANT): Running ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:49:53.784Z,1370306993.784 [Default] Stopped 2013-06-04T00:49:53.784Z,1370306993.784 [Default](INFO): Aggregate::uninitialize Default 2013-06-04T00:49:53.784Z,1370306993.784 [Default:GPS] Stopped 2013-06-04T00:49:53.784Z,1370306993.784 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-06-04T00:49:53.784Z,1370306993.784 [Default:GPS:A.SetSpeed] Stopped 2013-06-04T00:49:53.784Z,1370306993.784 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:49:53.785Z,1370306993.784 [Default:GPS:Read_GPS] Stopped 2013-06-04T00:49:53.785Z,1370306993.784 [Default:Iridium] Stopped 2013-06-04T00:49:53.785Z,1370306993.785 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-06-04T00:49:53.785Z,1370306993.785 [Default:Iridium:A.SetSpeed] Stopped 2013-06-04T00:49:53.785Z,1370306993.785 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:49:53.785Z,1370306993.785 [Default:Iridium:Read_Iridium] Stopped 2013-06-04T00:49:53.785Z,1370306993.785 [Default:D.SetSpeed] Stopped 2013-06-04T00:49:53.785Z,1370306993.785 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:49:53.785Z,1370306993.785 [Default:E.GoToSurface] Stopped 2013-06-04T00:49:53.785Z,1370306993.785 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:49:53.785Z,1370306993.785 [MissionManager](IMPORTANT): Started mission homing_pursuit 2013-06-04T00:49:53.786Z,1370306993.786 [homing_pursuit] Running Loop=1 2013-06-04T00:49:53.786Z,1370306993.786 [homing_pursuit](INFO): Aggregate::initialize homing_pursuit 2013-06-04T00:49:53.790Z,1370306993.790 [homing_pursuit:A.Pitch] Running Loop=1 2013-06-04T00:49:53.790Z,1370306993.790 [homing_pursuit:A.Pitch](DEBUG): Initialize. 2013-06-04T00:49:53.790Z,1370306993.790 [homing_pursuit:B.Buoyancy] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:C] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:D] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:E] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:PowerOnDAT] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:PowerOnDAT](INFO): Aggregate::initialize homing_pursuit:PowerOnDAT 2013-06-04T00:49:53.791Z,1370306993.791 [homing_pursuit:PowerOnDAT:A.SetSpeed] Running Loop=1 2013-06-04T00:49:53.791Z,1370306993.792 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:49:53.792Z,1370306993.792 [homing_pursuit:PowerOnDAT:B.Pitch] Running Loop=1 2013-06-04T00:49:53.792Z,1370306993.792 [homing_pursuit:PowerOnDAT:B.Pitch](DEBUG): Initialize. 2013-06-04T00:49:53.792Z,1370306993.792 [homing_pursuit:PowerOnDAT:C.Wait] Running Loop=1 2013-06-04T00:49:53.792Z,1370306993.792 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:49:53.801Z,1370306993.801 [homing_pursuit:PowerOnDAT:B.Pitch] Running Loop=1 2013-06-04T00:49:53.816Z,1370306993.816 [homing_pursuit:PowerOnDAT:A.SetSpeed] Running Loop=1 2013-06-04T00:49:53.821Z,1370306993.821 [homing_pursuit:E] Running Loop=1 2013-06-04T00:49:53.821Z,1370306993.821 [homing_pursuit:E](DEBUG): Initialize ReadDataComponent to sense homing_target_range 2013-06-04T00:49:53.823Z,1370306993.823 [homing_pursuit:D] Running Loop=1 2013-06-04T00:49:53.824Z,1370306993.824 [homing_pursuit:D](DEBUG): Initialize ReadDataComponent to sense platform_orientation 2013-06-04T00:49:53.825Z,1370306993.825 [homing_pursuit:C] Running Loop=1 2013-06-04T00:49:53.826Z,1370306993.826 [homing_pursuit:C](DEBUG): Initialize ReadDataComponent to sense height_above_sea_floor 2013-06-04T00:49:53.828Z,1370306993.828 [homing_pursuit:B.Buoyancy] Running Loop=1 2013-06-04T00:49:53.833Z,1370306993.833 [homing_pursuit:A.Pitch] Running Loop=1 2013-06-04T00:49:54.119Z,1370306994.119 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:49:54.119Z,1370306994.119 [DVL_micro](INFO): resume:Powering up 2013-06-04T00:49:54.119Z,1370306994.119 [DVL_micro](INFO): Cycling power to configure device. 2013-06-04T00:49:54.146Z,1370306994.146 [DAT](INFO): Powering up 2013-06-04T00:49:55.304Z,1370306995.304 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:49:56.126Z,1370306996.126 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:49:56.127Z,1370306996.127 [DVL_micro](INFO): Querying output modes 2013-06-04T00:49:56.127Z,1370306996.127 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-06-04T00:49:56.138Z,1370306996.138 [DVL_micro](DEBUG): cmdResponse: 01 2013-06-04T00:49:56.138Z,1370306996.138 [DVL_micro](INFO): NQ1 output enabled 2013-06-04T00:49:56.139Z,1370306996.139 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-06-04T00:49:56.150Z,1370306996.150 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-06-04T00:49:58.539Z,1370306998.539 [CommandLine](IMPORTANT): got command show variable headingcmd 2013-06-04T00:49:58.623Z,1370306998.622 [CommandLine](INFO): HorizontalControl.headingCmd (radian) 2013-06-04T00:49:58.673Z,1370306998.673 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:00.980Z,1370307000.980 [NAL9602](INFO): Powering down 2013-06-04T00:50:01.214Z,1370307001.214 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:03.767Z,1370307003.767 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:05.043Z,1370307005.043 [CommandLine](IMPORTANT): got command report touch HorizontalControl.headingCmd 2013-06-04T00:50:06.326Z,1370307006.326 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:08.878Z,1370307008.878 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:11.426Z,1370307011.426 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:13.978Z,1370307013.978 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:16.530Z,1370307016.530 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:18.262Z,1370307018.262 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:50:18.283Z,1370307018.283 [Reporter](INFO): homing_target_azimuth 278.111588 arcdeg 2013-06-04T00:50:19.098Z,1370307019.098 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:21.658Z,1370307021.658 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:22.262Z,1370307022.261 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:50:22.282Z,1370307022.283 [Reporter](INFO): homing_target_azimuth 278.328296 arcdeg 2013-06-04T00:50:24.186Z,1370307024.186 [homing_pursuit:PowerOnDAT:C.Wait](INFO): Done Waiting. 2013-06-04T00:50:24.186Z,1370307024.186 [homing_pursuit:PowerOnDAT:C.Wait] Stopped 2013-06-04T00:50:24.186Z,1370307024.187 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT](INFO): Completed homing_pursuit:PowerOnDAT 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT] Stopped 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT](INFO): Aggregate::uninitialize homing_pursuit:PowerOnDAT 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT:A.SetSpeed] Stopped 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:PowerOnDAT:B.Pitch] Stopped 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:InitialPursuit] Running Loop=1 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:InitialPursuit](INFO): Aggregate::initialize homing_pursuit:InitialPursuit 2013-06-04T00:50:24.188Z,1370307024.188 [homing_pursuit:InitialPursuit:A.SetSpeed] Running Loop=1 2013-06-04T00:50:24.189Z,1370307024.188 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:50:24.189Z,1370307024.189 [homing_pursuit:InitialPursuit:B.Pitch] Running Loop=1 2013-06-04T00:50:24.189Z,1370307024.189 [homing_pursuit:InitialPursuit:B.Pitch](DEBUG): Initialize. 2013-06-04T00:50:24.189Z,1370307024.189 [homing_pursuit:InitialPursuit:C.Point] Running Loop=1 2013-06-04T00:50:24.189Z,1370307024.189 [homing_pursuit:InitialPursuit:C.Point](DEBUG): Initialize. 2013-06-04T00:50:24.189Z,1370307024.189 [homing_pursuit:InitialPursuit:D.Wait] Running Loop=1 2013-06-04T00:50:24.190Z,1370307024.190 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:50:24.214Z,1370307024.214 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit] Stopped 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit](INFO): Aggregate::uninitialize homing_pursuit:InitialPursuit 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:A.SetSpeed] Stopped 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:B.Pitch] Stopped 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:C.Point] Stopped 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:D.Wait] Stopped 2013-06-04T00:50:24.584Z,1370307024.584 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit] Running Loop=1 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit](INFO): Aggregate::initialize homing_pursuit:ClosePursuit 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:A.SetSpeed] Running Loop=1 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:B.Pitch] Running Loop=1 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:B.Pitch](DEBUG): Initialize. 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:C.Point] Running Loop=1 2013-06-04T00:50:24.585Z,1370307024.585 [homing_pursuit:ClosePursuit:C.Point](DEBUG): Initialize. 2013-06-04T00:50:24.586Z,1370307024.586 [homing_pursuit:ClosePursuit:D.Wait] Running Loop=1 2013-06-04T00:50:24.586Z,1370307024.586 [homing_pursuit:ClosePursuit:D.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:50:25.024Z,1370307025.024 [homing_pursuit:ClosePursuit:C.Point] Running Loop=1 2013-06-04T00:50:25.030Z,1370307025.030 [homing_pursuit:ClosePursuit:B.Pitch] Running Loop=1 2013-06-04T00:50:25.035Z,1370307025.035 [homing_pursuit:ClosePursuit:A.SetSpeed] Running Loop=1 2013-06-04T00:50:25.202Z,1370307025.202 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:25.517Z,1370307025.517 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:25.915Z,1370307025.915 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:26.557Z,1370307026.557 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:50:26.558Z,1370307026.558 [Reporter](INFO): homing_target_azimuth 276.978405 arcdeg 2013-06-04T00:50:26.559Z,1370307026.559 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:26.770Z,1370307026.770 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:26.906Z,1370307026.906 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:27.274Z,1370307027.274 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:27.674Z,1370307027.674 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:28.122Z,1370307028.122 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:28.514Z,1370307028.514 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:28.881Z,1370307028.881 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:29.286Z,1370307029.286 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:29.330Z,1370307029.330 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:29.714Z,1370307029.714 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:30.083Z,1370307030.083 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:30.586Z,1370307030.586 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:50:30.587Z,1370307030.587 [Reporter](INFO): homing_target_azimuth 276.029719 arcdeg 2013-06-04T00:50:30.587Z,1370307030.587 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:30.890Z,1370307030.890 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:31.318Z,1370307031.318 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:31.714Z,1370307031.714 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:31.906Z,1370307031.906 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:32.085Z,1370307032.085 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:32.461Z,1370307032.461 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:32.858Z,1370307032.858 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:33.329Z,1370307033.329 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:33.730Z,1370307033.730 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:34.186Z,1370307034.186 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:34.474Z,1370307034.474 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:34.479Z,1370307034.479 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:50:34.480Z,1370307034.480 [Reporter](INFO): homing_target_azimuth 275.635426 arcdeg 2013-06-04T00:50:34.480Z,1370307034.480 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:34.918Z,1370307034.918 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:35.258Z,1370307035.258 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:35.662Z,1370307035.662 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:36.058Z,1370307036.057 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:36.582Z,1370307036.582 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:36.893Z,1370307036.894 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:37.026Z,1370307037.026 [DVL_micro](DEBUG): NQ1 2013-06-04T00:50:37.330Z,1370307037.330 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:37.690Z,1370307037.690 [Reporter](INFO): HorizontalControl.headingCmd 4.857745 rad 2013-06-04T00:50:37.963Z,1370307037.963 [CommandLine](IMPORTANT): got command stop 2013-06-04T00:50:38.048Z,1370307038.048 [homing_pursuit] Stopped 2013-06-04T00:50:38.048Z,1370307038.048 [homing_pursuit](INFO): Aggregate::uninitialize homing_pursuit 2013-06-04T00:50:38.048Z,1370307038.048 [homing_pursuit:A.Pitch] Stopped 2013-06-04T00:50:38.048Z,1370307038.048 [homing_pursuit:B.Buoyancy] Stopped 2013-06-04T00:50:38.048Z,1370307038.048 [homing_pursuit:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:C] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:D] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:E] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit](INFO): Aggregate::uninitialize homing_pursuit:ClosePursuit 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:A.SetSpeed] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:B.Pitch] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:C.Point] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:D.Wait] Stopped 2013-06-04T00:50:38.049Z,1370307038.049 [homing_pursuit:ClosePursuit:D.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:50:38.301Z,1370307038.301 [Reporter](INFO): HorizontalControl.headingCmd no_value 2013-06-04T00:50:38.503Z,1370307038.503 [MissionManager](IMPORTANT): Started mission Default 2013-06-04T00:50:38.503Z,1370307038.503 [Default] Running Loop=1 2013-06-04T00:50:38.503Z,1370307038.503 [Default](INFO): Aggregate::initialize Default 2013-06-04T00:50:38.503Z,1370307038.503 [Default:D.SetSpeed] Running Loop=1 2013-06-04T00:50:38.503Z,1370307038.503 [Default:D.SetSpeed](DEBUG): Initialize. 2013-06-04T00:50:38.503Z,1370307038.503 [Default:E.GoToSurface] Running Loop=1 2013-06-04T00:50:38.503Z,1370307038.503 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:50:38.503Z,1370307038.503 [Default:Iridium] Running Loop=1 2013-06-04T00:50:38.504Z,1370307038.504 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-06-04T00:50:38.504Z,1370307038.504 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-06-04T00:50:38.504Z,1370307038.504 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:50:38.504Z,1370307038.504 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-06-04T00:50:38.504Z,1370307038.504 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:50:38.506Z,1370307038.506 [Default:Iridium:B.GoToSurface] Stopped 2013-06-04T00:50:38.506Z,1370307038.506 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:50:38.506Z,1370307038.506 [Default:Iridium:Read_Iridium] Running Loop=1 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS] Running Loop=1 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS:A.SetSpeed] Running Loop=1 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS:B.GoToSurface] Running Loop=1 2013-06-04T00:50:38.507Z,1370307038.507 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:50:38.508Z,1370307038.508 [Default:GPS:B.GoToSurface] Stopped 2013-06-04T00:50:38.508Z,1370307038.508 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:50:38.508Z,1370307038.508 [Default:GPS:Read_GPS] Running Loop=1 2013-06-04T00:50:38.902Z,1370307038.902 [DAT](INFO): Powering down 2013-06-04T00:50:39.136Z,1370307039.136 [DVL_micro](INFO): pause:Powering down 2013-06-04T00:50:39.399Z,1370307039.399 [NAL9602](INFO): Powering up 2013-06-04T00:50:49.842Z,1370307049.842 [NAL9602](INFO): NAL9602 initialized 2013-06-04T00:50:53.888Z,1370307053.888 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:50:58.232Z,1370307058.232 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:51:00.726Z,1370307060.726 [CommandLine](IMPORTANT): got command run ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:51:00.727Z,1370307060.727 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:51:00.818Z,1370307060.818 [MissionManager](INFO): DefineArg homing_pursuit.Speed = 1.000000 m/s 2013-06-04T00:51:00.821Z,1370307060.821 [MissionManager](INFO): DefineArg homing_pursuit.MassDefault = -0.006000 n/a 2013-06-04T00:51:00.823Z,1370307060.823 [MissionManager](INFO): DefineArg homing_pursuit.BuoyancyNeutral = 0.000560 n/a 2013-06-04T00:51:00.826Z,1370307060.826 [MissionManager](INFO): DefineArg homing_pursuit.MinRange = 0.200000 m 2013-06-04T00:51:00.828Z,1370307060.828 [MissionManager](INFO): DefineArg homing_pursuit.OnewayRange = 40.000000 m 2013-06-04T00:51:00.831Z,1370307060.830 [MissionManager](INFO): DefineArg homing_pursuit.TimeoutDuration = 40.000000 min 2013-06-04T00:51:00.833Z,1370307060.833 [MissionManager](INFO): DefineArg homing_pursuit.PowerOnDATTimeoutDuration = 1.000000 min 2013-06-04T00:51:00.854Z,1370307060.854 [MissionManager](INFO): DefineArg homing_pursuit.ClosePursuitTimeout = 180.000000 s 2013-06-04T00:51:00.856Z,1370307060.856 [MissionManager](INFO): DefineArg homing_pursuit.RolloutTimeout = 7.000000 min 2013-06-04T00:51:00.859Z,1370307060.859 [MissionManager](INFO): DefineArg homing_pursuit.HomingDepth = 7.000000 m 2013-06-04T00:51:00.861Z,1370307060.861 [MissionManager](INFO): DefineArg homing_pursuit.MaxDepth = 45.000000 m 2013-06-04T00:51:00.884Z,1370307060.884 [MissionManager](INFO): DefineArg homing_pursuit.EnabledNeilBrown = 1.000000 n/a 2013-06-04T00:51:00.890Z,1370307060.890 [homing_pursuit:A.Pitch](DEBUG): Construct. 2013-06-04T00:51:00.898Z,1370307060.898 [homing_pursuit:B.Buoyancy](DEBUG): Construct Buoyancy. 2013-06-04T00:51:00.909Z,1370307060.909 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:51:00.915Z,1370307060.915 [homing_pursuit:PowerOnDAT:B.Pitch](DEBUG): Construct. 2013-06-04T00:51:00.920Z,1370307060.920 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Construct Wait. 2013-06-04T00:51:00.923Z,1370307060.923 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:51:00.926Z,1370307060.926 [homing_pursuit:InitialPursuit:B.Pitch](DEBUG): Construct. 2013-06-04T00:51:00.930Z,1370307060.930 [homing_pursuit:InitialPursuit:C.Point](DEBUG): Construct. 2013-06-04T00:51:00.938Z,1370307060.938 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Construct Wait. 2013-06-04T00:51:00.945Z,1370307060.945 [homing_pursuit:ClosePursuit:B.SetSpeed](DEBUG): Construct. 2013-06-04T00:51:00.949Z,1370307060.949 [homing_pursuit:ClosePursuit:C.Pitch](DEBUG): Construct. 2013-06-04T00:51:00.954Z,1370307060.954 [homing_pursuit:ClosePursuit:D.Point](DEBUG): Construct. 2013-06-04T00:51:00.961Z,1370307060.961 [homing_pursuit:ClosePursuit:E.Wait](DEBUG): Construct Wait. 2013-06-04T00:51:00.984Z,1370307060.984 [homing_pursuit:Rollout:A.SetSpeed](DEBUG): Construct. 2013-06-04T00:51:00.990Z,1370307060.990 [homing_pursuit:Rollout:B.Pitch](DEBUG): Construct. 2013-06-04T00:51:00.999Z,1370307060.999 [homing_pursuit:Rollout:C.Wait](DEBUG): Construct Wait. 2013-06-04T00:51:01.032Z,1370307061.032 [MissionManager](DEBUG): 1 Minimum range to continue to update heading being driven. 0.2 Minimum range to continue to update heading being driven. Max is 120 meters due to maximum sample output from modem in oneway mode. 40.0 Maximum length of mission 40 Wait this long after turning on DAT before starting any behaviors that require DAT output. 1 Run in OneWayMode for this long. 180 Drive on your last heading for this long after approaching within minimum range. 7 Depth for initial approach. 7 Maximum depth for the entire mission. 45 Set either this or PeakDetectChlActive to True in order to sample from the Neil Brown CTD. Give the DAT some time to start up before you ask for ranges from it. 30 Move toward the target using normal two-way queries. (These will also provide the heading of the compass attached to the acoustic modem.) Update the commanded heading with *Universal:homing_target_azimuth* each cycle. Continue until you approach within *OnewayRange*, then move on to the next aggregate. Move toward the target using fast one-way queries. (These will *NOT* provide the heading of the compass attached to the acoustic modem.) Update the commanded heading with *Universal:homing_target_azimuth* each cycle. Continue until you approach within *MinRange*, then move on to the next aggregate. 1 Move away from the target at the last commanded heading until *RolloutTimeout* has passed. (DAT should still be reporting. Target acoustic modem may still be in Oneway mode.) 2013-06-04T00:51:01.032Z,1370307061.033 [CommandLine](IMPORTANT): Running ./Missions/Engineering/Homing_pursuit.xml 2013-06-04T00:51:01.046Z,1370307061.046 [Default] Stopped 2013-06-04T00:51:01.046Z,1370307061.046 [Default](INFO): Aggregate::uninitialize Default 2013-06-04T00:51:01.046Z,1370307061.046 [Default:GPS] Stopped 2013-06-04T00:51:01.046Z,1370307061.046 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-06-04T00:51:01.047Z,1370307061.046 [Default:GPS:A.SetSpeed] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:51:01.047Z,1370307061.047 [Default:GPS:Read_GPS] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:Iridium] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-06-04T00:51:01.047Z,1370307061.047 [Default:Iridium:A.SetSpeed] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:51:01.047Z,1370307061.047 [Default:Iridium:Read_Iridium] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:D.SetSpeed] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:51:01.047Z,1370307061.047 [Default:E.GoToSurface] Stopped 2013-06-04T00:51:01.047Z,1370307061.047 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:51:01.048Z,1370307061.048 [MissionManager](IMPORTANT): Started mission homing_pursuit 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit] Running Loop=1 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit](INFO): Aggregate::initialize homing_pursuit 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit:A.Pitch] Running Loop=1 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit:A.Pitch](DEBUG): Initialize. 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit:B.Buoyancy] Running Loop=1 2013-06-04T00:51:01.048Z,1370307061.048 [homing_pursuit:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:C] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:D] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:E] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT](INFO): Aggregate::initialize homing_pursuit:PowerOnDAT 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT:A.SetSpeed] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT:B.Pitch] Running Loop=1 2013-06-04T00:51:01.049Z,1370307061.049 [homing_pursuit:PowerOnDAT:B.Pitch](DEBUG): Initialize. 2013-06-04T00:51:01.050Z,1370307061.050 [homing_pursuit:PowerOnDAT:C.Wait] Running Loop=1 2013-06-04T00:51:01.050Z,1370307061.050 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:51:01.051Z,1370307061.051 [homing_pursuit:PowerOnDAT:B.Pitch] Running Loop=1 2013-06-04T00:51:01.052Z,1370307061.052 [homing_pursuit:PowerOnDAT:A.SetSpeed] Running Loop=1 2013-06-04T00:51:01.053Z,1370307061.053 [homing_pursuit:E] Running Loop=1 2013-06-04T00:51:01.054Z,1370307061.054 [homing_pursuit:E](DEBUG): Initialize ReadDataComponent to sense homing_target_range 2013-06-04T00:51:01.055Z,1370307061.055 [homing_pursuit:D] Running Loop=1 2013-06-04T00:51:01.056Z,1370307061.056 [homing_pursuit:D](DEBUG): Initialize ReadDataComponent to sense platform_orientation 2013-06-04T00:51:01.056Z,1370307061.056 [homing_pursuit:C] Running Loop=1 2013-06-04T00:51:01.057Z,1370307061.057 [homing_pursuit:C](DEBUG): Initialize ReadDataComponent to sense height_above_sea_floor 2013-06-04T00:51:01.058Z,1370307061.058 [homing_pursuit:B.Buoyancy] Running Loop=1 2013-06-04T00:51:01.059Z,1370307061.059 [homing_pursuit:A.Pitch] Running Loop=1 2013-06-04T00:51:01.371Z,1370307061.371 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:51:01.371Z,1370307061.371 [DVL_micro](INFO): resume:Powering up 2013-06-04T00:51:01.371Z,1370307061.371 [DVL_micro](INFO): Cycling power to configure device. 2013-06-04T00:51:01.431Z,1370307061.431 [DAT](INFO): Powering up 2013-06-04T00:51:03.378Z,1370307063.378 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-06-04T00:51:03.379Z,1370307063.379 [DVL_micro](INFO): Querying output modes 2013-06-04T00:51:03.379Z,1370307063.379 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-06-04T00:51:03.390Z,1370307063.390 [DVL_micro](DEBUG): cmdResponse: 01 2013-06-04T00:51:03.390Z,1370307063.390 [DVL_micro](INFO): NQ1 output enabled 2013-06-04T00:51:03.390Z,1370307063.390 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-06-04T00:51:03.402Z,1370307063.402 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-06-04T00:51:05.910Z,1370307065.910 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:07.080Z,1370307067.080 [NAL9602](INFO): Powering down 2013-06-04T00:51:08.468Z,1370307068.468 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:11.022Z,1370307071.022 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:13.578Z,1370307073.578 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:16.134Z,1370307076.134 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:18.686Z,1370307078.686 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:21.246Z,1370307081.246 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:23.814Z,1370307083.814 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:25.158Z,1370307085.158 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:51:25.159Z,1370307085.159 [Reporter](INFO): homing_target_azimuth 278.032986 arcdeg 2013-06-04T00:51:26.378Z,1370307086.378 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:28.922Z,1370307088.922 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:29.282Z,1370307089.282 [Reporter](INFO): homing_target_range 0.500000 m 2013-06-04T00:51:29.282Z,1370307089.282 [Reporter](INFO): homing_target_azimuth 279.397795 arcdeg 2013-06-04T00:51:31.128Z,1370307091.128 [homing_pursuit:PowerOnDAT:C.Wait](INFO): Done Waiting. 2013-06-04T00:51:31.129Z,1370307091.129 [homing_pursuit:PowerOnDAT:C.Wait] Stopped 2013-06-04T00:51:31.129Z,1370307091.129 [homing_pursuit:PowerOnDAT:C.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:51:31.134Z,1370307091.134 [homing_pursuit:PowerOnDAT](INFO): Completed homing_pursuit:PowerOnDAT 2013-06-04T00:51:31.134Z,1370307091.134 [homing_pursuit:PowerOnDAT] Stopped 2013-06-04T00:51:31.134Z,1370307091.134 [homing_pursuit:PowerOnDAT](INFO): Aggregate::uninitialize homing_pursuit:PowerOnDAT 2013-06-04T00:51:31.134Z,1370307091.134 [homing_pursuit:PowerOnDAT:A.SetSpeed] Stopped 2013-06-04T00:51:31.134Z,1370307091.135 [homing_pursuit:PowerOnDAT:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:PowerOnDAT:B.Pitch] Stopped 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit] Running Loop=1 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit](INFO): Aggregate::initialize homing_pursuit:InitialPursuit 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit:A.SetSpeed] Running Loop=1 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit:B.Pitch] Running Loop=1 2013-06-04T00:51:31.135Z,1370307091.135 [homing_pursuit:InitialPursuit:B.Pitch](DEBUG): Initialize. 2013-06-04T00:51:31.136Z,1370307091.136 [homing_pursuit:InitialPursuit:C.Point] Running Loop=1 2013-06-04T00:51:31.136Z,1370307091.136 [homing_pursuit:InitialPursuit:C.Point](DEBUG): Initialize. 2013-06-04T00:51:31.136Z,1370307091.136 [homing_pursuit:InitialPursuit:D.Wait] Running Loop=1 2013-06-04T00:51:31.136Z,1370307091.136 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:51:31.470Z,1370307091.470 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:31.547Z,1370307091.547 [homing_pursuit:InitialPursuit] Stopped 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit](INFO): Aggregate::uninitialize homing_pursuit:InitialPursuit 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:A.SetSpeed] Stopped 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:B.Pitch] Stopped 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:C.Point] Stopped 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:D.Wait] Stopped 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:InitialPursuit:D.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:51:31.548Z,1370307091.548 [homing_pursuit:ClosePursuit] Running Loop=1 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit](INFO): Aggregate::initialize homing_pursuit:ClosePursuit 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:A] Running Loop=1 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:B.SetSpeed] Running Loop=1 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:B.SetSpeed](DEBUG): Initialize. 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:C.Pitch] Running Loop=1 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:C.Pitch](DEBUG): Initialize. 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:D.Point] Running Loop=1 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:D.Point](DEBUG): Initialize. 2013-06-04T00:51:31.549Z,1370307091.549 [homing_pursuit:ClosePursuit:E.Wait] Running Loop=1 2013-06-04T00:51:31.550Z,1370307091.550 [homing_pursuit:ClosePursuit:E.Wait](DEBUG): Initialize Wait Component. 2013-06-04T00:51:31.941Z,1370307091.941 [homing_pursuit:ClosePursuit:D.Point] Running Loop=1 2013-06-04T00:51:31.955Z,1370307091.955 [homing_pursuit:ClosePursuit:C.Pitch] Running Loop=1 2013-06-04T00:51:31.984Z,1370307091.984 [homing_pursuit:ClosePursuit:B.SetSpeed] Running Loop=1 2013-06-04T00:51:31.997Z,1370307091.997 [homing_pursuit:ClosePursuit:A] Running Loop=1 2013-06-04T00:51:32.170Z,1370307092.170 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:32.621Z,1370307092.621 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:32.951Z,1370307092.951 [DAT](ERROR): Unexpected response:01:50:05.4458 , LVL= 31664, 11713, 14322, 24499, AGC= 56, IDX= 62-0.15,-1.057, PHS= 0.122, 0.392, 0.193, |v|= 0.201, RAW= 315.3,-45.8, CAL= 328.7,-45.0, ROT= 47.7,-45.0 Com 2013-06-04T00:51:33.056Z,1370307093.056 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:33.305Z,1370307093.305 [DAT](FAULT): Parse Failed - Received:pass 169.3 Range 1 to 0 : 0.5 m 2013-06-04T00:51:33.546Z,1370307093.546 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:33.937Z,1370307093.937 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:34.022Z,1370307094.022 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:34.397Z,1370307094.397 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:34.890Z,1370307094.890 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:35.302Z,1370307095.302 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:35.714Z,1370307095.714 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:36.098Z,1370307096.098 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:36.550Z,1370307096.550 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:36.570Z,1370307096.570 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:36.966Z,1370307096.966 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:37.354Z,1370307097.354 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:37.855Z,1370307097.855 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:38.330Z,1370307098.330 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:38.687Z,1370307098.687 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:39.058Z,1370307099.058 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:39.131Z,1370307099.131 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:39.666Z,1370307099.666 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:40.030Z,1370307100.030 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:40.558Z,1370307100.558 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:40.886Z,1370307100.886 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:41.258Z,1370307101.258 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:41.686Z,1370307101.686 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:41.694Z,1370307101.694 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:42.110Z,1370307102.110 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:42.498Z,1370307102.498 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:43.154Z,1370307103.154 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:43.482Z,1370307103.482 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:43.890Z,1370307103.890 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:44.234Z,1370307104.234 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:44.314Z,1370307104.314 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:44.774Z,1370307104.774 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:45.138Z,1370307105.138 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:45.598Z,1370307105.598 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:45.986Z,1370307105.986 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:46.350Z,1370307106.350 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:46.718Z,1370307106.718 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:46.818Z,1370307106.818 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:47.078Z,1370307107.078 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:47.478Z,1370307107.478 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:47.958Z,1370307107.958 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:48.278Z,1370307108.278 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:48.678Z,1370307108.678 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:49.078Z,1370307109.078 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:49.354Z,1370307109.354 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:49.546Z,1370307109.546 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:49.878Z,1370307109.878 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:50.313Z,1370307110.313 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:50.674Z,1370307110.674 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:51.168Z,1370307111.168 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:51.542Z,1370307111.542 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:51.937Z,1370307111.937 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:52.026Z,1370307112.026 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:52.306Z,1370307112.306 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:52.855Z,1370307112.855 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:53.178Z,1370307113.178 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:53.562Z,1370307113.562 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:53.578Z,1370307113.579 [Reporter](INFO): homing_target_azimuth 275.152040 arcdeg 2013-06-04T00:51:53.579Z,1370307113.579 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:53.974Z,1370307113.974 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:54.383Z,1370307114.383 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:51:54.383Z,1370307114.383 [Reporter](INFO): homing_target_azimuth 276.853795 arcdeg 2013-06-04T00:51:54.384Z,1370307114.384 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:54.482Z,1370307114.482 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:54.758Z,1370307114.759 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:54.759Z,1370307114.759 [Reporter](INFO): homing_target_azimuth 276.594166 arcdeg 2013-06-04T00:51:54.760Z,1370307114.760 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:55.162Z,1370307115.162 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:51:55.179Z,1370307115.179 [Reporter](INFO): homing_target_azimuth 277.292539 arcdeg 2013-06-04T00:51:55.179Z,1370307115.179 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:55.594Z,1370307115.594 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:55.595Z,1370307115.595 [Reporter](INFO): homing_target_azimuth 277.893814 arcdeg 2013-06-04T00:51:55.595Z,1370307115.595 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:56.038Z,1370307116.037 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:56.438Z,1370307116.438 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:51:56.439Z,1370307116.439 [Reporter](INFO): homing_target_azimuth 277.000098 arcdeg 2013-06-04T00:51:56.440Z,1370307116.440 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:56.831Z,1370307116.831 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:56.832Z,1370307116.832 [Reporter](INFO): homing_target_azimuth 276.301561 arcdeg 2013-06-04T00:51:56.833Z,1370307116.833 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:57.038Z,1370307117.038 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:57.367Z,1370307117.367 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:51:57.368Z,1370307117.368 [Reporter](INFO): homing_target_azimuth 275.256514 arcdeg 2013-06-04T00:51:57.368Z,1370307117.368 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:57.734Z,1370307117.734 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:57.734Z,1370307117.734 [Reporter](INFO): homing_target_azimuth 276.091764 arcdeg 2013-06-04T00:51:57.735Z,1370307117.735 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:58.274Z,1370307118.274 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:51:58.275Z,1370307118.275 [Reporter](INFO): homing_target_azimuth 276.340028 arcdeg 2013-06-04T00:51:58.276Z,1370307118.276 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:58.562Z,1370307118.562 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:58.579Z,1370307118.579 [Reporter](INFO): homing_target_azimuth 276.781969 arcdeg 2013-06-04T00:51:58.579Z,1370307118.579 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:59.046Z,1370307119.046 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:51:59.047Z,1370307119.047 [Reporter](INFO): homing_target_azimuth 273.597789 arcdeg 2013-06-04T00:51:59.047Z,1370307119.047 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:59.379Z,1370307119.379 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:51:59.590Z,1370307119.590 [DVL_micro](DEBUG): NQ1 2013-06-04T00:51:59.784Z,1370307119.784 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:51:59.784Z,1370307119.784 [Reporter](INFO): homing_target_azimuth 277.249700 arcdeg 2013-06-04T00:51:59.785Z,1370307119.785 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:00.178Z,1370307120.178 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:00.178Z,1370307120.178 [Reporter](INFO): homing_target_azimuth 276.239542 arcdeg 2013-06-04T00:52:00.179Z,1370307120.179 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:00.578Z,1370307120.578 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:00.578Z,1370307120.579 [Reporter](INFO): homing_target_azimuth 276.389779 arcdeg 2013-06-04T00:52:00.579Z,1370307120.579 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:00.958Z,1370307120.958 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:01.379Z,1370307121.379 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:01.380Z,1370307121.380 [Reporter](INFO): homing_target_azimuth 277.291665 arcdeg 2013-06-04T00:52:01.380Z,1370307121.381 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:01.779Z,1370307121.779 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:01.780Z,1370307121.780 [Reporter](INFO): homing_target_azimuth 277.059548 arcdeg 2013-06-04T00:52:01.780Z,1370307121.780 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:02.134Z,1370307122.134 [DVL_micro](DEBUG): NQ1 2013-06-04T00:52:02.222Z,1370307122.223 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:02.223Z,1370307122.223 [Reporter](INFO): homing_target_azimuth 277.759096 arcdeg 2013-06-04T00:52:02.224Z,1370307122.224 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:02.582Z,1370307122.582 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:02.583Z,1370307122.583 [Reporter](INFO): homing_target_azimuth 275.614963 arcdeg 2013-06-04T00:52:02.583Z,1370307122.583 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:03.114Z,1370307123.114 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:03.115Z,1370307123.115 [Reporter](INFO): homing_target_azimuth 276.364207 arcdeg 2013-06-04T00:52:03.116Z,1370307123.115 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:03.433Z,1370307123.434 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:03.887Z,1370307123.887 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:03.888Z,1370307123.888 [Reporter](INFO): homing_target_azimuth 275.096169 arcdeg 2013-06-04T00:52:03.888Z,1370307123.888 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:04.331Z,1370307124.330 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:52:04.331Z,1370307124.331 [Reporter](INFO): homing_target_azimuth 273.974215 arcdeg 2013-06-04T00:52:04.332Z,1370307124.332 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:04.641Z,1370307124.641 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:04.642Z,1370307124.642 [Reporter](INFO): homing_target_azimuth 275.722115 arcdeg 2013-06-04T00:52:04.643Z,1370307124.643 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:04.706Z,1370307124.706 [DVL_micro](DEBUG): NQ1 2013-06-04T00:52:05.042Z,1370307125.042 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:52:05.042Z,1370307125.042 [Reporter](INFO): homing_target_azimuth 276.390435 arcdeg 2013-06-04T00:52:05.043Z,1370307125.043 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:05.474Z,1370307125.474 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:05.843Z,1370307125.843 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:05.844Z,1370307125.844 [Reporter](INFO): homing_target_azimuth 275.148707 arcdeg 2013-06-04T00:52:05.845Z,1370307125.845 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:06.222Z,1370307126.222 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:52:06.223Z,1370307126.223 [Reporter](INFO): homing_target_azimuth 277.259399 arcdeg 2013-06-04T00:52:06.224Z,1370307126.224 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:06.618Z,1370307126.618 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:06.618Z,1370307126.618 [Reporter](INFO): homing_target_azimuth 277.307429 arcdeg 2013-06-04T00:52:06.619Z,1370307126.619 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:07.046Z,1370307127.046 [Reporter](INFO): homing_target_range 0.700000 m 2013-06-04T00:52:07.046Z,1370307127.046 [Reporter](INFO): homing_target_azimuth 278.057875 arcdeg 2013-06-04T00:52:07.047Z,1370307127.047 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:07.282Z,1370307127.282 [DVL_micro](DEBUG): NQ1 2013-06-04T00:52:07.419Z,1370307127.418 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:07.851Z,1370307127.851 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:07.852Z,1370307127.852 [Reporter](INFO): homing_target_azimuth 277.617875 arcdeg 2013-06-04T00:52:07.852Z,1370307127.852 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:08.304Z,1370307128.304 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:08.305Z,1370307128.305 [Reporter](INFO): homing_target_azimuth 277.331854 arcdeg 2013-06-04T00:52:08.305Z,1370307128.305 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:08.743Z,1370307128.743 [Reporter](INFO): homing_target_range 0.400000 m 2013-06-04T00:52:08.744Z,1370307128.744 [Reporter](INFO): homing_target_azimuth 273.310593 arcdeg 2013-06-04T00:52:08.745Z,1370307128.745 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:09.083Z,1370307129.083 [CommandLine](IMPORTANT): got command stop 2013-06-04T00:52:09.102Z,1370307129.102 [Reporter](INFO): homing_target_range 0.600000 m 2013-06-04T00:52:09.102Z,1370307129.102 [Reporter](INFO): homing_target_azimuth 277.861221 arcdeg 2013-06-04T00:52:09.103Z,1370307129.103 [Reporter](INFO): HorizontalControl.headingCmd 4.876411 rad 2013-06-04T00:52:09.384Z,1370307129.384 [homing_pursuit] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit](INFO): Aggregate::uninitialize homing_pursuit 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:A.Pitch] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:B.Buoyancy] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:C] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:D] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:E] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:ClosePursuit] Stopped 2013-06-04T00:52:09.385Z,1370307129.385 [homing_pursuit:ClosePursuit](INFO): Aggregate::uninitialize homing_pursuit:ClosePursuit 2013-06-04T00:52:09.386Z,1370307129.386 [homing_pursuit:ClosePursuit:A] Stopped 2013-06-04T00:52:09.386Z,1370307129.386 [homing_pursuit:ClosePursuit:B.SetSpeed] Stopped 2013-06-04T00:52:09.388Z,1370307129.388 [DVL_micro](INFO): pause:Powering down 2013-06-04T00:52:09.386Z,1370307129.386 [homing_pursuit:ClosePursuit:B.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:52:09.397Z,1370307129.397 [homing_pursuit:ClosePursuit:C.Pitch] Stopped 2013-06-04T00:52:09.397Z,1370307129.397 [homing_pursuit:ClosePursuit:D.Point] Stopped 2013-06-04T00:52:09.397Z,1370307129.397 [homing_pursuit:ClosePursuit:E.Wait] Stopped 2013-06-04T00:52:09.397Z,1370307129.397 [homing_pursuit:ClosePursuit:E.Wait](DEBUG): Uninitialize Wait Component. 2013-06-04T00:52:09.641Z,1370307129.641 [Reporter](INFO): HorizontalControl.headingCmd no_value 2013-06-04T00:52:09.843Z,1370307129.843 [MissionManager](IMPORTANT): Started mission Default 2013-06-04T00:52:09.843Z,1370307129.843 [Default] Running Loop=1 2013-06-04T00:52:09.844Z,1370307129.843 [Default](INFO): Aggregate::initialize Default 2013-06-04T00:52:09.844Z,1370307129.844 [Default:D.SetSpeed] Running Loop=1 2013-06-04T00:52:09.844Z,1370307129.844 [Default:D.SetSpeed](DEBUG): Initialize. 2013-06-04T00:52:09.844Z,1370307129.844 [Default:E.GoToSurface] Running Loop=1 2013-06-04T00:52:09.844Z,1370307129.844 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:52:09.844Z,1370307129.844 [Default:Iridium] Running Loop=1 2013-06-04T00:52:09.844Z,1370307129.844 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-06-04T00:52:09.845Z,1370307129.845 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-06-04T00:52:09.845Z,1370307129.845 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:52:09.845Z,1370307129.845 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-06-04T00:52:09.845Z,1370307129.845 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:52:09.848Z,1370307129.848 [Default:Iridium:B.GoToSurface] Stopped 2013-06-04T00:52:09.848Z,1370307129.848 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:52:09.848Z,1370307129.848 [Default:Iridium:Read_Iridium] Running Loop=1 2013-06-04T00:52:09.848Z,1370307129.848 [Default:GPS] Running Loop=1 2013-06-04T00:52:09.849Z,1370307129.849 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-06-04T00:52:09.849Z,1370307129.849 [Default:GPS:A.SetSpeed] Running Loop=1 2013-06-04T00:52:09.849Z,1370307129.849 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-06-04T00:52:09.849Z,1370307129.849 [Default:GPS:B.GoToSurface] Running Loop=1 2013-06-04T00:52:09.849Z,1370307129.849 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-06-04T00:52:09.850Z,1370307129.851 [Default:GPS:B.GoToSurface] Stopped 2013-06-04T00:52:09.851Z,1370307129.851 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:52:09.851Z,1370307129.851 [Default:GPS:Read_GPS] Running Loop=1 2013-06-04T00:52:10.247Z,1370307130.247 [DAT](INFO): Powering down 2013-06-04T00:52:10.735Z,1370307130.735 [NAL9602](INFO): Powering up 2013-06-04T00:52:21.186Z,1370307141.187 [NAL9602](INFO): NAL9602 initialized 2013-06-04T00:52:25.191Z,1370307145.191 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:29.620Z,1370307149.620 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:34.461Z,1370307154.461 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:38.828Z,1370307158.828 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:43.124Z,1370307163.124 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:47.520Z,1370307167.520 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:52.227Z,1370307172.227 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:52:56.580Z,1370307176.580 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:53:01.299Z,1370307181.299 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:53:03.974Z,1370307183.974 [CommandLine](IMPORTANT): got command quit 2013-06-04T00:53:05.018Z,1370307185.018 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-06-04T00:53:05.018Z,1370307185.018 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-06-04T00:53:05.402Z,1370307185.402 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2013-06-04T00:53:05.632Z,1370307185.632 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-06-04T00:53:05.674Z,1370307185.674 [WetLabsBB2FL](INFO): Powering down 2013-06-04T00:53:05.690Z,1370307185.690 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2013-06-04T00:53:05.818Z,1370307185.819 [CTD_NeilBrown](INFO): Powering down 2013-06-04T00:53:05.850Z,1370307185.850 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-06-04T00:53:06.006Z,1370307186.006 [DVL_micro](INFO): uninitialize:Powering down 2013-06-04T00:53:06.010Z,1370307186.010 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-06-04T00:53:06.266Z,1370307186.266 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-06-04T00:53:06.271Z,1370307186.271 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-06-04T00:53:06.367Z,1370307186.367 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-06-04T00:53:06.380Z,1370307186.380 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-06-04T00:53:06.489Z,1370307186.489 [controlThread](DEBUG): Uninitializing ControlThread 2013-06-04T00:53:06.490Z,1370307186.490 [AHRS_sp3003D](INFO): Powering down 2013-06-04T00:53:06.579Z,1370307186.579 [NAL9602](INFO): Powering down 2013-06-04T00:53:06.581Z,1370307186.581 [DAT](INFO): Powering down 2013-06-04T00:53:06.582Z,1370307186.582 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-06-04T00:53:06.583Z,1370307186.583 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-06-04T00:53:06.584Z,1370307186.584 [Default] Stopped 2013-06-04T00:53:06.584Z,1370307186.584 [Default](INFO): Aggregate::uninitialize Default 2013-06-04T00:53:06.584Z,1370307186.584 [Default:GPS] Stopped 2013-06-04T00:53:06.584Z,1370307186.584 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-06-04T00:53:06.584Z,1370307186.584 [Default:GPS:A.SetSpeed] Stopped 2013-06-04T00:53:06.584Z,1370307186.584 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:53:06.584Z,1370307186.584 [Default:GPS:Read_GPS] Stopped 2013-06-04T00:53:06.584Z,1370307186.584 [Default:Iridium] Stopped 2013-06-04T00:53:06.585Z,1370307186.585 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-06-04T00:53:06.585Z,1370307186.585 [Default:Iridium:A.SetSpeed] Stopped 2013-06-04T00:53:06.585Z,1370307186.585 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:53:06.585Z,1370307186.585 [Default:Iridium:Read_Iridium] Stopped 2013-06-04T00:53:06.585Z,1370307186.585 [Default:D.SetSpeed] Stopped 2013-06-04T00:53:06.585Z,1370307186.585 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-06-04T00:53:06.585Z,1370307186.585 [Default:E.GoToSurface] Stopped 2013-06-04T00:53:06.585Z,1370307186.585 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-06-04T00:53:06.589Z,1370307186.589 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-06-04T00:53:06.589Z,1370307186.589 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-06-04T00:53:06.590Z,1370307186.589 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-06-04T00:53:06.590Z,1370307186.590 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-06-04T00:53:06.590Z,1370307186.590 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-06-04T00:53:06.591Z,1370307186.591 [BuoyancyServo](INFO): Powering down 2013-06-04T00:53:06.602Z,1370307186.602 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-06-04T00:53:06.602Z,1370307186.602 [ElevatorServo](INFO): Powering down 2013-06-04T00:53:06.603Z,1370307186.603 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-06-04T00:53:06.603Z,1370307186.603 [MassServo](INFO): Powering down 2013-06-04T00:53:06.604Z,1370307186.604 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-06-04T00:53:06.604Z,1370307186.604 [RudderServo](INFO): Powering down 2013-06-04T00:53:06.605Z,1370307186.605 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-06-04T00:53:06.605Z,1370307186.605 [ThrusterServo](INFO): Powering down 2013-06-04T00:53:06.606Z,1370307186.606 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-06-04T00:53:06.607Z,1370307186.606 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-06-04T00:53:06.607Z,1370307186.607 [CBIT](DEBUG): Uninitialize CBIT Component.