2013-05-16T23:08:00.015Z,1368745680.015 [Supervisor](DEBUG): Initializing supervisor.
2013-05-16T23:08:00.018Z,1368745680.018 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-16T23:08:00.019Z,1368745680.019 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-16T23:08:00.020Z,1368745680.020 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-16T23:08:00.025Z,1368745680.025 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-16T23:08:00.036Z,1368745680.036 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-16T23:08:00.037Z,1368745680.037 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-16T23:08:00.038Z,1368745680.038 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-16T23:08:00.039Z,1368745680.039 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-16T23:08:00.040Z,1368745680.040 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-16T23:08:00.041Z,1368745680.041 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-16T23:08:00.379Z,1368745680.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-16T23:08:00.380Z,1368745680.379 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-16T23:08:00.571Z,1368745680.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-16T23:08:00.571Z,1368745680.571 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-16T23:08:00.655Z,1368745680.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-16T23:08:00.656Z,1368745680.656 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-16T23:08:00.859Z,1368745680.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-16T23:08:00.860Z,1368745680.860 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-16T23:08:00.998Z,1368745680.998 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-16T23:08:00.998Z,1368745680.998 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-16T23:08:01.236Z,1368745681.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-16T23:08:01.237Z,1368745681.237 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-16T23:08:01.409Z,1368745681.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-16T23:08:01.409Z,1368745681.409 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-16T23:08:01.667Z,1368745681.667 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-16T23:08:01.667Z,1368745681.667 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-16T23:08:01.766Z,1368745681.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-16T23:08:01.766Z,1368745681.766 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-16T23:08:02.176Z,1368745682.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-16T23:08:02.177Z,1368745682.177 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-16T23:08:02.291Z,1368745682.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-16T23:08:02.292Z,1368745682.292 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-16T23:08:02.377Z,1368745682.377 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-16T23:08:02.378Z,1368745682.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-16T23:08:02.483Z,1368745682.483 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-16T23:08:02.613Z,1368745682.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-16T23:08:02.698Z,1368745682.698 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-16T23:08:02.806Z,1368745682.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-16T23:08:02.908Z,1368745682.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-16T23:08:03.031Z,1368745683.030 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-16T23:08:03.127Z,1368745683.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-16T23:08:03.215Z,1368745683.215 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-05-16T23:08:03.215Z,1368745683.216 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-05-16T23:08:03.241Z,1368745683.241 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-16T23:08:03.401Z,1368745683.401 [InternalSim] Loaded
2013-05-16T23:08:03.401Z,1368745683.401 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-16T23:08:03.402Z,1368745683.402 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-16T23:08:03.403Z,1368745683.403 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-16T23:08:03.464Z,1368745683.464 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-16T23:08:03.494Z,1368745683.494 [SBIT] Loaded
2013-05-16T23:08:03.494Z,1368745683.494 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-16T23:08:03.495Z,1368745683.495 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-16T23:08:03.525Z,1368745683.525 [IBIT] Loaded
2013-05-16T23:08:03.525Z,1368745683.525 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-16T23:08:03.529Z,1368745683.529 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-16T23:08:03.651Z,1368745683.651 [CBIT] Loaded
2013-05-16T23:08:03.651Z,1368745683.651 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-16T23:08:03.652Z,1368745683.652 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-16T23:08:03.653Z,1368745683.653 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-16T23:08:03.807Z,1368745683.807 [BuoyancyServo] Loaded
2013-05-16T23:08:03.807Z,1368745683.807 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-16T23:08:03.820Z,1368745683.820 [ElevatorServo] Loaded
2013-05-16T23:08:03.821Z,1368745683.820 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-16T23:08:03.833Z,1368745683.833 [MassServo] Loaded
2013-05-16T23:08:03.833Z,1368745683.833 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-16T23:08:03.845Z,1368745683.845 [RudderServo] Loaded
2013-05-16T23:08:03.846Z,1368745683.846 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-16T23:08:03.858Z,1368745683.858 [ThrusterServo] Loaded
2013-05-16T23:08:03.858Z,1368745683.858 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-16T23:08:03.858Z,1368745683.858 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-16T23:08:03.859Z,1368745683.859 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-16T23:08:03.878Z,1368745683.878 [DepthRateCalculator] Loaded
2013-05-16T23:08:03.878Z,1368745683.878 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-16T23:08:06.928Z,1368745686.928 [HFRadarModelCalc] Loaded
2013-05-16T23:08:06.928Z,1368745686.928 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-16T23:08:06.945Z,1368745686.945 [NavChart] Loaded
2013-05-16T23:08:06.946Z,1368745686.945 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-16T23:08:06.951Z,1368745686.951 [PitchRateCalculator] Loaded
2013-05-16T23:08:06.952Z,1368745686.952 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-16T23:08:06.963Z,1368745686.963 [SpeedCalculator] Loaded
2013-05-16T23:08:06.963Z,1368745686.963 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-16T23:08:06.979Z,1368745686.979 [TempGradientCalculator] Loaded
2013-05-16T23:08:06.979Z,1368745686.980 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-16T23:08:06.985Z,1368745686.986 [YawRateCalculator] Loaded
2013-05-16T23:08:06.986Z,1368745686.986 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-16T23:08:07.033Z,1368745687.033 [Navigation] Loaded
2013-05-16T23:08:07.034Z,1368745687.034 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-16T23:08:07.034Z,1368745687.034 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-16T23:08:07.035Z,1368745687.035 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-16T23:08:07.260Z,1368745687.260 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-16T23:08:07.261Z,1368745687.260 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-16T23:08:07.284Z,1368745687.284 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-16T23:08:07.284Z,1368745687.284 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-16T23:08:07.328Z,1368745687.328 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-16T23:08:07.425Z,1368745687.425 [VerticalControl] Loaded
2013-05-16T23:08:07.425Z,1368745687.425 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-16T23:08:07.426Z,1368745687.426 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-16T23:08:07.485Z,1368745687.485 [HorizontalControl] Loaded
2013-05-16T23:08:07.485Z,1368745687.485 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-16T23:08:07.486Z,1368745687.486 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-16T23:08:07.488Z,1368745687.488 [SpeedControl] Loaded
2013-05-16T23:08:07.488Z,1368745687.488 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-16T23:08:07.489Z,1368745687.489 [LoopControl](DEBUG): Construct LoopControl.
2013-05-16T23:08:07.489Z,1368745687.489 [LoopControl] Loaded
2013-05-16T23:08:07.490Z,1368745687.490 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-16T23:08:07.490Z,1368745687.490 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-16T23:08:07.491Z,1368745687.491 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-16T23:08:07.496Z,1368745687.496 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-16T23:08:07.502Z,1368745687.502 [AsyncPiEstimator] Loaded
2013-05-16T23:08:07.502Z,1368745687.502 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-16T23:08:07.503Z,1368745687.503 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-16T23:08:07.504Z,1368745687.504 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-16T23:08:07.505Z,1368745687.505 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-16T23:08:07.638Z,1368745687.638 [AHRS_sp3003D] Loaded
2013-05-16T23:08:07.638Z,1368745687.638 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-16T23:08:07.904Z,1368745687.904 [Batt_Ocean_Server] Loaded
2013-05-16T23:08:07.905Z,1368745687.905 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-16T23:08:07.919Z,1368745687.919 [Depth_Keller] Loaded
2013-05-16T23:08:07.919Z,1368745687.919 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-16T23:08:07.925Z,1368745687.925 [DropWeight] Loaded
2013-05-16T23:08:07.925Z,1368745687.925 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-05-16T23:08:08.103Z,1368745688.103 [DVL_micro] Loaded
2013-05-16T23:08:08.104Z,1368745688.103 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-16T23:08:08.105Z,1368745688.105 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406BD4E0
2013-05-16T23:08:08.190Z,1368745688.190 [NAL9602] Loaded
2013-05-16T23:08:08.190Z,1368745688.190 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-16T23:08:08.243Z,1368745688.243 [Onboard] Loaded
2013-05-16T23:08:08.243Z,1368745688.243 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-16T23:08:08.250Z,1368745688.250 [Radio_Freewave] Loaded
2013-05-16T23:08:08.250Z,1368745688.250 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-16T23:08:08.374Z,1368745688.374 [DAT] Loaded
2013-05-16T23:08:08.374Z,1368745688.374 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-05-16T23:08:08.375Z,1368745688.375 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-16T23:08:08.375Z,1368745688.375 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-16T23:08:08.451Z,1368745688.451 [CTD_NeilBrown] Loaded
2013-05-16T23:08:08.451Z,1368745688.451 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-16T23:08:08.452Z,1368745688.453 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4070F4E0
2013-05-16T23:08:08.484Z,1368745688.484 [WetLabsBB2FL] Loaded
2013-05-16T23:08:08.485Z,1368745688.485 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-16T23:08:08.486Z,1368745688.486 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4073F4E0
2013-05-16T23:08:08.487Z,1368745688.487 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-16T23:08:08.489Z,1368745688.489 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-16T23:08:08.490Z,1368745688.490 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-16T23:08:08.497Z,1368745688.497 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-16T23:08:08.498Z,1368745688.498 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4076F4E0
2013-05-16T23:08:08.503Z,1368745688.503 [Supervisor](DEBUG): Running supervisor.
2013-05-16T23:08:08.504Z,1368745688.504 [CommandLine](INFO): Thread ID is 1416
2013-05-16T23:08:08.507Z,1368745688.507 [controlThread](INFO): Thread ID is 1415
2013-05-16T23:08:08.507Z,1368745688.507 [controlThread](DEBUG): Initializing ControlThread
2013-05-16T23:08:08.507Z,1368745688.507 [CycleStarter](INFO): Thread ID is 1414
2013-05-16T23:08:08.508Z,1368745688.508 [InternalSim](DEBUG):  InternalSim initializing...
2013-05-16T23:08:08.542Z,1368745688.542 [logger](INFO): Thread ID is 1417
2013-05-16T23:08:08.567Z,1368745688.567 [SBIT](INFO): Initialize SBIT Component.
2013-05-16T23:08:08.568Z,1368745688.568 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10359
2013-05-16T23:08:08.568Z,1368745688.568 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-16T23:08:08.568Z,1368745688.568 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-16T23:08:08.569Z,1368745688.569 [IBIT](INFO): Initialize IBIT Component.
2013-05-16T23:08:08.570Z,1368745688.570 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-16T23:08:08.570Z,1368745688.570 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-05-16T23:08:08.582Z,1368745688.582 [AsyncPiEstimator](INFO): Thread ID is 1478
2013-05-16T23:08:08.582Z,1368745688.582 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-16T23:08:08.594Z,1368745688.594 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-16T23:08:08.595Z,1368745688.595 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-16T23:08:08.595Z,1368745688.595 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-16T23:08:08.596Z,1368745688.596 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-16T23:08:08.596Z,1368745688.596 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-16T23:08:08.598Z,1368745688.598 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-16T23:08:08.598Z,1368745688.598 [Navigation](DEBUG): Initializing Navigation.
2013-05-16T23:08:08.598Z,1368745688.598 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-16T23:08:08.600Z,1368745688.600 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-16T23:08:08.601Z,1368745688.601 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-16T23:08:08.601Z,1368745688.602 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-16T23:08:08.607Z,1368745688.607 [DVL_micro](INFO): Thread ID is 1479
2013-05-16T23:08:08.616Z,1368745688.616 [DVL_micro](INFO): Initializing
2013-05-16T23:08:08.617Z,1368745688.617 [DVL_micro](INFO): start:Powering up
2013-05-16T23:08:08.618Z,1368745688.618 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T23:08:08.618Z,1368745688.618 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T23:08:08.630Z,1368745688.630 [CTD_NeilBrown](INFO): Thread ID is 1480
2013-05-16T23:08:08.631Z,1368745688.631 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-16T23:08:08.633Z,1368745688.634 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-16T23:08:08.643Z,1368745688.643 [WetLabsBB2FL](INFO): Thread ID is 1481
2013-05-16T23:08:08.643Z,1368745688.643 [WetLabsBB2FL](INFO): Powering down
2013-05-16T23:08:08.686Z,1368745688.686 [NavChartDb](INFO): Thread ID is 1482
2013-05-16T23:08:08.691Z,1368745688.691 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-16T23:08:08.692Z,1368745688.692 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-16T23:08:08.693Z,1368745688.693 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-16T23:08:08.693Z,1368745688.693 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-16T23:08:08.693Z,1368745688.693 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-16T23:08:08.694Z,1368745688.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-16T23:08:08.694Z,1368745688.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-16T23:08:08.694Z,1368745688.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-16T23:08:08.694Z,1368745688.694 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-16T23:08:09.564Z,1368745689.564 [CommandLine](IMPORTANT): got command report touch homing_target_azimuth
2013-05-16T23:08:10.054Z,1368745690.054 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-16T23:08:10.082Z,1368745690.082 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-05-16T23:08:10.082Z,1368745690.082 [DropWeight] Hardware Fault, FailCount= 1
2013-05-16T23:08:10.082Z,1368745690.082 [DropWeight](ERROR): Hardware Fault
2013-05-16T23:08:10.084Z,1368745690.084 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-16T23:08:10.117Z,1368745690.117 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T23:08:10.172Z,1368745690.172 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

        <ReadDatum>
            <Timeout Duration="P1M" /><Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" /><Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2013-05-16T23:08:10.173Z,1368745690.173 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-16T23:08:10.291Z,1368745690.291 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-16T23:08:10.293Z,1368745690.293 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-16T23:08:10.296Z,1368745690.296 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T23:08:10.324Z,1368745690.325 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-16T23:08:10.344Z,1368745690.344 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T23:08:10.366Z,1368745690.366 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-16T23:08:10.399Z,1368745690.399 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-16T23:08:10.419Z,1368745690.419 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T23:08:10.424Z,1368745690.424 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-16T23:08:10.444Z,1368745690.444 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

        <When><Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS"><Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="Sequence">
                    <Setting>
                    <Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout><Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="CallIridium" >

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or>
            <Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

        <Assign><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

    <Guidance:SetSpeed RunIn="Parallel">
        <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
    </Guidance:SetSpeed>

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-05-16T23:08:10.452Z,1368745690.452 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-05-16T23:08:10.535Z,1368745690.534 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-16T23:08:10.707Z,1368745690.707 [CommandLine](IMPORTANT): got command report touch homing_target_elevation
2013-05-16T23:08:10.734Z,1368745690.734 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T23:08:10.734Z,1368745690.734 [DVL_micro](INFO): Querying output modes
2013-05-16T23:08:10.734Z,1368745690.734 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T23:08:10.735Z,1368745690.735 [Radio_Freewave](INFO): Powering up
2013-05-16T23:08:10.745Z,1368745690.745 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-05-16T23:08:10.746Z,1368745690.746 [DVL_micro](INFO): NQ1 output enabled
2013-05-16T23:08:10.746Z,1368745690.746 [DVL_micro](INFO): RSSI output enabled
2013-05-16T23:08:10.746Z,1368745690.746 [DVL_micro](INFO): ADCP output enabled
2013-05-16T23:08:10.746Z,1368745690.746 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T23:08:10.757Z,1368745690.757 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-05-16T23:08:10.762Z,1368745690.762 [DVL_micro](INFO): pause:Powering down
2013-05-16T23:08:10.768Z,1368745690.769 [DAT](INFO): Powering up
2013-05-16T23:08:10.769Z,1368745690.769 [DAT](DEBUG): Initializing DAT.
2013-05-16T23:08:11.034Z,1368745691.034 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:11.042Z,1368745691.042 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-16T23:08:11.065Z,1368745691.065 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:11.089Z,1368745691.089 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-16T23:08:11.112Z,1368745691.112 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:11.117Z,1368745691.117 [MassServo](DEBUG): Initializing MassServo.
2013-05-16T23:08:11.123Z,1368745691.123 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:11.129Z,1368745691.129 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-16T23:08:11.175Z,1368745691.175 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:11.182Z,1368745691.181 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-16T23:08:11.227Z,1368745691.227 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-05-16T23:08:11.228Z,1368745691.227 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-05-16T23:08:11.622Z,1368745691.622 [CommandLine](IMPORTANT): got command report touch DAT.rawAzimuth
2013-05-16T23:08:12.133Z,1368745692.133 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2013-05-16T23:08:12.133Z,1368745692.133 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2013-05-16T23:08:12.133Z,1368745692.134 [BuoyancyServo] Communications Fault, FailCount= 1
2013-05-16T23:08:12.133Z,1368745692.134 [BuoyancyServo](ERROR): Communications Fault
2013-05-16T23:08:12.343Z,1368745692.343 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2013-05-16T23:08:12.631Z,1368745692.631 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-05-16T23:08:12.632Z,1368745692.632 [BuoyancyServo](INFO): Powering down
2013-05-16T23:08:12.696Z,1368745692.696 [CommandLine](IMPORTANT): got command get platform_orientation
2013-05-16T23:08:12.697Z,1368745692.697 [CommandLine](IMPORTANT): platform_orientation 9.322235 degree
2013-05-16T23:08:13.364Z,1368745693.364 [NAL9602](INFO): Powering up NAL9602
2013-05-16T23:08:15.512Z,1368745695.512 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2013-05-16T23:08:15.512Z,1368745695.512 [BuoyancyServo] No Fault, FailCount= 1
2013-05-16T23:08:15.837Z,1368745695.837 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-16T23:08:15.970Z,1368745695.970 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-16T23:08:23.838Z,1368745703.838 [NAL9602](INFO): NAL9602 initialized
2013-05-16T23:08:24.299Z,1368745704.299 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-16T23:08:24.306Z,1368745704.306 [CBIT](IMPORTANT): Beginning GF scan
2013-05-16T23:08:27.345Z,1368745707.345 [CommandLine](IMPORTANT): got command report
2013-05-16T23:08:27.346Z,1368745707.346 [Reporter](INFO): homing_target_azimuth reporting when touched
2013-05-16T23:08:27.346Z,1368745707.346 [Reporter](INFO): homing_target_elevation reporting when touched
2013-05-16T23:08:27.346Z,1368745707.346 [Reporter](INFO): DAT.rawAzimuth reporting when touched
2013-05-16T23:08:30.900Z,1368745710.900 [DAT](INFO): Powering down
2013-05-16T23:08:36.626Z,1368745716.625 [CommandLine](IMPORTANT): got command get platform_orientation
2013-05-16T23:08:36.626Z,1368745716.626 [CommandLine](IMPORTANT): platform_orientation -135.609403 degree
2013-05-16T23:08:41.245Z,1368745721.245 [CommandLine](IMPORTANT): got command report
2013-05-16T23:08:41.246Z,1368745721.246 [Reporter](INFO): homing_target_azimuth reporting when touched
2013-05-16T23:08:41.246Z,1368745721.246 [Reporter](INFO): homing_target_elevation reporting when touched
2013-05-16T23:08:41.246Z,1368745721.246 [Reporter](INFO): DAT.rawAzimuth reporting when touched
2013-05-16T23:08:50.960Z,1368745730.960 [CBIT](IMPORTANT): No ground fault detected
2013-05-16T23:08:51.608Z,1368745731.608 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-05-16T23:08:51.609Z,1368745731.609 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2013-05-16T23:09:01.401Z,1368745741.401 [NAL9602](INFO): Powering down
2013-05-16T23:09:17.666Z,1368745757.666 [SBIT](IMPORTANT): SBIT PASSED
2013-05-16T23:09:18.063Z,1368745758.063 [MissionManager](IMPORTANT): Started mission Startup
2013-05-16T23:09:18.063Z,1368745758.063 [Startup] Running Loop=1
2013-05-16T23:09:18.063Z,1368745758.063 [Startup](INFO): Aggregate::initialize Startup
2013-05-16T23:09:18.063Z,1368745758.063 [Startup:A.GoToSurface] Running Loop=1
2013-05-16T23:09:18.063Z,1368745758.063 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:09:18.069Z,1368745758.069 [Startup:StartupSatComms] Running Loop=1
2013-05-16T23:09:18.070Z,1368745758.070 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-05-16T23:09:18.070Z,1368745758.070 [Startup:StartupSatComms:A] Running Loop=1
2013-05-16T23:09:18.463Z,1368745758.464 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-16T23:09:18.878Z,1368745758.878 [NAL9602](INFO): Powering up
2013-05-16T23:09:24.118Z,1368745764.118 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-05-16T23:09:24.144Z,1368745764.144 [Startup:StartupSatComms:A] Stopped
2013-05-16T23:09:24.144Z,1368745764.144 [Startup:StartupSatComms:B] Running Loop=1
2013-05-16T23:09:24.469Z,1368745764.469 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-16T23:09:25.366Z,1368745765.366 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2013-05-16T23:09:29.270Z,1368745769.270 [Startup:StartupSatComms:B] Stopped
2013-05-16T23:09:29.270Z,1368745769.270 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-05-16T23:09:29.270Z,1368745769.270 [Startup:StartupSatComms] Stopped
2013-05-16T23:09:29.270Z,1368745769.270 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-05-16T23:09:29.271Z,1368745769.271 [Startup](INFO): Completed Startup
2013-05-16T23:09:29.271Z,1368745769.271 [Startup] Stopped
2013-05-16T23:09:29.271Z,1368745769.271 [Startup](INFO): Aggregate::uninitialize Startup
2013-05-16T23:09:29.271Z,1368745769.271 [Startup:A.GoToSurface] Stopped
2013-05-16T23:09:29.271Z,1368745769.272 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:09:29.637Z,1368745769.636 [MissionManager](IMPORTANT): Started mission Default
2013-05-16T23:09:29.637Z,1368745769.637 [Default] Running Loop=1
2013-05-16T23:09:29.637Z,1368745769.637 [Default](INFO): Aggregate::initialize Default
2013-05-16T23:09:29.637Z,1368745769.637 [Default:D.SetSpeed] Running Loop=1
2013-05-16T23:09:29.637Z,1368745769.637 [Default:D.SetSpeed](DEBUG): Initialize.
2013-05-16T23:09:29.637Z,1368745769.637 [Default:E.GoToSurface] Running Loop=1
2013-05-16T23:09:29.637Z,1368745769.637 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:09:29.637Z,1368745769.638 [Default:Iridium] Running Loop=1
2013-05-16T23:09:29.638Z,1368745769.638 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-16T23:09:29.638Z,1368745769.638 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-16T23:09:29.638Z,1368745769.638 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-16T23:09:29.638Z,1368745769.638 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-16T23:09:29.638Z,1368745769.638 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:09:29.638Z,1368745769.638 [Default:E.GoToSurface] Running Loop=1
2013-05-16T23:09:29.644Z,1368745769.644 [Default:D.SetSpeed] Running Loop=1
2013-05-16T23:09:29.698Z,1368745769.698 [Default:Iridium:B.GoToSurface] Stopped
2013-05-16T23:09:29.698Z,1368745769.698 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:09:29.698Z,1368745769.698 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-16T23:09:29.698Z,1368745769.698 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-16T23:09:29.705Z,1368745769.705 [Default:GPS] Running Loop=1
2013-05-16T23:09:29.705Z,1368745769.705 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-16T23:09:29.705Z,1368745769.705 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-16T23:09:29.705Z,1368745769.705 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-16T23:09:29.706Z,1368745769.706 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-16T23:09:29.706Z,1368745769.706 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:09:29.711Z,1368745769.711 [Default:GPS:B.GoToSurface] Stopped
2013-05-16T23:09:29.711Z,1368745769.711 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:09:29.711Z,1368745769.711 [Default:GPS:Read_GPS] Running Loop=1
2013-05-16T23:09:29.711Z,1368745769.711 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-16T23:09:29.946Z,1368745769.945 [NAL9602](INFO): NAL9602 initialized
2013-05-16T23:09:29.971Z,1368745769.971 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-16T23:09:29.974Z,1368745769.974 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-16T23:09:34.255Z,1368745774.256 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-16T23:09:35.577Z,1368745775.578 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/dat_on.xml
2013-05-16T23:09:35.578Z,1368745775.578 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/dat_on.xml
2013-05-16T23:09:35.596Z,1368745775.596 [MissionManager](INFO): DefineArg dat_on.MassDefault = 0.000000 n/a
2013-05-16T23:09:35.599Z,1368745775.599 [dat_on:A.Pitch](DEBUG): Construct.
2013-05-16T23:09:35.610Z,1368745775.610 [dat_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2013-05-16T23:09:35.613Z,1368745775.613 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="dat_on">

    <DefineArg Name="MassDefault"><Control:VerticalControl.massDefault/></DefineArg>

    <Timeout Duration="P15M"/>

    <Guidance:Pitch RunIn="Parallel">
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="TestDrive">

        <ReadData>
            <Universal:homing_target_range/>
        </ReadData>

        <Aggregate Id="Data">

            <When><True/>
            </When>

            <Shorelog><Control:HorizontalControl.latitudeCmd/><Units:degree/><Control:HorizontalControl.longitudeCmd/><Units:degree/>
            </Shorelog>

            <Syslog Severity="None">Pause a cycle</Syslog>

        </Aggregate>

        <Guidance:Wait RunIn="Sequence">
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>2</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2013-05-16T23:09:35.613Z,1368745775.614 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/dat_on.xml
2013-05-16T23:09:35.886Z,1368745775.886 [Default] Stopped
2013-05-16T23:09:35.886Z,1368745775.886 [Default](INFO): Aggregate::uninitialize Default
2013-05-16T23:09:35.887Z,1368745775.886 [Default:GPS] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-16T23:09:35.887Z,1368745775.887 [Default:GPS:A.SetSpeed] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:09:35.887Z,1368745775.887 [Default:GPS:Read_GPS] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:Iridium] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-16T23:09:35.887Z,1368745775.887 [Default:Iridium:A.SetSpeed] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:09:35.887Z,1368745775.887 [Default:Iridium:Read_Iridium] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:D.SetSpeed] Stopped
2013-05-16T23:09:35.887Z,1368745775.887 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:09:35.887Z,1368745775.888 [Default:E.GoToSurface] Stopped
2013-05-16T23:09:35.888Z,1368745775.888 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:09:35.888Z,1368745775.888 [MissionManager](IMPORTANT): Started mission dat_on
2013-05-16T23:09:35.888Z,1368745775.888 [dat_on] Running Loop=1
2013-05-16T23:09:35.888Z,1368745775.888 [dat_on](INFO): Aggregate::initialize dat_on
2013-05-16T23:09:35.888Z,1368745775.888 [dat_on:A.Pitch] Running Loop=1
2013-05-16T23:09:35.888Z,1368745775.888 [dat_on:A.Pitch](DEBUG): Initialize.
2013-05-16T23:09:35.889Z,1368745775.889 [dat_on:TestDrive] Running Loop=1
2013-05-16T23:09:35.889Z,1368745775.889 [dat_on:TestDrive](INFO): Aggregate::initialize dat_on:TestDrive
2013-05-16T23:09:35.889Z,1368745775.889 [dat_on:TestDrive:A] Running Loop=1
2013-05-16T23:09:35.889Z,1368745775.889 [dat_on:TestDrive:C.Wait] Running Loop=1
2013-05-16T23:09:35.889Z,1368745775.889 [dat_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2013-05-16T23:09:35.895Z,1368745775.895 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:35.895Z,1368745775.895 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:35.895Z,1368745775.895 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:35.899Z,1368745775.899 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:35.899Z,1368745775.899 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:35.899Z,1368745775.899 [dat_on:TestDrive:A] Running Loop=1
2013-05-16T23:09:35.900Z,1368745775.900 [dat_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense homing_target_range
2013-05-16T23:09:35.901Z,1368745775.901 [dat_on:A.Pitch] Running Loop=1
2013-05-16T23:09:36.308Z,1368745776.308 [DAT](INFO): Powering up
2013-05-16T23:09:36.319Z,1368745776.319 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:36.319Z,1368745776.319 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:36.319Z,1368745776.319 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:36.319Z,1368745776.319 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:36.669Z,1368745776.669 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:36.669Z,1368745776.669 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:36.669Z,1368745776.669 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:36.670Z,1368745776.670 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:36.670Z,1368745776.670 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:37.069Z,1368745777.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:37.069Z,1368745777.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:37.069Z,1368745777.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:37.069Z,1368745777.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:37.463Z,1368745777.463 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:37.463Z,1368745777.463 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:37.463Z,1368745777.463 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:37.464Z,1368745777.464 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:37.464Z,1368745777.464 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:37.869Z,1368745777.869 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:37.870Z,1368745777.870 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:37.870Z,1368745777.870 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:37.870Z,1368745777.870 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:38.308Z,1368745778.308 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:38.308Z,1368745778.308 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:38.308Z,1368745778.308 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:38.309Z,1368745778.309 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:38.309Z,1368745778.309 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:38.663Z,1368745778.663 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:38.663Z,1368745778.663 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:38.663Z,1368745778.663 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:38.664Z,1368745778.664 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:39.068Z,1368745779.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:39.069Z,1368745779.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:39.069Z,1368745779.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:39.069Z,1368745779.069 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:39.070Z,1368745779.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:39.473Z,1368745779.473 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:39.474Z,1368745779.474 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:39.474Z,1368745779.474 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:39.474Z,1368745779.474 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:39.867Z,1368745779.867 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:39.867Z,1368745779.867 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:39.868Z,1368745779.868 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:39.868Z,1368745779.868 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:39.868Z,1368745779.868 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:40.267Z,1368745780.267 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:40.268Z,1368745780.268 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:40.268Z,1368745780.268 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:40.268Z,1368745780.268 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:40.673Z,1368745780.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:40.673Z,1368745780.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:40.674Z,1368745780.674 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:40.674Z,1368745780.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:40.675Z,1368745780.675 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:41.073Z,1368745781.073 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:41.073Z,1368745781.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:41.073Z,1368745781.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:41.073Z,1368745781.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:41.566Z,1368745781.566 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:41.566Z,1368745781.566 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:41.566Z,1368745781.566 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:41.567Z,1368745781.567 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:41.567Z,1368745781.567 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:41.936Z,1368745781.936 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:41.936Z,1368745781.936 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:41.936Z,1368745781.936 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:41.936Z,1368745781.936 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:42.266Z,1368745782.266 [NAL9602](INFO): Powering down
2013-05-16T23:09:42.283Z,1368745782.283 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:42.283Z,1368745782.283 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:42.283Z,1368745782.283 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:42.283Z,1368745782.283 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:42.284Z,1368745782.284 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:42.672Z,1368745782.672 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:42.672Z,1368745782.672 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:42.672Z,1368745782.672 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:42.672Z,1368745782.672 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:43.067Z,1368745783.066 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:43.067Z,1368745783.067 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:43.067Z,1368745783.067 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:43.067Z,1368745783.067 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:43.068Z,1368745783.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:43.496Z,1368745783.496 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:43.496Z,1368745783.496 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:43.496Z,1368745783.497 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:43.497Z,1368745783.497 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:43.866Z,1368745783.866 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:43.866Z,1368745783.866 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:43.866Z,1368745783.866 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:43.867Z,1368745783.867 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:43.867Z,1368745783.867 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:44.269Z,1368745784.269 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:44.269Z,1368745784.269 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:44.269Z,1368745784.270 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:44.270Z,1368745784.270 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:44.704Z,1368745784.704 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:44.704Z,1368745784.704 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:44.705Z,1368745784.705 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:44.705Z,1368745784.705 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:44.706Z,1368745784.705 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:45.072Z,1368745785.072 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:45.072Z,1368745785.072 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:45.072Z,1368745785.072 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:45.072Z,1368745785.072 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:45.496Z,1368745785.496 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:45.496Z,1368745785.496 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:45.496Z,1368745785.497 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:45.497Z,1368745785.497 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:45.497Z,1368745785.497 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:45.873Z,1368745785.873 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:45.873Z,1368745785.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:45.873Z,1368745785.874 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:45.874Z,1368745785.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:46.276Z,1368745786.276 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:46.276Z,1368745786.276 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:46.276Z,1368745786.276 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:46.277Z,1368745786.277 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:46.277Z,1368745786.277 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:46.741Z,1368745786.741 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:46.741Z,1368745786.741 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:46.742Z,1368745786.741 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:46.742Z,1368745786.742 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:47.065Z,1368745787.066 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:47.066Z,1368745787.066 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:47.066Z,1368745787.066 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:47.066Z,1368745787.066 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:47.067Z,1368745787.066 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:47.472Z,1368745787.472 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:47.472Z,1368745787.472 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:47.472Z,1368745787.472 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:47.472Z,1368745787.473 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:47.904Z,1368745787.904 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:47.904Z,1368745787.904 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:47.904Z,1368745787.904 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:47.905Z,1368745787.905 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:47.905Z,1368745787.905 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:48.270Z,1368745788.270 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:48.270Z,1368745788.270 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:48.270Z,1368745788.270 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:48.270Z,1368745788.270 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:48.666Z,1368745788.666 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:48.667Z,1368745788.667 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:48.667Z,1368745788.667 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:48.667Z,1368745788.667 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:48.668Z,1368745788.668 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:49.068Z,1368745789.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:49.069Z,1368745789.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:49.069Z,1368745789.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:49.069Z,1368745789.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:49.467Z,1368745789.467 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:49.467Z,1368745789.467 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:49.467Z,1368745789.467 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:49.468Z,1368745789.468 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:49.468Z,1368745789.468 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:49.866Z,1368745789.866 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:49.867Z,1368745789.866 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:49.867Z,1368745789.867 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:49.867Z,1368745789.867 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:50.272Z,1368745790.272 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:50.272Z,1368745790.272 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:50.273Z,1368745790.273 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:50.273Z,1368745790.273 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:50.273Z,1368745790.273 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:50.667Z,1368745790.667 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:50.667Z,1368745790.667 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:50.668Z,1368745790.668 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:50.668Z,1368745790.668 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:51.096Z,1368745791.096 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:51.096Z,1368745791.096 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:51.096Z,1368745791.096 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:51.097Z,1368745791.097 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:51.097Z,1368745791.098 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:51.517Z,1368745791.517 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:51.517Z,1368745791.517 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:51.517Z,1368745791.517 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:51.517Z,1368745791.517 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:51.863Z,1368745791.863 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:51.863Z,1368745791.863 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:51.863Z,1368745791.863 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:51.864Z,1368745791.864 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:51.864Z,1368745791.864 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:52.270Z,1368745792.270 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:52.270Z,1368745792.270 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:52.270Z,1368745792.270 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:52.270Z,1368745792.270 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:52.667Z,1368745792.667 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:52.668Z,1368745792.668 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:52.668Z,1368745792.668 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:52.668Z,1368745792.668 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:52.669Z,1368745792.668 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:53.067Z,1368745793.067 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:53.067Z,1368745793.067 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:53.068Z,1368745793.068 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:53.068Z,1368745793.068 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:53.465Z,1368745793.465 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:53.465Z,1368745793.465 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:53.465Z,1368745793.466 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:53.466Z,1368745793.466 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:53.466Z,1368745793.466 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:53.867Z,1368745793.867 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:09:53.897Z,1368745793.897 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:53.897Z,1368745793.897 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:53.897Z,1368745793.897 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:53.897Z,1368745793.897 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:54.267Z,1368745794.267 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:54.267Z,1368745794.267 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:54.267Z,1368745794.267 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:54.268Z,1368745794.268 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:54.268Z,1368745794.268 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:54.667Z,1368745794.667 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:54.667Z,1368745794.667 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:54.667Z,1368745794.667 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:54.667Z,1368745794.667 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:55.068Z,1368745795.068 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:55.068Z,1368745795.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:55.069Z,1368745795.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:55.069Z,1368745795.069 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:55.070Z,1368745795.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:55.462Z,1368745795.462 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:55.463Z,1368745795.463 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:55.463Z,1368745795.463 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:55.463Z,1368745795.463 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:55.965Z,1368745795.965 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:55.965Z,1368745795.965 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:55.965Z,1368745795.965 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:55.966Z,1368745795.966 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:55.966Z,1368745795.966 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:56.270Z,1368745796.270 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:09:56.329Z,1368745796.329 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:56.330Z,1368745796.330 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:56.330Z,1368745796.330 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:56.330Z,1368745796.330 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:56.713Z,1368745796.713 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:56.713Z,1368745796.713 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:56.714Z,1368745796.714 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:56.714Z,1368745796.714 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:56.714Z,1368745796.714 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:57.069Z,1368745797.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:57.069Z,1368745797.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:57.069Z,1368745797.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:57.069Z,1368745797.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:57.467Z,1368745797.467 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:57.467Z,1368745797.467 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:57.468Z,1368745797.468 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:57.468Z,1368745797.468 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:57.468Z,1368745797.468 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:57.891Z,1368745797.891 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:57.892Z,1368745797.892 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:57.892Z,1368745797.892 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:57.892Z,1368745797.892 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:58.277Z,1368745798.277 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:58.277Z,1368745798.277 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:58.277Z,1368745798.277 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:58.278Z,1368745798.278 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:58.278Z,1368745798.278 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:58.667Z,1368745798.667 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:09:58.697Z,1368745798.697 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:58.697Z,1368745798.697 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:58.697Z,1368745798.697 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:58.698Z,1368745798.698 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:59.067Z,1368745799.066 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:59.067Z,1368745799.067 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:59.067Z,1368745799.067 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:59.067Z,1368745799.067 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:59.068Z,1368745799.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:59.471Z,1368745799.471 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:09:59.471Z,1368745799.471 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:09:59.471Z,1368745799.471 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:09:59.471Z,1368745799.471 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:09:59.866Z,1368745799.866 [DAT](INFO): PRE-clean:00:08:53.2634 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 82-0.14,-1.172, PHS= 1.215, 1.088, 1.223, |v|= 0.724, RAW= 153.0,-83.9, CAL= 152.7,-83.4, ROT= 231.7,-83.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:09:59.866Z,1368745799.866 [DAT](INFO): POST-clean:00:08:53.2634 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 82-0.14,-1.172, PHS= 1.215, 1.088, 1.223, |v|= 0.724, RAW= 153.0,-83.9, CAL= 152.7,-83.4, ROT= 231.7,-83.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:09:59.880Z,1368745799.880 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:09:59.881Z,1368745799.881 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:09:59.881Z,1368745799.881 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:09:59.882Z,1368745799.882 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:09:59.882Z,1368745799.882 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:09:59.892Z,1368745799.892 [Reporter](INFO): homing_target_azimuth 175.963350 arcdeg
2013-05-16T23:09:59.893Z,1368745799.893 [Reporter](INFO): homing_target_elevation -86.460715 arcdeg
2013-05-16T23:09:59.894Z,1368745799.894 [Reporter](INFO): DAT.rawAzimuth 153.000000 arcdeg
2013-05-16T23:10:00.290Z,1368745800.290 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:00.290Z,1368745800.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:00.290Z,1368745800.290 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:00.290Z,1368745800.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:00.672Z,1368745800.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:00.673Z,1368745800.672 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:00.673Z,1368745800.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:00.673Z,1368745800.673 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:00.674Z,1368745800.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:01.074Z,1368745801.074 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:01.114Z,1368745801.114 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:01.114Z,1368745801.114 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:01.114Z,1368745801.114 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:01.114Z,1368745801.114 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:01.492Z,1368745801.492 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:01.492Z,1368745801.492 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:01.493Z,1368745801.493 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:01.493Z,1368745801.493 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:01.493Z,1368745801.493 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:01.920Z,1368745801.920 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:01.921Z,1368745801.921 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:01.921Z,1368745801.921 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:01.921Z,1368745801.921 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:02.276Z,1368745802.276 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:02.277Z,1368745802.277 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:02.277Z,1368745802.277 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:02.278Z,1368745802.278 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:02.278Z,1368745802.278 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:02.673Z,1368745802.672 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:02.673Z,1368745802.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:02.673Z,1368745802.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:02.673Z,1368745802.673 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:03.092Z,1368745803.092 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:03.092Z,1368745803.092 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:03.093Z,1368745803.092 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:03.093Z,1368745803.093 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:03.093Z,1368745803.093 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:03.470Z,1368745803.470 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:03.511Z,1368745803.511 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:03.511Z,1368745803.511 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:03.512Z,1368745803.511 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:03.512Z,1368745803.512 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:03.870Z,1368745803.870 [DAT](INFO): PRE-clean:00:08:57.2136 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.21,-2.164, PHS= 1.211, 1.042, 1.249, |v|= 0.723, RAW= 160.0,-81.1, CAL= 159.1,-80.4, ROT= 238.1,-80.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:03.870Z,1368745803.870 [DAT](INFO): POST-clean:00:08:57.2136 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.21,-2.164, PHS= 1.211, 1.042, 1.249, |v|= 0.723, RAW= 160.0,-81.1, CAL= 159.1,-80.4, ROT= 238.1,-80.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:03.883Z,1368745803.883 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:03.883Z,1368745803.883 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:03.883Z,1368745803.883 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:03.884Z,1368745803.884 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:03.884Z,1368745803.884 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:03.894Z,1368745803.894 [Reporter](INFO): homing_target_azimuth 220.987724 arcdeg
2013-05-16T23:10:03.895Z,1368745803.895 [Reporter](INFO): homing_target_elevation -86.008467 arcdeg
2013-05-16T23:10:03.895Z,1368745803.895 [Reporter](INFO): DAT.rawAzimuth 160.000000 arcdeg
2013-05-16T23:10:04.287Z,1368745804.287 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:04.287Z,1368745804.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:04.287Z,1368745804.287 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:04.287Z,1368745804.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:04.673Z,1368745804.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:04.673Z,1368745804.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:04.673Z,1368745804.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:04.674Z,1368745804.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:04.674Z,1368745804.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:05.073Z,1368745805.073 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:05.073Z,1368745805.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:05.073Z,1368745805.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:05.073Z,1368745805.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:05.472Z,1368745805.472 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:05.472Z,1368745805.472 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:05.472Z,1368745805.472 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:05.473Z,1368745805.473 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:05.473Z,1368745805.473 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:05.867Z,1368745805.867 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:05.897Z,1368745805.897 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:05.898Z,1368745805.898 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:05.898Z,1368745805.898 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:05.898Z,1368745805.898 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:06.269Z,1368745806.269 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:06.269Z,1368745806.269 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:06.269Z,1368745806.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:06.270Z,1368745806.270 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:06.270Z,1368745806.270 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:06.713Z,1368745806.713 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:06.714Z,1368745806.714 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:06.714Z,1368745806.714 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:06.714Z,1368745806.714 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:07.069Z,1368745807.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:07.069Z,1368745807.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:07.069Z,1368745807.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:07.070Z,1368745807.070 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:07.070Z,1368745807.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:07.468Z,1368745807.468 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:07.468Z,1368745807.468 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:07.469Z,1368745807.469 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:07.469Z,1368745807.469 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:07.864Z,1368745807.864 [DAT](INFO): PRE-clean:00:09:01.2139 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.23,-2.957, PHS= 1.109, 1.008, 1.160, |v|= 0.674, RAW= 169.1,-83.3, CAL= 168.0,-82.7, ROT= 247.0,-82.7
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:07.864Z,1368745807.864 [DAT](INFO): POST-clean:00:09:01.2139 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.23,-2.957, PHS= 1.109, 1.008, 1.160, |v|= 0.674, RAW= 169.1,-83.3, CAL= 168.0,-82.7, ROT= 247.0,-82.7
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:07.877Z,1368745807.877 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:07.877Z,1368745807.877 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:07.877Z,1368745807.877 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:07.877Z,1368745807.878 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:07.878Z,1368745807.878 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:07.888Z,1368745807.888 [Reporter](INFO): homing_target_azimuth 193.858336 arcdeg
2013-05-16T23:10:07.888Z,1368745807.888 [Reporter](INFO): homing_target_elevation -88.191621 arcdeg
2013-05-16T23:10:07.889Z,1368745807.889 [Reporter](INFO): DAT.rawAzimuth 169.100006 arcdeg
2013-05-16T23:10:08.269Z,1368745808.269 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:08.322Z,1368745808.322 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:08.322Z,1368745808.322 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:08.322Z,1368745808.322 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:08.322Z,1368745808.322 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:08.667Z,1368745808.667 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:08.667Z,1368745808.667 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:08.667Z,1368745808.667 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:08.668Z,1368745808.668 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:08.668Z,1368745808.668 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:09.073Z,1368745809.073 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:09.073Z,1368745809.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:09.073Z,1368745809.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:09.073Z,1368745809.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:09.469Z,1368745809.469 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:09.469Z,1368745809.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:09.469Z,1368745809.469 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:09.470Z,1368745809.470 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:09.470Z,1368745809.470 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:09.867Z,1368745809.867 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:09.867Z,1368745809.867 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:09.867Z,1368745809.867 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:09.867Z,1368745809.867 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:10.269Z,1368745810.269 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:10.269Z,1368745810.269 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:10.269Z,1368745810.269 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:10.270Z,1368745810.270 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:10.270Z,1368745810.270 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:10.667Z,1368745810.667 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:10.698Z,1368745810.698 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:10.698Z,1368745810.698 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:10.698Z,1368745810.698 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:10.698Z,1368745810.698 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:11.067Z,1368745811.067 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:11.067Z,1368745811.067 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:11.067Z,1368745811.067 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:11.068Z,1368745811.068 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:11.068Z,1368745811.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:11.475Z,1368745811.475 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:11.476Z,1368745811.476 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:11.476Z,1368745811.476 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:11.476Z,1368745811.476 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:11.915Z,1368745811.915 [DAT](INFO): PRE-clean:00:09:05.2643 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.05, 0.636, PHS= 1.100, 0.985, 1.170, |v|= 0.671, RAW= 172.0,-81.9, CAL= 170.5,-81.1, ROT= 249.5,-81.1
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:11.915Z,1368745811.915 [DAT](INFO): POST-clean:00:09:05.2643 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.05, 0.636, PHS= 1.100, 0.985, 1.170, |v|= 0.671, RAW= 172.0,-81.9, CAL= 170.5,-81.1, ROT= 249.5,-81.1
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:11.930Z,1368745811.930 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:11.931Z,1368745811.931 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:11.931Z,1368745811.931 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:11.931Z,1368745811.931 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:11.932Z,1368745811.931 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:11.942Z,1368745811.942 [Reporter](INFO): homing_target_azimuth 233.961956 arcdeg
2013-05-16T23:10:11.943Z,1368745811.943 [Reporter](INFO): homing_target_elevation -87.666079 arcdeg
2013-05-16T23:10:11.943Z,1368745811.943 [Reporter](INFO): DAT.rawAzimuth 172.000000 arcdeg
2013-05-16T23:10:12.288Z,1368745812.288 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:12.289Z,1368745812.289 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:12.289Z,1368745812.289 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:12.289Z,1368745812.289 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:12.675Z,1368745812.675 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:12.675Z,1368745812.675 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:12.675Z,1368745812.675 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:12.676Z,1368745812.676 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:12.676Z,1368745812.676 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:13.072Z,1368745813.072 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:13.101Z,1368745813.102 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:13.102Z,1368745813.102 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:13.102Z,1368745813.102 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:13.102Z,1368745813.102 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:13.469Z,1368745813.469 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:13.469Z,1368745813.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:13.470Z,1368745813.470 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:13.470Z,1368745813.470 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:13.470Z,1368745813.470 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:13.869Z,1368745813.869 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:13.869Z,1368745813.869 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:13.870Z,1368745813.870 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:13.870Z,1368745813.870 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:14.305Z,1368745814.305 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:14.305Z,1368745814.305 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:14.305Z,1368745814.305 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:14.306Z,1368745814.306 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:14.306Z,1368745814.306 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:14.681Z,1368745814.681 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:14.681Z,1368745814.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:14.681Z,1368745814.681 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:14.681Z,1368745814.681 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:15.069Z,1368745815.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:15.069Z,1368745815.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:15.070Z,1368745815.070 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:15.070Z,1368745815.070 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:15.070Z,1368745815.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:15.474Z,1368745815.474 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:15.509Z,1368745815.509 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:15.509Z,1368745815.509 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:15.509Z,1368745815.509 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:15.510Z,1368745815.510 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:15.871Z,1368745815.871 [DAT](INFO): PRE-clean:00:09:09.2145 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.06, 0.444, PHS= 1.165, 0.995, 1.231, |v|= 0.703, RAW= 165.8,-79.9, CAL= 164.4,-79.0, ROT= 243.4,-79.0
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:15.871Z,1368745815.871 [DAT](INFO): POST-clean:00:09:09.2145 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.06, 0.444, PHS= 1.165, 0.995, 1.231, |v|= 0.703, RAW= 165.8,-79.9, CAL= 164.4,-79.0, ROT= 243.4,-79.0
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:15.883Z,1368745815.884 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:15.884Z,1368745815.884 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:15.884Z,1368745815.884 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:15.884Z,1368745815.884 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:15.885Z,1368745815.885 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:15.895Z,1368745815.895 [Reporter](INFO): homing_target_azimuth 240.392934 arcdeg
2013-05-16T23:10:15.896Z,1368745815.895 [Reporter](INFO): homing_target_elevation -85.557258 arcdeg
2013-05-16T23:10:15.896Z,1368745815.896 [Reporter](INFO): DAT.rawAzimuth 165.800003 arcdeg
2013-05-16T23:10:16.293Z,1368745816.293 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:16.293Z,1368745816.293 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:16.293Z,1368745816.293 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:16.294Z,1368745816.293 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:16.674Z,1368745816.674 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:16.674Z,1368745816.674 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:16.674Z,1368745816.674 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:16.674Z,1368745816.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:16.674Z,1368745816.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:17.126Z,1368745817.126 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:17.126Z,1368745817.126 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:17.126Z,1368745817.126 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:17.126Z,1368745817.126 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:17.472Z,1368745817.473 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:17.473Z,1368745817.473 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:17.473Z,1368745817.473 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:17.473Z,1368745817.473 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:17.474Z,1368745817.474 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:17.899Z,1368745817.898 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:17.932Z,1368745817.932 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:17.933Z,1368745817.933 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:17.933Z,1368745817.933 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:17.933Z,1368745817.933 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:18.270Z,1368745818.270 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:18.270Z,1368745818.270 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:18.270Z,1368745818.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:18.271Z,1368745818.270 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:18.271Z,1368745818.271 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:18.673Z,1368745818.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:18.673Z,1368745818.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:18.673Z,1368745818.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:18.673Z,1368745818.673 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:19.081Z,1368745819.081 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:19.081Z,1368745819.081 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:19.081Z,1368745819.081 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:19.082Z,1368745819.082 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:19.082Z,1368745819.082 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:19.488Z,1368745819.489 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:19.489Z,1368745819.489 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:19.489Z,1368745819.489 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:19.489Z,1368745819.489 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:19.863Z,1368745819.863 [DAT](INFO): PRE-clean:00:09:13.2649 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.23,-1.821, PHS= 1.199, 1.016, 1.247, |v|= 0.717, RAW= 161.5,-80.1, CAL= 160.5,-79.2, ROT= 239.5,-79.2
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:19.863Z,1368745819.863 [DAT](INFO): POST-clean:00:09:13.2649 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.23,-1.821, PHS= 1.199, 1.016, 1.247, |v|= 0.717, RAW= 161.5,-80.1, CAL= 160.5,-79.2, ROT= 239.5,-79.2
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:19.875Z,1368745819.875 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:19.876Z,1368745819.875 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:19.876Z,1368745819.876 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:19.876Z,1368745819.876 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:19.876Z,1368745819.876 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:19.887Z,1368745819.886 [Reporter](INFO): homing_target_azimuth 231.517759 arcdeg
2013-05-16T23:10:19.887Z,1368745819.887 [Reporter](INFO): homing_target_elevation -85.266531 arcdeg
2013-05-16T23:10:19.888Z,1368745819.888 [Reporter](INFO): DAT.rawAzimuth 161.500000 arcdeg
2013-05-16T23:10:20.274Z,1368745820.274 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:20.324Z,1368745820.324 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:20.324Z,1368745820.324 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:20.324Z,1368745820.324 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:20.324Z,1368745820.325 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:20.672Z,1368745820.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:20.672Z,1368745820.672 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:20.673Z,1368745820.672 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:20.673Z,1368745820.673 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:20.674Z,1368745820.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:21.068Z,1368745821.068 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:21.069Z,1368745821.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:21.069Z,1368745821.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:21.069Z,1368745821.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:21.473Z,1368745821.473 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:21.473Z,1368745821.473 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:21.473Z,1368745821.473 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:21.474Z,1368745821.474 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:21.474Z,1368745821.474 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:21.868Z,1368745821.868 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:21.868Z,1368745821.868 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:21.868Z,1368745821.868 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:21.868Z,1368745821.868 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:22.324Z,1368745822.324 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:22.324Z,1368745822.325 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:22.325Z,1368745822.325 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:22.326Z,1368745822.326 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:22.326Z,1368745822.326 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:22.671Z,1368745822.671 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:22.701Z,1368745822.701 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:22.702Z,1368745822.702 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:22.702Z,1368745822.702 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:22.702Z,1368745822.702 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:23.067Z,1368745823.067 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:23.067Z,1368745823.067 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:23.067Z,1368745823.067 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:23.068Z,1368745823.068 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:23.068Z,1368745823.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:23.471Z,1368745823.471 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:23.471Z,1368745823.471 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:23.471Z,1368745823.471 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:23.471Z,1368745823.471 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:23.871Z,1368745823.871 [DAT](INFO): PRE-clean:00:09:17.2652 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.25, 2.256, PHS= 1.177, 0.982, 1.213, |v|= 0.699, RAW= 158.3,-79.7, CAL= 157.4,-78.8, ROT= 236.4,-78.8
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:23.871Z,1368745823.871 [DAT](INFO): POST-clean:00:09:17.2652 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.25, 2.256, PHS= 1.177, 0.982, 1.213, |v|= 0.699, RAW= 158.3,-79.7, CAL= 157.4,-78.8, ROT= 236.4,-78.8
Compass 323.9
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:23.884Z,1368745823.884 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:23.884Z,1368745823.884 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:23.884Z,1368745823.884 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:23.885Z,1368745823.885 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:23.885Z,1368745823.885 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:23.895Z,1368745823.895 [Reporter](INFO): homing_target_azimuth 229.927254 arcdeg
2013-05-16T23:10:23.896Z,1368745823.896 [Reporter](INFO): homing_target_elevation -84.574619 arcdeg
2013-05-16T23:10:23.897Z,1368745823.897 [Reporter](INFO): DAT.rawAzimuth 158.300003 arcdeg
2013-05-16T23:10:24.283Z,1368745824.283 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:24.283Z,1368745824.283 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:24.284Z,1368745824.284 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:24.284Z,1368745824.284 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:24.673Z,1368745824.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:24.673Z,1368745824.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:24.673Z,1368745824.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:24.674Z,1368745824.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:24.674Z,1368745824.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:25.071Z,1368745825.071 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:25.101Z,1368745825.101 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:25.102Z,1368745825.102 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:25.102Z,1368745825.102 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:25.102Z,1368745825.102 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:25.467Z,1368745825.467 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:25.467Z,1368745825.467 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:25.467Z,1368745825.467 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:25.468Z,1368745825.468 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:25.468Z,1368745825.468 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:25.867Z,1368745825.867 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:25.867Z,1368745825.867 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:25.867Z,1368745825.867 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:25.867Z,1368745825.867 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:26.273Z,1368745826.273 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:26.273Z,1368745826.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:26.273Z,1368745826.273 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:26.274Z,1368745826.274 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:26.274Z,1368745826.274 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:26.668Z,1368745826.668 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:26.668Z,1368745826.668 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:26.668Z,1368745826.668 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:26.668Z,1368745826.668 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:27.067Z,1368745827.067 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:27.067Z,1368745827.067 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:27.067Z,1368745827.067 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:27.068Z,1368745827.068 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:27.068Z,1368745827.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:27.529Z,1368745827.529 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:27.581Z,1368745827.581 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:27.581Z,1368745827.581 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:27.581Z,1368745827.581 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:27.581Z,1368745827.581 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:27.870Z,1368745827.870 [DAT](INFO): PRE-clean:00:09:21.2655 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.45, 3.032, PHS= 1.165, 0.992, 1.197, |v|= 0.693, RAW= 158.3,-80.8, CAL= 157.5,-80.0, ROT= 236.5,-80.0
Compass 323.9
Range 1 to 0 : 2.9 m 
2013-05-16T23:10:27.870Z,1368745827.870 [DAT](INFO): POST-clean:00:09:21.2655 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.45, 3.032, PHS= 1.165, 0.992, 1.197, |v|= 0.693, RAW= 158.3,-80.8, CAL= 157.5,-80.0, ROT= 236.5,-80.0
Compass 323.9
Range 1 to 0 : 2.9 m 
2013-05-16T23:10:27.883Z,1368745827.883 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:27.883Z,1368745827.883 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:27.883Z,1368745827.883 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:27.884Z,1368745827.884 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:27.884Z,1368745827.884 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:27.894Z,1368745827.894 [Reporter](INFO): homing_target_azimuth 222.584486 arcdeg
2013-05-16T23:10:27.895Z,1368745827.895 [Reporter](INFO): homing_target_elevation -85.425121 arcdeg
2013-05-16T23:10:27.895Z,1368745827.895 [Reporter](INFO): DAT.rawAzimuth 158.300003 arcdeg
2013-05-16T23:10:28.287Z,1368745828.287 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:28.287Z,1368745828.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:28.287Z,1368745828.287 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:28.287Z,1368745828.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:28.668Z,1368745828.668 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:28.668Z,1368745828.668 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:28.668Z,1368745828.668 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:28.669Z,1368745828.669 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:28.669Z,1368745828.669 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:29.067Z,1368745829.067 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:29.068Z,1368745829.068 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:29.068Z,1368745829.068 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:29.068Z,1368745829.068 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:29.469Z,1368745829.469 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:29.469Z,1368745829.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:29.469Z,1368745829.469 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:29.470Z,1368745829.470 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:29.470Z,1368745829.470 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:29.871Z,1368745829.871 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:29.902Z,1368745829.902 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:29.902Z,1368745829.902 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:29.902Z,1368745829.902 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:29.902Z,1368745829.902 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:30.272Z,1368745830.272 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:30.272Z,1368745830.272 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:30.273Z,1368745830.273 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:30.274Z,1368745830.274 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:30.274Z,1368745830.274 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:30.688Z,1368745830.688 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:30.688Z,1368745830.688 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:30.688Z,1368745830.688 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:30.688Z,1368745830.688 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:31.081Z,1368745831.081 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:31.082Z,1368745831.082 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:31.082Z,1368745831.082 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:31.083Z,1368745831.082 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:31.083Z,1368745831.083 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:31.468Z,1368745831.468 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:31.469Z,1368745831.469 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:31.469Z,1368745831.469 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:31.469Z,1368745831.469 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:31.864Z,1368745831.864 [DAT](INFO): PRE-clean:00:09:25.2659 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.31,-0.669, PHS= 1.149, 1.009, 1.163, |v|= 0.683, RAW= 154.8,-82.7, CAL= 154.4,-82.1, ROT= 233.4,-82.1
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:31.864Z,1368745831.864 [DAT](INFO): POST-clean:00:09:25.2659 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.31,-0.669, PHS= 1.149, 1.009, 1.163, |v|= 0.683, RAW= 154.8,-82.7, CAL= 154.4,-82.1, ROT= 233.4,-82.1
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:31.877Z,1368745831.877 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:31.877Z,1368745831.877 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:31.877Z,1368745831.877 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:31.878Z,1368745831.878 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:31.878Z,1368745831.878 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:31.888Z,1368745831.888 [Reporter](INFO): homing_target_azimuth 195.031544 arcdeg
2013-05-16T23:10:31.889Z,1368745831.889 [Reporter](INFO): homing_target_elevation -86.332778 arcdeg
2013-05-16T23:10:31.890Z,1368745831.890 [Reporter](INFO): DAT.rawAzimuth 154.800003 arcdeg
2013-05-16T23:10:32.327Z,1368745832.327 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535
2013-05-16T23:10:32.394Z,1368745832.394 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:32.394Z,1368745832.394 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:32.394Z,1368745832.394 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:32.394Z,1368745832.394 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:32.672Z,1368745832.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:32.673Z,1368745832.672 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:32.673Z,1368745832.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:32.674Z,1368745832.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:32.674Z,1368745832.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:33.072Z,1368745833.072 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:33.073Z,1368745833.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:33.073Z,1368745833.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:33.073Z,1368745833.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:33.472Z,1368745833.473 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:33.473Z,1368745833.473 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:33.473Z,1368745833.473 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:33.474Z,1368745833.474 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:33.474Z,1368745833.474 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:33.873Z,1368745833.873 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:33.873Z,1368745833.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:33.873Z,1368745833.873 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:33.873Z,1368745833.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:34.287Z,1368745834.287 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:34.287Z,1368745834.287 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:34.287Z,1368745834.287 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:34.288Z,1368745834.288 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:34.288Z,1368745834.288 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:34.664Z,1368745834.664 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:34.664Z,1368745834.664 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:34.664Z,1368745834.664 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:34.664Z,1368745834.664 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:35.081Z,1368745835.081 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:35.081Z,1368745835.081 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:35.082Z,1368745835.082 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:35.082Z,1368745835.082 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:35.082Z,1368745835.082 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:35.507Z,1368745835.507 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:35.507Z,1368745835.507 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:35.507Z,1368745835.507 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:35.508Z,1368745835.508 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:35.906Z,1368745835.906 [DAT](INFO): PRE-clean:00:09:29.3662 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.12, 2.275, PHS= 1.108, 0.968, 1.130, |v|= 0.660, RAW= 157.3,-82.2, CAL= 156.8,-81.6, ROT= 235.8,-81.6
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:35.906Z,1368745835.906 [DAT](INFO): POST-clean:00:09:29.3662 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.12, 2.275, PHS= 1.108, 0.968, 1.130, |v|= 0.660, RAW= 157.3,-82.2, CAL= 156.8,-81.6, ROT= 235.8,-81.6
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:35.922Z,1368745835.922 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:35.922Z,1368745835.922 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:35.923Z,1368745835.922 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:35.923Z,1368745835.923 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:35.923Z,1368745835.923 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:35.934Z,1368745835.934 [Reporter](INFO): homing_target_azimuth 204.702900 arcdeg
2013-05-16T23:10:35.935Z,1368745835.935 [Reporter](INFO): homing_target_elevation -86.312821 arcdeg
2013-05-16T23:10:35.936Z,1368745835.935 [Reporter](INFO): DAT.rawAzimuth 157.300003 arcdeg
2013-05-16T23:10:36.297Z,1368745836.297 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:36.298Z,1368745836.297 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:36.298Z,1368745836.298 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:36.298Z,1368745836.298 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:36.672Z,1368745836.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:36.673Z,1368745836.672 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:36.673Z,1368745836.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:36.673Z,1368745836.673 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:36.674Z,1368745836.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:37.068Z,1368745837.068 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:37.068Z,1368745837.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:37.069Z,1368745837.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:37.069Z,1368745837.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:37.513Z,1368745837.513 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:37.513Z,1368745837.513 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:37.514Z,1368745837.514 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:37.514Z,1368745837.514 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:37.514Z,1368745837.514 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:37.867Z,1368745837.867 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:37.867Z,1368745837.867 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:37.867Z,1368745837.867 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:37.867Z,1368745837.867 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:38.270Z,1368745838.270 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:38.270Z,1368745838.270 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:38.270Z,1368745838.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:38.271Z,1368745838.271 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:38.271Z,1368745838.271 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:38.673Z,1368745838.672 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:38.673Z,1368745838.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:38.673Z,1368745838.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:38.673Z,1368745838.673 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:39.097Z,1368745839.096 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:39.097Z,1368745839.097 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:39.097Z,1368745839.097 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:39.097Z,1368745839.098 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:39.098Z,1368745839.098 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:39.471Z,1368745839.471 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:39.472Z,1368745839.471 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:39.472Z,1368745839.472 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:39.472Z,1368745839.472 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:39.866Z,1368745839.866 [DAT](INFO): PRE-clean:00:09:33.2665 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.13, 0.496, PHS= 1.097, 0.953, 1.144, |v|= 0.660, RAW= 163.6,-81.2, CAL= 162.5,-80.5, ROT= 241.5,-80.5
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:39.866Z,1368745839.866 [DAT](INFO): POST-clean:00:09:33.2665 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.13, 0.496, PHS= 1.097, 0.953, 1.144, |v|= 0.660, RAW= 163.6,-81.2, CAL= 162.5,-80.5, ROT= 241.5,-80.5
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:39.879Z,1368745839.879 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:39.879Z,1368745839.879 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:39.879Z,1368745839.879 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:39.880Z,1368745839.880 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:39.880Z,1368745839.880 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:39.890Z,1368745839.890 [Reporter](INFO): homing_target_azimuth 225.174876 arcdeg
2013-05-16T23:10:39.891Z,1368745839.891 [Reporter](INFO): homing_target_elevation -86.347142 arcdeg
2013-05-16T23:10:39.892Z,1368745839.892 [Reporter](INFO): DAT.rawAzimuth 163.600006 arcdeg
2013-05-16T23:10:40.287Z,1368745840.287 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:40.287Z,1368745840.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:40.287Z,1368745840.287 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:40.287Z,1368745840.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:40.673Z,1368745840.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:40.673Z,1368745840.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:40.673Z,1368745840.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:40.674Z,1368745840.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:40.674Z,1368745840.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:41.067Z,1368745841.067 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:41.067Z,1368745841.067 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:41.067Z,1368745841.067 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:41.068Z,1368745841.068 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:41.468Z,1368745841.468 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:41.468Z,1368745841.468 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:41.469Z,1368745841.469 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:41.469Z,1368745841.469 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:41.469Z,1368745841.469 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:41.874Z,1368745841.874 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:41.874Z,1368745841.874 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:41.874Z,1368745841.874 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:41.874Z,1368745841.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:42.313Z,1368745842.313 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:42.313Z,1368745842.313 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:42.313Z,1368745842.313 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:42.314Z,1368745842.314 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:42.314Z,1368745842.314 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:42.713Z,1368745842.713 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:42.714Z,1368745842.714 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:42.714Z,1368745842.714 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:42.714Z,1368745842.714 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:43.069Z,1368745843.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:43.069Z,1368745843.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:43.069Z,1368745843.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:43.070Z,1368745843.070 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:43.070Z,1368745843.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:43.470Z,1368745843.470 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:43.470Z,1368745843.470 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:43.470Z,1368745843.470 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:43.470Z,1368745843.470 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:43.864Z,1368745843.864 [DAT](INFO): PRE-clean:00:09:37.2668 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.42, 2.328, PHS= 0.990, 0.923, 1.058, |v|= 0.610, RAW= 180.3,-83.6, CAL= 178.7,-82.9, ROT= 257.7,-82.9
Compass 324.0
Range 1 to 0 : 3.1 m 
2013-05-16T23:10:43.864Z,1368745843.864 [DAT](INFO): POST-clean:00:09:37.2668 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.42, 2.328, PHS= 0.990, 0.923, 1.058, |v|= 0.610, RAW= 180.3,-83.6, CAL= 178.7,-82.9, ROT= 257.7,-82.9
Compass 324.0
Range 1 to 0 : 3.1 m 
2013-05-16T23:10:43.877Z,1368745843.877 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:43.877Z,1368745843.877 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:43.877Z,1368745843.877 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:43.878Z,1368745843.878 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:43.878Z,1368745843.878 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:43.888Z,1368745843.888 [Reporter](INFO): homing_target_azimuth 184.199260 arcdeg
2013-05-16T23:10:43.888Z,1368745843.888 [Reporter](INFO): homing_target_elevation -89.360833 arcdeg
2013-05-16T23:10:43.889Z,1368745843.889 [Reporter](INFO): DAT.rawAzimuth 180.300003 arcdeg
2013-05-16T23:10:44.289Z,1368745844.289 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:44.290Z,1368745844.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:44.290Z,1368745844.290 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:44.290Z,1368745844.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:44.672Z,1368745844.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:44.673Z,1368745844.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:44.673Z,1368745844.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:44.674Z,1368745844.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:44.674Z,1368745844.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:45.073Z,1368745845.073 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:45.073Z,1368745845.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:45.073Z,1368745845.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:45.073Z,1368745845.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:45.508Z,1368745845.508 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:45.508Z,1368745845.509 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:45.509Z,1368745845.509 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:45.509Z,1368745845.509 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:45.510Z,1368745845.510 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:45.873Z,1368745845.873 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:45.873Z,1368745845.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:45.873Z,1368745845.873 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:45.873Z,1368745845.873 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:46.267Z,1368745846.267 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:46.267Z,1368745846.267 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:46.267Z,1368745846.267 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:46.268Z,1368745846.268 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:46.268Z,1368745846.268 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:46.673Z,1368745846.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:46.673Z,1368745846.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:46.673Z,1368745846.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:46.673Z,1368745846.673 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:47.093Z,1368745847.093 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:47.093Z,1368745847.093 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:47.093Z,1368745847.093 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:47.094Z,1368745847.094 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:47.094Z,1368745847.094 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:47.527Z,1368745847.527 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:47.528Z,1368745847.528 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:47.528Z,1368745847.528 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:47.528Z,1368745847.528 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:47.866Z,1368745847.866 [DAT](INFO): PRE-clean:00:09:41.2670 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.18,-0.278, PHS= 1.049, 0.942, 1.112, |v|= 0.639, RAW= 171.6,-82.2, CAL= 170.1,-81.4, ROT= 249.1,-81.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:47.866Z,1368745847.866 [DAT](INFO): POST-clean:00:09:41.2670 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.18,-0.278, PHS= 1.049, 0.942, 1.112, |v|= 0.639, RAW= 171.6,-82.2, CAL= 170.1,-81.4, ROT= 249.1,-81.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:47.879Z,1368745847.879 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:47.879Z,1368745847.879 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:47.879Z,1368745847.879 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:47.880Z,1368745847.880 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:47.880Z,1368745847.880 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:47.891Z,1368745847.891 [Reporter](INFO): homing_target_azimuth 229.134542 arcdeg
2013-05-16T23:10:47.891Z,1368745847.891 [Reporter](INFO): homing_target_elevation -87.916262 arcdeg
2013-05-16T23:10:47.892Z,1368745847.892 [Reporter](INFO): DAT.rawAzimuth 171.600006 arcdeg
2013-05-16T23:10:48.290Z,1368745848.290 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:48.290Z,1368745848.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:48.290Z,1368745848.290 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:48.290Z,1368745848.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:48.701Z,1368745848.701 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:48.701Z,1368745848.701 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:48.701Z,1368745848.701 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:48.702Z,1368745848.702 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:48.702Z,1368745848.702 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:49.069Z,1368745849.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:49.069Z,1368745849.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:49.069Z,1368745849.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:49.069Z,1368745849.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:49.463Z,1368745849.463 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:49.463Z,1368745849.463 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:49.464Z,1368745849.464 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:49.464Z,1368745849.464 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:49.464Z,1368745849.464 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:49.873Z,1368745849.872 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:49.873Z,1368745849.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:49.873Z,1368745849.873 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:49.873Z,1368745849.873 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:50.277Z,1368745850.277 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:50.277Z,1368745850.277 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:50.277Z,1368745850.277 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:50.278Z,1368745850.278 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:50.278Z,1368745850.278 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:50.688Z,1368745850.688 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:50.688Z,1368745850.688 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:50.688Z,1368745850.688 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:50.688Z,1368745850.688 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:51.069Z,1368745851.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:51.069Z,1368745851.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:51.069Z,1368745851.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:51.070Z,1368745851.070 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:51.070Z,1368745851.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:51.476Z,1368745851.476 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:51.477Z,1368745851.477 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:51.477Z,1368745851.477 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:51.477Z,1368745851.477 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:51.910Z,1368745851.910 [DAT](INFO): PRE-clean:00:09:45.3173 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.05,-2.585, PHS= 1.157, 0.971, 1.177, |v|= 0.684, RAW= 155.3,-80.3, CAL= 154.7,-79.5, ROT= 233.7,-79.5
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:51.910Z,1368745851.910 [DAT](INFO): POST-clean:00:09:45.3173 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.05,-2.585, PHS= 1.157, 0.971, 1.177, |v|= 0.684, RAW= 155.3,-80.3, CAL= 154.7,-79.5, ROT= 233.7,-79.5
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:51.926Z,1368745851.926 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:51.926Z,1368745851.926 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:51.926Z,1368745851.926 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:51.927Z,1368745851.927 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:51.927Z,1368745851.927 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:51.938Z,1368745851.938 [Reporter](INFO): homing_target_azimuth 220.300184 arcdeg
2013-05-16T23:10:51.938Z,1368745851.938 [Reporter](INFO): homing_target_elevation -84.811046 arcdeg
2013-05-16T23:10:51.939Z,1368745851.939 [Reporter](INFO): DAT.rawAzimuth 155.300003 arcdeg
2013-05-16T23:10:52.309Z,1368745852.309 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:52.310Z,1368745852.309 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:52.310Z,1368745852.309 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:52.310Z,1368745852.310 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:52.718Z,1368745852.718 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:52.718Z,1368745852.718 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:52.718Z,1368745852.718 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:52.719Z,1368745852.718 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:52.719Z,1368745852.719 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:53.069Z,1368745853.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:53.069Z,1368745853.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:53.069Z,1368745853.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:53.069Z,1368745853.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:53.468Z,1368745853.468 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:53.468Z,1368745853.468 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:53.468Z,1368745853.468 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:53.469Z,1368745853.469 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:53.469Z,1368745853.469 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:53.869Z,1368745853.869 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:53.869Z,1368745853.869 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:53.869Z,1368745853.869 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:53.869Z,1368745853.869 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:54.269Z,1368745854.270 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:54.270Z,1368745854.270 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:54.270Z,1368745854.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:54.270Z,1368745854.270 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:54.271Z,1368745854.270 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:54.673Z,1368745854.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:54.674Z,1368745854.674 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:54.674Z,1368745854.674 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:54.674Z,1368745854.674 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:55.109Z,1368745855.109 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:55.109Z,1368745855.109 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:55.110Z,1368745855.110 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:55.110Z,1368745855.110 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:55.110Z,1368745855.110 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:55.470Z,1368745855.470 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:55.470Z,1368745855.470 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:55.470Z,1368745855.470 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:55.470Z,1368745855.470 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:55.864Z,1368745855.864 [DAT](INFO): PRE-clean:00:09:49.3176 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.22, 2.811, PHS= 1.160, 0.972, 1.169, |v|= 0.683, RAW= 152.1,-80.5, CAL= 151.8,-79.8, ROT= 230.8,-79.8
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:55.864Z,1368745855.864 [DAT](INFO): POST-clean:00:09:49.3176 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.22, 2.811, PHS= 1.160, 0.972, 1.169, |v|= 0.683, RAW= 152.1,-80.5, CAL= 151.8,-79.8, ROT= 230.8,-79.8
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:55.877Z,1368745855.877 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:55.877Z,1368745855.877 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:55.877Z,1368745855.877 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:55.878Z,1368745855.878 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:55.878Z,1368745855.878 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:55.888Z,1368745855.888 [Reporter](INFO): homing_target_azimuth 215.540785 arcdeg
2013-05-16T23:10:55.888Z,1368745855.888 [Reporter](INFO): homing_target_elevation -84.621918 arcdeg
2013-05-16T23:10:55.889Z,1368745855.889 [Reporter](INFO): DAT.rawAzimuth 152.100006 arcdeg
2013-05-16T23:10:56.289Z,1368745856.289 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:56.290Z,1368745856.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:56.290Z,1368745856.290 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:56.290Z,1368745856.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:56.672Z,1368745856.672 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:56.673Z,1368745856.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:56.673Z,1368745856.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:56.674Z,1368745856.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:56.674Z,1368745856.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:57.069Z,1368745857.069 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:57.069Z,1368745857.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:57.069Z,1368745857.069 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:57.069Z,1368745857.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:57.469Z,1368745857.469 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:57.469Z,1368745857.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:57.469Z,1368745857.469 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:57.470Z,1368745857.470 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:57.470Z,1368745857.470 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:57.920Z,1368745857.920 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:57.920Z,1368745857.920 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:57.920Z,1368745857.920 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:57.920Z,1368745857.921 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:58.270Z,1368745858.270 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:58.270Z,1368745858.270 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:58.270Z,1368745858.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:58.271Z,1368745858.271 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:58.271Z,1368745858.271 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:58.705Z,1368745858.705 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:58.706Z,1368745858.706 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:58.706Z,1368745858.706 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:58.706Z,1368745858.706 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:59.065Z,1368745859.065 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:59.065Z,1368745859.065 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:59.065Z,1368745859.066 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:59.066Z,1368745859.066 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:59.066Z,1368745859.066 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:59.470Z,1368745859.470 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:10:59.470Z,1368745859.470 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:10:59.470Z,1368745859.470 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:10:59.470Z,1368745859.470 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:10:59.866Z,1368745859.866 [DAT](INFO): PRE-clean:00:09:53.3178 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.00,-3.108, PHS= 1.115, 0.972, 1.120, |v|= 0.660, RAW= 152.0,-82.6, CAL= 151.7,-82.0, ROT= 230.7,-82.0
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:59.866Z,1368745859.866 [DAT](INFO): POST-clean:00:09:53.3178 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.00,-3.108, PHS= 1.115, 0.972, 1.120, |v|= 0.660, RAW= 152.0,-82.6, CAL= 151.7,-82.0, ROT= 230.7,-82.0
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:10:59.879Z,1368745859.879 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:10:59.879Z,1368745859.879 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:10:59.879Z,1368745859.879 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:10:59.880Z,1368745859.880 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:10:59.880Z,1368745859.880 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:10:59.891Z,1368745859.891 [Reporter](INFO): homing_target_azimuth 194.836214 arcdeg
2013-05-16T23:10:59.891Z,1368745859.891 [Reporter](INFO): homing_target_elevation -85.886050 arcdeg
2013-05-16T23:10:59.892Z,1368745859.892 [Reporter](INFO): DAT.rawAzimuth 152.000000 arcdeg
2013-05-16T23:11:00.289Z,1368745860.289 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:00.289Z,1368745860.289 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:00.289Z,1368745860.289 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:00.290Z,1368745860.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:00.667Z,1368745860.667 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:00.667Z,1368745860.667 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:00.667Z,1368745860.667 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:00.668Z,1368745860.668 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:00.668Z,1368745860.668 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:01.073Z,1368745861.073 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:01.073Z,1368745861.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:01.073Z,1368745861.073 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:01.073Z,1368745861.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:01.467Z,1368745861.467 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:01.467Z,1368745861.467 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:01.467Z,1368745861.467 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:01.468Z,1368745861.468 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:01.468Z,1368745861.468 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:01.901Z,1368745861.901 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:01.901Z,1368745861.901 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:01.901Z,1368745861.901 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:01.902Z,1368745861.902 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:02.273Z,1368745862.273 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:02.273Z,1368745862.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:02.273Z,1368745862.273 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:02.274Z,1368745862.274 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:02.274Z,1368745862.274 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:02.673Z,1368745862.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:02.673Z,1368745862.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:02.673Z,1368745862.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:02.673Z,1368745862.673 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:03.117Z,1368745863.117 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:03.117Z,1368745863.117 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:03.117Z,1368745863.118 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:03.118Z,1368745863.118 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:03.118Z,1368745863.118 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:03.499Z,1368745863.499 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:03.500Z,1368745863.500 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:03.500Z,1368745863.500 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:03.500Z,1368745863.500 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:03.878Z,1368745863.878 [DAT](INFO): PRE-clean:00:09:57.3181 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.50,-0.458, PHS= 1.157, 0.991, 1.124, |v|= 0.674, RAW= 139.0,-82.4, CAL= 139.5,-82.0, ROT= 218.5,-82.0
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:03.878Z,1368745863.878 [DAT](INFO): POST-clean:00:09:57.3181 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.50,-0.458, PHS= 1.157, 0.991, 1.124, |v|= 0.674, RAW= 139.0,-82.4, CAL= 139.5,-82.0, ROT= 218.5,-82.0
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:03.891Z,1368745863.891 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:03.891Z,1368745863.891 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:03.891Z,1368745863.891 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:03.892Z,1368745863.892 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:03.892Z,1368745863.892 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:03.902Z,1368745863.902 [Reporter](INFO): homing_target_azimuth 187.199475 arcdeg
2013-05-16T23:11:03.903Z,1368745863.903 [Reporter](INFO): homing_target_elevation -84.450877 arcdeg
2013-05-16T23:11:03.904Z,1368745863.904 [Reporter](INFO): DAT.rawAzimuth 139.000000 arcdeg
2013-05-16T23:11:04.287Z,1368745864.287 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:04.287Z,1368745864.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:04.287Z,1368745864.287 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:04.287Z,1368745864.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:04.673Z,1368745864.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:04.673Z,1368745864.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:04.673Z,1368745864.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:04.674Z,1368745864.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:04.674Z,1368745864.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:05.109Z,1368745865.109 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:05.110Z,1368745865.110 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:05.110Z,1368745865.110 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:05.110Z,1368745865.110 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:05.469Z,1368745865.469 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:05.469Z,1368745865.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:05.469Z,1368745865.469 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:05.470Z,1368745865.470 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:05.470Z,1368745865.470 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:05.870Z,1368745865.870 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:05.870Z,1368745865.870 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:05.870Z,1368745865.870 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:05.870Z,1368745865.870 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:06.268Z,1368745866.267 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:06.268Z,1368745866.268 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:06.268Z,1368745866.268 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:06.268Z,1368745866.268 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:06.269Z,1368745866.269 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:06.673Z,1368745866.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:06.673Z,1368745866.673 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:06.673Z,1368745866.673 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:06.674Z,1368745866.674 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:07.101Z,1368745867.101 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:07.101Z,1368745867.101 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:07.101Z,1368745867.101 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:07.102Z,1368745867.102 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:07.102Z,1368745867.102 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:07.476Z,1368745867.476 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:07.477Z,1368745867.477 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:07.477Z,1368745867.477 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:07.477Z,1368745867.477 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:07.870Z,1368745867.870 [DAT](INFO): PRE-clean:00:10:01.3184 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.00, 1.810, PHS= 1.148, 0.975, 1.116, |v|= 0.668, RAW= 140.1,-82.0, CAL= 140.6,-81.4, ROT= 219.6,-81.4
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:07.870Z,1368745867.870 [DAT](INFO): POST-clean:00:10:01.3184 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.00, 1.810, PHS= 1.148, 0.975, 1.116, |v|= 0.668, RAW= 140.1,-82.0, CAL= 140.6,-81.4, ROT= 219.6,-81.4
Compass 324.1
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:07.883Z,1368745867.883 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:07.884Z,1368745867.884 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:07.884Z,1368745867.884 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:07.884Z,1368745867.884 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:07.885Z,1368745867.885 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:07.895Z,1368745867.895 [Reporter](INFO): homing_target_azimuth 190.791157 arcdeg
2013-05-16T23:11:07.895Z,1368745867.895 [Reporter](INFO): homing_target_elevation -84.245302 arcdeg
2013-05-16T23:11:07.896Z,1368745867.896 [Reporter](INFO): DAT.rawAzimuth 140.100006 arcdeg
2013-05-16T23:11:08.393Z,1368745868.393 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:08.394Z,1368745868.394 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:08.394Z,1368745868.394 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:08.394Z,1368745868.394 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:08.701Z,1368745868.701 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:08.701Z,1368745868.701 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:08.701Z,1368745868.701 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:08.702Z,1368745868.702 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:08.702Z,1368745868.702 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:09.066Z,1368745869.066 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:09.066Z,1368745869.066 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:09.066Z,1368745869.066 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:09.066Z,1368745869.066 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:09.473Z,1368745869.473 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:09.473Z,1368745869.473 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:09.473Z,1368745869.473 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:09.474Z,1368745869.474 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:09.474Z,1368745869.474 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:09.873Z,1368745869.873 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:09.873Z,1368745869.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:09.873Z,1368745869.873 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:09.873Z,1368745869.873 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:10.269Z,1368745870.269 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:10.269Z,1368745870.270 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:10.270Z,1368745870.270 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:10.270Z,1368745870.270 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:10.270Z,1368745870.270 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:10.673Z,1368745870.673 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:10.674Z,1368745870.674 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:10.674Z,1368745870.674 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:10.674Z,1368745870.674 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:11.067Z,1368745871.067 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:11.068Z,1368745871.068 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:11.068Z,1368745871.068 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:11.068Z,1368745871.068 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:11.068Z,1368745871.068 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:11.470Z,1368745871.470 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:11.471Z,1368745871.471 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:11.471Z,1368745871.471 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:11.471Z,1368745871.471 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:11.906Z,1368745871.906 [DAT](INFO): PRE-clean:00:10:05.4187 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.44,-0.316, PHS= 1.184, 0.978, 1.128, |v|= 0.680, RAW= 134.9,-80.9, CAL= 135.8,-80.4, ROT= 214.8,-80.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:11.906Z,1368745871.906 [DAT](INFO): POST-clean:00:10:05.4187 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62 0.44,-0.316, PHS= 1.184, 0.978, 1.128, |v|= 0.680, RAW= 134.9,-80.9, CAL= 135.8,-80.4, ROT= 214.8,-80.4
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:11.922Z,1368745871.922 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:11.923Z,1368745871.922 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:11.923Z,1368745871.923 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:11.923Z,1368745871.923 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:11.923Z,1368745871.923 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:11.934Z,1368745871.934 [Reporter](INFO): homing_target_azimuth 194.326422 arcdeg
2013-05-16T23:11:11.934Z,1368745871.934 [Reporter](INFO): homing_target_elevation -83.020205 arcdeg
2013-05-16T23:11:11.935Z,1368745871.935 [Reporter](INFO): DAT.rawAzimuth 134.899994 arcdeg
2013-05-16T23:11:12.289Z,1368745872.289 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:12.290Z,1368745872.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:12.290Z,1368745872.290 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:12.290Z,1368745872.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:12.673Z,1368745872.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:12.673Z,1368745872.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:12.674Z,1368745872.674 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:12.674Z,1368745872.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:12.674Z,1368745872.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:13.118Z,1368745873.118 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:13.118Z,1368745873.118 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:13.118Z,1368745873.118 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:13.118Z,1368745873.118 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:13.467Z,1368745873.467 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:13.467Z,1368745873.467 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:13.467Z,1368745873.467 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:13.468Z,1368745873.467 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:13.468Z,1368745873.468 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:13.867Z,1368745873.867 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:13.867Z,1368745873.867 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:13.867Z,1368745873.867 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:13.867Z,1368745873.867 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:14.273Z,1368745874.273 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:14.273Z,1368745874.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:14.273Z,1368745874.273 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:14.274Z,1368745874.274 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:14.274Z,1368745874.274 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:14.667Z,1368745874.667 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:14.668Z,1368745874.668 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:14.668Z,1368745874.668 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:14.668Z,1368745874.668 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:15.102Z,1368745875.102 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:15.102Z,1368745875.102 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:15.102Z,1368745875.102 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:15.102Z,1368745875.102 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:15.103Z,1368745875.103 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:15.472Z,1368745875.472 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:15.472Z,1368745875.472 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:15.472Z,1368745875.472 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:15.472Z,1368745875.472 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:15.864Z,1368745875.864 [DAT](INFO): PRE-clean:00:10:09.3189 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.04, 1.941, PHS= 1.144, 0.987, 1.093, |v|= 0.663, RAW= 131.5,-83.0, CAL= 132.4,-82.6, ROT= 211.4,-82.6
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:15.864Z,1368745875.864 [DAT](INFO): POST-clean:00:10:09.3189 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.04, 1.941, PHS= 1.144, 0.987, 1.093, |v|= 0.663, RAW= 131.5,-83.0, CAL= 132.4,-82.6, ROT= 211.4,-82.6
Compass 324.0
Range 1 to 0 : 3.0 m 
2013-05-16T23:11:15.877Z,1368745875.877 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:15.877Z,1368745875.878 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:15.878Z,1368745875.878 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:15.878Z,1368745875.878 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:15.878Z,1368745875.878 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:15.888Z,1368745875.888 [Reporter](INFO): homing_target_azimuth 176.960243 arcdeg
2013-05-16T23:11:15.889Z,1368745875.889 [Reporter](INFO): homing_target_elevation -83.859109 arcdeg
2013-05-16T23:11:15.890Z,1368745875.890 [Reporter](INFO): DAT.rawAzimuth 131.500000 arcdeg
2013-05-16T23:11:16.287Z,1368745876.287 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:16.287Z,1368745876.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:16.287Z,1368745876.287 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:16.287Z,1368745876.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:16.673Z,1368745876.673 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:16.673Z,1368745876.673 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:16.673Z,1368745876.673 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:16.674Z,1368745876.674 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:16.674Z,1368745876.674 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:17.067Z,1368745877.067 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:17.067Z,1368745877.067 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:17.067Z,1368745877.067 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:17.067Z,1368745877.067 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:17.472Z,1368745877.473 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:17.473Z,1368745877.473 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:17.473Z,1368745877.473 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:17.474Z,1368745877.474 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:17.474Z,1368745877.474 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:17.873Z,1368745877.874 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:17.874Z,1368745877.874 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:17.874Z,1368745877.874 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:17.874Z,1368745877.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:18.369Z,1368745878.369 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:18.369Z,1368745878.369 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:18.370Z,1368745878.370 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:18.370Z,1368745878.370 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:18.370Z,1368745878.370 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:18.672Z,1368745878.672 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:18.672Z,1368745878.672 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:18.672Z,1368745878.672 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:18.672Z,1368745878.672 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:19.068Z,1368745879.069 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:19.069Z,1368745879.069 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:19.069Z,1368745879.069 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:19.070Z,1368745879.070 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:19.070Z,1368745879.070 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:19.475Z,1368745879.475 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:19.475Z,1368745879.476 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:19.476Z,1368745879.476 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:19.476Z,1368745879.476 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:19.932Z,1368745879.931 [DAT](INFO): PRE-clean:00:10:13.3193 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.26,-2.619, PHS= 1.157, 0.999, 1.105, |v|= 0.671, RAW= 130.9,-83.0, CAL= 131.8,-82.6, ROT= 210.8,-82.6
Compass 324.1
Range 1 to 0 : 3.1 m 
2013-05-16T23:11:19.932Z,1368745879.932 [DAT](INFO): POST-clean:00:10:13.3193 , LVL= 32752, 32753, 32754, 32755, AGC=  65, IDX= 62-0.26,-2.619, PHS= 1.157, 0.999, 1.105, |v|= 0.671, RAW= 130.9,-83.0, CAL= 131.8,-82.6, ROT= 210.8,-82.6
Compass 324.1
Range 1 to 0 : 3.1 m 
2013-05-16T23:11:20.008Z,1368745880.008 [dat_on:TestDrive:Data] Running Loop=1
2013-05-16T23:11:20.008Z,1368745880.008 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2013-05-16T23:11:20.008Z,1368745880.008 [dat_on:TestDrive:Data:A] Running Loop=1
2013-05-16T23:11:20.010Z,1368745880.010 [dat_on:TestDrive:Data:A] Stopped
2013-05-16T23:11:20.010Z,1368745880.010 [dat_on:TestDrive:Data:B] Running Loop=1
2013-05-16T23:11:20.032Z,1368745880.032 [Reporter](INFO): homing_target_azimuth 176.297633 arcdeg
2013-05-16T23:11:20.033Z,1368745880.033 [Reporter](INFO): homing_target_elevation -83.851856 arcdeg
2013-05-16T23:11:20.033Z,1368745880.033 [Reporter](INFO): DAT.rawAzimuth 130.899994 arcdeg
2013-05-16T23:11:20.266Z,1368745880.266 [CommandLine](IMPORTANT): got command stop
2013-05-16T23:11:20.340Z,1368745880.340 [dat_on:TestDrive:Data:B] Stopped
2013-05-16T23:11:20.340Z,1368745880.340 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2013-05-16T23:11:20.340Z,1368745880.340 [dat_on:TestDrive:Data] Stopped
2013-05-16T23:11:20.340Z,1368745880.340 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2013-05-16T23:11:20.366Z,1368745880.365 [dat_on] Stopped
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on](INFO): Aggregate::uninitialize dat_on
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:A.Pitch] Stopped
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:TestDrive] Stopped
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:TestDrive](INFO): Aggregate::uninitialize dat_on:TestDrive
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:TestDrive:A] Stopped
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:TestDrive:C.Wait] Stopped
2013-05-16T23:11:20.366Z,1368745880.366 [dat_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2013-05-16T23:11:20.709Z,1368745880.709 [MissionManager](IMPORTANT): Started mission Default
2013-05-16T23:11:20.709Z,1368745880.709 [Default] Running Loop=1
2013-05-16T23:11:20.710Z,1368745880.710 [Default](INFO): Aggregate::initialize Default
2013-05-16T23:11:20.710Z,1368745880.710 [Default:D.SetSpeed] Running Loop=1
2013-05-16T23:11:20.710Z,1368745880.710 [Default:D.SetSpeed](DEBUG): Initialize.
2013-05-16T23:11:20.710Z,1368745880.710 [Default:E.GoToSurface] Running Loop=1
2013-05-16T23:11:20.710Z,1368745880.710 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:11:20.710Z,1368745880.710 [Default:Iridium] Running Loop=1
2013-05-16T23:11:20.710Z,1368745880.710 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-16T23:11:20.710Z,1368745880.710 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-16T23:11:20.710Z,1368745880.710 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-16T23:11:20.711Z,1368745880.711 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-16T23:11:20.711Z,1368745880.711 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:11:20.713Z,1368745880.713 [Default:Iridium:B.GoToSurface] Stopped
2013-05-16T23:11:20.713Z,1368745880.713 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:11:20.713Z,1368745880.713 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS] Running Loop=1
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-16T23:11:20.718Z,1368745880.718 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T23:11:20.719Z,1368745880.719 [Default:GPS:B.GoToSurface] Stopped
2013-05-16T23:11:20.719Z,1368745880.719 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:11:20.719Z,1368745880.719 [Default:GPS:Read_GPS] Running Loop=1
2013-05-16T23:11:21.064Z,1368745881.064 [DAT](INFO): Powering down
2013-05-16T23:11:21.529Z,1368745881.529 [NAL9602](INFO): Powering up
2013-05-16T23:11:27.106Z,1368745887.106 [CommandLine](IMPORTANT): got command quit
2013-05-16T23:11:28.273Z,1368745888.273 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-05-16T23:11:28.273Z,1368745888.273 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-05-16T23:11:28.481Z,1368745888.481 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-05-16T23:11:28.842Z,1368745888.842 [WetLabsBB2FL](INFO): Powering down
2013-05-16T23:11:28.861Z,1368745888.861 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-05-16T23:11:29.082Z,1368745889.082 [CTD_NeilBrown](INFO): Powering down
2013-05-16T23:11:29.089Z,1368745889.089 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-05-16T23:11:29.318Z,1368745889.318 [DVL_micro](INFO): uninitialize:Powering down
2013-05-16T23:11:29.333Z,1368745889.333 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-05-16T23:11:29.586Z,1368745889.586 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-05-16T23:11:29.594Z,1368745889.594 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-05-16T23:11:29.647Z,1368745889.647 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-05-16T23:11:29.658Z,1368745889.658 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-05-16T23:11:29.694Z,1368745889.694 [controlThread](DEBUG): Uninitializing ControlThread
2013-05-16T23:11:29.694Z,1368745889.694 [AHRS_sp3003D](INFO): Powering down
2013-05-16T23:11:29.782Z,1368745889.782 [NAL9602](INFO): Powering down
2013-05-16T23:11:29.784Z,1368745889.784 [DAT](INFO): Powering down
2013-05-16T23:11:29.785Z,1368745889.785 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-16T23:11:29.786Z,1368745889.786 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-05-16T23:11:29.787Z,1368745889.787 [Default] Stopped
2013-05-16T23:11:29.787Z,1368745889.787 [Default](INFO): Aggregate::uninitialize Default
2013-05-16T23:11:29.787Z,1368745889.787 [Default:GPS] Stopped
2013-05-16T23:11:29.787Z,1368745889.787 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-16T23:11:29.787Z,1368745889.787 [Default:GPS:A.SetSpeed] Stopped
2013-05-16T23:11:29.787Z,1368745889.787 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:11:29.787Z,1368745889.787 [Default:GPS:Read_GPS] Stopped
2013-05-16T23:11:29.787Z,1368745889.787 [Default:Iridium] Stopped
2013-05-16T23:11:29.788Z,1368745889.788 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-16T23:11:29.788Z,1368745889.788 [Default:Iridium:A.SetSpeed] Stopped
2013-05-16T23:11:29.788Z,1368745889.788 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:11:29.788Z,1368745889.788 [Default:Iridium:Read_Iridium] Stopped
2013-05-16T23:11:29.788Z,1368745889.788 [Default:D.SetSpeed] Stopped
2013-05-16T23:11:29.788Z,1368745889.788 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-05-16T23:11:29.788Z,1368745889.788 [Default:E.GoToSurface] Stopped
2013-05-16T23:11:29.788Z,1368745889.788 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T23:11:29.792Z,1368745889.792 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-05-16T23:11:29.793Z,1368745889.793 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-05-16T23:11:29.793Z,1368745889.793 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-05-16T23:11:29.794Z,1368745889.793 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-05-16T23:11:29.794Z,1368745889.794 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-05-16T23:11:29.794Z,1368745889.794 [BuoyancyServo](INFO): Powering down
2013-05-16T23:11:29.806Z,1368745889.806 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-05-16T23:11:29.806Z,1368745889.806 [ElevatorServo](INFO): Powering down
2013-05-16T23:11:29.807Z,1368745889.807 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-05-16T23:11:29.807Z,1368745889.807 [MassServo](INFO): Powering down
2013-05-16T23:11:29.808Z,1368745889.807 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-05-16T23:11:29.808Z,1368745889.808 [RudderServo](INFO): Powering down
2013-05-16T23:11:29.808Z,1368745889.808 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-05-16T23:11:29.809Z,1368745889.809 [ThrusterServo](INFO): Powering down
2013-05-16T23:11:29.810Z,1368745889.810 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-05-16T23:11:29.810Z,1368745889.810 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-05-16T23:11:29.810Z,1368745889.810 [CBIT](DEBUG): Uninitialize CBIT Component.