2013-06-03T22:45:35.067Z,1370299535.067 [Supervisor](DEBUG): Initializing supervisor.
2013-06-03T22:45:35.069Z,1370299535.069 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-06-03T22:45:35.070Z,1370299535.070 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-06-03T22:45:35.071Z,1370299535.071 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-06-03T22:45:35.075Z,1370299535.075 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-06-03T22:45:35.085Z,1370299535.085 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-06-03T22:45:35.086Z,1370299535.086 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-06-03T22:45:35.087Z,1370299535.087 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-06-03T22:45:35.088Z,1370299535.088 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-06-03T22:45:35.089Z,1370299535.089 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-06-03T22:45:35.090Z,1370299535.090 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-06-03T22:45:35.498Z,1370299535.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-06-03T22:45:35.498Z,1370299535.498 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-06-03T22:45:35.703Z,1370299535.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-06-03T22:45:35.704Z,1370299535.704 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-06-03T22:45:35.791Z,1370299535.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-06-03T22:45:35.792Z,1370299535.792 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-06-03T22:45:35.935Z,1370299535.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-06-03T22:45:35.936Z,1370299535.936 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-06-03T22:45:36.116Z,1370299536.116 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-06-03T22:45:36.117Z,1370299536.117 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-06-03T22:45:36.382Z,1370299536.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-06-03T22:45:36.383Z,1370299536.383 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-06-03T22:45:36.556Z,1370299536.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-06-03T22:45:36.557Z,1370299536.556 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-06-03T22:45:36.896Z,1370299536.896 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-06-03T22:45:36.897Z,1370299536.897 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-06-03T22:45:36.997Z,1370299536.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-06-03T22:45:36.997Z,1370299536.997 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-06-03T22:45:37.601Z,1370299537.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-06-03T22:45:37.601Z,1370299537.601 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-06-03T22:45:37.716Z,1370299537.716 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-06-03T22:45:37.717Z,1370299537.717 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-06-03T22:45:37.803Z,1370299537.803 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-06-03T22:45:37.804Z,1370299537.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-06-03T22:45:37.909Z,1370299537.909 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-06-03T22:45:38.044Z,1370299538.044 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-06-03T22:45:38.136Z,1370299538.136 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-06-03T22:45:38.240Z,1370299538.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-06-03T22:45:38.347Z,1370299538.347 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-06-03T22:45:38.551Z,1370299538.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-06-03T22:45:38.646Z,1370299538.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-06-03T22:45:38.734Z,1370299538.734 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-06-03T22:45:38.735Z,1370299538.735 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-06-03T22:45:38.741Z,1370299538.741 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-06-03T22:45:38.904Z,1370299538.904 [InternalSim] Loaded
2013-06-03T22:45:38.904Z,1370299538.904 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-06-03T22:45:38.905Z,1370299538.905 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-06-03T22:45:38.905Z,1370299538.905 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-06-03T22:45:40.833Z,1370299540.833 [SBIT](DEBUG): Construct Startup Built In Test.
2013-06-03T22:45:40.861Z,1370299540.861 [SBIT] Loaded
2013-06-03T22:45:40.862Z,1370299540.862 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-06-03T22:45:40.863Z,1370299540.862 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-06-03T22:45:40.890Z,1370299540.890 [IBIT] Loaded
2013-06-03T22:45:40.891Z,1370299540.891 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-06-03T22:45:40.894Z,1370299540.894 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-06-03T22:45:41.007Z,1370299541.007 [CBIT] Loaded
2013-06-03T22:45:41.007Z,1370299541.007 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-06-03T22:45:41.007Z,1370299541.007 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-06-03T22:45:41.008Z,1370299541.008 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-06-03T22:45:41.159Z,1370299541.159 [BuoyancyServo] Loaded
2013-06-03T22:45:41.159Z,1370299541.159 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-06-03T22:45:41.171Z,1370299541.171 [ElevatorServo] Loaded
2013-06-03T22:45:41.172Z,1370299541.172 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-06-03T22:45:41.184Z,1370299541.184 [MassServo] Loaded
2013-06-03T22:45:41.184Z,1370299541.184 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-06-03T22:45:41.196Z,1370299541.196 [RudderServo] Loaded
2013-06-03T22:45:41.196Z,1370299541.196 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-06-03T22:45:41.207Z,1370299541.207 [ThrusterServo] Loaded
2013-06-03T22:45:41.208Z,1370299541.208 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-06-03T22:45:41.208Z,1370299541.208 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-06-03T22:45:41.209Z,1370299541.209 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-06-03T22:45:41.227Z,1370299541.227 [DepthRateCalculator] Loaded
2013-06-03T22:45:41.227Z,1370299541.227 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-06-03T22:45:44.329Z,1370299544.329 [HFRadarModelCalc] Loaded
2013-06-03T22:45:44.329Z,1370299544.329 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-06-03T22:45:44.345Z,1370299544.345 [NavChart] Loaded
2013-06-03T22:45:44.345Z,1370299544.345 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-06-03T22:45:44.351Z,1370299544.351 [PitchRateCalculator] Loaded
2013-06-03T22:45:44.351Z,1370299544.351 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-06-03T22:45:44.362Z,1370299544.362 [SpeedCalculator] Loaded
2013-06-03T22:45:44.362Z,1370299544.362 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-06-03T22:45:44.376Z,1370299544.376 [TempGradientCalculator] Loaded
2013-06-03T22:45:44.377Z,1370299544.377 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-06-03T22:45:44.382Z,1370299544.382 [YawRateCalculator] Loaded
2013-06-03T22:45:44.383Z,1370299544.383 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-06-03T22:45:44.427Z,1370299544.427 [Navigation] Loaded
2013-06-03T22:45:44.427Z,1370299544.427 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-06-03T22:45:44.427Z,1370299544.427 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-06-03T22:45:44.428Z,1370299544.428 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-06-03T22:45:44.642Z,1370299544.642 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-06-03T22:45:44.642Z,1370299544.642 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-06-03T22:45:44.667Z,1370299544.667 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-06-03T22:45:44.668Z,1370299544.668 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-06-03T22:45:44.708Z,1370299544.708 [VerticalControl](DEBUG): Construct VerticalControl.
2013-06-03T22:45:44.799Z,1370299544.799 [VerticalControl] Loaded
2013-06-03T22:45:44.800Z,1370299544.800 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-06-03T22:45:44.801Z,1370299544.801 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-06-03T22:45:44.855Z,1370299544.855 [HorizontalControl] Loaded
2013-06-03T22:45:44.855Z,1370299544.855 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-06-03T22:45:44.856Z,1370299544.856 [SpeedControl](DEBUG): Construct SpeedControl.
2013-06-03T22:45:44.858Z,1370299544.858 [SpeedControl] Loaded
2013-06-03T22:45:44.858Z,1370299544.858 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-06-03T22:45:44.859Z,1370299544.859 [LoopControl](DEBUG): Construct LoopControl.
2013-06-03T22:45:44.859Z,1370299544.859 [LoopControl] Loaded
2013-06-03T22:45:44.859Z,1370299544.859 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-06-03T22:45:44.860Z,1370299544.860 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-06-03T22:45:44.860Z,1370299544.861 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-06-03T22:45:44.866Z,1370299544.866 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-06-03T22:45:44.871Z,1370299544.871 [AsyncPiEstimator] Loaded
2013-06-03T22:45:44.871Z,1370299544.871 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-06-03T22:45:44.872Z,1370299544.872 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-06-03T22:45:44.873Z,1370299544.873 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-06-03T22:45:44.873Z,1370299544.873 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-06-03T22:45:45.014Z,1370299545.014 [AHRS_sp3003D] Loaded
2013-06-03T22:45:45.015Z,1370299545.015 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-06-03T22:45:45.263Z,1370299545.263 [Batt_Ocean_Server] Loaded
2013-06-03T22:45:45.263Z,1370299545.263 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-06-03T22:45:45.276Z,1370299545.276 [Depth_Keller] Loaded
2013-06-03T22:45:45.276Z,1370299545.276 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-06-03T22:45:45.281Z,1370299545.281 [DropWeight] Loaded
2013-06-03T22:45:45.282Z,1370299545.282 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-06-03T22:45:45.448Z,1370299545.448 [DVL_micro] Loaded
2013-06-03T22:45:45.448Z,1370299545.448 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-06-03T22:45:45.449Z,1370299545.449 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406C34E0
2013-06-03T22:45:45.529Z,1370299545.529 [NAL9602] Loaded
2013-06-03T22:45:45.530Z,1370299545.530 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-06-03T22:45:45.578Z,1370299545.578 [Onboard] Loaded
2013-06-03T22:45:45.578Z,1370299545.578 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-06-03T22:45:45.585Z,1370299545.585 [Radio_Freewave] Loaded
2013-06-03T22:45:45.585Z,1370299545.585 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-06-03T22:45:45.739Z,1370299545.739 [DAT] Loaded
2013-06-03T22:45:45.739Z,1370299545.739 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-06-03T22:45:45.746Z,1370299545.746 [SCPI] Loaded
2013-06-03T22:45:45.746Z,1370299545.746 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2013-06-03T22:45:45.747Z,1370299545.747 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-06-03T22:45:45.747Z,1370299545.747 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-06-03T22:45:45.820Z,1370299545.820 [CTD_NeilBrown] Loaded
2013-06-03T22:45:45.820Z,1370299545.820 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-06-03T22:45:45.821Z,1370299545.821 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407154E0
2013-06-03T22:45:45.851Z,1370299545.851 [WetLabsBB2FL] Loaded
2013-06-03T22:45:45.851Z,1370299545.852 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-06-03T22:45:45.853Z,1370299545.853 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407454E0
2013-06-03T22:45:45.853Z,1370299545.853 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-06-03T22:45:45.855Z,1370299545.855 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-06-03T22:45:45.856Z,1370299545.856 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-06-03T22:45:45.863Z,1370299545.863 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-06-03T22:45:45.864Z,1370299545.864 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407754E0
2013-06-03T22:45:45.868Z,1370299545.868 [Supervisor](DEBUG): Running supervisor.
2013-06-03T22:45:45.869Z,1370299545.869 [CommandLine](INFO): Thread ID is 1089
2013-06-03T22:45:45.872Z,1370299545.872 [controlThread](INFO): Thread ID is 1088
2013-06-03T22:45:45.872Z,1370299545.872 [controlThread](DEBUG): Initializing ControlThread
2013-06-03T22:45:45.873Z,1370299545.873 [CycleStarter](INFO): Thread ID is 1087
2013-06-03T22:45:45.873Z,1370299545.873 [InternalSim](DEBUG):  InternalSim initializing...
2013-06-03T22:45:45.972Z,1370299545.972 [logger](INFO): Thread ID is 1090
2013-06-03T22:45:46.059Z,1370299546.059 [AsyncPiEstimator](INFO): Thread ID is 1151
2013-06-03T22:45:46.059Z,1370299546.059 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-06-03T22:45:46.068Z,1370299546.068 [DVL_micro](INFO): Thread ID is 1152
2013-06-03T22:45:46.186Z,1370299546.186 [CTD_NeilBrown](INFO): Thread ID is 1153
2013-06-03T22:45:46.187Z,1370299546.187 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-06-03T22:45:46.191Z,1370299546.191 [WetLabsBB2FL](INFO): Thread ID is 1154
2013-06-03T22:45:46.191Z,1370299546.191 [WetLabsBB2FL](INFO): Powering down
2013-06-03T22:45:46.210Z,1370299546.210 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-06-03T22:45:46.299Z,1370299546.299 [DVL_micro](INFO): Initializing
2013-06-03T22:45:46.299Z,1370299546.299 [DVL_micro](INFO): start:Powering up
2013-06-03T22:45:46.300Z,1370299546.300 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-06-03T22:45:46.301Z,1370299546.301 [DVL_micro](INFO): Cycling power to configure device.
2013-06-03T22:45:46.307Z,1370299546.307 [NavChartDb](INFO): Thread ID is 1155
2013-06-03T22:45:46.312Z,1370299546.312 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-06-03T22:45:46.313Z,1370299546.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-06-03T22:45:46.313Z,1370299546.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-06-03T22:45:46.313Z,1370299546.313 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-06-03T22:45:46.314Z,1370299546.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-06-03T22:45:46.314Z,1370299546.314 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-06-03T22:45:46.315Z,1370299546.315 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-06-03T22:45:46.315Z,1370299546.315 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-06-03T22:45:46.315Z,1370299546.315 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-06-03T22:45:46.334Z,1370299546.334 [SBIT](INFO): Initialize SBIT Component.
2013-06-03T22:45:46.335Z,1370299546.335 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10401
2013-06-03T22:45:46.335Z,1370299546.335 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-06-03T22:45:46.335Z,1370299546.335 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-06-03T22:45:46.336Z,1370299546.336 [IBIT](INFO): Initialize IBIT Component.
2013-06-03T22:45:46.337Z,1370299546.337 [CBIT](DEBUG): Initialize CBIT Component.
2013-06-03T22:45:46.337Z,1370299546.337 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-06-03T22:45:46.363Z,1370299546.364 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-06-03T22:45:46.364Z,1370299546.364 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-06-03T22:45:46.364Z,1370299546.365 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-06-03T22:45:46.365Z,1370299546.365 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-06-03T22:45:46.365Z,1370299546.365 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-06-03T22:45:46.367Z,1370299546.367 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-06-03T22:45:46.367Z,1370299546.367 [Navigation](DEBUG): Initializing Navigation.
2013-06-03T22:45:46.368Z,1370299546.368 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-06-03T22:45:46.369Z,1370299546.369 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-06-03T22:45:46.370Z,1370299546.370 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-06-03T22:45:46.371Z,1370299546.371 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-06-03T22:45:47.961Z,1370299547.961 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-06-03T22:45:48.001Z,1370299548.001 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-06-03T22:45:48.035Z,1370299548.035 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-06-03T22:45:48.065Z,1370299548.065 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-06-03T22:45:48.066Z,1370299548.066 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-06-03T22:45:48.150Z,1370299548.150 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-06-03T22:45:48.152Z,1370299548.152 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-06-03T22:45:48.163Z,1370299548.163 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-06-03T22:45:48.183Z,1370299548.183 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-06-03T22:45:48.199Z,1370299548.198 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-06-03T22:45:48.205Z,1370299548.205 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-06-03T22:45:48.230Z,1370299548.230 [Default:D.SetSpeed](DEBUG): Construct.
2013-06-03T22:45:48.245Z,1370299548.245 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-06-03T22:45:48.250Z,1370299548.250 [Default:F.Wait](DEBUG): Construct Wait.
2013-06-03T22:45:48.266Z,1370299548.266 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Aggregate Id="GPS" >

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

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

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

        <Call RefId="Iridium"/>

    </Aggregate>

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

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

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

</Mission>


2013-06-03T22:45:48.271Z,1370299548.271 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,DAT,SCPI,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-06-03T22:45:48.330Z,1370299548.330 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-06-03T22:45:48.402Z,1370299548.402 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-06-03T22:45:48.403Z,1370299548.403 [DVL_micro](INFO): Querying output modes
2013-06-03T22:45:48.403Z,1370299548.403 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-06-03T22:45:48.414Z,1370299548.414 [DVL_micro](DEBUG): cmdResponse: 01
2013-06-03T22:45:48.414Z,1370299548.414 [DVL_micro](INFO): NQ1 output enabled
2013-06-03T22:45:48.415Z,1370299548.415 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-06-03T22:45:48.426Z,1370299548.426 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-06-03T22:45:48.431Z,1370299548.431 [DVL_micro](INFO): pause:Powering down
2013-06-03T22:45:48.651Z,1370299548.651 [Radio_Freewave](INFO): Powering up
2013-06-03T22:45:48.656Z,1370299548.656 [DAT](INFO): Powering up
2013-06-03T22:45:48.656Z,1370299548.656 [DAT](DEBUG): Initializing DAT.
2013-06-03T22:45:48.898Z,1370299548.898 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-06-03T22:45:48.902Z,1370299548.902 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-06-03T22:45:48.925Z,1370299548.925 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-06-03T22:45:48.930Z,1370299548.930 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-06-03T22:45:48.941Z,1370299548.941 [MassServo](DEBUG): Initializing EZServoServo.
2013-06-03T22:45:48.947Z,1370299548.947 [MassServo](DEBUG): Initializing MassServo.
2013-06-03T22:45:48.952Z,1370299548.953 [RudderServo](DEBUG): Initializing EZServoServo.
2013-06-03T22:45:48.958Z,1370299548.958 [RudderServo](DEBUG): Initializing RudderServo.
2013-06-03T22:45:48.964Z,1370299548.964 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-06-03T22:45:48.970Z,1370299548.970 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-06-03T22:45:50.575Z,1370299550.575 [NAL9602](INFO): Powering up NAL9602
2013-06-03T22:46:00.218Z,1370299560.218 [CommandLine](IMPORTANT): got command show stack
2013-06-03T22:46:00.219Z,1370299560.218 [CommandLine](INFO): Behavior Stack:

2013-06-03T22:46:00.219Z,1370299560.219 [MissionManager](INFO): Mission loaded, but not running.
2013-06-03T22:46:01.194Z,1370299561.194 [NAL9602](INFO): NAL9602 initialized
2013-06-03T22:46:02.096Z,1370299562.096 [SBIT](IMPORTANT): Beginning Startup BIT
2013-06-03T22:46:02.099Z,1370299562.099 [CBIT](IMPORTANT): Beginning GF scan
2013-06-03T22:46:08.855Z,1370299568.855 [DAT](INFO): Powering down
2013-06-03T22:46:28.863Z,1370299588.863 [CBIT](IMPORTANT): No ground fault detected
2013-06-03T22:46:43.867Z,1370299603.867 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2013-06-03T22:46:43.868Z,1370299603.868 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-06-03T22:46:55.829Z,1370299615.829 [SBIT](FAULT): Mass: EXPECTED:0.000000 ACTUAL:-0.000629
2013-06-03T22:46:55.829Z,1370299615.829 [SBIT](FAULT): Control surface position failure.
2013-06-03T22:46:56.119Z,1370299616.119 [NAL9602](INFO): Powering down
2013-06-03T22:46:56.180Z,1370299616.180 [SBIT](CRITICAL): SBIT FAILED
2013-06-03T22:46:56.528Z,1370299616.528 [MissionManager](IMPORTANT): Started mission Startup
2013-06-03T22:46:56.528Z,1370299616.528 [Startup] Running Loop=1
2013-06-03T22:46:56.528Z,1370299616.528 [Startup](INFO): Aggregate::initialize Startup
2013-06-03T22:46:56.528Z,1370299616.528 [Startup:A.GoToSurface] Running Loop=1
2013-06-03T22:46:56.528Z,1370299616.528 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:46:56.534Z,1370299616.534 [Startup:StartupSatComms] Running Loop=1
2013-06-03T22:46:56.534Z,1370299616.534 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-06-03T22:46:56.535Z,1370299616.535 [Startup:StartupSatComms:A] Running Loop=1
2013-06-03T22:46:56.938Z,1370299616.938 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-06-03T22:46:57.319Z,1370299617.319 [NAL9602](INFO): Powering up
2013-06-03T22:47:01.226Z,1370299621.226 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2013-06-03T22:47:02.344Z,1370299622.344 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-06-03T22:47:04.932Z,1370299624.931 [Startup:StartupSatComms:A] Stopped
2013-06-03T22:47:04.932Z,1370299624.932 [Startup:StartupSatComms:B] Running Loop=1
2013-06-03T22:47:05.383Z,1370299625.383 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-06-03T22:47:08.070Z,1370299628.070 [NAL9602](INFO): NAL9602 initialized
2013-06-03T22:47:10.252Z,1370299630.253 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:11.035Z,1370299631.035 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-06-03T22:47:14.636Z,1370299634.636 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:16.607Z,1370299636.607 [CommandLine](IMPORTANT): got command set NAL9602.latitude_fix 36.799999 degree
2013-06-03T22:47:16.908Z,1370299636.908 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:21.216Z,1370299641.216 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:23.563Z,1370299643.563 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:27.997Z,1370299647.997 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:29.039Z,1370299649.039 [CommandLine](IMPORTANT): got command set NAL9602.platform_communications 1.000000 bool
2013-06-03T22:47:32.237Z,1370299652.237 [Startup:StartupSatComms:B] Stopped
2013-06-03T22:47:32.237Z,1370299652.237 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-06-03T22:47:32.237Z,1370299652.237 [Startup:StartupSatComms] Stopped
2013-06-03T22:47:32.237Z,1370299652.237 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-06-03T22:47:32.238Z,1370299652.238 [Startup](INFO): Completed Startup
2013-06-03T22:47:32.238Z,1370299652.238 [Startup] Stopped
2013-06-03T22:47:32.239Z,1370299652.239 [Startup](INFO): Aggregate::uninitialize Startup
2013-06-03T22:47:32.239Z,1370299652.239 [Startup:A.GoToSurface] Stopped
2013-06-03T22:47:32.239Z,1370299652.239 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:47:33.128Z,1370299653.128 [MissionManager](IMPORTANT): Started mission Default
2013-06-03T22:47:33.128Z,1370299653.128 [Default] Running Loop=1
2013-06-03T22:47:33.128Z,1370299653.128 [Default](INFO): Aggregate::initialize Default
2013-06-03T22:47:33.129Z,1370299653.129 [Default:D.SetSpeed] Running Loop=1
2013-06-03T22:47:33.129Z,1370299653.129 [Default:D.SetSpeed](DEBUG): Initialize.
2013-06-03T22:47:33.129Z,1370299653.129 [Default:E.GoToSurface] Running Loop=1
2013-06-03T22:47:33.129Z,1370299653.129 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:47:33.129Z,1370299653.129 [Default:Iridium] Running Loop=1
2013-06-03T22:47:33.129Z,1370299653.129 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-06-03T22:47:33.129Z,1370299653.129 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-06-03T22:47:33.130Z,1370299653.129 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-06-03T22:47:33.130Z,1370299653.130 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-06-03T22:47:33.130Z,1370299653.130 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:47:33.130Z,1370299653.130 [Default:E.GoToSurface] Running Loop=1
2013-06-03T22:47:33.136Z,1370299653.136 [Default:D.SetSpeed] Running Loop=1
2013-06-03T22:47:33.146Z,1370299653.146 [Default:Iridium:B.GoToSurface] Stopped
2013-06-03T22:47:33.146Z,1370299653.146 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:47:33.146Z,1370299653.146 [Default:Iridium:Read_Iridium] Running Loop=1
2013-06-03T22:47:33.146Z,1370299653.146 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-06-03T22:47:33.151Z,1370299653.151 [Default:GPS] Running Loop=1
2013-06-03T22:47:33.151Z,1370299653.151 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-06-03T22:47:33.152Z,1370299653.151 [Default:GPS:A.SetSpeed] Running Loop=1
2013-06-03T22:47:33.152Z,1370299653.152 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-06-03T22:47:33.152Z,1370299653.152 [Default:GPS:B.GoToSurface] Running Loop=1
2013-06-03T22:47:33.152Z,1370299653.152 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:47:33.157Z,1370299653.157 [Default:GPS:B.GoToSurface] Stopped
2013-06-03T22:47:33.157Z,1370299653.157 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:47:33.157Z,1370299653.158 [Default:GPS:Read_GPS] Running Loop=1
2013-06-03T22:47:33.158Z,1370299653.158 [Default:GPS:A.SetSpeed] Running Loop=1
2013-06-03T22:47:33.398Z,1370299653.398 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:33.421Z,1370299653.421 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-06-03T22:47:33.424Z,1370299653.424 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-06-03T22:47:37.740Z,1370299657.740 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-06-03T22:47:39.450Z,1370299659.450 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/SCPI_on.xml
2013-06-03T22:47:39.451Z,1370299659.451 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/SCPI_on.xml
2013-06-03T22:47:39.467Z,1370299659.467 [MissionManager](INFO): DefineArg SCPI_on.MassDefault = -0.006000 n/a
2013-06-03T22:47:39.468Z,1370299659.468 [SCPI_on:A.Pitch](DEBUG): Construct.
2013-06-03T22:47:39.479Z,1370299659.480 [SCPI_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2013-06-03T22:47:39.483Z,1370299659.483 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="SCPI_on">

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

    <Timeout Duration="P15M"/>

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

    <Aggregate Id="TestDrive">

        <ReadData Strategy="MinError">
            <Sensor:SCPI.sampleSCPI/>
        </ReadData>

        <Aggregate Id="Data">

            <When><True/>
            </When>

            <SendData Service="Express"><Sensor:SCPI.sampleSCPI/><Units:bool/>
            </SendData>

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

        </Aggregate>

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

    </Aggregate>

</Mission>


2013-06-03T22:47:39.483Z,1370299659.483 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/SCPI_on.xml
2013-06-03T22:47:39.714Z,1370299659.714 [Default] Stopped
2013-06-03T22:47:39.714Z,1370299659.714 [Default](INFO): Aggregate::uninitialize Default
2013-06-03T22:47:39.714Z,1370299659.714 [Default:GPS] Stopped
2013-06-03T22:47:39.715Z,1370299659.714 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-06-03T22:47:39.715Z,1370299659.714 [Default:GPS:A.SetSpeed] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:47:39.715Z,1370299659.715 [Default:GPS:Read_GPS] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:Iridium] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-06-03T22:47:39.715Z,1370299659.715 [Default:Iridium:A.SetSpeed] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:47:39.715Z,1370299659.715 [Default:Iridium:Read_Iridium] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:D.SetSpeed] Stopped
2013-06-03T22:47:39.715Z,1370299659.715 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:47:39.715Z,1370299659.715 [Default:E.GoToSurface] Stopped
2013-06-03T22:47:39.715Z,1370299659.716 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:47:39.716Z,1370299659.716 [MissionManager](IMPORTANT): Started mission SCPI_on
2013-06-03T22:47:39.716Z,1370299659.716 [SCPI_on] Running Loop=1
2013-06-03T22:47:39.716Z,1370299659.716 [SCPI_on](INFO): Aggregate::initialize SCPI_on
2013-06-03T22:47:39.716Z,1370299659.716 [SCPI_on:A.Pitch] Running Loop=1
2013-06-03T22:47:39.716Z,1370299659.716 [SCPI_on:A.Pitch](DEBUG): Initialize.
2013-06-03T22:47:39.716Z,1370299659.717 [SCPI_on:TestDrive] Running Loop=1
2013-06-03T22:47:39.717Z,1370299659.717 [SCPI_on:TestDrive](INFO): Aggregate::initialize SCPI_on:TestDrive
2013-06-03T22:47:39.717Z,1370299659.717 [SCPI_on:TestDrive:A] Running Loop=1
2013-06-03T22:47:39.717Z,1370299659.717 [SCPI_on:TestDrive:C.Wait] Running Loop=1
2013-06-03T22:47:39.717Z,1370299659.717 [SCPI_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2013-06-03T22:47:39.722Z,1370299659.722 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:39.723Z,1370299659.723 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:39.723Z,1370299659.723 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:39.725Z,1370299659.725 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:39.725Z,1370299659.726 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:39.726Z,1370299659.726 [SCPI_on:TestDrive:A] Running Loop=1
2013-06-03T22:47:39.729Z,1370299659.729 [SCPI_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense SCPI.sampleSCPI
2013-06-03T22:47:39.731Z,1370299659.731 [SCPI_on:A.Pitch] Running Loop=1
2013-06-03T22:47:40.166Z,1370299660.166 [SCPI](INFO): Powering up
2013-06-03T22:47:40.177Z,1370299660.177 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:40.177Z,1370299660.177 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:40.177Z,1370299660.177 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:40.177Z,1370299660.177 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:40.511Z,1370299660.511 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:40.511Z,1370299660.511 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:40.511Z,1370299660.511 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:40.512Z,1370299660.512 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:40.512Z,1370299660.512 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:40.951Z,1370299660.951 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:40.951Z,1370299660.951 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:40.951Z,1370299660.951 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:40.951Z,1370299660.951 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:41.318Z,1370299661.318 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:41.318Z,1370299661.318 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:41.318Z,1370299661.318 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:41.319Z,1370299661.319 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:41.319Z,1370299661.319 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:41.714Z,1370299661.714 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:41.714Z,1370299661.714 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:41.714Z,1370299661.714 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:41.714Z,1370299661.714 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:42.113Z,1370299662.113 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:42.113Z,1370299662.113 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:42.113Z,1370299662.113 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:42.114Z,1370299662.114 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:42.114Z,1370299662.114 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:42.618Z,1370299662.618 [SCPI](INFO): Init failed - response: 
2013-06-03T22:47:42.618Z,1370299662.618 [SCPI](FAULT): SCPI failed to initialize
2013-06-03T22:47:42.618Z,1370299662.618 [SCPI] Communications Fault, FailCount= 1
2013-06-03T22:47:42.618Z,1370299662.618 [SCPI](ERROR): Communications Fault
2013-06-03T22:47:42.627Z,1370299662.628 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:42.628Z,1370299662.628 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:42.628Z,1370299662.628 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:42.628Z,1370299662.628 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:42.637Z,1370299662.637 [CBIT](ERROR): Communications Fault in component: SCPI
2013-06-03T22:47:42.917Z,1370299662.917 [SCPI](INFO): Powering down
2013-06-03T22:47:43.072Z,1370299663.072 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:43.072Z,1370299663.072 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:43.072Z,1370299663.072 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:43.073Z,1370299663.073 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:43.073Z,1370299663.073 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:43.315Z,1370299663.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:43.315Z,1370299663.316 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:43.316Z,1370299663.316 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:43.316Z,1370299663.316 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:43.718Z,1370299663.718 [SCPI](INFO): Powering up
2013-06-03T22:47:43.729Z,1370299663.730 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:43.730Z,1370299663.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:43.730Z,1370299663.730 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:43.730Z,1370299663.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:43.730Z,1370299663.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:43.739Z,1370299663.739 [CBIT](INFO): Clearing failed state for component SCPI
2013-06-03T22:47:43.739Z,1370299663.739 [SCPI] No Fault, FailCount= 1
2013-06-03T22:47:44.143Z,1370299664.143 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:44.143Z,1370299664.143 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:44.143Z,1370299664.143 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:44.143Z,1370299664.143 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:44.515Z,1370299664.514 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:44.515Z,1370299664.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:44.515Z,1370299664.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:44.515Z,1370299664.515 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:44.515Z,1370299664.515 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:44.914Z,1370299664.914 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:44.914Z,1370299664.914 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:44.915Z,1370299664.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:44.915Z,1370299664.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:45.359Z,1370299665.359 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:45.359Z,1370299665.359 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:45.359Z,1370299665.359 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:45.359Z,1370299665.359 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:45.359Z,1370299665.359 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:45.692Z,1370299665.692 [NAL9602](INFO): Powering down
2013-06-03T22:47:45.710Z,1370299665.710 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:45.710Z,1370299665.710 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:45.710Z,1370299665.710 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:45.710Z,1370299665.710 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:46.114Z,1370299666.114 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:46.114Z,1370299666.114 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:46.115Z,1370299666.115 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:46.115Z,1370299666.115 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:46.115Z,1370299666.115 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:46.538Z,1370299666.538 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:46.539Z,1370299666.539 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:46.539Z,1370299666.539 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:46.539Z,1370299666.539 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:46.915Z,1370299666.915 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:46.915Z,1370299666.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:46.915Z,1370299666.915 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:46.915Z,1370299666.915 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:46.916Z,1370299666.916 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:47.343Z,1370299667.343 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:47.343Z,1370299667.343 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:47.343Z,1370299667.343 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:47.343Z,1370299667.343 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:47.708Z,1370299667.708 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:47.708Z,1370299667.708 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:47.708Z,1370299667.708 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:47.709Z,1370299667.709 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:47.709Z,1370299667.709 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:48.115Z,1370299668.115 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:48.115Z,1370299668.115 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:48.115Z,1370299668.115 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:48.115Z,1370299668.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:48.514Z,1370299668.514 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:48.514Z,1370299668.514 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:48.515Z,1370299668.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:48.515Z,1370299668.515 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:48.515Z,1370299668.515 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:48.915Z,1370299668.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:48.915Z,1370299668.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:48.915Z,1370299668.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:48.916Z,1370299668.916 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:49.315Z,1370299669.315 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:49.315Z,1370299669.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:49.315Z,1370299669.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:49.315Z,1370299669.316 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:49.316Z,1370299669.316 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:49.716Z,1370299669.716 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:49.716Z,1370299669.716 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:49.716Z,1370299669.716 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:49.716Z,1370299669.717 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:50.171Z,1370299670.171 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:50.171Z,1370299670.171 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:50.171Z,1370299670.171 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:50.171Z,1370299670.171 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:50.172Z,1370299670.172 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:50.555Z,1370299670.555 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:50.555Z,1370299670.555 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:50.555Z,1370299670.555 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:50.555Z,1370299670.555 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:50.914Z,1370299670.914 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:50.914Z,1370299670.914 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:50.915Z,1370299670.915 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:50.915Z,1370299670.915 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:50.915Z,1370299670.915 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:51.315Z,1370299671.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:51.315Z,1370299671.316 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:51.316Z,1370299671.316 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:51.316Z,1370299671.316 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:51.715Z,1370299671.714 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:51.715Z,1370299671.715 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:51.715Z,1370299671.715 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:51.715Z,1370299671.715 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:51.715Z,1370299671.715 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:52.114Z,1370299672.114 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:52.115Z,1370299672.115 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:52.115Z,1370299672.115 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:52.115Z,1370299672.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:52.515Z,1370299672.515 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:52.515Z,1370299672.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:52.515Z,1370299672.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:52.516Z,1370299672.516 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:52.516Z,1370299672.516 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:52.915Z,1370299672.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:52.915Z,1370299672.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:52.915Z,1370299672.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:52.915Z,1370299672.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:53.314Z,1370299673.314 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:53.315Z,1370299673.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:53.315Z,1370299673.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:53.315Z,1370299673.315 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:53.315Z,1370299673.315 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:53.751Z,1370299673.751 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:53.751Z,1370299673.751 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:53.751Z,1370299673.751 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:53.751Z,1370299673.751 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:54.142Z,1370299674.142 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:54.143Z,1370299674.143 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:54.143Z,1370299674.143 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:54.143Z,1370299674.143 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:54.143Z,1370299674.143 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:54.515Z,1370299674.515 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:54.515Z,1370299674.515 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:54.515Z,1370299674.515 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:54.515Z,1370299674.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:54.915Z,1370299674.915 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:54.915Z,1370299674.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:54.915Z,1370299674.915 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:54.916Z,1370299674.916 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:54.916Z,1370299674.916 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:55.363Z,1370299675.363 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:55.363Z,1370299675.364 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:55.363Z,1370299675.364 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:55.364Z,1370299675.364 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:55.715Z,1370299675.715 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:55.715Z,1370299675.715 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:55.715Z,1370299675.715 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:55.716Z,1370299675.716 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:55.716Z,1370299675.716 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:56.116Z,1370299676.116 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:56.116Z,1370299676.116 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:56.116Z,1370299676.116 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:56.116Z,1370299676.116 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:56.515Z,1370299676.515 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:56.515Z,1370299676.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:56.516Z,1370299676.516 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:56.516Z,1370299676.516 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:56.516Z,1370299676.516 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:56.950Z,1370299676.950 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:56.951Z,1370299676.951 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:56.951Z,1370299676.951 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:56.951Z,1370299676.951 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:57.319Z,1370299677.319 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:57.320Z,1370299677.320 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:57.320Z,1370299677.320 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:57.320Z,1370299677.320 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:57.320Z,1370299677.320 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:57.712Z,1370299677.712 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:57.712Z,1370299677.713 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:57.713Z,1370299677.713 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:57.713Z,1370299677.713 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:58.118Z,1370299678.118 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:58.118Z,1370299678.118 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:58.119Z,1370299678.118 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:58.119Z,1370299678.119 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:58.119Z,1370299678.119 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:58.519Z,1370299678.519 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:58.519Z,1370299678.519 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:58.520Z,1370299678.520 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:58.520Z,1370299678.520 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:58.950Z,1370299678.950 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:58.950Z,1370299678.950 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:58.950Z,1370299678.950 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:58.951Z,1370299678.951 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:58.951Z,1370299678.951 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:47:59.337Z,1370299679.337 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:47:59.337Z,1370299679.337 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:47:59.337Z,1370299679.337 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:47:59.337Z,1370299679.337 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:47:59.715Z,1370299679.715 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:47:59.715Z,1370299679.715 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:47:59.715Z,1370299679.715 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:47:59.716Z,1370299679.716 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:47:59.716Z,1370299679.716 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:00.139Z,1370299680.139 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:00.140Z,1370299680.139 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:00.140Z,1370299680.140 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:00.140Z,1370299680.140 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:00.567Z,1370299680.567 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:00.567Z,1370299680.567 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:00.567Z,1370299680.568 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:00.568Z,1370299680.568 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:00.568Z,1370299680.568 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:00.915Z,1370299680.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:00.915Z,1370299680.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:00.915Z,1370299680.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:00.916Z,1370299680.916 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:01.315Z,1370299681.315 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:01.315Z,1370299681.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:01.315Z,1370299681.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:01.315Z,1370299681.315 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:01.315Z,1370299681.315 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:01.714Z,1370299681.714 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:01.715Z,1370299681.715 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:01.715Z,1370299681.715 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:01.715Z,1370299681.715 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:02.115Z,1370299682.115 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:02.115Z,1370299682.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:02.115Z,1370299682.115 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:02.116Z,1370299682.116 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:02.116Z,1370299682.116 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:02.515Z,1370299682.515 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:02.515Z,1370299682.515 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:02.515Z,1370299682.515 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:02.515Z,1370299682.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:02.914Z,1370299682.914 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:02.914Z,1370299682.914 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:02.914Z,1370299682.914 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:02.915Z,1370299682.915 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:02.915Z,1370299682.915 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:03.315Z,1370299683.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:03.315Z,1370299683.315 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:03.315Z,1370299683.316 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:03.316Z,1370299683.316 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:03.745Z,1370299683.745 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:03.745Z,1370299683.745 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:03.746Z,1370299683.746 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:03.746Z,1370299683.746 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:03.746Z,1370299683.746 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:04.115Z,1370299684.115 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:04.115Z,1370299684.115 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:04.115Z,1370299684.115 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:04.115Z,1370299684.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:04.515Z,1370299684.515 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:04.515Z,1370299684.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:04.515Z,1370299684.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:04.516Z,1370299684.516 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:04.516Z,1370299684.516 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:04.915Z,1370299684.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:04.915Z,1370299684.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:04.915Z,1370299684.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:04.915Z,1370299684.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:05.363Z,1370299685.363 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:05.363Z,1370299685.363 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:05.363Z,1370299685.363 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:05.363Z,1370299685.363 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:05.364Z,1370299685.364 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:05.712Z,1370299685.712 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:05.712Z,1370299685.713 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:05.712Z,1370299685.713 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:05.713Z,1370299685.713 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:06.115Z,1370299686.115 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:06.115Z,1370299686.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:06.115Z,1370299686.115 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:06.115Z,1370299686.115 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:06.115Z,1370299686.115 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:06.515Z,1370299686.515 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:06.515Z,1370299686.515 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:06.515Z,1370299686.515 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:06.515Z,1370299686.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:06.951Z,1370299686.951 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:06.951Z,1370299686.951 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:06.951Z,1370299686.951 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:06.952Z,1370299686.952 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:06.952Z,1370299686.952 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:07.315Z,1370299687.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:07.315Z,1370299687.315 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:07.315Z,1370299687.315 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:07.315Z,1370299687.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:07.711Z,1370299687.711 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:07.711Z,1370299687.711 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:07.711Z,1370299687.711 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:07.711Z,1370299687.711 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:07.712Z,1370299687.712 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:08.116Z,1370299688.116 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:08.116Z,1370299688.116 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:08.116Z,1370299688.116 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:08.116Z,1370299688.116 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:08.515Z,1370299688.515 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:08.515Z,1370299688.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:08.515Z,1370299688.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:08.516Z,1370299688.516 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:08.516Z,1370299688.516 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:08.915Z,1370299688.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:08.915Z,1370299688.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:08.915Z,1370299688.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:08.915Z,1370299688.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:09.315Z,1370299689.315 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:09.316Z,1370299689.316 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:09.316Z,1370299689.316 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:09.316Z,1370299689.316 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:09.316Z,1370299689.316 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:09.715Z,1370299689.715 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:09.715Z,1370299689.716 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:09.716Z,1370299689.716 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:09.716Z,1370299689.716 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:10.214Z,1370299690.214 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:10.214Z,1370299690.214 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:10.214Z,1370299690.214 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:10.215Z,1370299690.215 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:10.215Z,1370299690.215 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:10.519Z,1370299690.519 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:10.520Z,1370299690.520 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:10.520Z,1370299690.520 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:10.520Z,1370299690.520 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:10.963Z,1370299690.963 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:10.963Z,1370299690.963 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:10.963Z,1370299690.963 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:10.964Z,1370299690.964 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:10.964Z,1370299690.964 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:11.306Z,1370299691.306 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:11.306Z,1370299691.306 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:11.306Z,1370299691.306 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:11.306Z,1370299691.306 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:11.737Z,1370299691.737 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:11.737Z,1370299691.737 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:11.737Z,1370299691.737 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:11.738Z,1370299691.738 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:11.738Z,1370299691.738 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:12.136Z,1370299692.136 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:12.137Z,1370299692.137 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:12.137Z,1370299692.137 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:12.137Z,1370299692.137 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:12.514Z,1370299692.514 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:12.514Z,1370299692.514 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:12.515Z,1370299692.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:12.515Z,1370299692.515 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:12.515Z,1370299692.515 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:12.915Z,1370299692.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:12.915Z,1370299692.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:12.916Z,1370299692.916 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:12.916Z,1370299692.916 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:13.347Z,1370299693.347 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:13.347Z,1370299693.347 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:13.347Z,1370299693.347 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:13.348Z,1370299693.348 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:13.348Z,1370299693.348 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:13.722Z,1370299693.722 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:13.722Z,1370299693.722 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:13.722Z,1370299693.722 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:13.722Z,1370299693.722 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:14.119Z,1370299694.119 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:14.119Z,1370299694.119 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:14.119Z,1370299694.119 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:14.120Z,1370299694.120 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:14.120Z,1370299694.120 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:14.519Z,1370299694.519 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:14.519Z,1370299694.519 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:14.519Z,1370299694.519 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:14.519Z,1370299694.519 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:14.917Z,1370299694.917 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:14.918Z,1370299694.918 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:14.918Z,1370299694.918 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:14.918Z,1370299694.918 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:14.918Z,1370299694.918 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:15.315Z,1370299695.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:15.315Z,1370299695.316 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:15.316Z,1370299695.316 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:15.316Z,1370299695.316 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:15.763Z,1370299695.763 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:15.763Z,1370299695.763 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:15.763Z,1370299695.763 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:15.764Z,1370299695.764 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:15.764Z,1370299695.764 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:16.115Z,1370299696.115 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:16.115Z,1370299696.115 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:16.115Z,1370299696.115 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:16.115Z,1370299696.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:16.551Z,1370299696.551 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:16.551Z,1370299696.551 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:16.551Z,1370299696.551 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:16.552Z,1370299696.552 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:16.552Z,1370299696.552 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:16.915Z,1370299696.915 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:16.915Z,1370299696.915 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:16.915Z,1370299696.915 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:16.915Z,1370299696.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:17.314Z,1370299697.314 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:17.315Z,1370299697.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:17.315Z,1370299697.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:17.315Z,1370299697.315 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:17.315Z,1370299697.315 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:17.715Z,1370299697.715 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:17.715Z,1370299697.715 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:17.715Z,1370299697.715 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:17.716Z,1370299697.716 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:18.114Z,1370299698.114 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:18.115Z,1370299698.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:18.115Z,1370299698.115 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:18.115Z,1370299698.115 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:18.115Z,1370299698.115 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:18.515Z,1370299698.514 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:18.515Z,1370299698.515 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:18.515Z,1370299698.515 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:18.515Z,1370299698.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:18.915Z,1370299698.915 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:18.915Z,1370299698.915 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:18.915Z,1370299698.915 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:18.915Z,1370299698.915 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:18.916Z,1370299698.916 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:19.315Z,1370299699.315 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:19.315Z,1370299699.315 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:19.315Z,1370299699.315 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:19.315Z,1370299699.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:19.745Z,1370299699.745 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:19.745Z,1370299699.745 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:19.745Z,1370299699.745 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:19.746Z,1370299699.746 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:19.746Z,1370299699.746 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:20.115Z,1370299700.115 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:20.116Z,1370299700.116 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:20.116Z,1370299700.116 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:20.116Z,1370299700.116 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:20.515Z,1370299700.515 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:20.515Z,1370299700.515 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:20.515Z,1370299700.515 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:20.515Z,1370299700.515 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:20.516Z,1370299700.516 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:20.963Z,1370299700.963 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:20.963Z,1370299700.963 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:20.963Z,1370299700.963 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:20.963Z,1370299700.963 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:21.315Z,1370299701.315 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:21.315Z,1370299701.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:21.315Z,1370299701.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:21.316Z,1370299701.316 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:21.316Z,1370299701.316 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:21.715Z,1370299701.715 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:21.715Z,1370299701.716 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:21.716Z,1370299701.716 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:21.716Z,1370299701.716 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:22.115Z,1370299702.115 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:22.115Z,1370299702.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:22.115Z,1370299702.115 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:22.116Z,1370299702.115 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:22.116Z,1370299702.116 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:22.516Z,1370299702.516 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:22.516Z,1370299702.516 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:22.516Z,1370299702.516 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:22.516Z,1370299702.516 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:22.943Z,1370299702.943 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:22.943Z,1370299702.943 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:22.943Z,1370299702.943 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:22.944Z,1370299702.944 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:22.944Z,1370299702.944 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:23.318Z,1370299703.318 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:23.318Z,1370299703.318 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:23.318Z,1370299703.318 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:23.318Z,1370299703.318 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:23.708Z,1370299703.708 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:23.708Z,1370299703.708 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:23.709Z,1370299703.709 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:23.709Z,1370299703.709 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:23.709Z,1370299703.709 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:24.115Z,1370299704.115 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:24.115Z,1370299704.115 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:24.116Z,1370299704.115 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:24.116Z,1370299704.116 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:24.447Z,1370299704.447 [CommandLine](IMPORTANT): got command show variable scpi
2013-06-03T22:48:24.456Z,1370299704.457 [CommandLine](INFO): Config/vehicle.SCPI_card (none)
2013-06-03T22:48:24.457Z,1370299704.457 [CommandLine](INFO): Config/vehicle.SCPI_uart (none)
2013-06-03T22:48:24.457Z,1370299704.457 [CommandLine](INFO): Config/vehicle.SCPI_baud (bit_per_second)
2013-06-03T22:48:24.463Z,1370299704.463 [CommandLine](INFO): Config/Sensor.SCPI_enable (bool)
2013-06-03T22:48:24.463Z,1370299704.463 [CommandLine](INFO): Config/Sensor.SCPI_useHardware (bool)
2013-06-03T22:48:24.463Z,1370299704.463 [CommandLine](INFO): Config/Sensor.SCPISampleTime (second)
2013-06-03T22:48:24.517Z,1370299704.517 [CommandLine](INFO): SCPI.sampleSCPI (bool)
2013-06-03T22:48:24.532Z,1370299704.532 [CommandLine](INFO): SCPI.durationOfLastRun (second)
2013-06-03T22:48:24.536Z,1370299704.536 [CommandLine](INFO): SCPI_on.MassDefault (none)
2013-06-03T22:48:24.537Z,1370299704.537 [CommandLine](INFO): SCPI_on:TestDrive:C.Wait.durationOfLastRun (second)
2013-06-03T22:48:24.537Z,1370299704.537 [CommandLine](INFO): SCPI_on:TestDrive:Data:A.durationOfLastRun (second)
2013-06-03T22:48:24.537Z,1370299704.537 [CommandLine](INFO): SCPI_on:TestDrive:A.durationOfLastRun (second)
2013-06-03T22:48:24.538Z,1370299704.538 [CommandLine](INFO): SCPI_on:A.Pitch.durationOfLastRun (second)
2013-06-03T22:48:24.546Z,1370299704.546 [CommandLine](INFO): SCPI_on:TestDrive:Data:B.durationOfLastRun (second)
2013-06-03T22:48:24.547Z,1370299704.546 [CommandLine](INFO): SCPI.component_voltage (volt)
2013-06-03T22:48:24.547Z,1370299704.547 [CommandLine](INFO): SCPI.component_avgVoltage (volt)
2013-06-03T22:48:24.547Z,1370299704.547 [CommandLine](INFO): SCPI.component_current (milliampere)
2013-06-03T22:48:24.548Z,1370299704.548 [CommandLine](INFO): SCPI.component_avgCurrent (milliampere)
2013-06-03T22:48:24.566Z,1370299704.566 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:24.566Z,1370299704.566 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:24.567Z,1370299704.566 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:24.567Z,1370299704.567 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:24.567Z,1370299704.567 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:24.938Z,1370299704.938 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:24.939Z,1370299704.939 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:24.939Z,1370299704.939 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:24.939Z,1370299704.939 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:25.311Z,1370299705.311 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:25.311Z,1370299705.311 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:25.311Z,1370299705.311 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:25.312Z,1370299705.312 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:25.312Z,1370299705.312 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:25.711Z,1370299705.711 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:25.711Z,1370299705.711 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:25.711Z,1370299705.711 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:25.711Z,1370299705.711 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:26.279Z,1370299706.279 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:26.279Z,1370299706.279 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:26.280Z,1370299706.280 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:26.280Z,1370299706.280 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:26.280Z,1370299706.280 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:26.548Z,1370299706.548 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:26.548Z,1370299706.548 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:26.548Z,1370299706.548 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:26.548Z,1370299706.548 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:26.927Z,1370299706.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:26.927Z,1370299706.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:26.927Z,1370299706.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:26.928Z,1370299706.928 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:26.928Z,1370299706.928 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:27.327Z,1370299707.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:27.328Z,1370299707.328 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:27.328Z,1370299707.328 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:27.328Z,1370299707.328 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:27.729Z,1370299707.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:27.729Z,1370299707.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:27.729Z,1370299707.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:27.730Z,1370299707.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:27.730Z,1370299707.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:28.126Z,1370299708.126 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:28.127Z,1370299708.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:28.127Z,1370299708.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:28.127Z,1370299708.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:28.531Z,1370299708.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:28.531Z,1370299708.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:28.531Z,1370299708.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:28.532Z,1370299708.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:28.532Z,1370299708.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:28.927Z,1370299708.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:28.927Z,1370299708.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:28.927Z,1370299708.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:28.927Z,1370299708.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:29.359Z,1370299709.359 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:29.359Z,1370299709.359 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:29.359Z,1370299709.359 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:29.359Z,1370299709.359 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:29.359Z,1370299709.359 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:29.734Z,1370299709.734 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:29.734Z,1370299709.734 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:29.734Z,1370299709.734 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:29.734Z,1370299709.734 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:30.131Z,1370299710.131 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:30.131Z,1370299710.131 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:30.131Z,1370299710.131 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:30.131Z,1370299710.131 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:30.131Z,1370299710.131 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:30.531Z,1370299710.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:30.531Z,1370299710.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:30.531Z,1370299710.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:30.531Z,1370299710.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:31.017Z,1370299711.017 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:31.017Z,1370299711.017 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:31.017Z,1370299711.017 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:31.018Z,1370299711.018 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:31.018Z,1370299711.018 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:31.327Z,1370299711.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:31.327Z,1370299711.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:31.327Z,1370299711.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:31.327Z,1370299711.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:31.729Z,1370299711.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:31.729Z,1370299711.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:31.729Z,1370299711.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:31.730Z,1370299711.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:31.730Z,1370299711.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:32.140Z,1370299712.140 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:32.140Z,1370299712.140 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:32.140Z,1370299712.140 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:32.140Z,1370299712.140 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:32.570Z,1370299712.570 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:32.571Z,1370299712.570 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:32.571Z,1370299712.571 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:32.571Z,1370299712.571 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:32.571Z,1370299712.571 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:32.938Z,1370299712.938 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:32.939Z,1370299712.939 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:32.939Z,1370299712.939 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:32.939Z,1370299712.939 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:33.327Z,1370299713.327 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:33.327Z,1370299713.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:33.327Z,1370299713.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:33.328Z,1370299713.328 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:33.328Z,1370299713.328 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:33.729Z,1370299713.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:33.729Z,1370299713.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:33.729Z,1370299713.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:33.730Z,1370299713.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:34.123Z,1370299714.123 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:34.123Z,1370299714.123 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:34.123Z,1370299714.123 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:34.123Z,1370299714.124 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:34.124Z,1370299714.124 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:34.531Z,1370299714.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:34.531Z,1370299714.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:34.531Z,1370299714.532 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:34.532Z,1370299714.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:34.927Z,1370299714.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:34.927Z,1370299714.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:34.928Z,1370299714.928 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:34.928Z,1370299714.928 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:34.928Z,1370299714.928 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:35.327Z,1370299715.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:35.328Z,1370299715.328 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:35.328Z,1370299715.328 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:35.328Z,1370299715.328 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:35.711Z,1370299715.711 [CommandLine](IMPORTANT): got command report mod SCPI.sampleSCPI
2013-06-03T22:48:35.767Z,1370299715.767 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:35.767Z,1370299715.767 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:35.767Z,1370299715.767 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:35.768Z,1370299715.768 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:35.768Z,1370299715.768 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:35.778Z,1370299715.778 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:48:36.175Z,1370299716.175 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:36.175Z,1370299716.175 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:36.176Z,1370299716.175 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:36.176Z,1370299716.176 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:36.531Z,1370299716.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:36.531Z,1370299716.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:36.531Z,1370299716.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:36.532Z,1370299716.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:36.532Z,1370299716.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:36.927Z,1370299716.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:36.928Z,1370299716.928 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:36.928Z,1370299716.928 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:36.928Z,1370299716.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:37.346Z,1370299717.346 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:37.347Z,1370299717.347 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:37.347Z,1370299717.347 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:37.347Z,1370299717.347 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:37.347Z,1370299717.347 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:37.358Z,1370299717.358 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:48:37.749Z,1370299717.749 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:37.749Z,1370299717.750 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:37.750Z,1370299717.750 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:37.750Z,1370299717.750 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:37.762Z,1370299717.762 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:48:38.127Z,1370299718.127 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:38.127Z,1370299718.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:38.127Z,1370299718.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:38.128Z,1370299718.128 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:38.128Z,1370299718.128 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:38.531Z,1370299718.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:38.531Z,1370299718.532 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:38.532Z,1370299718.532 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:38.532Z,1370299718.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:38.955Z,1370299718.955 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:38.955Z,1370299718.955 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:38.956Z,1370299718.955 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:38.956Z,1370299718.956 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:38.956Z,1370299718.956 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:39.327Z,1370299719.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:39.327Z,1370299719.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:39.327Z,1370299719.328 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:39.328Z,1370299719.328 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:39.729Z,1370299719.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:39.729Z,1370299719.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:39.729Z,1370299719.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:39.730Z,1370299719.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:39.730Z,1370299719.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:40.126Z,1370299720.126 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:40.127Z,1370299720.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:40.127Z,1370299720.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:40.127Z,1370299720.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:40.531Z,1370299720.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:40.531Z,1370299720.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:40.531Z,1370299720.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:40.532Z,1370299720.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:40.532Z,1370299720.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:40.927Z,1370299720.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:40.927Z,1370299720.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:40.927Z,1370299720.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:40.928Z,1370299720.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:41.383Z,1370299721.383 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:41.384Z,1370299721.384 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:41.384Z,1370299721.384 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:41.384Z,1370299721.384 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:41.384Z,1370299721.384 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:41.730Z,1370299721.730 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:41.730Z,1370299721.730 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:41.730Z,1370299721.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:41.730Z,1370299721.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:42.159Z,1370299722.159 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:42.160Z,1370299722.159 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:42.160Z,1370299722.160 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:42.160Z,1370299722.160 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:42.160Z,1370299722.160 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:42.567Z,1370299722.567 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:42.567Z,1370299722.567 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:42.567Z,1370299722.567 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:42.567Z,1370299722.568 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:42.927Z,1370299722.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:42.927Z,1370299722.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:42.927Z,1370299722.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:42.928Z,1370299722.928 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:42.928Z,1370299722.928 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:43.327Z,1370299723.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:43.327Z,1370299723.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:43.327Z,1370299723.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:43.327Z,1370299723.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:43.729Z,1370299723.728 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:43.729Z,1370299723.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:43.729Z,1370299723.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:43.729Z,1370299723.729 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:43.729Z,1370299723.729 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:44.127Z,1370299724.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:44.127Z,1370299724.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:44.127Z,1370299724.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:44.127Z,1370299724.128 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:44.530Z,1370299724.530 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:44.531Z,1370299724.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:44.531Z,1370299724.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:44.531Z,1370299724.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:44.531Z,1370299724.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:44.927Z,1370299724.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:44.927Z,1370299724.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:44.927Z,1370299724.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:44.927Z,1370299724.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:45.331Z,1370299725.331 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:45.331Z,1370299725.331 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:45.331Z,1370299725.332 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:45.332Z,1370299725.332 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:45.332Z,1370299725.332 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:45.775Z,1370299725.775 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:45.775Z,1370299725.776 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:45.776Z,1370299725.776 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:45.776Z,1370299725.776 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:46.142Z,1370299726.142 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:46.142Z,1370299726.142 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:46.143Z,1370299726.143 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:46.143Z,1370299726.143 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:46.143Z,1370299726.143 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:46.580Z,1370299726.579 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:46.580Z,1370299726.580 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:46.580Z,1370299726.580 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:46.580Z,1370299726.580 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:46.929Z,1370299726.929 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:46.930Z,1370299726.930 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:46.930Z,1370299726.930 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:46.930Z,1370299726.930 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:46.930Z,1370299726.931 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:47.327Z,1370299727.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:47.327Z,1370299727.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:47.327Z,1370299727.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:47.327Z,1370299727.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:47.729Z,1370299727.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:47.730Z,1370299727.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:47.730Z,1370299727.730 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:47.730Z,1370299727.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:47.730Z,1370299727.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:48.127Z,1370299728.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:48.127Z,1370299728.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:48.127Z,1370299728.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:48.127Z,1370299728.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:48.531Z,1370299728.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:48.531Z,1370299728.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:48.531Z,1370299728.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:48.531Z,1370299728.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:48.531Z,1370299728.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:48.963Z,1370299728.963 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:48.963Z,1370299728.963 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:48.963Z,1370299728.963 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:48.963Z,1370299728.963 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:49.326Z,1370299729.326 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:49.326Z,1370299729.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:49.326Z,1370299729.326 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:49.327Z,1370299729.327 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:49.327Z,1370299729.327 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:49.729Z,1370299729.730 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:49.730Z,1370299729.730 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:49.730Z,1370299729.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:49.730Z,1370299729.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:50.146Z,1370299730.146 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:50.146Z,1370299730.146 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:50.146Z,1370299730.146 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:50.147Z,1370299730.147 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:50.147Z,1370299730.147 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:50.157Z,1370299730.157 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:48:50.558Z,1370299730.558 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:50.558Z,1370299730.558 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:50.558Z,1370299730.558 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:50.558Z,1370299730.558 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:50.570Z,1370299730.570 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:48:50.939Z,1370299730.939 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:50.939Z,1370299730.939 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:50.939Z,1370299730.939 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:50.939Z,1370299730.940 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:50.940Z,1370299730.940 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:51.327Z,1370299731.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:51.328Z,1370299731.328 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:51.328Z,1370299731.328 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:51.328Z,1370299731.328 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:51.782Z,1370299731.782 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:51.783Z,1370299731.783 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:51.783Z,1370299731.783 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:51.783Z,1370299731.783 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:51.783Z,1370299731.783 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:52.166Z,1370299732.166 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:52.167Z,1370299732.167 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:52.167Z,1370299732.167 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:52.167Z,1370299732.167 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:52.531Z,1370299732.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:52.531Z,1370299732.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:52.531Z,1370299732.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:52.532Z,1370299732.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:52.532Z,1370299732.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:52.927Z,1370299732.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:52.927Z,1370299732.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:52.927Z,1370299732.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:52.927Z,1370299732.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:53.326Z,1370299733.326 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:53.326Z,1370299733.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:53.327Z,1370299733.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:53.327Z,1370299733.327 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:53.327Z,1370299733.327 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:53.729Z,1370299733.730 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:53.730Z,1370299733.730 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:53.730Z,1370299733.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:53.730Z,1370299733.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:54.126Z,1370299734.126 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:54.126Z,1370299734.126 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:54.127Z,1370299734.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:54.127Z,1370299734.127 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:54.127Z,1370299734.127 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:54.531Z,1370299734.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:54.531Z,1370299734.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:54.531Z,1370299734.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:54.531Z,1370299734.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:54.927Z,1370299734.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:54.927Z,1370299734.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:54.927Z,1370299734.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:54.928Z,1370299734.928 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:54.928Z,1370299734.928 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:55.363Z,1370299735.363 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:55.363Z,1370299735.363 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:55.363Z,1370299735.363 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:55.363Z,1370299735.363 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:55.729Z,1370299735.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:55.729Z,1370299735.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:55.729Z,1370299735.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:55.730Z,1370299735.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:55.730Z,1370299735.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:56.127Z,1370299736.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:56.128Z,1370299736.128 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:56.128Z,1370299736.128 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:56.128Z,1370299736.128 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:56.530Z,1370299736.530 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:56.531Z,1370299736.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:56.531Z,1370299736.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:56.531Z,1370299736.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:56.531Z,1370299736.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:56.975Z,1370299736.975 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:56.975Z,1370299736.975 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:56.975Z,1370299736.975 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:56.975Z,1370299736.975 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:57.327Z,1370299737.327 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:57.327Z,1370299737.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:57.327Z,1370299737.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:57.328Z,1370299737.328 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:57.328Z,1370299737.328 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:57.729Z,1370299737.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:57.729Z,1370299737.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:57.729Z,1370299737.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:57.730Z,1370299737.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:58.142Z,1370299738.142 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:58.143Z,1370299738.143 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:58.143Z,1370299738.143 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:58.143Z,1370299738.143 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:58.143Z,1370299738.143 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:58.571Z,1370299738.571 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:58.572Z,1370299738.572 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:58.572Z,1370299738.572 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:58.572Z,1370299738.572 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:58.927Z,1370299738.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:58.927Z,1370299738.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:58.927Z,1370299738.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:58.927Z,1370299738.927 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:58.927Z,1370299738.927 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:48:59.326Z,1370299739.326 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:48:59.327Z,1370299739.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:48:59.327Z,1370299739.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:48:59.327Z,1370299739.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:48:59.729Z,1370299739.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:48:59.729Z,1370299739.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:48:59.729Z,1370299739.730 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:48:59.730Z,1370299739.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:48:59.730Z,1370299739.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:00.127Z,1370299740.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:00.127Z,1370299740.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:00.127Z,1370299740.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:00.127Z,1370299740.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:00.530Z,1370299740.530 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:00.530Z,1370299740.530 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:00.531Z,1370299740.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:00.531Z,1370299740.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:00.531Z,1370299740.531 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:00.927Z,1370299740.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:00.927Z,1370299740.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:00.928Z,1370299740.928 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:00.928Z,1370299740.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:01.331Z,1370299741.331 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:01.331Z,1370299741.331 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:01.331Z,1370299741.331 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:01.332Z,1370299741.332 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:01.332Z,1370299741.332 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:01.825Z,1370299741.825 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:01.825Z,1370299741.825 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:01.825Z,1370299741.825 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:01.825Z,1370299741.825 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:02.143Z,1370299742.143 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:02.143Z,1370299742.143 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:02.143Z,1370299742.143 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:02.144Z,1370299742.144 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:02.144Z,1370299742.144 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:02.531Z,1370299742.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:02.531Z,1370299742.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:02.531Z,1370299742.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:02.531Z,1370299742.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:02.946Z,1370299742.946 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:02.946Z,1370299742.946 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:02.946Z,1370299742.946 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:02.947Z,1370299742.947 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:02.947Z,1370299742.947 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:02.957Z,1370299742.957 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:49:03.350Z,1370299743.350 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:03.350Z,1370299743.350 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:03.350Z,1370299743.350 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:03.350Z,1370299743.350 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:03.363Z,1370299743.362 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:49:03.730Z,1370299743.730 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:03.730Z,1370299743.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:03.730Z,1370299743.730 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:03.731Z,1370299743.731 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:03.731Z,1370299743.731 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:04.127Z,1370299744.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:04.127Z,1370299744.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:04.127Z,1370299744.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:04.127Z,1370299744.128 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:04.532Z,1370299744.532 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:04.532Z,1370299744.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:04.532Z,1370299744.532 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:04.533Z,1370299744.533 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:04.533Z,1370299744.533 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:04.955Z,1370299744.955 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:04.955Z,1370299744.955 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:04.956Z,1370299744.955 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:04.956Z,1370299744.956 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:05.326Z,1370299745.326 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:05.326Z,1370299745.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:05.327Z,1370299745.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:05.327Z,1370299745.327 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:05.327Z,1370299745.327 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:05.730Z,1370299745.730 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:05.730Z,1370299745.730 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:05.730Z,1370299745.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:05.730Z,1370299745.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:06.126Z,1370299746.126 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:06.127Z,1370299746.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:06.127Z,1370299746.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:06.127Z,1370299746.127 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:06.127Z,1370299746.128 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:06.531Z,1370299746.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:06.531Z,1370299746.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:06.531Z,1370299746.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:06.531Z,1370299746.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:06.975Z,1370299746.975 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:06.975Z,1370299746.975 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:06.975Z,1370299746.975 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:06.976Z,1370299746.976 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:06.976Z,1370299746.976 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:07.327Z,1370299747.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:07.327Z,1370299747.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:07.327Z,1370299747.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:07.327Z,1370299747.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:07.729Z,1370299747.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:07.729Z,1370299747.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:07.729Z,1370299747.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:07.730Z,1370299747.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:07.730Z,1370299747.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:08.163Z,1370299748.163 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:08.164Z,1370299748.164 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:08.164Z,1370299748.164 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:08.164Z,1370299748.164 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:08.538Z,1370299748.538 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:08.539Z,1370299748.539 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:08.539Z,1370299748.539 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:08.539Z,1370299748.539 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:08.539Z,1370299748.539 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:08.927Z,1370299748.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:08.927Z,1370299748.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:08.927Z,1370299748.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:08.927Z,1370299748.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:09.354Z,1370299749.354 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:09.354Z,1370299749.354 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:09.354Z,1370299749.354 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:09.355Z,1370299749.355 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:09.355Z,1370299749.355 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:09.729Z,1370299749.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:09.729Z,1370299749.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:09.729Z,1370299749.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:09.730Z,1370299749.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:10.126Z,1370299750.126 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:10.126Z,1370299750.126 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:10.127Z,1370299750.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:10.127Z,1370299750.127 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:10.127Z,1370299750.127 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:10.531Z,1370299750.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:10.531Z,1370299750.532 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:10.532Z,1370299750.532 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:10.532Z,1370299750.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:10.924Z,1370299750.924 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:10.924Z,1370299750.924 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:10.924Z,1370299750.924 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:10.924Z,1370299750.924 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:10.924Z,1370299750.924 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:11.363Z,1370299751.362 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:11.363Z,1370299751.363 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:11.363Z,1370299751.363 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:11.363Z,1370299751.363 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:11.738Z,1370299751.737 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:11.738Z,1370299751.738 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:11.738Z,1370299751.738 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:11.738Z,1370299751.739 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:11.739Z,1370299751.739 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:12.207Z,1370299752.207 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:12.207Z,1370299752.207 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:12.207Z,1370299752.207 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:12.208Z,1370299752.208 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:12.530Z,1370299752.530 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:12.531Z,1370299752.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:12.531Z,1370299752.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:12.531Z,1370299752.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:12.531Z,1370299752.531 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:12.935Z,1370299752.935 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:12.935Z,1370299752.935 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:12.935Z,1370299752.935 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:12.936Z,1370299752.935 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:13.326Z,1370299753.326 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:13.326Z,1370299753.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:13.327Z,1370299753.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:13.327Z,1370299753.327 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:13.327Z,1370299753.327 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:13.729Z,1370299753.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:13.729Z,1370299753.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:13.729Z,1370299753.729 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:13.729Z,1370299753.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:14.140Z,1370299754.140 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:14.140Z,1370299754.140 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:14.140Z,1370299754.140 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:14.141Z,1370299754.141 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:14.141Z,1370299754.141 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:14.563Z,1370299754.563 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:14.564Z,1370299754.564 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:14.564Z,1370299754.564 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:14.564Z,1370299754.564 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:14.926Z,1370299754.926 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:14.927Z,1370299754.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:14.927Z,1370299754.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:14.927Z,1370299754.927 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:14.927Z,1370299754.927 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:15.328Z,1370299755.328 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:15.328Z,1370299755.328 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:15.328Z,1370299755.328 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:15.328Z,1370299755.328 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:15.746Z,1370299755.746 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:15.746Z,1370299755.746 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:15.746Z,1370299755.746 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:15.747Z,1370299755.747 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:15.747Z,1370299755.747 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:15.757Z,1370299755.757 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:49:16.149Z,1370299756.149 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:16.149Z,1370299756.149 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:16.149Z,1370299756.149 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:16.149Z,1370299756.149 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:16.161Z,1370299756.161 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:49:16.532Z,1370299756.532 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:16.532Z,1370299756.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:16.532Z,1370299756.532 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:16.532Z,1370299756.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:16.533Z,1370299756.533 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:16.927Z,1370299756.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:16.927Z,1370299756.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:16.927Z,1370299756.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:16.927Z,1370299756.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:17.406Z,1370299757.406 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:17.406Z,1370299757.406 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:17.407Z,1370299757.407 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:17.407Z,1370299757.407 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:17.407Z,1370299757.407 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:17.767Z,1370299757.767 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:17.767Z,1370299757.767 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:17.767Z,1370299757.767 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:17.767Z,1370299757.767 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:18.126Z,1370299758.126 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:18.126Z,1370299758.126 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:18.127Z,1370299758.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:18.127Z,1370299758.127 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:18.127Z,1370299758.127 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:18.530Z,1370299758.530 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:18.531Z,1370299758.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:18.531Z,1370299758.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:18.531Z,1370299758.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:18.931Z,1370299758.931 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:18.931Z,1370299758.931 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:18.931Z,1370299758.931 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:18.932Z,1370299758.931 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:18.932Z,1370299758.932 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:19.327Z,1370299759.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:19.327Z,1370299759.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:19.327Z,1370299759.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:19.327Z,1370299759.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:19.728Z,1370299759.728 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:19.729Z,1370299759.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:19.729Z,1370299759.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:19.729Z,1370299759.729 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:19.729Z,1370299759.729 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:20.127Z,1370299760.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:20.127Z,1370299760.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:20.127Z,1370299760.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:20.127Z,1370299760.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:20.531Z,1370299760.531 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:20.531Z,1370299760.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:20.531Z,1370299760.531 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:20.532Z,1370299760.532 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:20.532Z,1370299760.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:20.963Z,1370299760.963 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:20.963Z,1370299760.963 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:20.963Z,1370299760.963 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:20.963Z,1370299760.963 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:21.327Z,1370299761.327 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:21.327Z,1370299761.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:21.327Z,1370299761.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:21.328Z,1370299761.328 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:21.328Z,1370299761.328 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:21.729Z,1370299761.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:21.729Z,1370299761.730 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:21.730Z,1370299761.730 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:21.730Z,1370299761.730 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:22.178Z,1370299762.178 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:22.178Z,1370299762.178 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:22.179Z,1370299762.179 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:22.179Z,1370299762.179 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:22.179Z,1370299762.179 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:22.531Z,1370299762.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:22.531Z,1370299762.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:22.531Z,1370299762.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:22.532Z,1370299762.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:22.926Z,1370299762.926 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:22.927Z,1370299762.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:22.927Z,1370299762.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:22.927Z,1370299762.927 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:22.927Z,1370299762.927 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:23.326Z,1370299763.326 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:23.327Z,1370299763.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:23.327Z,1370299763.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:23.327Z,1370299763.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:23.729Z,1370299763.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:23.729Z,1370299763.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:23.729Z,1370299763.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:23.730Z,1370299763.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:23.730Z,1370299763.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:24.127Z,1370299764.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:24.127Z,1370299764.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:24.127Z,1370299764.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:24.127Z,1370299764.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:24.554Z,1370299764.555 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:24.555Z,1370299764.555 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:24.555Z,1370299764.555 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:24.555Z,1370299764.555 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:24.555Z,1370299764.556 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:24.927Z,1370299764.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:24.927Z,1370299764.927 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:24.927Z,1370299764.927 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:24.928Z,1370299764.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:25.326Z,1370299765.326 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:25.326Z,1370299765.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:25.327Z,1370299765.327 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:25.327Z,1370299765.327 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:25.327Z,1370299765.327 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:25.729Z,1370299765.729 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:25.729Z,1370299765.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:25.729Z,1370299765.729 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:25.729Z,1370299765.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:26.127Z,1370299766.127 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:26.127Z,1370299766.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:26.127Z,1370299766.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:26.127Z,1370299766.127 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:26.127Z,1370299766.128 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:26.531Z,1370299766.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:26.531Z,1370299766.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:26.531Z,1370299766.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:26.531Z,1370299766.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:26.926Z,1370299766.926 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:26.927Z,1370299766.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:26.927Z,1370299766.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:26.927Z,1370299766.927 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:26.927Z,1370299766.927 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:27.427Z,1370299767.427 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:27.427Z,1370299767.427 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:27.427Z,1370299767.427 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:27.427Z,1370299767.427 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:27.729Z,1370299767.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:27.729Z,1370299767.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:27.729Z,1370299767.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:27.730Z,1370299767.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:27.730Z,1370299767.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:28.126Z,1370299768.126 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:28.126Z,1370299768.126 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:28.127Z,1370299768.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:28.127Z,1370299768.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:28.550Z,1370299768.550 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:28.550Z,1370299768.550 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:28.550Z,1370299768.550 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:28.551Z,1370299768.551 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:28.551Z,1370299768.551 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:28.561Z,1370299768.561 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:49:28.950Z,1370299768.950 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:28.950Z,1370299768.950 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:28.950Z,1370299768.950 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:28.950Z,1370299768.950 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:28.963Z,1370299768.963 [Reporter](INFO): SCPI.sampleSCPI 1 bool
2013-06-03T22:49:29.322Z,1370299769.322 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:29.323Z,1370299769.323 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:29.323Z,1370299769.323 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:29.323Z,1370299769.323 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:29.323Z,1370299769.323 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:29.730Z,1370299769.730 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:29.731Z,1370299769.731 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:29.731Z,1370299769.731 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:29.731Z,1370299769.731 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:30.167Z,1370299770.167 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:30.167Z,1370299770.167 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:30.167Z,1370299770.167 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:30.167Z,1370299770.167 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:30.168Z,1370299770.168 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:30.571Z,1370299770.571 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:30.571Z,1370299770.571 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:30.571Z,1370299770.571 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:30.572Z,1370299770.572 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:30.927Z,1370299770.927 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:30.928Z,1370299770.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:30.928Z,1370299770.928 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:30.928Z,1370299770.928 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:30.928Z,1370299770.928 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:31.327Z,1370299771.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:31.327Z,1370299771.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:31.327Z,1370299771.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:31.327Z,1370299771.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:31.729Z,1370299771.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:31.729Z,1370299771.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:31.729Z,1370299771.729 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:31.729Z,1370299771.729 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:31.730Z,1370299771.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:32.127Z,1370299772.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:32.127Z,1370299772.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:32.127Z,1370299772.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:32.127Z,1370299772.128 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:32.579Z,1370299772.579 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:32.579Z,1370299772.579 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:32.579Z,1370299772.579 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:32.580Z,1370299772.580 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:32.580Z,1370299772.580 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:32.930Z,1370299772.930 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:32.931Z,1370299772.931 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:32.931Z,1370299772.931 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:32.931Z,1370299772.931 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:33.331Z,1370299773.331 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:33.331Z,1370299773.331 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:33.331Z,1370299773.331 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:33.332Z,1370299773.332 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:33.332Z,1370299773.332 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:33.733Z,1370299773.733 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:33.733Z,1370299773.733 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:33.733Z,1370299773.733 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:33.734Z,1370299773.734 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:34.155Z,1370299774.155 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:34.155Z,1370299774.155 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:34.155Z,1370299774.155 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:34.155Z,1370299774.155 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:34.155Z,1370299774.155 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:34.531Z,1370299774.531 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:34.531Z,1370299774.531 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:34.531Z,1370299774.531 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:34.531Z,1370299774.532 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:34.933Z,1370299774.933 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:34.933Z,1370299774.933 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:34.933Z,1370299774.933 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:34.934Z,1370299774.934 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:34.934Z,1370299774.934 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:35.326Z,1370299775.326 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:35.326Z,1370299775.326 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:35.326Z,1370299775.326 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:35.326Z,1370299775.326 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:35.729Z,1370299775.729 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:35.729Z,1370299775.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:35.730Z,1370299775.730 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:35.730Z,1370299775.730 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:35.730Z,1370299775.730 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:36.127Z,1370299776.127 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:36.127Z,1370299776.127 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:36.127Z,1370299776.127 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:36.127Z,1370299776.128 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:36.530Z,1370299776.530 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:36.530Z,1370299776.530 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:36.530Z,1370299776.530 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:36.531Z,1370299776.531 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:36.531Z,1370299776.531 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:36.927Z,1370299776.927 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:36.928Z,1370299776.928 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:36.928Z,1370299776.928 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:36.928Z,1370299776.928 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:37.435Z,1370299777.435 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:37.435Z,1370299777.435 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:37.435Z,1370299777.435 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:37.436Z,1370299777.436 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:37.436Z,1370299777.436 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:37.737Z,1370299777.737 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:37.737Z,1370299777.737 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:37.737Z,1370299777.737 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:37.738Z,1370299777.737 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:38.127Z,1370299778.127 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:38.127Z,1370299778.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:38.127Z,1370299778.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:38.127Z,1370299778.128 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:38.128Z,1370299778.128 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:38.526Z,1370299778.526 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:38.526Z,1370299778.526 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:38.526Z,1370299778.526 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:38.526Z,1370299778.526 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:38.926Z,1370299778.926 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:38.927Z,1370299778.927 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:38.927Z,1370299778.927 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:38.927Z,1370299778.927 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:38.927Z,1370299778.927 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:39.327Z,1370299779.327 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:39.327Z,1370299779.327 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2013-06-03T22:49:39.327Z,1370299779.327 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:39.327Z,1370299779.327 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:39.721Z,1370299779.721 [SCPI_on:TestDrive:C.Wait](INFO): Done Waiting.
2013-06-03T22:49:39.722Z,1370299779.722 [SCPI_on:TestDrive:C.Wait] Stopped
2013-06-03T22:49:39.722Z,1370299779.722 [SCPI_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2013-06-03T22:49:39.722Z,1370299779.722 [SCPI_on:TestDrive:Data] Running Loop=1
2013-06-03T22:49:39.722Z,1370299779.722 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2013-06-03T22:49:39.722Z,1370299779.722 [SCPI_on:TestDrive:Data:A] Running Loop=1
2013-06-03T22:49:39.723Z,1370299779.723 [SCPI_on:TestDrive:Data:A] Stopped
2013-06-03T22:49:39.723Z,1370299779.723 [SCPI_on:TestDrive:Data:B] Running Loop=1
2013-06-03T22:49:39.723Z,1370299779.723 [SCPI_on:TestDrive](INFO): Completed SCPI_on:TestDrive
2013-06-03T22:49:39.723Z,1370299779.723 [SCPI_on:TestDrive] Stopped
2013-06-03T22:49:39.724Z,1370299779.724 [SCPI_on:TestDrive](INFO): Aggregate::uninitialize SCPI_on:TestDrive
2013-06-03T22:49:39.724Z,1370299779.724 [SCPI_on:TestDrive:A] Stopped
2013-06-03T22:49:39.724Z,1370299779.724 [SCPI_on:TestDrive:Data] Stopped
2013-06-03T22:49:39.724Z,1370299779.724 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2013-06-03T22:49:39.724Z,1370299779.724 [SCPI_on:TestDrive:Data:B] Stopped
2013-06-03T22:49:39.725Z,1370299779.724 [SCPI_on](INFO): Completed SCPI_on
2013-06-03T22:49:39.725Z,1370299779.725 [SCPI_on] Stopped
2013-06-03T22:49:39.725Z,1370299779.725 [SCPI_on](INFO): Aggregate::uninitialize SCPI_on
2013-06-03T22:49:39.725Z,1370299779.725 [SCPI_on:A.Pitch] Stopped
2013-06-03T22:49:40.138Z,1370299780.138 [MissionManager](IMPORTANT): Started mission Default
2013-06-03T22:49:40.138Z,1370299780.138 [Default] Running Loop=1
2013-06-03T22:49:40.138Z,1370299780.138 [Default](INFO): Aggregate::initialize Default
2013-06-03T22:49:40.139Z,1370299780.138 [Default:D.SetSpeed] Running Loop=1
2013-06-03T22:49:40.139Z,1370299780.139 [Default:D.SetSpeed](DEBUG): Initialize.
2013-06-03T22:49:40.139Z,1370299780.139 [Default:E.GoToSurface] Running Loop=1
2013-06-03T22:49:40.139Z,1370299780.139 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:49:40.139Z,1370299780.139 [Default:Iridium] Running Loop=1
2013-06-03T22:49:40.139Z,1370299780.139 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-06-03T22:49:40.139Z,1370299780.139 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-06-03T22:49:40.139Z,1370299780.139 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-06-03T22:49:40.140Z,1370299780.139 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-06-03T22:49:40.140Z,1370299780.140 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:49:40.142Z,1370299780.142 [Default:Iridium:B.GoToSurface] Stopped
2013-06-03T22:49:40.142Z,1370299780.142 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:49:40.142Z,1370299780.142 [Default:Iridium:Read_Iridium] Running Loop=1
2013-06-03T22:49:40.142Z,1370299780.142 [Default:GPS] Running Loop=1
2013-06-03T22:49:40.143Z,1370299780.143 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-06-03T22:49:40.143Z,1370299780.143 [Default:GPS:A.SetSpeed] Running Loop=1
2013-06-03T22:49:40.143Z,1370299780.143 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-06-03T22:49:40.143Z,1370299780.143 [Default:GPS:B.GoToSurface] Running Loop=1
2013-06-03T22:49:40.143Z,1370299780.143 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-06-03T22:49:40.144Z,1370299780.144 [Default:GPS:B.GoToSurface] Stopped
2013-06-03T22:49:40.144Z,1370299780.144 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:49:40.144Z,1370299780.144 [Default:GPS:Read_GPS] Running Loop=1
2013-06-03T22:49:40.906Z,1370299780.906 [NAL9602](INFO): Powering up
2013-06-03T22:49:41.357Z,1370299781.358 [Reporter](INFO): SCPI.sampleSCPI 0 bool
2013-06-03T22:49:41.740Z,1370299781.740 [Reporter](INFO): SCPI.sampleSCPI no_value
2013-06-03T22:49:42.566Z,1370299782.566 [SCPI](INFO): Powering down
2013-06-03T22:49:50.490Z,1370299790.490 [CommandLine](IMPORTANT): got command quit
2013-06-03T22:49:51.346Z,1370299791.346 [NAL9602](INFO): NAL9602 initialized
2013-06-03T22:49:51.526Z,1370299791.526 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-06-03T22:49:51.526Z,1370299791.526 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-06-03T22:49:51.666Z,1370299791.666 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-06-03T22:49:51.934Z,1370299791.934 [WetLabsBB2FL](INFO): Powering down
2013-06-03T22:49:51.949Z,1370299791.949 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-06-03T22:49:52.086Z,1370299792.086 [CTD_NeilBrown](INFO): Powering down
2013-06-03T22:49:52.090Z,1370299792.090 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-06-03T22:49:52.194Z,1370299792.194 [DVL_micro](INFO): uninitialize:Powering down
2013-06-03T22:49:52.202Z,1370299792.202 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-06-03T22:49:52.394Z,1370299792.394 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-06-03T22:49:52.411Z,1370299792.411 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-06-03T22:49:52.491Z,1370299792.491 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-06-03T22:49:52.493Z,1370299792.493 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-06-03T22:49:52.608Z,1370299792.608 [controlThread](DEBUG): Uninitializing ControlThread
2013-06-03T22:49:52.609Z,1370299792.609 [AHRS_sp3003D](INFO): Powering down
2013-06-03T22:49:52.697Z,1370299792.697 [NAL9602](INFO): Powering down
2013-06-03T22:49:52.698Z,1370299792.698 [DAT](INFO): Powering down
2013-06-03T22:49:52.699Z,1370299792.699 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-06-03T22:49:52.700Z,1370299792.700 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-06-03T22:49:52.701Z,1370299792.701 [Default] Stopped
2013-06-03T22:49:52.701Z,1370299792.701 [Default](INFO): Aggregate::uninitialize Default
2013-06-03T22:49:52.701Z,1370299792.701 [Default:GPS] Stopped
2013-06-03T22:49:52.701Z,1370299792.701 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-06-03T22:49:52.701Z,1370299792.701 [Default:GPS:A.SetSpeed] Stopped
2013-06-03T22:49:52.701Z,1370299792.701 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:49:52.702Z,1370299792.702 [Default:GPS:Read_GPS] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:Iridium] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-06-03T22:49:52.702Z,1370299792.702 [Default:Iridium:A.SetSpeed] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:49:52.702Z,1370299792.702 [Default:Iridium:Read_Iridium] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:D.SetSpeed] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:D.SetSpeed](DEBUG): Uninitialize.
2013-06-03T22:49:52.702Z,1370299792.702 [Default:E.GoToSurface] Stopped
2013-06-03T22:49:52.702Z,1370299792.702 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-06-03T22:49:52.706Z,1370299792.706 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-06-03T22:49:52.707Z,1370299792.707 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-06-03T22:49:52.707Z,1370299792.707 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-06-03T22:49:52.707Z,1370299792.707 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-06-03T22:49:52.708Z,1370299792.708 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-06-03T22:49:52.708Z,1370299792.708 [BuoyancyServo](INFO): Powering down
2013-06-03T22:49:52.722Z,1370299792.722 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-06-03T22:49:52.722Z,1370299792.722 [ElevatorServo](INFO): Powering down
2013-06-03T22:49:52.723Z,1370299792.723 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-06-03T22:49:52.723Z,1370299792.723 [MassServo](INFO): Powering down
2013-06-03T22:49:52.724Z,1370299792.724 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-06-03T22:49:52.724Z,1370299792.724 [RudderServo](INFO): Powering down
2013-06-03T22:49:52.725Z,1370299792.725 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-06-03T22:49:52.725Z,1370299792.725 [ThrusterServo](INFO): Powering down
2013-06-03T22:49:52.726Z,1370299792.726 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-06-03T22:49:52.726Z,1370299792.727 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-06-03T22:49:52.727Z,1370299792.727 [CBIT](DEBUG): Uninitialize CBIT Component.