2013-04-23T16:28:43.941Z,1366734523.941 [Supervisor](DEBUG): Initializing supervisor. 2013-04-23T16:28:43.943Z,1366734523.943 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-04-23T16:28:43.944Z,1366734523.944 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-04-23T16:28:43.945Z,1366734523.945 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-04-23T16:28:43.963Z,1366734523.963 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-04-23T16:28:43.973Z,1366734523.973 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-04-23T16:28:43.974Z,1366734523.974 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-04-23T16:28:43.975Z,1366734523.975 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-04-23T16:28:43.976Z,1366734523.976 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-04-23T16:28:43.976Z,1366734523.977 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-04-23T16:28:43.981Z,1366734523.981 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-04-23T16:28:44.335Z,1366734524.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-04-23T16:28:44.336Z,1366734524.336 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-04-23T16:28:44.530Z,1366734524.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-04-23T16:28:44.531Z,1366734524.531 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-04-23T16:28:44.617Z,1366734524.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-04-23T16:28:44.619Z,1366734524.619 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-04-23T16:28:44.799Z,1366734524.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-04-23T16:28:44.800Z,1366734524.800 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-04-23T16:28:44.940Z,1366734524.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-04-23T16:28:44.942Z,1366734524.942 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-04-23T16:28:45.175Z,1366734525.175 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-04-23T16:28:45.175Z,1366734525.175 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-04-23T16:28:45.347Z,1366734525.347 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-04-23T16:28:45.413Z,1366734525.413 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-04-23T16:28:45.676Z,1366734525.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-04-23T16:28:45.678Z,1366734525.678 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-04-23T16:28:45.779Z,1366734525.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-04-23T16:28:45.780Z,1366734525.780 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-04-23T16:28:46.175Z,1366734526.175 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-04-23T16:28:46.176Z,1366734526.176 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-04-23T16:28:46.293Z,1366734526.293 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-04-23T16:28:46.294Z,1366734526.294 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-04-23T16:28:46.380Z,1366734526.381 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-04-23T16:28:46.384Z,1366734526.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-04-23T16:28:46.492Z,1366734526.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-04-23T16:28:46.621Z,1366734526.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-04-23T16:28:46.708Z,1366734526.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-04-23T16:28:46.813Z,1366734526.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-04-23T16:28:46.914Z,1366734526.914 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-04-23T16:28:47.033Z,1366734527.033 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-04-23T16:28:47.128Z,1366734527.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-04-23T16:28:47.217Z,1366734527.217 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2013-04-23T16:28:47.249Z,1366734527.249 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-04-23T16:28:47.431Z,1366734527.431 [InternalSim] Loaded 2013-04-23T16:28:47.431Z,1366734527.431 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-04-23T16:28:47.432Z,1366734527.432 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-04-23T16:28:47.433Z,1366734527.433 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-04-23T16:28:47.513Z,1366734527.513 [SBIT](DEBUG): Construct Startup Built In Test. 2013-04-23T16:28:47.543Z,1366734527.543 [SBIT] Loaded 2013-04-23T16:28:47.543Z,1366734527.543 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-04-23T16:28:47.544Z,1366734527.544 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-04-23T16:28:47.573Z,1366734527.573 [IBIT] Loaded 2013-04-23T16:28:47.573Z,1366734527.573 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-04-23T16:28:47.577Z,1366734527.577 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-04-23T16:28:47.694Z,1366734527.694 [CBIT] Loaded 2013-04-23T16:28:47.695Z,1366734527.694 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-04-23T16:28:47.695Z,1366734527.695 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-04-23T16:28:47.696Z,1366734527.695 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-04-23T16:28:47.864Z,1366734527.864 [BuoyancyServo] Loaded 2013-04-23T16:28:47.864Z,1366734527.864 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-04-23T16:28:47.876Z,1366734527.876 [ElevatorServo] Loaded 2013-04-23T16:28:47.877Z,1366734527.877 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-04-23T16:28:47.888Z,1366734527.888 [MassServo] Loaded 2013-04-23T16:28:47.889Z,1366734527.889 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-04-23T16:28:47.901Z,1366734527.901 [RudderServo] Loaded 2013-04-23T16:28:47.901Z,1366734527.901 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-04-23T16:28:47.913Z,1366734527.913 [ThrusterServo] Loaded 2013-04-23T16:28:47.913Z,1366734527.913 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-04-23T16:28:47.914Z,1366734527.914 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-04-23T16:28:47.914Z,1366734527.914 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-04-23T16:28:47.947Z,1366734527.947 [DepthRateCalculator] Loaded 2013-04-23T16:28:47.948Z,1366734527.948 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-04-23T16:28:51.045Z,1366734531.046 [HFRadarModelCalc] Loaded 2013-04-23T16:28:51.046Z,1366734531.046 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-04-23T16:28:51.062Z,1366734531.062 [NavChart] Loaded 2013-04-23T16:28:51.062Z,1366734531.062 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-04-23T16:28:51.068Z,1366734531.068 [PitchRateCalculator] Loaded 2013-04-23T16:28:51.068Z,1366734531.068 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-04-23T16:28:51.074Z,1366734531.074 [SpeedCalculator] Loaded 2013-04-23T16:28:51.075Z,1366734531.075 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-04-23T16:28:51.089Z,1366734531.089 [TempGradientCalculator] Loaded 2013-04-23T16:28:51.090Z,1366734531.089 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-04-23T16:28:51.095Z,1366734531.095 [YawRateCalculator] Loaded 2013-04-23T16:28:51.096Z,1366734531.096 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-04-23T16:28:51.136Z,1366734531.136 [Navigation] Loaded 2013-04-23T16:28:51.137Z,1366734531.136 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-04-23T16:28:51.137Z,1366734531.137 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-04-23T16:28:51.138Z,1366734531.138 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-04-23T16:28:51.488Z,1366734531.488 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-04-23T16:28:51.489Z,1366734531.489 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-04-23T16:28:51.539Z,1366734531.539 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-04-23T16:28:51.539Z,1366734531.539 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-04-23T16:28:51.660Z,1366734531.659 [VerticalControl](DEBUG): Construct VerticalControl. 2013-04-23T16:28:51.841Z,1366734531.841 [VerticalControl] Loaded 2013-04-23T16:28:51.841Z,1366734531.841 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-04-23T16:28:51.842Z,1366734531.842 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-04-23T16:28:51.933Z,1366734531.933 [HorizontalControl] Loaded 2013-04-23T16:28:51.933Z,1366734531.933 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-04-23T16:28:51.934Z,1366734531.934 [SpeedControl](DEBUG): Construct SpeedControl. 2013-04-23T16:28:51.936Z,1366734531.936 [SpeedControl] Loaded 2013-04-23T16:28:51.936Z,1366734531.936 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-04-23T16:28:51.937Z,1366734531.937 [LoopControl](DEBUG): Construct LoopControl. 2013-04-23T16:28:51.938Z,1366734531.938 [LoopControl] Loaded 2013-04-23T16:28:51.938Z,1366734531.938 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-04-23T16:28:51.939Z,1366734531.939 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-04-23T16:28:51.939Z,1366734531.939 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-04-23T16:28:51.954Z,1366734531.954 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-04-23T16:28:51.958Z,1366734531.958 [AsyncPiEstimator] Loaded 2013-04-23T16:28:51.959Z,1366734531.959 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-04-23T16:28:51.966Z,1366734531.966 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0 2013-04-23T16:28:51.967Z,1366734531.967 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-04-23T16:28:51.968Z,1366734531.968 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-04-23T16:28:52.263Z,1366734532.263 [AHRS_sp3003D] Loaded 2013-04-23T16:28:52.264Z,1366734532.264 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-04-23T16:28:52.797Z,1366734532.797 [Batt_Ocean_Server] Loaded 2013-04-23T16:28:52.797Z,1366734532.797 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-04-23T16:28:52.822Z,1366734532.822 [Depth_Keller] Loaded 2013-04-23T16:28:52.823Z,1366734532.823 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-04-23T16:28:52.841Z,1366734532.841 [DropWeight] Loaded 2013-04-23T16:28:52.841Z,1366734532.841 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-04-23T16:28:53.234Z,1366734533.234 [DVL_micro] Loaded 2013-04-23T16:28:53.234Z,1366734533.234 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-04-23T16:28:53.235Z,1366734533.235 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406BF4E0 2013-04-23T16:28:53.419Z,1366734533.420 [NAL9602] Loaded 2013-04-23T16:28:53.426Z,1366734533.425 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-04-23T16:28:53.560Z,1366734533.560 [Onboard] Loaded 2013-04-23T16:28:53.560Z,1366734533.560 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-04-23T16:28:53.567Z,1366734533.567 [Radio_Freewave] Loaded 2013-04-23T16:28:53.567Z,1366734533.567 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-04-23T16:28:53.842Z,1366734533.842 [DAT] Loaded 2013-04-23T16:28:53.842Z,1366734533.842 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2013-04-23T16:28:53.843Z,1366734533.843 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-04-23T16:28:53.843Z,1366734533.843 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-04-23T16:28:53.952Z,1366734533.952 [CTD_NeilBrown] Loaded 2013-04-23T16:28:53.952Z,1366734533.952 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-04-23T16:28:53.953Z,1366734533.954 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407114E0 2013-04-23T16:28:54.016Z,1366734534.016 [PAR_Licor] Loaded 2013-04-23T16:28:54.017Z,1366734534.017 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2013-04-23T16:28:54.108Z,1366734534.108 [WetLabsBB2FL] Loaded 2013-04-23T16:28:54.108Z,1366734534.108 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-04-23T16:28:54.115Z,1366734534.115 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407414E0 2013-04-23T16:28:54.116Z,1366734534.116 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-04-23T16:28:54.118Z,1366734534.118 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-04-23T16:28:54.119Z,1366734534.119 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-04-23T16:28:54.129Z,1366734534.129 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-04-23T16:28:54.139Z,1366734534.138 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407714E0 2013-04-23T16:28:54.143Z,1366734534.143 [Supervisor](DEBUG): Running supervisor. 2013-04-23T16:28:54.151Z,1366734534.151 [CommandLine](INFO): Thread ID is 8627 2013-04-23T16:28:54.153Z,1366734534.153 [controlThread](INFO): Thread ID is 8626 2013-04-23T16:28:54.154Z,1366734534.154 [controlThread](DEBUG): Initializing ControlThread 2013-04-23T16:28:54.154Z,1366734534.154 [CycleStarter](INFO): Thread ID is 8625 2013-04-23T16:28:54.154Z,1366734534.154 [InternalSim](DEBUG): InternalSim initializing... 2013-04-23T16:28:54.199Z,1366734534.199 [logger](INFO): Thread ID is 8628 2013-04-23T16:28:54.447Z,1366734534.447 [AsyncPiEstimator](INFO): Thread ID is 8692 2013-04-23T16:28:54.447Z,1366734534.447 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-04-23T16:28:54.467Z,1366734534.467 [DVL_micro](INFO): Thread ID is 8695 2013-04-23T16:28:54.935Z,1366734534.935 [CTD_NeilBrown](INFO): Thread ID is 8696 2013-04-23T16:28:54.935Z,1366734534.935 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-04-23T16:28:54.943Z,1366734534.943 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-04-23T16:28:54.945Z,1366734534.944 [WetLabsBB2FL](INFO): Thread ID is 8697 2013-04-23T16:28:54.946Z,1366734534.946 [WetLabsBB2FL](INFO): Powering down 2013-04-23T16:28:54.995Z,1366734534.995 [DVL_micro](INFO): pause:Powering down 2013-04-23T16:28:55.083Z,1366734535.082 [NavChartDb](INFO): Thread ID is 8698 2013-04-23T16:28:55.092Z,1366734535.092 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-04-23T16:28:55.093Z,1366734535.093 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-04-23T16:28:55.093Z,1366734535.093 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-04-23T16:28:55.094Z,1366734535.094 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-04-23T16:28:55.094Z,1366734535.094 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-04-23T16:28:55.094Z,1366734535.094 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-04-23T16:28:55.094Z,1366734535.095 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-04-23T16:28:55.095Z,1366734535.095 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-04-23T16:28:55.095Z,1366734535.095 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-04-23T16:28:55.121Z,1366734535.121 [SBIT](INFO): Initialize SBIT Component. 2013-04-23T16:28:55.121Z,1366734535.121 [SBIT](IMPORTANT): Tethys CM Info: $Rev:10302 2013-04-23T16:28:55.122Z,1366734535.122 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2013-04-23T16:28:55.164Z,1366734535.164 [SBIT](FAULT): Kernel Reporting Different Version From Configuration. Expected:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013 Kernel Reported:#625 PREEMPT Mon Nov 5 10:42:26 PST 2012 2013-04-23T16:28:55.165Z,1366734535.165 [IBIT](INFO): Initialize IBIT Component. 2013-04-23T16:28:55.166Z,1366734535.166 [CBIT](DEBUG): Initialize CBIT Component. 2013-04-23T16:28:55.166Z,1366734535.166 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2013-04-23T16:28:55.212Z,1366734535.211 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-04-23T16:28:55.212Z,1366734535.212 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-04-23T16:28:55.213Z,1366734535.213 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-04-23T16:28:55.213Z,1366734535.213 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-04-23T16:28:55.213Z,1366734535.213 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-04-23T16:28:55.215Z,1366734535.215 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-04-23T16:28:55.215Z,1366734535.215 [Navigation](DEBUG): Initializing Navigation. 2013-04-23T16:28:55.216Z,1366734535.216 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-04-23T16:28:55.218Z,1366734535.218 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-04-23T16:28:55.235Z,1366734535.234 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-04-23T16:28:55.235Z,1366734535.235 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-04-23T16:28:56.915Z,1366734536.915 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-04-23T16:28:56.950Z,1366734536.950 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-04-23T16:28:57.020Z,1366734537.020 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-04-23T16:28:57.054Z,1366734537.054 [MissionManager](DEBUG): 2013-04-23T16:28:57.079Z,1366734537.079 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-04-23T16:28:57.163Z,1366734537.163 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-04-23T16:28:57.165Z,1366734537.165 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-04-23T16:28:57.181Z,1366734537.181 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-04-23T16:28:57.208Z,1366734537.208 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-04-23T16:28:57.231Z,1366734537.231 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-04-23T16:28:57.237Z,1366734537.237 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-04-23T16:28:57.289Z,1366734537.289 [Default:D.SetSpeed](DEBUG): Construct. 2013-04-23T16:28:57.293Z,1366734537.293 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-04-23T16:28:57.341Z,1366734537.341 [Default:F.Wait](DEBUG): Construct Wait. 2013-04-23T16:28:57.344Z,1366734537.344 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-04-23T16:28:57.367Z,1366734537.367 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-04-23T16:28:57.709Z,1366734537.709 [Radio_Freewave](INFO): Powering up 2013-04-23T16:28:57.747Z,1366734537.747 [DAT](INFO): Powering up 2013-04-23T16:28:57.747Z,1366734537.747 [DAT](DEBUG): Initializing DAT. 2013-04-23T16:28:58.304Z,1366734538.304 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:28:58.306Z,1366734538.306 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-04-23T16:28:58.347Z,1366734538.347 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:28:58.359Z,1366734538.359 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-04-23T16:28:58.376Z,1366734538.376 [MassServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:28:58.383Z,1366734538.383 [MassServo](DEBUG): Initializing MassServo. 2013-04-23T16:28:58.409Z,1366734538.409 [RudderServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:28:58.415Z,1366734538.415 [RudderServo](DEBUG): Initializing RudderServo. 2013-04-23T16:28:58.463Z,1366734538.463 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:28:58.479Z,1366734538.479 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-04-23T16:28:58.695Z,1366734538.695 [NAL9602](INFO): Powering up NAL9602 2013-04-23T16:28:59.382Z,1366734539.382 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2013-04-23T16:28:59.382Z,1366734539.382 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2013-04-23T16:28:59.383Z,1366734539.383 [BuoyancyServo] Communications Fault, FailCount= 1 2013-04-23T16:28:59.383Z,1366734539.383 [BuoyancyServo](ERROR): Communications Fault 2013-04-23T16:28:59.585Z,1366734539.585 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2013-04-23T16:28:59.803Z,1366734539.803 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-04-23T16:28:59.804Z,1366734539.804 [BuoyancyServo](INFO): Powering down 2013-04-23T16:29:02.541Z,1366734542.541 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2013-04-23T16:29:02.541Z,1366734542.541 [BuoyancyServo] No Fault, FailCount= 1 2013-04-23T16:29:02.664Z,1366734542.664 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-04-23T16:29:02.783Z,1366734542.783 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-04-23T16:29:08.135Z,1366734548.135 [CommandLine](IMPORTANT): got command failComponent 2013-04-23T16:29:08.135Z,1366734548.135 [CommandLine](IMPORTANT): Failed components: 2013-04-23T16:29:08.135Z,1366734548.135 [CommandLine](IMPORTANT): No failed Components. 2013-04-23T16:29:09.431Z,1366734549.431 [NAL9602](INFO): NAL9602 initialized 2013-04-23T16:29:10.721Z,1366734550.721 [SBIT](IMPORTANT): Beginning Startup BIT 2013-04-23T16:29:10.737Z,1366734550.737 [CBIT](IMPORTANT): Beginning GF scan 2013-04-23T16:29:16.203Z,1366734556.203 [CommandLine](IMPORTANT): got command show variable DAT 2013-04-23T16:29:16.345Z,1366734556.345 [CommandLine](INFO): Config/vehicle.sendDataToShore (bool) 2013-04-23T16:29:16.361Z,1366734556.361 [CommandLine](INFO): Config/vehicle.DAT_card (none) 2013-04-23T16:29:16.361Z,1366734556.361 [CommandLine](INFO): Config/vehicle.DAT_uart (none) 2013-04-23T16:29:16.361Z,1366734556.361 [CommandLine](INFO): Config/vehicle.DAT_baud (bit_per_second) 2013-04-23T16:29:16.376Z,1366734556.376 [CommandLine](INFO): Config/Sensor.DAT_enable (bool) 2013-04-23T16:29:16.377Z,1366734556.377 [CommandLine](INFO): Config/Sensor.DAT_useHardware (bool) 2013-04-23T16:29:16.377Z,1366734556.377 [CommandLine](INFO): Config/Sensor.DAT_remoteAddress (count) 2013-04-23T16:29:16.378Z,1366734556.378 [CommandLine](INFO): Config/Sensor.DAT_rotationOffset (degree) 2013-04-23T16:29:16.416Z,1366734556.416 [CommandLine](INFO): Config/Simulator.oceanModelData (none) 2013-04-23T16:29:16.475Z,1366734556.475 [CommandLine](INFO): DAT.onewayRequestedCmd (bool) 2013-04-23T16:29:16.475Z,1366734556.475 [CommandLine](INFO): DAT.homing_target_range (meter) 2013-04-23T16:29:16.475Z,1366734556.476 [CommandLine](INFO): DAT.homing_target_azimuth (degree) 2013-04-23T16:29:16.476Z,1366734556.476 [CommandLine](INFO): DAT.homing_target_elevation (degree) 2013-04-23T16:29:16.476Z,1366734556.476 [CommandLine](INFO): DAT.homing_target_heading (degree) 2013-04-23T16:29:16.477Z,1366734556.477 [CommandLine](INFO): DAT.LVL1 (count) 2013-04-23T16:29:16.477Z,1366734556.477 [CommandLine](INFO): DAT.LVL2 (count) 2013-04-23T16:29:16.477Z,1366734556.477 [CommandLine](INFO): DAT.LVL3 (count) 2013-04-23T16:29:16.478Z,1366734556.478 [CommandLine](INFO): DAT.LVL4 (count) 2013-04-23T16:29:16.482Z,1366734556.482 [CommandLine](INFO): DAT.AGC (count) 2013-04-23T16:29:16.483Z,1366734556.483 [CommandLine](INFO): DAT.IDXPeak (count) 2013-04-23T16:29:16.483Z,1366734556.483 [CommandLine](INFO): DAT.IDXFit (degree) 2013-04-23T16:29:16.484Z,1366734556.484 [CommandLine](INFO): DAT.IDXPhase (degree) 2013-04-23T16:29:16.484Z,1366734556.484 [CommandLine](INFO): DAT.phaseA (degree) 2013-04-23T16:29:16.484Z,1366734556.484 [CommandLine](INFO): DAT.phaseB (degree) 2013-04-23T16:29:16.485Z,1366734556.485 [CommandLine](INFO): DAT.phaseC (degree) 2013-04-23T16:29:16.485Z,1366734556.485 [CommandLine](INFO): DAT.vectorMagnitude (degree) 2013-04-23T16:29:16.486Z,1366734556.486 [CommandLine](INFO): DAT.rawAzimuth (degree) 2013-04-23T16:29:16.486Z,1366734556.486 [CommandLine](INFO): DAT.rawElevation (degree) 2013-04-23T16:29:16.491Z,1366734556.490 [CommandLine](INFO): DAT.calibratedAzimuth (degree) 2013-04-23T16:29:16.491Z,1366734556.491 [CommandLine](INFO): DAT.calibratedElevation (degree) 2013-04-23T16:29:16.493Z,1366734556.493 [CommandLine](INFO): DAT.durationOfLastRun (second) 2013-04-23T16:29:17.886Z,1366734557.886 [DAT](INFO): Powering down 2013-04-23T16:29:24.215Z,1366734564.215 [CommandLine](IMPORTANT): got command report touch DAT.LVL1 2013-04-23T16:29:32.743Z,1366734572.743 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-04-23T16:29:40.515Z,1366734580.515 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree 2013-04-23T16:29:41.043Z,1366734581.043 [CBIT](IMPORTANT): No ground fault detected 2013-04-23T16:29:44.283Z,1366734584.283 [CommandLine](IMPORTANT): got command show stack 2013-04-23T16:29:44.283Z,1366734584.283 [CommandLine](INFO): Behavior Stack: 2013-04-23T16:29:44.283Z,1366734584.283 [MissionManager](INFO): Mission loaded, but not running. 2013-04-23T16:30:04.596Z,1366734604.596 [SBIT](IMPORTANT): SBIT PASSED 2013-04-23T16:30:05.001Z,1366734605.001 [MissionManager](IMPORTANT): Started mission Startup 2013-04-23T16:30:05.001Z,1366734605.001 [Startup] Running Loop=1 2013-04-23T16:30:05.001Z,1366734605.001 [Startup](INFO): Aggregate::initialize Startup 2013-04-23T16:30:05.001Z,1366734605.001 [Startup:A.GoToSurface] Running Loop=1 2013-04-23T16:30:05.001Z,1366734605.001 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-04-23T16:30:05.007Z,1366734605.007 [Startup:StartupSatComms] Running Loop=1 2013-04-23T16:30:05.007Z,1366734605.007 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-04-23T16:30:05.007Z,1366734605.007 [Startup:StartupSatComms:A] Running Loop=1 2013-04-23T16:30:05.385Z,1366734605.385 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-04-23T16:30:29.635Z,1366734629.635 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/dat_on.xml 2013-04-23T16:30:29.635Z,1366734629.635 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/dat_on.xml 2013-04-23T16:30:29.652Z,1366734629.652 [MissionManager](INFO): DefineArg dat_on.MassDefault = 0.004000 n/a 2013-04-23T16:30:29.654Z,1366734629.654 [dat_on:A.Pitch](DEBUG): Construct. 2013-04-23T16:30:29.670Z,1366734629.670 [dat_on:TestDrive:C.Wait](DEBUG): Construct Wait. 2013-04-23T16:30:29.673Z,1366734629.673 [MissionManager](DEBUG): Pause a cycle 2 2013-04-23T16:30:29.673Z,1366734629.673 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/dat_on.xml 2013-04-23T16:30:34.615Z,1366734634.615 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree 2013-04-23T16:30:34.818Z,1366734634.818 [Startup:StartupSatComms:A] Stopped 2013-04-23T16:30:34.818Z,1366734634.819 [Startup:StartupSatComms:B] Running Loop=1 2013-04-23T16:30:35.246Z,1366734635.246 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-04-23T16:30:37.004Z,1366734637.004 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:30:39.947Z,1366734639.947 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool 2013-04-23T16:30:43.672Z,1366734643.672 [Startup:StartupSatComms:B] Stopped 2013-04-23T16:30:43.672Z,1366734643.672 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-04-23T16:30:43.672Z,1366734643.672 [Startup:StartupSatComms] Stopped 2013-04-23T16:30:43.672Z,1366734643.672 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-04-23T16:30:43.673Z,1366734643.673 [Startup](INFO): Completed Startup 2013-04-23T16:30:43.673Z,1366734643.673 [Startup] Stopped 2013-04-23T16:30:43.674Z,1366734643.674 [Startup](INFO): Aggregate::uninitialize Startup 2013-04-23T16:30:43.674Z,1366734643.674 [Startup:A.GoToSurface] Stopped 2013-04-23T16:30:43.674Z,1366734643.674 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-04-23T16:30:44.369Z,1366734644.369 [MissionManager](IMPORTANT): Started mission dat_on 2013-04-23T16:30:44.369Z,1366734644.369 [dat_on] Running Loop=1 2013-04-23T16:30:44.369Z,1366734644.369 [dat_on](INFO): Aggregate::initialize dat_on 2013-04-23T16:30:44.369Z,1366734644.369 [dat_on:A.Pitch] Running Loop=1 2013-04-23T16:30:44.369Z,1366734644.369 [dat_on:A.Pitch](DEBUG): Initialize. 2013-04-23T16:30:44.370Z,1366734644.370 [dat_on:TestDrive] Running Loop=1 2013-04-23T16:30:44.370Z,1366734644.370 [dat_on:TestDrive](INFO): Aggregate::initialize dat_on:TestDrive 2013-04-23T16:30:44.370Z,1366734644.370 [dat_on:TestDrive:A] Running Loop=1 2013-04-23T16:30:44.370Z,1366734644.370 [dat_on:TestDrive:C.Wait] Running Loop=1 2013-04-23T16:30:44.370Z,1366734644.370 [dat_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component. 2013-04-23T16:30:44.392Z,1366734644.392 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:44.392Z,1366734644.392 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:44.392Z,1366734644.392 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:44.395Z,1366734644.395 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:44.396Z,1366734644.395 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:44.396Z,1366734644.396 [dat_on:TestDrive:A] Running Loop=1 2013-04-23T16:30:44.396Z,1366734644.396 [dat_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense homing_target_range 2013-04-23T16:30:44.398Z,1366734644.398 [dat_on:A.Pitch] Running Loop=1 2013-04-23T16:30:44.442Z,1366734644.442 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:30:44.448Z,1366734644.448 [DAT](INFO): Powering up 2013-04-23T16:30:44.460Z,1366734644.460 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:44.460Z,1366734644.460 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:44.460Z,1366734644.460 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:44.461Z,1366734644.461 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:44.906Z,1366734644.906 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:44.906Z,1366734644.906 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:44.906Z,1366734644.906 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:44.907Z,1366734644.907 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:44.907Z,1366734644.907 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:45.273Z,1366734645.273 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:45.273Z,1366734645.273 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:45.273Z,1366734645.273 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:45.273Z,1366734645.273 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:45.690Z,1366734645.690 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:45.690Z,1366734645.690 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:45.691Z,1366734645.691 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:45.691Z,1366734645.691 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:45.691Z,1366734645.691 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:46.068Z,1366734646.068 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:46.068Z,1366734646.068 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:46.068Z,1366734646.069 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:46.069Z,1366734646.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:46.464Z,1366734646.464 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:46.464Z,1366734646.464 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:46.465Z,1366734646.464 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:46.465Z,1366734646.465 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:46.465Z,1366734646.465 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:46.861Z,1366734646.861 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:46.861Z,1366734646.861 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:46.861Z,1366734646.861 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:46.861Z,1366734646.861 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:47.261Z,1366734647.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:47.261Z,1366734647.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:47.261Z,1366734647.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:47.262Z,1366734647.262 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:47.262Z,1366734647.262 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:47.663Z,1366734647.663 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:47.663Z,1366734647.663 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:47.663Z,1366734647.663 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:47.663Z,1366734647.663 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:48.097Z,1366734648.097 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:48.097Z,1366734648.097 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:48.098Z,1366734648.098 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:48.098Z,1366734648.098 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:48.099Z,1366734648.099 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:48.474Z,1366734648.474 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:48.474Z,1366734648.474 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:48.474Z,1366734648.474 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:48.491Z,1366734648.490 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:48.927Z,1366734648.927 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:48.928Z,1366734648.928 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:48.928Z,1366734648.928 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:48.928Z,1366734648.928 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:48.928Z,1366734648.928 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:49.274Z,1366734649.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:49.274Z,1366734649.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:49.289Z,1366734649.289 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:49.289Z,1366734649.289 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:49.660Z,1366734649.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:49.661Z,1366734649.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:49.661Z,1366734649.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:49.661Z,1366734649.661 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:49.661Z,1366734649.661 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:50.054Z,1366734650.054 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:50.054Z,1366734650.054 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:50.054Z,1366734650.054 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:50.054Z,1366734650.054 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:50.464Z,1366734650.464 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:50.464Z,1366734650.464 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:50.464Z,1366734650.464 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:50.465Z,1366734650.465 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:50.465Z,1366734650.465 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:50.861Z,1366734650.861 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:50.861Z,1366734650.861 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:50.861Z,1366734650.861 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:50.861Z,1366734650.861 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:51.307Z,1366734651.307 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:51.308Z,1366734651.307 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:51.308Z,1366734651.308 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:51.308Z,1366734651.308 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:51.308Z,1366734651.308 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:51.688Z,1366734651.688 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:51.688Z,1366734651.688 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:51.688Z,1366734651.688 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:51.688Z,1366734651.688 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:52.073Z,1366734652.073 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:52.073Z,1366734652.073 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:52.074Z,1366734652.074 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:52.090Z,1366734652.090 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:52.090Z,1366734652.090 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:52.465Z,1366734652.464 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:52.465Z,1366734652.465 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:52.465Z,1366734652.465 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:52.465Z,1366734652.465 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:52.861Z,1366734652.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:52.861Z,1366734652.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:52.861Z,1366734652.861 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:52.862Z,1366734652.862 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:52.862Z,1366734652.862 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:53.261Z,1366734653.261 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:53.261Z,1366734653.261 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:53.261Z,1366734653.261 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:53.261Z,1366734653.261 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:53.714Z,1366734653.714 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:53.714Z,1366734653.714 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:53.715Z,1366734653.715 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:53.715Z,1366734653.715 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:53.715Z,1366734653.715 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:54.066Z,1366734654.066 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:54.066Z,1366734654.066 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:54.066Z,1366734654.066 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:54.066Z,1366734654.066 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:54.472Z,1366734654.472 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:54.472Z,1366734654.472 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:54.472Z,1366734654.472 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:54.473Z,1366734654.473 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:54.473Z,1366734654.473 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:54.907Z,1366734654.907 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:54.908Z,1366734654.908 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:54.908Z,1366734654.908 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:54.908Z,1366734654.908 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:55.273Z,1366734655.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:55.274Z,1366734655.274 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:55.274Z,1366734655.274 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:55.290Z,1366734655.290 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:55.291Z,1366734655.291 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:55.661Z,1366734655.661 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:55.661Z,1366734655.661 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:55.661Z,1366734655.661 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:55.661Z,1366734655.661 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:56.054Z,1366734656.053 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:56.054Z,1366734656.054 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:56.054Z,1366734656.054 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:56.055Z,1366734656.055 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:56.055Z,1366734656.055 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:56.461Z,1366734656.461 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:56.461Z,1366734656.461 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:56.461Z,1366734656.461 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:56.461Z,1366734656.461 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:56.860Z,1366734656.860 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:56.861Z,1366734656.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:56.861Z,1366734656.861 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:56.861Z,1366734656.861 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:56.861Z,1366734656.861 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:57.272Z,1366734657.272 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:57.273Z,1366734657.273 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:57.273Z,1366734657.273 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:57.273Z,1366734657.273 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:57.690Z,1366734657.690 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:57.691Z,1366734657.691 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:57.691Z,1366734657.691 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:57.691Z,1366734657.691 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:57.692Z,1366734657.691 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:58.113Z,1366734658.113 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:58.113Z,1366734658.113 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:58.113Z,1366734658.113 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:58.113Z,1366734658.113 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:58.464Z,1366734658.464 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:58.465Z,1366734658.465 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:58.465Z,1366734658.465 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:58.465Z,1366734658.465 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:58.465Z,1366734658.466 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:58.914Z,1366734658.914 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:58.914Z,1366734658.914 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:58.914Z,1366734658.914 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:58.914Z,1366734658.914 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:30:59.260Z,1366734659.260 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:30:59.261Z,1366734659.260 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:30:59.261Z,1366734659.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:30:59.261Z,1366734659.261 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:30:59.261Z,1366734659.261 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:30:59.654Z,1366734659.654 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:30:59.654Z,1366734659.654 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:30:59.654Z,1366734659.654 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:30:59.655Z,1366734659.655 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:00.088Z,1366734660.088 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:00.088Z,1366734660.088 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:00.088Z,1366734660.088 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:00.089Z,1366734660.089 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:00.089Z,1366734660.089 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:00.473Z,1366734660.473 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:00.473Z,1366734660.473 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:00.474Z,1366734660.474 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:00.474Z,1366734660.474 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:00.888Z,1366734660.888 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:00.888Z,1366734660.888 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:00.888Z,1366734660.888 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:00.889Z,1366734660.889 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:00.889Z,1366734660.889 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:01.297Z,1366734661.297 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:01.297Z,1366734661.297 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:01.297Z,1366734661.297 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:01.297Z,1366734661.297 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:01.661Z,1366734661.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:01.661Z,1366734661.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:01.661Z,1366734661.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:01.662Z,1366734661.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:01.662Z,1366734661.662 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:02.068Z,1366734662.069 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:02.069Z,1366734662.069 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:02.069Z,1366734662.069 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:02.069Z,1366734662.069 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:02.488Z,1366734662.488 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:02.488Z,1366734662.489 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:02.489Z,1366734662.489 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:02.489Z,1366734662.489 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:02.489Z,1366734662.489 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:02.873Z,1366734662.874 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:02.874Z,1366734662.874 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:02.874Z,1366734662.874 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:02.874Z,1366734662.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:03.262Z,1366734663.262 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:03.263Z,1366734663.263 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:03.263Z,1366734663.263 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:03.264Z,1366734663.264 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:03.264Z,1366734663.264 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:03.661Z,1366734663.661 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:03.661Z,1366734663.661 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:03.662Z,1366734663.662 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:03.662Z,1366734663.662 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:04.197Z,1366734664.197 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:04.197Z,1366734664.197 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:04.197Z,1366734664.197 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:04.198Z,1366734664.198 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:04.198Z,1366734664.198 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:04.501Z,1366734664.501 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:04.502Z,1366734664.501 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:04.502Z,1366734664.502 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:04.502Z,1366734664.502 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:04.913Z,1366734664.913 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:04.913Z,1366734664.913 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:04.914Z,1366734664.914 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:04.914Z,1366734664.914 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:04.914Z,1366734664.914 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:05.259Z,1366734665.259 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:05.259Z,1366734665.259 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:05.259Z,1366734665.259 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:05.259Z,1366734665.259 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:05.655Z,1366734665.655 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:05.655Z,1366734665.655 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:05.655Z,1366734665.655 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:05.656Z,1366734665.656 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:05.656Z,1366734665.656 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:06.074Z,1366734666.074 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:06.088Z,1366734666.088 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:06.088Z,1366734666.088 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:06.088Z,1366734666.088 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:06.486Z,1366734666.486 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:06.486Z,1366734666.486 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:06.486Z,1366734666.486 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:06.487Z,1366734666.487 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:06.487Z,1366734666.487 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:06.873Z,1366734666.873 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:06.874Z,1366734666.874 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:06.874Z,1366734666.874 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:06.874Z,1366734666.874 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:07.262Z,1366734667.262 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:07.263Z,1366734667.263 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:07.263Z,1366734667.263 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:07.264Z,1366734667.264 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:07.264Z,1366734667.264 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:07.664Z,1366734667.664 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:07.664Z,1366734667.664 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:07.664Z,1366734667.664 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:07.664Z,1366734667.664 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:08.120Z,1366734668.120 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:08.120Z,1366734668.120 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:08.121Z,1366734668.121 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:08.121Z,1366734668.121 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:08.121Z,1366734668.121 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:08.132Z,1366734668.132 [Reporter](INFO): DAT.LVL1 17680 count 2013-04-23T16:31:08.500Z,1366734668.500 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:08.500Z,1366734668.500 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:08.500Z,1366734668.500 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:08.500Z,1366734668.500 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:08.873Z,1366734668.872 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:08.873Z,1366734668.873 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:08.873Z,1366734668.873 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:08.873Z,1366734668.874 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:08.874Z,1366734668.874 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:09.311Z,1366734669.311 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:09.312Z,1366734669.312 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:09.312Z,1366734669.312 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:09.312Z,1366734669.312 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:09.661Z,1366734669.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:09.661Z,1366734669.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:09.661Z,1366734669.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:09.662Z,1366734669.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:09.663Z,1366734669.663 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:10.072Z,1366734670.072 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:10.073Z,1366734670.073 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:10.073Z,1366734670.073 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:10.073Z,1366734670.073 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:10.486Z,1366734670.486 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:10.486Z,1366734670.486 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:10.486Z,1366734670.487 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:10.487Z,1366734670.487 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:10.487Z,1366734670.487 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:10.889Z,1366734670.889 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:10.889Z,1366734670.889 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:10.889Z,1366734670.889 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:10.889Z,1366734670.889 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:11.298Z,1366734671.298 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:11.298Z,1366734671.298 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:11.299Z,1366734671.299 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:11.299Z,1366734671.299 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:11.299Z,1366734671.299 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:11.657Z,1366734671.657 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:11.657Z,1366734671.657 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:11.657Z,1366734671.657 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:11.657Z,1366734671.657 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:12.097Z,1366734672.097 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:12.097Z,1366734672.097 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:12.097Z,1366734672.097 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:12.097Z,1366734672.098 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:12.098Z,1366734672.098 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:12.108Z,1366734672.108 [Reporter](INFO): DAT.LVL1 12080 count 2013-04-23T16:31:12.494Z,1366734672.494 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:12.495Z,1366734672.494 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:12.495Z,1366734672.495 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:12.495Z,1366734672.495 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:12.873Z,1366734672.873 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:12.873Z,1366734672.873 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:12.873Z,1366734672.873 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:12.873Z,1366734672.874 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:12.874Z,1366734672.874 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:13.263Z,1366734673.263 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:13.263Z,1366734673.263 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:13.263Z,1366734673.263 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:13.263Z,1366734673.263 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:13.661Z,1366734673.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:13.661Z,1366734673.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:13.661Z,1366734673.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:13.663Z,1366734673.663 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:13.663Z,1366734673.663 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:14.131Z,1366734674.131 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:14.131Z,1366734674.131 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:14.131Z,1366734674.131 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:14.131Z,1366734674.131 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:14.489Z,1366734674.489 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:14.489Z,1366734674.489 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:14.489Z,1366734674.489 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:14.490Z,1366734674.490 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:14.490Z,1366734674.490 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:14.908Z,1366734674.908 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:14.909Z,1366734674.908 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:14.909Z,1366734674.908 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:14.909Z,1366734674.909 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:15.261Z,1366734675.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:15.262Z,1366734675.262 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:15.262Z,1366734675.262 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:15.263Z,1366734675.263 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:15.263Z,1366734675.263 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:15.659Z,1366734675.659 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:15.659Z,1366734675.659 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:15.660Z,1366734675.660 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:15.660Z,1366734675.660 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:16.070Z,1366734676.070 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:16.070Z,1366734676.070 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:16.070Z,1366734676.070 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:16.071Z,1366734676.070 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:16.071Z,1366734676.071 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:16.104Z,1366734676.104 [Reporter](INFO): DAT.LVL1 18672 count 2013-04-23T16:31:16.498Z,1366734676.498 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:16.498Z,1366734676.498 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:16.498Z,1366734676.498 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:16.498Z,1366734676.498 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:16.857Z,1366734676.857 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:16.857Z,1366734676.857 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:16.858Z,1366734676.858 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:16.858Z,1366734676.858 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:16.858Z,1366734676.858 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:17.274Z,1366734677.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:17.286Z,1366734677.286 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:17.286Z,1366734677.286 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:17.287Z,1366734677.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:17.689Z,1366734677.689 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:17.689Z,1366734677.689 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:17.689Z,1366734677.689 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:17.690Z,1366734677.690 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:17.690Z,1366734677.690 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:18.113Z,1366734678.113 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:18.114Z,1366734678.114 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:18.114Z,1366734678.114 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:18.114Z,1366734678.114 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:18.464Z,1366734678.464 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:18.464Z,1366734678.464 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:18.465Z,1366734678.465 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:18.465Z,1366734678.465 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:18.465Z,1366734678.465 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:18.859Z,1366734678.859 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:18.859Z,1366734678.859 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:18.859Z,1366734678.859 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:18.859Z,1366734678.859 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:19.311Z,1366734679.311 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:19.311Z,1366734679.311 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:19.311Z,1366734679.311 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:19.312Z,1366734679.312 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:19.312Z,1366734679.312 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:19.665Z,1366734679.665 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:19.665Z,1366734679.665 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:19.665Z,1366734679.665 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:19.665Z,1366734679.665 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:20.090Z,1366734680.091 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:20.091Z,1366734680.091 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:20.091Z,1366734680.091 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:20.091Z,1366734680.091 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:20.091Z,1366734680.092 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:20.101Z,1366734680.102 [Reporter](INFO): DAT.LVL1 17504 count 2013-04-23T16:31:20.508Z,1366734680.508 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:20.509Z,1366734680.509 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:20.509Z,1366734680.509 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:20.509Z,1366734680.509 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:20.889Z,1366734680.889 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:20.889Z,1366734680.889 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:20.889Z,1366734680.889 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:20.890Z,1366734680.890 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:20.890Z,1366734680.890 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:21.298Z,1366734681.298 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:21.298Z,1366734681.298 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:21.298Z,1366734681.298 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:21.299Z,1366734681.299 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:21.661Z,1366734681.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:21.661Z,1366734681.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:21.661Z,1366734681.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:21.662Z,1366734681.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:21.663Z,1366734681.663 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:22.074Z,1366734682.074 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:22.088Z,1366734682.088 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:22.088Z,1366734682.088 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:22.088Z,1366734682.088 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:22.488Z,1366734682.488 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:22.488Z,1366734682.488 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:22.488Z,1366734682.489 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:22.489Z,1366734682.489 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:22.489Z,1366734682.489 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:22.890Z,1366734682.890 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:22.890Z,1366734682.890 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:22.890Z,1366734682.890 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:22.890Z,1366734682.890 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:23.258Z,1366734683.258 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:23.258Z,1366734683.258 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:23.258Z,1366734683.258 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:23.259Z,1366734683.259 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:23.259Z,1366734683.259 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:23.660Z,1366734683.660 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:23.660Z,1366734683.660 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:23.660Z,1366734683.660 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:23.660Z,1366734683.660 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:24.098Z,1366734684.098 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:24.098Z,1366734684.098 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:24.098Z,1366734684.099 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:24.099Z,1366734684.099 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:24.099Z,1366734684.099 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:24.109Z,1366734684.109 [Reporter](INFO): DAT.LVL1 12368 count 2013-04-23T16:31:24.600Z,1366734684.600 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:24.600Z,1366734684.600 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:24.600Z,1366734684.600 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:24.600Z,1366734684.601 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:24.887Z,1366734684.887 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:24.887Z,1366734684.887 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:24.887Z,1366734684.887 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:24.888Z,1366734684.888 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:24.888Z,1366734684.888 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:25.263Z,1366734685.263 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:25.263Z,1366734685.263 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:25.263Z,1366734685.263 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:25.263Z,1366734685.263 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:25.539Z,1366734685.539 [CommandLine](IMPORTANT): got command show variable dat 2013-04-23T16:31:25.543Z,1366734685.543 [CommandLine](INFO): Config/vehicle.sendDataToShore (bool) 2013-04-23T16:31:25.546Z,1366734685.546 [CommandLine](INFO): Config/vehicle.DAT_card (none) 2013-04-23T16:31:25.546Z,1366734685.546 [CommandLine](INFO): Config/vehicle.DAT_uart (none) 2013-04-23T16:31:25.547Z,1366734685.547 [CommandLine](INFO): Config/vehicle.DAT_baud (bit_per_second) 2013-04-23T16:31:25.549Z,1366734685.549 [CommandLine](INFO): Config/Sensor.DAT_enable (bool) 2013-04-23T16:31:25.550Z,1366734685.550 [CommandLine](INFO): Config/Sensor.DAT_useHardware (bool) 2013-04-23T16:31:25.550Z,1366734685.550 [CommandLine](INFO): Config/Sensor.DAT_remoteAddress (count) 2013-04-23T16:31:25.550Z,1366734685.550 [CommandLine](INFO): Config/Sensor.DAT_rotationOffset (degree) 2013-04-23T16:31:25.567Z,1366734685.566 [CommandLine](INFO): Config/Simulator.oceanModelData (none) 2013-04-23T16:31:25.601Z,1366734685.601 [CommandLine](INFO): DAT.onewayRequestedCmd (bool) 2013-04-23T16:31:25.602Z,1366734685.602 [CommandLine](INFO): DAT.homing_target_range (meter) 2013-04-23T16:31:25.602Z,1366734685.602 [CommandLine](INFO): DAT.homing_target_azimuth (degree) 2013-04-23T16:31:25.603Z,1366734685.602 [CommandLine](INFO): DAT.homing_target_elevation (degree) 2013-04-23T16:31:25.603Z,1366734685.603 [CommandLine](INFO): DAT.homing_target_heading (degree) 2013-04-23T16:31:25.603Z,1366734685.603 [CommandLine](INFO): DAT.LVL1 (count) 2013-04-23T16:31:25.604Z,1366734685.604 [CommandLine](INFO): DAT.LVL2 (count) 2013-04-23T16:31:25.604Z,1366734685.604 [CommandLine](INFO): DAT.LVL3 (count) 2013-04-23T16:31:25.604Z,1366734685.604 [CommandLine](INFO): DAT.LVL4 (count) 2013-04-23T16:31:25.605Z,1366734685.605 [CommandLine](INFO): DAT.AGC (count) 2013-04-23T16:31:25.605Z,1366734685.605 [CommandLine](INFO): DAT.IDXPeak (count) 2013-04-23T16:31:25.605Z,1366734685.605 [CommandLine](INFO): DAT.IDXFit (degree) 2013-04-23T16:31:25.606Z,1366734685.606 [CommandLine](INFO): DAT.IDXPhase (degree) 2013-04-23T16:31:25.607Z,1366734685.607 [CommandLine](INFO): DAT.phaseA (degree) 2013-04-23T16:31:25.607Z,1366734685.607 [CommandLine](INFO): DAT.phaseB (degree) 2013-04-23T16:31:25.608Z,1366734685.608 [CommandLine](INFO): DAT.phaseC (degree) 2013-04-23T16:31:25.608Z,1366734685.608 [CommandLine](INFO): DAT.vectorMagnitude (degree) 2013-04-23T16:31:25.608Z,1366734685.608 [CommandLine](INFO): DAT.rawAzimuth (degree) 2013-04-23T16:31:25.609Z,1366734685.609 [CommandLine](INFO): DAT.rawElevation (degree) 2013-04-23T16:31:25.609Z,1366734685.609 [CommandLine](INFO): DAT.calibratedAzimuth (degree) 2013-04-23T16:31:25.609Z,1366734685.609 [CommandLine](INFO): DAT.calibratedElevation (degree) 2013-04-23T16:31:25.612Z,1366734685.612 [CommandLine](INFO): DAT.durationOfLastRun (second) 2013-04-23T16:31:25.614Z,1366734685.615 [CommandLine](INFO): DAT.component_voltage (volt) 2013-04-23T16:31:25.615Z,1366734685.615 [CommandLine](INFO): DAT.component_avgVoltage (volt) 2013-04-23T16:31:25.615Z,1366734685.615 [CommandLine](INFO): DAT.component_current (milliampere) 2013-04-23T16:31:25.616Z,1366734685.616 [CommandLine](INFO): DAT.component_avgCurrent (milliampere) 2013-04-23T16:31:25.616Z,1366734685.616 [CommandLine](INFO): dat_on.MassDefault (none) 2013-04-23T16:31:25.617Z,1366734685.617 [CommandLine](INFO): dat_on:TestDrive:C.Wait.durationOfLastRun (second) 2013-04-23T16:31:25.617Z,1366734685.617 [CommandLine](INFO): dat_on:TestDrive:Data:A.durationOfLastRun (second) 2013-04-23T16:31:25.617Z,1366734685.617 [CommandLine](INFO): dat_on:TestDrive:A.durationOfLastRun (second) 2013-04-23T16:31:25.618Z,1366734685.618 [CommandLine](INFO): dat_on:A.Pitch.durationOfLastRun (second) 2013-04-23T16:31:25.618Z,1366734685.618 [CommandLine](INFO): dat_on:TestDrive:Data:B.durationOfLastRun (second) 2013-04-23T16:31:25.657Z,1366734685.657 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:25.657Z,1366734685.657 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:25.657Z,1366734685.657 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:25.658Z,1366734685.658 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:25.658Z,1366734685.658 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:26.087Z,1366734686.087 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:26.087Z,1366734686.087 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:26.087Z,1366734686.087 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:26.087Z,1366734686.087 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:26.489Z,1366734686.489 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:26.489Z,1366734686.489 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:26.489Z,1366734686.489 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:26.490Z,1366734686.490 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:26.490Z,1366734686.490 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:26.881Z,1366734686.881 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:26.881Z,1366734686.881 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:26.881Z,1366734686.881 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:26.881Z,1366734686.881 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:27.273Z,1366734687.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:27.273Z,1366734687.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:27.273Z,1366734687.273 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:27.274Z,1366734687.274 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:27.274Z,1366734687.274 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:27.657Z,1366734687.657 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:27.657Z,1366734687.657 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:27.657Z,1366734687.657 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:27.657Z,1366734687.657 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:28.136Z,1366734688.136 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:28.136Z,1366734688.136 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:28.136Z,1366734688.136 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:28.137Z,1366734688.137 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:28.137Z,1366734688.137 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:28.147Z,1366734688.147 [Reporter](INFO): DAT.LVL1 16368 count 2013-04-23T16:31:28.508Z,1366734688.508 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:28.508Z,1366734688.508 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:28.508Z,1366734688.509 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:28.509Z,1366734688.509 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:28.879Z,1366734688.879 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:28.879Z,1366734688.879 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:28.880Z,1366734688.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:28.880Z,1366734688.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:28.880Z,1366734688.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:29.277Z,1366734689.277 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:29.277Z,1366734689.277 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:29.277Z,1366734689.277 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:29.278Z,1366734689.277 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:29.710Z,1366734689.710 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:29.710Z,1366734689.710 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:29.710Z,1366734689.710 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:29.711Z,1366734689.711 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:29.711Z,1366734689.711 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:29.785Z,1366734689.785 [CommandLine](IMPORTANT): got command report touch DAT.phaseA 2013-04-23T16:31:30.079Z,1366734690.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:30.079Z,1366734690.079 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:30.079Z,1366734690.079 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:30.080Z,1366734690.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:30.479Z,1366734690.479 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:30.479Z,1366734690.479 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:30.479Z,1366734690.479 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:30.480Z,1366734690.480 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:30.480Z,1366734690.480 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:30.885Z,1366734690.885 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:30.886Z,1366734690.885 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:30.886Z,1366734690.886 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:30.886Z,1366734690.886 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:31.290Z,1366734691.290 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:31.291Z,1366734691.291 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:31.291Z,1366734691.291 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:31.291Z,1366734691.291 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:31.292Z,1366734691.292 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:31.674Z,1366734691.674 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:31.674Z,1366734691.674 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:31.674Z,1366734691.674 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:31.674Z,1366734691.674 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:32.085Z,1366734692.085 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:32.085Z,1366734692.085 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:32.085Z,1366734692.085 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:32.086Z,1366734692.086 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:32.086Z,1366734692.086 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:32.096Z,1366734692.096 [Reporter](INFO): DAT.LVL1 18688 count 2013-04-23T16:31:32.097Z,1366734692.097 [Reporter](INFO): DAT.phaseA -0.022000 arcdeg 2013-04-23T16:31:32.512Z,1366734692.512 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:32.512Z,1366734692.512 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:32.512Z,1366734692.513 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:32.513Z,1366734692.513 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:32.879Z,1366734692.879 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:32.880Z,1366734692.880 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:32.880Z,1366734692.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:32.880Z,1366734692.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:32.881Z,1366734692.881 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:33.273Z,1366734693.273 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:33.274Z,1366734693.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:33.274Z,1366734693.274 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:33.274Z,1366734693.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:33.661Z,1366734693.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:33.661Z,1366734693.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:33.661Z,1366734693.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:33.662Z,1366734693.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:33.662Z,1366734693.662 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:34.086Z,1366734694.086 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:34.086Z,1366734694.086 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:34.086Z,1366734694.086 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:34.086Z,1366734694.086 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:34.580Z,1366734694.580 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:34.580Z,1366734694.580 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:34.580Z,1366734694.580 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:34.581Z,1366734694.580 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:34.581Z,1366734694.581 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:34.885Z,1366734694.885 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:34.885Z,1366734694.885 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:34.885Z,1366734694.885 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:34.886Z,1366734694.885 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:35.261Z,1366734695.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:35.261Z,1366734695.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:35.261Z,1366734695.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:35.279Z,1366734695.279 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:35.279Z,1366734695.279 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:35.656Z,1366734695.656 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:35.656Z,1366734695.656 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:35.656Z,1366734695.656 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:35.656Z,1366734695.657 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:36.080Z,1366734696.080 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:36.080Z,1366734696.080 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:36.080Z,1366734696.080 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:36.081Z,1366734696.081 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:36.081Z,1366734696.081 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:36.091Z,1366734696.091 [Reporter](INFO): DAT.LVL1 10992 count 2013-04-23T16:31:36.092Z,1366734696.092 [Reporter](INFO): DAT.phaseA -0.020000 arcdeg 2013-04-23T16:31:36.483Z,1366734696.483 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:36.483Z,1366734696.483 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:36.483Z,1366734696.483 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:36.484Z,1366734696.484 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:36.861Z,1366734696.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:36.861Z,1366734696.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:36.862Z,1366734696.862 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:36.880Z,1366734696.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:36.880Z,1366734696.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:37.285Z,1366734697.285 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:37.285Z,1366734697.285 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:37.285Z,1366734697.286 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:37.286Z,1366734697.286 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:37.704Z,1366734697.704 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:37.704Z,1366734697.704 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:37.704Z,1366734697.704 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:37.705Z,1366734697.705 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:37.705Z,1366734697.705 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:38.080Z,1366734698.080 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:38.080Z,1366734698.080 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:38.080Z,1366734698.080 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:38.080Z,1366734698.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:38.474Z,1366734698.474 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:38.474Z,1366734698.474 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:38.474Z,1366734698.474 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:38.475Z,1366734698.475 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:38.475Z,1366734698.475 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:38.861Z,1366734698.861 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:38.862Z,1366734698.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:38.862Z,1366734698.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:38.862Z,1366734698.862 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:39.273Z,1366734699.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:39.273Z,1366734699.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:39.274Z,1366734699.274 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:39.274Z,1366734699.274 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:39.275Z,1366734699.274 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:39.716Z,1366734699.716 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:39.716Z,1366734699.716 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:39.716Z,1366734699.716 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:39.717Z,1366734699.717 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:40.087Z,1366734700.087 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:40.088Z,1366734700.088 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:40.088Z,1366734700.088 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:40.088Z,1366734700.088 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:40.089Z,1366734700.089 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:40.098Z,1366734700.098 [Reporter](INFO): DAT.LVL1 18384 count 2013-04-23T16:31:40.099Z,1366734700.099 [Reporter](INFO): DAT.phaseA -0.019000 arcdeg 2013-04-23T16:31:40.508Z,1366734700.508 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:40.508Z,1366734700.508 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:40.508Z,1366734700.509 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:40.509Z,1366734700.509 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:40.880Z,1366734700.880 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:40.880Z,1366734700.880 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:40.880Z,1366734700.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:40.881Z,1366734700.881 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:40.881Z,1366734700.881 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:41.290Z,1366734701.290 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:41.290Z,1366734701.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:41.290Z,1366734701.290 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:41.290Z,1366734701.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:41.654Z,1366734701.654 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:41.654Z,1366734701.654 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:41.654Z,1366734701.654 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:41.655Z,1366734701.655 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:41.655Z,1366734701.655 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:42.062Z,1366734702.062 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:42.062Z,1366734702.062 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:42.062Z,1366734702.062 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:42.079Z,1366734702.079 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:42.474Z,1366734702.474 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:42.474Z,1366734702.474 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:42.475Z,1366734702.474 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:42.475Z,1366734702.475 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:42.475Z,1366734702.475 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:42.862Z,1366734702.862 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:42.862Z,1366734702.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:42.862Z,1366734702.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:42.862Z,1366734702.862 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:43.285Z,1366734703.285 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:43.285Z,1366734703.285 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:43.285Z,1366734703.286 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:43.286Z,1366734703.286 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:43.287Z,1366734703.287 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:43.681Z,1366734703.681 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:43.681Z,1366734703.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:43.682Z,1366734703.681 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:43.682Z,1366734703.682 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:44.094Z,1366734704.094 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:44.094Z,1366734704.094 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:44.095Z,1366734704.095 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:44.095Z,1366734704.095 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:44.095Z,1366734704.095 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:44.105Z,1366734704.105 [Reporter](INFO): DAT.LVL1 17088 count 2013-04-23T16:31:44.106Z,1366734704.106 [Reporter](INFO): DAT.phaseA -0.018000 arcdeg 2013-04-23T16:31:44.532Z,1366734704.532 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:44.532Z,1366734704.532 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:44.532Z,1366734704.532 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:44.533Z,1366734704.533 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:44.910Z,1366734704.909 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:44.910Z,1366734704.910 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:44.910Z,1366734704.910 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:44.911Z,1366734704.911 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:44.911Z,1366734704.911 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:45.274Z,1366734705.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:45.274Z,1366734705.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:45.274Z,1366734705.274 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:45.274Z,1366734705.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:45.661Z,1366734705.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:45.661Z,1366734705.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:45.661Z,1366734705.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:45.662Z,1366734705.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:45.681Z,1366734705.681 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:46.079Z,1366734706.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:46.079Z,1366734706.079 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:46.079Z,1366734706.079 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:46.079Z,1366734706.079 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:46.482Z,1366734706.482 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:46.482Z,1366734706.483 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:46.483Z,1366734706.483 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:46.483Z,1366734706.483 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:46.483Z,1366734706.483 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:46.886Z,1366734706.886 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:46.886Z,1366734706.886 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:46.887Z,1366734706.886 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:46.887Z,1366734706.887 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:47.257Z,1366734707.257 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:47.257Z,1366734707.257 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:47.258Z,1366734707.258 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:47.258Z,1366734707.258 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:47.259Z,1366734707.259 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:47.700Z,1366734707.700 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:47.700Z,1366734707.700 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:47.700Z,1366734707.700 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:47.700Z,1366734707.700 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:48.080Z,1366734708.080 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:48.080Z,1366734708.080 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:48.080Z,1366734708.080 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:48.081Z,1366734708.081 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:48.081Z,1366734708.081 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:48.092Z,1366734708.092 [Reporter](INFO): DAT.LVL1 16800 count 2013-04-23T16:31:48.092Z,1366734708.092 [Reporter](INFO): DAT.phaseA -0.023000 arcdeg 2013-04-23T16:31:48.484Z,1366734708.484 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:48.484Z,1366734708.484 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:48.484Z,1366734708.484 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:48.484Z,1366734708.484 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:48.861Z,1366734708.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:48.862Z,1366734708.862 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:48.862Z,1366734708.862 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:48.879Z,1366734708.879 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:48.880Z,1366734708.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:49.279Z,1366734709.279 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:49.279Z,1366734709.279 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:49.279Z,1366734709.279 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:49.280Z,1366734709.280 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:49.724Z,1366734709.724 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:49.724Z,1366734709.724 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:49.724Z,1366734709.724 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:49.725Z,1366734709.724 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:49.725Z,1366734709.725 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:50.080Z,1366734710.080 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:50.080Z,1366734710.080 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:50.080Z,1366734710.080 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:50.080Z,1366734710.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:50.475Z,1366734710.475 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:50.475Z,1366734710.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:50.475Z,1366734710.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:50.476Z,1366734710.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:50.476Z,1366734710.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:50.890Z,1366734710.890 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:50.890Z,1366734710.890 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:50.890Z,1366734710.890 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:50.890Z,1366734710.890 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:51.273Z,1366734711.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:51.273Z,1366734711.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:51.273Z,1366734711.273 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:51.274Z,1366734711.274 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:51.274Z,1366734711.274 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:51.659Z,1366734711.659 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:51.659Z,1366734711.659 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:51.660Z,1366734711.659 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:51.660Z,1366734711.660 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:52.088Z,1366734712.088 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:52.088Z,1366734712.088 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:52.088Z,1366734712.088 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:52.089Z,1366734712.089 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:52.089Z,1366734712.089 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:52.098Z,1366734712.098 [Reporter](INFO): DAT.LVL1 14864 count 2013-04-23T16:31:52.099Z,1366734712.099 [Reporter](INFO): DAT.phaseA -0.024000 arcdeg 2013-04-23T16:31:52.508Z,1366734712.508 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:52.508Z,1366734712.508 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:52.508Z,1366734712.509 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:52.509Z,1366734712.509 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:52.880Z,1366734712.880 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:52.880Z,1366734712.880 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:52.880Z,1366734712.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:52.881Z,1366734712.881 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:52.881Z,1366734712.881 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:53.261Z,1366734713.261 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:53.261Z,1366734713.261 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:53.262Z,1366734713.261 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:53.262Z,1366734713.262 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:53.654Z,1366734713.654 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:53.654Z,1366734713.654 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:53.654Z,1366734713.654 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:53.655Z,1366734713.655 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:53.655Z,1366734713.655 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:54.062Z,1366734714.062 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:54.062Z,1366734714.062 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:54.062Z,1366734714.062 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:54.080Z,1366734714.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:54.505Z,1366734714.505 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:54.505Z,1366734714.505 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:54.506Z,1366734714.506 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:54.506Z,1366734714.506 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:54.507Z,1366734714.507 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:54.910Z,1366734714.911 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:54.911Z,1366734714.911 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:54.911Z,1366734714.911 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:54.911Z,1366734714.911 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:55.285Z,1366734715.285 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:55.285Z,1366734715.285 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:55.285Z,1366734715.286 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:55.286Z,1366734715.286 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:55.287Z,1366734715.287 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:55.681Z,1366734715.681 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:55.681Z,1366734715.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:55.681Z,1366734715.681 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:55.681Z,1366734715.681 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:56.084Z,1366734716.084 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:56.084Z,1366734716.084 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:56.084Z,1366734716.085 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:56.085Z,1366734716.085 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:56.085Z,1366734716.085 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:56.095Z,1366734716.095 [Reporter](INFO): DAT.LVL1 19808 count 2013-04-23T16:31:56.096Z,1366734716.096 [Reporter](INFO): DAT.phaseA -0.019000 arcdeg 2013-04-23T16:31:56.492Z,1366734716.492 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:56.493Z,1366734716.493 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:56.493Z,1366734716.493 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:56.493Z,1366734716.493 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:56.861Z,1366734716.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:56.861Z,1366734716.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:56.861Z,1366734716.861 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:56.862Z,1366734716.862 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:56.880Z,1366734716.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:57.274Z,1366734717.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:57.274Z,1366734717.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:57.274Z,1366734717.274 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:57.275Z,1366734717.275 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:57.690Z,1366734717.690 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:57.690Z,1366734717.690 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:57.690Z,1366734717.690 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:57.691Z,1366734717.691 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:57.691Z,1366734717.691 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:58.079Z,1366734718.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:58.080Z,1366734718.080 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:58.080Z,1366734718.080 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:58.080Z,1366734718.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:58.482Z,1366734718.482 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:58.482Z,1366734718.482 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:58.482Z,1366734718.482 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:58.483Z,1366734718.483 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:58.483Z,1366734718.483 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:58.885Z,1366734718.885 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:58.885Z,1366734718.885 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:58.886Z,1366734718.885 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:58.886Z,1366734718.886 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:31:59.258Z,1366734719.258 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:31:59.258Z,1366734719.258 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:31:59.259Z,1366734719.259 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:31:59.259Z,1366734719.259 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:31:59.259Z,1366734719.259 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:31:59.676Z,1366734719.676 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:31:59.676Z,1366734719.676 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:31:59.676Z,1366734719.676 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:31:59.676Z,1366734719.676 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:00.121Z,1366734720.121 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:00.121Z,1366734720.121 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:00.121Z,1366734720.121 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:00.122Z,1366734720.122 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:00.122Z,1366734720.122 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:00.132Z,1366734720.132 [Reporter](INFO): DAT.LVL1 18400 count 2013-04-23T16:32:00.133Z,1366734720.133 [Reporter](INFO): DAT.phaseA -0.022000 arcdeg 2013-04-23T16:32:00.489Z,1366734720.489 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:00.489Z,1366734720.489 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:00.489Z,1366734720.489 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:00.489Z,1366734720.490 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:00.890Z,1366734720.890 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:00.891Z,1366734720.891 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:00.891Z,1366734720.891 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:00.891Z,1366734720.891 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:00.891Z,1366734720.891 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:01.287Z,1366734721.286 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:01.287Z,1366734721.287 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:01.287Z,1366734721.287 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:01.287Z,1366734721.287 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:01.680Z,1366734721.680 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:01.680Z,1366734721.681 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:01.681Z,1366734721.681 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:01.681Z,1366734721.681 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:01.681Z,1366734721.681 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:02.077Z,1366734722.077 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:02.077Z,1366734722.077 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:02.077Z,1366734722.077 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:02.078Z,1366734722.078 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:02.474Z,1366734722.474 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:02.475Z,1366734722.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:02.475Z,1366734722.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:02.475Z,1366734722.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:02.476Z,1366734722.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:02.861Z,1366734722.861 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:02.862Z,1366734722.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:02.862Z,1366734722.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:02.862Z,1366734722.862 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:03.273Z,1366734723.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:03.273Z,1366734723.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:03.273Z,1366734723.273 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:03.274Z,1366734723.274 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:03.274Z,1366734723.274 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:03.674Z,1366734723.674 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:03.674Z,1366734723.674 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:03.674Z,1366734723.674 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:03.675Z,1366734723.675 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:04.120Z,1366734724.120 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:04.120Z,1366734724.120 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:04.120Z,1366734724.120 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:04.121Z,1366734724.121 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:04.121Z,1366734724.121 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:04.131Z,1366734724.131 [Reporter](INFO): DAT.LVL1 17392 count 2013-04-23T16:32:04.132Z,1366734724.132 [Reporter](INFO): DAT.phaseA -0.023000 arcdeg 2013-04-23T16:32:04.510Z,1366734724.510 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:04.510Z,1366734724.510 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:04.510Z,1366734724.510 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:04.510Z,1366734724.510 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:04.880Z,1366734724.880 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:04.880Z,1366734724.880 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:04.880Z,1366734724.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:04.881Z,1366734724.881 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:04.881Z,1366734724.881 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:05.310Z,1366734725.310 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:05.311Z,1366734725.311 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:05.311Z,1366734725.311 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:05.311Z,1366734725.311 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:05.654Z,1366734725.654 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:05.654Z,1366734725.654 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:05.655Z,1366734725.655 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:05.655Z,1366734725.655 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:05.655Z,1366734725.655 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:06.058Z,1366734726.057 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:06.058Z,1366734726.058 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:06.058Z,1366734726.058 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:06.058Z,1366734726.058 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:06.460Z,1366734726.460 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:06.460Z,1366734726.460 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:06.461Z,1366734726.461 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:06.461Z,1366734726.461 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:06.461Z,1366734726.461 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:06.862Z,1366734726.862 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:06.862Z,1366734726.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:06.862Z,1366734726.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:06.879Z,1366734726.879 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:07.309Z,1366734727.309 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:07.309Z,1366734727.309 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:07.309Z,1366734727.309 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:07.310Z,1366734727.310 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:07.310Z,1366734727.310 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:07.681Z,1366734727.681 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:07.681Z,1366734727.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:07.681Z,1366734727.681 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:07.681Z,1366734727.681 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:08.084Z,1366734728.084 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:08.084Z,1366734728.084 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:08.084Z,1366734728.084 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:08.085Z,1366734728.085 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:08.085Z,1366734728.085 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:08.095Z,1366734728.095 [Reporter](INFO): DAT.LVL1 18272 count 2013-04-23T16:32:08.096Z,1366734728.096 [Reporter](INFO): DAT.phaseA -0.021000 arcdeg 2013-04-23T16:32:08.492Z,1366734728.492 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:08.493Z,1366734728.493 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:08.493Z,1366734728.493 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:08.493Z,1366734728.493 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:08.857Z,1366734728.857 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:08.857Z,1366734728.857 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:08.857Z,1366734728.857 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:08.858Z,1366734728.858 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:08.858Z,1366734728.858 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:09.274Z,1366734729.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:09.274Z,1366734729.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:09.274Z,1366734729.274 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:09.274Z,1366734729.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:09.661Z,1366734729.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:09.661Z,1366734729.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:09.661Z,1366734729.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:09.679Z,1366734729.679 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:09.679Z,1366734729.679 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:10.134Z,1366734730.134 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:10.134Z,1366734730.134 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:10.134Z,1366734730.134 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:10.134Z,1366734730.134 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:10.485Z,1366734730.485 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:10.486Z,1366734730.486 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:10.486Z,1366734730.486 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:10.487Z,1366734730.487 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:10.487Z,1366734730.487 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:10.917Z,1366734730.917 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:10.918Z,1366734730.918 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:10.918Z,1366734730.918 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:10.918Z,1366734730.918 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:11.261Z,1366734731.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:11.261Z,1366734731.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:11.261Z,1366734731.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:11.281Z,1366734731.281 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:11.282Z,1366734731.282 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:11.656Z,1366734731.657 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:11.657Z,1366734731.657 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:11.657Z,1366734731.657 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:11.657Z,1366734731.657 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:12.078Z,1366734732.078 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:12.078Z,1366734732.078 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:12.079Z,1366734732.079 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:12.079Z,1366734732.079 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:12.079Z,1366734732.079 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:12.089Z,1366734732.089 [Reporter](INFO): DAT.LVL1 18512 count 2013-04-23T16:32:12.090Z,1366734732.090 [Reporter](INFO): DAT.phaseA -0.016000 arcdeg 2013-04-23T16:32:12.483Z,1366734732.483 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:12.483Z,1366734732.483 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:12.483Z,1366734732.483 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:12.484Z,1366734732.484 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:12.861Z,1366734732.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:12.862Z,1366734732.862 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:12.862Z,1366734732.862 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:12.880Z,1366734732.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:12.880Z,1366734732.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:13.285Z,1366734733.285 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:13.286Z,1366734733.286 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:13.286Z,1366734733.286 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:13.286Z,1366734733.286 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:13.685Z,1366734733.685 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:13.685Z,1366734733.685 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:13.685Z,1366734733.685 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:13.686Z,1366734733.686 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:13.686Z,1366734733.686 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:14.104Z,1366734734.104 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:14.105Z,1366734734.105 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:14.105Z,1366734734.105 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:14.105Z,1366734734.105 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:14.475Z,1366734734.474 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:14.475Z,1366734734.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:14.475Z,1366734734.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:14.475Z,1366734734.475 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:14.475Z,1366734734.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:14.861Z,1366734734.861 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:14.862Z,1366734734.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:14.862Z,1366734734.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:14.862Z,1366734734.862 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:15.311Z,1366734735.311 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:15.311Z,1366734735.311 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:15.311Z,1366734735.311 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:15.312Z,1366734735.312 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:15.312Z,1366734735.312 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:15.675Z,1366734735.675 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:15.676Z,1366734735.676 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:15.676Z,1366734735.676 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:15.676Z,1366734735.676 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:16.088Z,1366734736.088 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:16.088Z,1366734736.088 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:16.088Z,1366734736.088 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:16.089Z,1366734736.089 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:16.089Z,1366734736.089 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:16.098Z,1366734736.098 [Reporter](INFO): DAT.LVL1 16944 count 2013-04-23T16:32:16.099Z,1366734736.099 [Reporter](INFO): DAT.phaseA -0.023000 arcdeg 2013-04-23T16:32:16.505Z,1366734736.505 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:16.505Z,1366734736.505 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:16.505Z,1366734736.505 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:16.505Z,1366734736.505 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:16.880Z,1366734736.880 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:16.880Z,1366734736.880 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:16.880Z,1366734736.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:16.881Z,1366734736.881 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:16.881Z,1366734736.881 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:17.290Z,1366734737.290 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:17.290Z,1366734737.290 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:17.290Z,1366734737.290 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:17.290Z,1366734737.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:17.654Z,1366734737.654 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:17.654Z,1366734737.654 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:17.655Z,1366734737.655 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:17.655Z,1366734737.655 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:17.655Z,1366734737.655 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:18.062Z,1366734738.062 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:18.062Z,1366734738.062 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:18.062Z,1366734738.062 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:18.062Z,1366734738.062 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:18.475Z,1366734738.475 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:18.475Z,1366734738.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:18.475Z,1366734738.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:18.476Z,1366734738.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:18.476Z,1366734738.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:18.862Z,1366734738.862 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:18.862Z,1366734738.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:18.862Z,1366734738.862 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:18.862Z,1366734738.862 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:19.285Z,1366734739.285 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:19.285Z,1366734739.285 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:19.285Z,1366734739.285 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:19.286Z,1366734739.286 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:19.286Z,1366734739.286 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:19.687Z,1366734739.687 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:19.687Z,1366734739.687 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:19.687Z,1366734739.687 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:19.687Z,1366734739.687 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:20.088Z,1366734740.088 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:20.088Z,1366734740.088 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:20.089Z,1366734740.089 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:20.089Z,1366734740.089 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:20.089Z,1366734740.089 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:20.100Z,1366734740.099 [Reporter](INFO): DAT.LVL1 17184 count 2013-04-23T16:32:20.100Z,1366734740.100 [Reporter](INFO): DAT.phaseA -0.021000 arcdeg 2013-04-23T16:32:20.588Z,1366734740.588 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:20.588Z,1366734740.588 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:20.589Z,1366734740.589 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:20.589Z,1366734740.589 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:20.861Z,1366734740.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:20.861Z,1366734740.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:20.861Z,1366734740.861 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:20.880Z,1366734740.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:20.880Z,1366734740.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:21.255Z,1366734741.255 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:21.255Z,1366734741.255 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:21.255Z,1366734741.255 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:21.255Z,1366734741.256 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:21.661Z,1366734741.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:21.661Z,1366734741.661 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:21.661Z,1366734741.661 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:21.662Z,1366734741.662 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:21.678Z,1366734741.678 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:22.079Z,1366734742.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:22.079Z,1366734742.079 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:22.079Z,1366734742.079 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:22.079Z,1366734742.079 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:22.482Z,1366734742.482 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:22.482Z,1366734742.482 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:22.482Z,1366734742.482 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:22.483Z,1366734742.483 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:22.483Z,1366734742.483 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:22.885Z,1366734742.885 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:22.885Z,1366734742.885 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:22.886Z,1366734742.885 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:22.886Z,1366734742.886 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:23.261Z,1366734743.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:23.261Z,1366734743.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:23.261Z,1366734743.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:23.262Z,1366734743.262 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:23.279Z,1366734743.279 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:23.700Z,1366734743.700 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:23.701Z,1366734743.701 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:23.701Z,1366734743.701 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:23.701Z,1366734743.701 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:24.080Z,1366734744.080 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:24.080Z,1366734744.080 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:24.081Z,1366734744.081 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:24.081Z,1366734744.081 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:24.081Z,1366734744.081 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:24.091Z,1366734744.091 [Reporter](INFO): DAT.LVL1 18384 count 2013-04-23T16:32:24.092Z,1366734744.092 [Reporter](INFO): DAT.phaseA -0.021000 arcdeg 2013-04-23T16:32:24.483Z,1366734744.483 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:24.483Z,1366734744.483 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:24.483Z,1366734744.483 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:24.483Z,1366734744.483 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:24.874Z,1366734744.874 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:24.874Z,1366734744.874 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:24.874Z,1366734744.874 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:24.875Z,1366734744.875 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:24.875Z,1366734744.875 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:25.329Z,1366734745.329 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:25.329Z,1366734745.329 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:25.330Z,1366734745.330 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:25.330Z,1366734745.330 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:25.679Z,1366734745.679 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:25.679Z,1366734745.680 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:25.680Z,1366734745.680 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:25.680Z,1366734745.680 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:25.680Z,1366734745.680 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:26.079Z,1366734746.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:26.080Z,1366734746.080 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:26.080Z,1366734746.080 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:26.080Z,1366734746.080 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:26.475Z,1366734746.475 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:26.475Z,1366734746.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:26.475Z,1366734746.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:26.476Z,1366734746.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:26.476Z,1366734746.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:26.890Z,1366734746.890 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:26.890Z,1366734746.890 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:26.891Z,1366734746.891 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:26.891Z,1366734746.891 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:27.273Z,1366734747.273 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:27.273Z,1366734747.273 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:27.273Z,1366734747.273 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:27.274Z,1366734747.274 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:27.274Z,1366734747.274 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:27.675Z,1366734747.675 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:27.675Z,1366734747.675 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:27.675Z,1366734747.675 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:27.675Z,1366734747.675 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:28.087Z,1366734748.087 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:28.087Z,1366734748.087 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:28.087Z,1366734748.087 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:28.088Z,1366734748.088 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:28.088Z,1366734748.088 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:28.098Z,1366734748.098 [Reporter](INFO): DAT.LVL1 15152 count 2013-04-23T16:32:28.098Z,1366734748.098 [Reporter](INFO): DAT.phaseA -0.019000 arcdeg 2013-04-23T16:32:28.508Z,1366734748.508 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:28.508Z,1366734748.508 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:28.508Z,1366734748.509 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:28.509Z,1366734748.509 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:28.879Z,1366734748.879 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:28.879Z,1366734748.879 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:28.880Z,1366734748.880 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:28.880Z,1366734748.880 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:28.880Z,1366734748.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:29.261Z,1366734749.261 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:29.262Z,1366734749.261 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:29.262Z,1366734749.262 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:29.262Z,1366734749.262 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:29.661Z,1366734749.661 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:29.662Z,1366734749.662 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:29.662Z,1366734749.662 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:29.679Z,1366734749.679 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:29.679Z,1366734749.679 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:30.062Z,1366734750.062 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:30.062Z,1366734750.062 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:30.062Z,1366734750.062 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:30.062Z,1366734750.062 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:30.550Z,1366734750.550 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:30.551Z,1366734750.551 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:30.551Z,1366734750.551 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:30.551Z,1366734750.551 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:30.552Z,1366734750.552 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:30.855Z,1366734750.855 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:30.855Z,1366734750.855 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:30.855Z,1366734750.855 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:30.855Z,1366734750.855 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:31.279Z,1366734751.279 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:31.279Z,1366734751.279 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:31.280Z,1366734751.280 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:31.280Z,1366734751.280 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:31.280Z,1366734751.280 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:31.681Z,1366734751.681 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:31.681Z,1366734751.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:31.681Z,1366734751.681 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:31.681Z,1366734751.681 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:32.085Z,1366734752.085 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:32.085Z,1366734752.085 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:32.085Z,1366734752.085 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:32.086Z,1366734752.086 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:32.086Z,1366734752.086 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:32.096Z,1366734752.096 [Reporter](INFO): DAT.LVL1 17376 count 2013-04-23T16:32:32.097Z,1366734752.097 [Reporter](INFO): DAT.phaseA -0.024000 arcdeg 2013-04-23T16:32:32.488Z,1366734752.488 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:32.488Z,1366734752.489 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:32.489Z,1366734752.489 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:32.489Z,1366734752.489 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:32.861Z,1366734752.861 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:32.861Z,1366734752.861 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:32.861Z,1366734752.861 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:32.862Z,1366734752.862 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:32.880Z,1366734752.880 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:33.274Z,1366734753.274 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:33.274Z,1366734753.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:33.274Z,1366734753.274 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:33.274Z,1366734753.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:33.689Z,1366734753.690 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:33.690Z,1366734753.690 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:33.690Z,1366734753.690 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:33.691Z,1366734753.691 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:33.691Z,1366734753.691 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:34.079Z,1366734754.079 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:34.079Z,1366734754.079 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:34.079Z,1366734754.079 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:34.079Z,1366734754.079 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:34.482Z,1366734754.482 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:34.482Z,1366734754.482 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:34.482Z,1366734754.482 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:34.483Z,1366734754.483 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:34.483Z,1366734754.483 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:34.885Z,1366734754.885 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:34.886Z,1366734754.885 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:34.886Z,1366734754.886 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:34.886Z,1366734754.886 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:35.261Z,1366734755.261 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:35.261Z,1366734755.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:35.261Z,1366734755.261 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:35.262Z,1366734755.262 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:35.283Z,1366734755.283 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:35.716Z,1366734755.716 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:35.716Z,1366734755.716 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:35.716Z,1366734755.716 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:35.716Z,1366734755.716 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:36.080Z,1366734756.080 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:36.081Z,1366734756.081 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:36.081Z,1366734756.081 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:36.081Z,1366734756.081 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:36.081Z,1366734756.081 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:36.092Z,1366734756.092 [Reporter](INFO): DAT.LVL1 17392 count 2013-04-23T16:32:36.092Z,1366734756.092 [Reporter](INFO): DAT.phaseA -0.022000 arcdeg 2013-04-23T16:32:36.492Z,1366734756.492 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:36.492Z,1366734756.492 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:36.493Z,1366734756.493 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:36.493Z,1366734756.493 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:36.890Z,1366734756.890 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:36.890Z,1366734756.890 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:36.890Z,1366734756.890 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:36.891Z,1366734756.891 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:36.891Z,1366734756.891 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:37.286Z,1366734757.286 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:37.286Z,1366734757.286 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:37.286Z,1366734757.286 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:37.287Z,1366734757.286 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:37.679Z,1366734757.679 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:37.679Z,1366734757.679 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:37.679Z,1366734757.679 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:37.680Z,1366734757.680 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:37.680Z,1366734757.680 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:38.080Z,1366734758.080 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:38.080Z,1366734758.080 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:38.080Z,1366734758.080 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:38.081Z,1366734758.081 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:38.475Z,1366734758.475 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:38.475Z,1366734758.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:38.475Z,1366734758.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:38.475Z,1366734758.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:38.476Z,1366734758.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:38.862Z,1366734758.862 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:38.862Z,1366734758.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:38.875Z,1366734758.875 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:38.875Z,1366734758.875 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:39.259Z,1366734759.259 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:39.259Z,1366734759.259 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:39.259Z,1366734759.260 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:39.260Z,1366734759.260 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:39.260Z,1366734759.260 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:39.676Z,1366734759.676 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:39.676Z,1366734759.676 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:39.676Z,1366734759.676 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:39.676Z,1366734759.676 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:40.132Z,1366734760.132 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:40.132Z,1366734760.132 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:40.132Z,1366734760.132 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:40.133Z,1366734760.133 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:40.133Z,1366734760.133 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:40.143Z,1366734760.143 [Reporter](INFO): DAT.LVL1 10736 count 2013-04-23T16:32:40.144Z,1366734760.144 [Reporter](INFO): DAT.phaseA -0.016000 arcdeg 2013-04-23T16:32:40.556Z,1366734760.556 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:40.557Z,1366734760.556 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:40.557Z,1366734760.557 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:40.557Z,1366734760.557 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:40.886Z,1366734760.886 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:40.886Z,1366734760.886 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:40.886Z,1366734760.886 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:40.887Z,1366734760.887 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:40.887Z,1366734760.887 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:41.261Z,1366734761.261 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:41.262Z,1366734761.261 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:41.262Z,1366734761.262 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:41.262Z,1366734761.262 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:41.654Z,1366734761.654 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:41.654Z,1366734761.654 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:41.655Z,1366734761.655 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:41.655Z,1366734761.655 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:41.655Z,1366734761.655 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:42.061Z,1366734762.061 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:42.062Z,1366734762.062 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:42.062Z,1366734762.062 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:42.062Z,1366734762.062 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:42.475Z,1366734762.475 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:42.475Z,1366734762.475 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:42.475Z,1366734762.475 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:42.476Z,1366734762.476 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:42.476Z,1366734762.476 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:42.862Z,1366734762.862 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:42.862Z,1366734762.862 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:42.875Z,1366734762.875 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:42.875Z,1366734762.875 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:43.310Z,1366734763.310 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:43.310Z,1366734763.310 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:43.310Z,1366734763.310 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:43.311Z,1366734763.311 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:43.311Z,1366734763.311 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:43.681Z,1366734763.681 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:43.682Z,1366734763.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:43.682Z,1366734763.682 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:43.682Z,1366734763.682 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:44.085Z,1366734764.085 [dat_on:TestDrive:Data] Running Loop=1 2013-04-23T16:32:44.085Z,1366734764.085 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data 2013-04-23T16:32:44.085Z,1366734764.085 [dat_on:TestDrive:Data:A] Running Loop=1 2013-04-23T16:32:44.086Z,1366734764.086 [dat_on:TestDrive:Data:A] Stopped 2013-04-23T16:32:44.086Z,1366734764.086 [dat_on:TestDrive:Data:B] Running Loop=1 2013-04-23T16:32:44.097Z,1366734764.097 [Reporter](INFO): DAT.LVL1 17392 count 2013-04-23T16:32:44.098Z,1366734764.098 [Reporter](INFO): DAT.phaseA -0.022000 arcdeg 2013-04-23T16:32:44.492Z,1366734764.492 [dat_on:TestDrive:C.Wait](INFO): Done Waiting. 2013-04-23T16:32:44.492Z,1366734764.492 [dat_on:TestDrive:C.Wait] Stopped 2013-04-23T16:32:44.492Z,1366734764.492 [dat_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component. 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive:Data:B] Stopped 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive:Data] Stopped 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive](INFO): Completed dat_on:TestDrive 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive] Stopped 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive](INFO): Aggregate::uninitialize dat_on:TestDrive 2013-04-23T16:32:44.493Z,1366734764.493 [dat_on:TestDrive:A] Stopped 2013-04-23T16:32:44.495Z,1366734764.495 [dat_on](INFO): Completed dat_on 2013-04-23T16:32:44.495Z,1366734764.495 [dat_on] Stopped 2013-04-23T16:32:44.495Z,1366734764.496 [dat_on](INFO): Aggregate::uninitialize dat_on 2013-04-23T16:32:44.495Z,1366734764.496 [dat_on:A.Pitch] Stopped 2013-04-23T16:32:44.861Z,1366734764.861 [MissionManager](IMPORTANT): Started mission Default 2013-04-23T16:32:44.861Z,1366734764.861 [Default] Running Loop=1 2013-04-23T16:32:44.861Z,1366734764.861 [Default](INFO): Aggregate::initialize Default 2013-04-23T16:32:44.861Z,1366734764.861 [Default:D.SetSpeed] Running Loop=1 2013-04-23T16:32:44.861Z,1366734764.861 [Default:D.SetSpeed](DEBUG): Initialize. 2013-04-23T16:32:44.861Z,1366734764.861 [Default:E.GoToSurface] Running Loop=1 2013-04-23T16:32:44.861Z,1366734764.861 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-04-23T16:32:44.862Z,1366734764.862 [Default:Iridium] Running Loop=1 2013-04-23T16:32:44.862Z,1366734764.862 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-04-23T16:32:44.862Z,1366734764.862 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-04-23T16:32:44.862Z,1366734764.862 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-04-23T16:32:44.874Z,1366734764.874 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-04-23T16:32:44.874Z,1366734764.874 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-04-23T16:32:44.875Z,1366734764.875 [Default:E.GoToSurface] Running Loop=1 2013-04-23T16:32:44.888Z,1366734764.888 [Default:D.SetSpeed] Running Loop=1 2013-04-23T16:32:44.916Z,1366734764.916 [Default:Iridium:B.GoToSurface] Stopped 2013-04-23T16:32:44.916Z,1366734764.916 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-04-23T16:32:44.916Z,1366734764.916 [Default:Iridium:Read_Iridium] Running Loop=1 2013-04-23T16:32:44.916Z,1366734764.916 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-04-23T16:32:44.921Z,1366734764.921 [Default:GPS] Running Loop=1 2013-04-23T16:32:44.921Z,1366734764.921 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-04-23T16:32:44.922Z,1366734764.921 [Default:GPS:A.SetSpeed] Running Loop=1 2013-04-23T16:32:44.922Z,1366734764.922 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-04-23T16:32:44.922Z,1366734764.922 [Default:GPS:B.GoToSurface] Running Loop=1 2013-04-23T16:32:44.922Z,1366734764.922 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-04-23T16:32:44.928Z,1366734764.928 [Default:GPS:B.GoToSurface] Stopped 2013-04-23T16:32:44.928Z,1366734764.928 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-04-23T16:32:44.928Z,1366734764.928 [Default:GPS:Read_GPS] Running Loop=1 2013-04-23T16:32:44.928Z,1366734764.928 [Default:GPS:A.SetSpeed] Running Loop=1 2013-04-23T16:32:45.254Z,1366734765.254 [DAT](INFO): Powering down 2013-04-23T16:32:45.390Z,1366734765.390 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-04-23T16:32:45.393Z,1366734765.393 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-04-23T16:32:49.856Z,1366734769.856 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:32:53.000Z,1366734774.000 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:32:57.760Z,1366734777.760 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:01.916Z,1366734781.916 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:05.676Z,1366734785.676 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:09.832Z,1366734789.832 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:13.600Z,1366734793.600 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:17.780Z,1366734797.780 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:21.529Z,1366734801.529 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:25.656Z,1366734805.656 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:29.412Z,1366734809.412 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:33.612Z,1366734813.612 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:37.778Z,1366734817.778 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:41.940Z,1366734821.940 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:45.676Z,1366734825.676 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:49.848Z,1366734829.848 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:53.608Z,1366734833.608 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:33:57.780Z,1366734837.780 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:01.512Z,1366734841.512 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:05.686Z,1366734845.686 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:09.508Z,1366734849.508 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:13.708Z,1366734853.708 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:17.461Z,1366734857.461 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:21.620Z,1366734861.620 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:25.380Z,1366734865.380 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:29.536Z,1366734869.536 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:33.292Z,1366734873.292 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:37.856Z,1366734877.856 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:41.604Z,1366734881.604 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:45.790Z,1366734885.790 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:49.556Z,1366734889.556 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:53.708Z,1366734893.708 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:55.619Z,1366734895.619 [CommandLine](IMPORTANT): got command quit 2013-04-23T16:34:56.810Z,1366734896.810 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2013-04-23T16:34:56.810Z,1366734896.810 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2013-04-23T16:34:56.878Z,1366734896.878 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2013-04-23T16:34:57.183Z,1366734897.182 [WetLabsBB2FL](INFO): Powering down 2013-04-23T16:34:57.198Z,1366734897.198 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2013-04-23T16:34:57.419Z,1366734897.418 [CTD_NeilBrown](INFO): Powering down 2013-04-23T16:34:57.420Z,1366734897.420 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler 2013-04-23T16:34:57.454Z,1366734897.454 [DVL_micro](INFO): uninitialize:Powering down 2013-04-23T16:34:57.458Z,1366734897.458 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2013-04-23T16:34:57.488Z,1366734897.488 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2013-04-23T16:34:57.783Z,1366734897.783 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2013-04-23T16:34:57.791Z,1366734897.791 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2013-04-23T16:34:57.879Z,1366734897.879 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2013-04-23T16:34:57.891Z,1366734897.891 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2013-04-23T16:34:57.934Z,1366734897.934 [controlThread](DEBUG): Uninitializing ControlThread 2013-04-23T16:34:57.936Z,1366734897.936 [NAL9602](INFO): Powering down 2013-04-23T16:34:57.938Z,1366734897.938 [DAT](INFO): Powering down 2013-04-23T16:34:57.939Z,1366734897.939 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-04-23T16:34:57.939Z,1366734897.939 [NavChart](DEBUG): Uninitialize NavChart Derivation. 2013-04-23T16:34:57.941Z,1366734897.941 [Default] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default](INFO): Aggregate::uninitialize Default 2013-04-23T16:34:57.941Z,1366734897.941 [Default:GPS] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-04-23T16:34:57.941Z,1366734897.941 [Default:GPS:A.SetSpeed] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-04-23T16:34:57.941Z,1366734897.941 [Default:GPS:Read_GPS] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default:Iridium] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-04-23T16:34:57.941Z,1366734897.941 [Default:Iridium:A.SetSpeed] Stopped 2013-04-23T16:34:57.941Z,1366734897.941 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-04-23T16:34:57.942Z,1366734897.941 [Default:Iridium:Read_Iridium] Stopped 2013-04-23T16:34:57.942Z,1366734897.941 [Default:D.SetSpeed] Stopped 2013-04-23T16:34:57.942Z,1366734897.942 [Default:D.SetSpeed](DEBUG): Uninitialize. 2013-04-23T16:34:57.942Z,1366734897.942 [Default:E.GoToSurface] Stopped 2013-04-23T16:34:57.942Z,1366734897.942 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-04-23T16:34:57.948Z,1366734897.948 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2013-04-23T16:34:57.949Z,1366734897.949 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2013-04-23T16:34:57.949Z,1366734897.949 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2013-04-23T16:34:57.949Z,1366734897.949 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2013-04-23T16:34:57.950Z,1366734897.950 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2013-04-23T16:34:57.950Z,1366734897.950 [BuoyancyServo](INFO): Powering down 2013-04-23T16:34:57.962Z,1366734897.962 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2013-04-23T16:34:57.962Z,1366734897.963 [ElevatorServo](INFO): Powering down 2013-04-23T16:34:57.963Z,1366734897.963 [MassServo](DEBUG): Uninitialize Mass Servo. 2013-04-23T16:34:57.963Z,1366734897.963 [MassServo](INFO): Powering down 2013-04-23T16:34:57.964Z,1366734897.964 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2013-04-23T16:34:57.964Z,1366734897.964 [RudderServo](INFO): Powering down 2013-04-23T16:34:57.965Z,1366734897.965 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2013-04-23T16:34:57.965Z,1366734897.965 [ThrusterServo](INFO): Powering down 2013-04-23T16:34:57.966Z,1366734897.966 [SBIT](DEBUG): Uninitialize SBIT Component. 2013-04-23T16:34:57.966Z,1366734897.967 [IBIT](DEBUG): Uninitialize IBIT Component. 2013-04-23T16:34:57.967Z,1366734897.967 [CBIT](DEBUG): Uninitialize CBIT Component.