2014-05-09T23:07:29.305Z,1399676849.305 [Supervisor](DEBUG): Initializing supervisor.
2014-05-09T23:07:29.307Z,1399676849.307 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-09T23:07:29.308Z,1399676849.308 [SyncHandler](INFO): Protected caller Thread ID is 1154
2014-05-09T23:07:29.308Z,1399676849.308 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-09T23:07:29.309Z,1399676849.309 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-09T23:07:29.310Z,1399676849.310 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1155
2014-05-09T23:07:29.313Z,1399676849.313 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-09T23:07:29.448Z,1399676849.448 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-09T23:07:29.449Z,1399676849.449 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-09T23:07:29.450Z,1399676849.450 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1156
2014-05-09T23:07:29.450Z,1399676849.450 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-09T23:07:29.452Z,1399676849.452 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-09T23:07:29.452Z,1399676849.452 [logger ThreadHandler](INFO): Protected caller Thread ID is 1157
2014-05-09T23:07:29.454Z,1399676849.454 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-09T23:07:29.455Z,1399676849.455 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-09T23:07:29.456Z,1399676849.456 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-09T23:07:29.815Z,1399676849.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-09T23:07:29.816Z,1399676849.816 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-09T23:07:30.104Z,1399676850.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-09T23:07:30.104Z,1399676850.104 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-09T23:07:30.199Z,1399676850.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-09T23:07:30.200Z,1399676850.200 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-09T23:07:30.401Z,1399676850.401 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-09T23:07:30.402Z,1399676850.402 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-09T23:07:30.563Z,1399676850.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-09T23:07:30.564Z,1399676850.564 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-09T23:07:30.862Z,1399676850.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-09T23:07:30.863Z,1399676850.863 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-09T23:07:31.050Z,1399676851.050 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-09T23:07:31.051Z,1399676851.051 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-09T23:07:31.389Z,1399676851.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-09T23:07:31.389Z,1399676851.389 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-09T23:07:31.504Z,1399676851.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-09T23:07:31.505Z,1399676851.505 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-09T23:07:32.035Z,1399676852.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-09T23:07:32.036Z,1399676852.036 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-09T23:07:32.148Z,1399676852.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-09T23:07:32.148Z,1399676852.148 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-09T23:07:32.237Z,1399676852.237 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-09T23:07:32.349Z,1399676852.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-09T23:07:32.350Z,1399676852.350 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-09T23:07:32.457Z,1399676852.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-09T23:07:32.458Z,1399676852.458 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-09T23:07:32.600Z,1399676852.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-09T23:07:32.602Z,1399676852.602 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-09T23:07:32.602Z,1399676852.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-09T23:07:32.711Z,1399676852.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-09T23:07:32.841Z,1399676852.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-09T23:07:32.940Z,1399676852.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-09T23:07:33.035Z,1399676853.035 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-09T23:07:33.188Z,1399676853.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-09T23:07:33.306Z,1399676853.306 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-09T23:07:33.395Z,1399676853.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-09T23:07:33.500Z,1399676853.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-09T23:07:33.603Z,1399676853.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-09T23:07:33.703Z,1399676853.703 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-09T23:07:33.796Z,1399676853.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-09T23:07:33.896Z,1399676853.896 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2014-05-09T23:07:33.897Z,1399676853.897 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-05-09T23:07:33.898Z,1399676853.898 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-09T23:07:34.255Z,1399676854.255 [AHRS_sp3003D] Loaded
2014-05-09T23:07:34.255Z,1399676854.255 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-09T23:07:34.572Z,1399676854.572 [Batt_Ocean_Server] Loaded
2014-05-09T23:07:34.572Z,1399676854.572 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-09T23:07:34.648Z,1399676854.648 [DataOverHttps] Loaded
2014-05-09T23:07:34.648Z,1399676854.648 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-05-09T23:07:34.662Z,1399676854.662 [Depth_Keller] Loaded
2014-05-09T23:07:34.663Z,1399676854.663 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-09T23:07:34.668Z,1399676854.668 [DropWeight] Loaded
2014-05-09T23:07:34.668Z,1399676854.668 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-05-09T23:07:34.773Z,1399676854.773 [NAL9602] Loaded
2014-05-09T23:07:34.774Z,1399676854.774 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-09T23:07:34.827Z,1399676854.827 [Onboard] Loaded
2014-05-09T23:07:34.828Z,1399676854.828 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-09T23:07:34.835Z,1399676854.835 [Radio_Freewave] Loaded
2014-05-09T23:07:34.835Z,1399676854.835 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-09T23:07:34.836Z,1399676854.836 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 406064E0
2014-05-09T23:07:34.837Z,1399676854.837 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 1239
2014-05-09T23:07:34.844Z,1399676854.844 [SCPI] Loaded
2014-05-09T23:07:34.844Z,1399676854.844 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-09T23:07:34.845Z,1399676854.845 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-09T23:07:34.845Z,1399676854.845 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-09T23:07:35.125Z,1399676855.125 [ExternalSim] Loaded
2014-05-09T23:07:35.126Z,1399676855.126 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2014-05-09T23:07:35.181Z,1399676855.181 [InternalSim] Loaded
2014-05-09T23:07:35.181Z,1399676855.181 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-09T23:07:35.182Z,1399676855.182 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-09T23:07:35.182Z,1399676855.182 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-09T23:07:35.492Z,1399676855.492 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-09T23:07:35.492Z,1399676855.492 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-09T23:07:35.498Z,1399676855.498 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-05-09T23:07:35.503Z,1399676855.503 [AsyncPiEstimator] Loaded
2014-05-09T23:07:35.504Z,1399676855.504 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-05-09T23:07:35.505Z,1399676855.505 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406E34E0
2014-05-09T23:07:35.505Z,1399676855.505 [AsyncPiEstimator ThreadHandler](INFO): Protected caller Thread ID is 1240
2014-05-09T23:07:35.506Z,1399676855.506 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-09T23:07:35.506Z,1399676855.506 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-09T23:07:35.593Z,1399676855.593 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-09T23:07:35.593Z,1399676855.593 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-09T23:07:35.611Z,1399676855.611 [NavChart] Loaded
2014-05-09T23:07:35.611Z,1399676855.611 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-09T23:07:35.616Z,1399676855.616 [UniversalFixResidualReporter] Loaded
2014-05-09T23:07:35.616Z,1399676855.616 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-09T23:07:35.616Z,1399676855.616 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-09T23:07:35.617Z,1399676855.617 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-09T23:07:35.671Z,1399676855.671 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-09T23:07:35.782Z,1399676855.782 [VerticalControl] Loaded
2014-05-09T23:07:35.783Z,1399676855.783 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-09T23:07:35.784Z,1399676855.784 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-09T23:07:35.853Z,1399676855.853 [HorizontalControl] Loaded
2014-05-09T23:07:35.853Z,1399676855.853 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-09T23:07:35.854Z,1399676855.854 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-09T23:07:35.856Z,1399676855.856 [SpeedControl] Loaded
2014-05-09T23:07:35.856Z,1399676855.856 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-09T23:07:35.857Z,1399676855.857 [LoopControl](DEBUG): Construct LoopControl.
2014-05-09T23:07:35.857Z,1399676855.857 [LoopControl] Loaded
2014-05-09T23:07:35.857Z,1399676855.857 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-09T23:07:35.858Z,1399676855.858 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-09T23:07:35.859Z,1399676855.859 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-09T23:07:35.878Z,1399676855.878 [DepthRateCalculator] Loaded
2014-05-09T23:07:35.878Z,1399676855.878 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-09T23:07:35.884Z,1399676855.884 [PitchRateCalculator] Loaded
2014-05-09T23:07:35.885Z,1399676855.885 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-09T23:07:35.892Z,1399676855.892 [SpeedCalculator] Loaded
2014-05-09T23:07:35.892Z,1399676855.892 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-09T23:07:35.910Z,1399676855.910 [TempGradientCalculator] Loaded
2014-05-09T23:07:35.910Z,1399676855.910 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-09T23:07:35.916Z,1399676855.916 [YawRateCalculator] Loaded
2014-05-09T23:07:35.916Z,1399676855.916 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-09T23:07:35.917Z,1399676855.917 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-09T23:07:35.917Z,1399676855.917 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-09T23:07:36.028Z,1399676856.028 [CTD_NeilBrown] Loaded
2014-05-09T23:07:36.028Z,1399676856.028 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-09T23:07:36.029Z,1399676856.029 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407854E0
2014-05-09T23:07:36.030Z,1399676856.030 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1241
2014-05-09T23:07:36.043Z,1399676856.043 [ISUS] Loaded
2014-05-09T23:07:36.044Z,1399676856.044 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-09T23:07:36.059Z,1399676856.059 [PAR_Licor] Loaded
2014-05-09T23:07:36.059Z,1399676856.059 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-09T23:07:36.095Z,1399676856.095 [WetLabsBB2FL] Loaded
2014-05-09T23:07:36.095Z,1399676856.095 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-09T23:07:36.096Z,1399676856.096 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407B54E0
2014-05-09T23:07:36.097Z,1399676856.097 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1242
2014-05-09T23:07:36.097Z,1399676856.097 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-09T23:07:36.098Z,1399676856.098 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-09T23:07:36.200Z,1399676856.200 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-09T23:07:36.212Z,1399676856.212 [SBIT] Loaded
2014-05-09T23:07:36.212Z,1399676856.212 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-09T23:07:36.213Z,1399676856.213 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-09T23:07:36.226Z,1399676856.226 [IBIT] Loaded
2014-05-09T23:07:36.226Z,1399676856.226 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-09T23:07:36.228Z,1399676856.228 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-09T23:07:36.299Z,1399676856.299 [CBIT] Loaded
2014-05-09T23:07:36.299Z,1399676856.299 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-09T23:07:36.300Z,1399676856.300 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-09T23:07:36.300Z,1399676856.300 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-09T23:07:36.344Z,1399676856.344 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-09T23:07:36.345Z,1399676856.345 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-09T23:07:36.447Z,1399676856.447 [BuoyancyServo] Loaded
2014-05-09T23:07:36.447Z,1399676856.447 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-09T23:07:36.456Z,1399676856.456 [ElevatorServo] Loaded
2014-05-09T23:07:36.456Z,1399676856.456 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-09T23:07:36.464Z,1399676856.464 [MassServo] Loaded
2014-05-09T23:07:36.465Z,1399676856.465 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-09T23:07:36.474Z,1399676856.474 [RudderServo] Loaded
2014-05-09T23:07:36.474Z,1399676856.474 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-09T23:07:36.482Z,1399676856.482 [ThrusterServo] Loaded
2014-05-09T23:07:36.482Z,1399676856.482 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-09T23:07:36.483Z,1399676856.483 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-09T23:07:36.483Z,1399676856.483 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-09T23:07:36.509Z,1399676856.509 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-09T23:07:36.511Z,1399676856.511 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-09T23:07:36.512Z,1399676856.512 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-09T23:07:36.518Z,1399676856.518 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-09T23:07:36.519Z,1399676856.519 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2014-05-09T23:07:36.520Z,1399676856.520 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1243
2014-05-09T23:07:36.525Z,1399676856.525 [Supervisor](INFO): Main Thread ID is 1153
2014-05-09T23:07:36.525Z,1399676856.525 [Supervisor](DEBUG): Running supervisor.
2014-05-09T23:07:36.526Z,1399676856.526 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1244
2014-05-09T23:07:36.528Z,1399676856.528 [controlThread ThreadHandler](INFO): Handler Thread ID is 1245
2014-05-09T23:07:36.528Z,1399676856.528 [controlThread](DEBUG): Initializing ControlThread
2014-05-09T23:07:36.531Z,1399676856.531 [logger ThreadHandler](INFO): Handler Thread ID is 1246
2014-05-09T23:07:36.550Z,1399676856.550 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 1247
2014-05-09T23:07:36.566Z,1399676856.566 [AsyncPiEstimator ThreadHandler](INFO): Handler Thread ID is 1248
2014-05-09T23:07:36.567Z,1399676856.567 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-05-09T23:07:36.590Z,1399676856.590 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1249
2014-05-09T23:07:36.591Z,1399676856.591 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-09T23:07:36.614Z,1399676856.614 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1250
2014-05-09T23:07:36.627Z,1399676856.627 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1251
2014-05-09T23:07:36.629Z,1399676856.629 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-09T23:07:36.630Z,1399676856.630 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-09T23:07:36.630Z,1399676856.630 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-09T23:07:36.631Z,1399676856.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-09T23:07:36.631Z,1399676856.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-09T23:07:36.631Z,1399676856.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-09T23:07:36.631Z,1399676856.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-09T23:07:36.632Z,1399676856.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-09T23:07:36.632Z,1399676856.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-09T23:07:36.999Z,1399676856.999 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.000000 psu
2014-05-09T23:07:37.953Z,1399676857.953 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-09T23:07:37.979Z,1399676857.979 [ExternalSim](INFO): ExternalSim initializing...
2014-05-09T23:07:38.121Z,1399676858.121 [ExternalSim](DEBUG): beaconLat = 36.81340
2014-05-09T23:07:38.121Z,1399676858.121 [ExternalSim](DEBUG): beaconLon = -121.82240
2014-05-09T23:07:38.121Z,1399676858.121 [ExternalSim](DEBUG): beaconDepth = 25.00
2014-05-09T23:07:38.152Z,1399676858.152 [ExternalSim](DEBUG): Simulator initialized
2014-05-09T23:07:38.158Z,1399676858.158 [InternalSim](DEBUG):  InternalSim initializing...
2014-05-09T23:07:38.265Z,1399676858.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-09T23:07:38.265Z,1399676858.265 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-09T23:07:38.265Z,1399676858.265 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-09T23:07:38.266Z,1399676858.266 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-09T23:07:38.268Z,1399676858.268 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-09T23:07:38.268Z,1399676858.268 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-09T23:07:38.269Z,1399676858.269 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-09T23:07:38.269Z,1399676858.269 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-09T23:07:38.270Z,1399676858.270 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-09T23:07:38.270Z,1399676858.270 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-09T23:07:38.270Z,1399676858.270 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-09T23:07:38.271Z,1399676858.271 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-09T23:07:38.272Z,1399676858.272 [SBIT](INFO): Initialize SBIT Component.
2014-05-09T23:07:38.273Z,1399676858.273 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:11280
2014-05-09T23:07:38.273Z,1399676858.273 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-09T23:07:38.273Z,1399676858.273 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-09T23:07:38.274Z,1399676858.274 [IBIT](INFO): Initialize IBIT Component.
2014-05-09T23:07:38.275Z,1399676858.275 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-09T23:07:38.275Z,1399676858.275 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-05-09T23:07:38.302Z,1399676858.302 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-09T23:07:38.312Z,1399676858.312 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-09T23:07:38.333Z,1399676858.333 [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>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2014-05-09T23:07:38.333Z,1399676858.333 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-09T23:07:38.424Z,1399676858.424 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-09T23:07:38.431Z,1399676858.431 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-09T23:07:38.443Z,1399676858.443 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-09T23:07:38.467Z,1399676858.467 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-09T23:07:38.482Z,1399676858.482 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-09T23:07:38.509Z,1399676858.509 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-09T23:07:38.535Z,1399676858.535 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-09T23:07:38.543Z,1399676858.543 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-09T23:07:38.566Z,1399676858.566 [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>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <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><Sequence/><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

        <Guidance:GoToSurface>
            <Parallel/>
        </Guidance:GoToSurface>

    </Aggregate>

</Mission>


2014-05-09T23:07:38.574Z,1399676858.574 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-05-09T23:07:38.879Z,1399676858.879 [Radio_Freewave](INFO): Powering up
2014-05-09T23:07:39.119Z,1399676859.119 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-09T23:07:39.126Z,1399676859.126 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-09T23:07:39.140Z,1399676859.140 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-09T23:07:39.146Z,1399676859.146 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-09T23:07:39.168Z,1399676859.168 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-09T23:07:39.174Z,1399676859.174 [MassServo](DEBUG): Initializing MassServo.
2014-05-09T23:07:39.196Z,1399676859.196 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-09T23:07:39.202Z,1399676859.202 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-09T23:07:39.216Z,1399676859.216 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-09T23:07:39.684Z,1399676859.684 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-05-09T23:07:42.394Z,1399676862.394 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003300
2014-05-09T23:07:45.589Z,1399676865.589 [NAL9602](IMPORTANT): GPS fix at: 1399676865.58
2014-05-09T23:07:46.806Z,1399676866.806 [NAL9602](INFO): No messages in MT queue
2014-05-09T23:07:52.405Z,1399676872.405 [NAL9602](INFO): Powering down
2014-05-09T23:07:53.677Z,1399676873.677 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-09T23:07:53.679Z,1399676873.679 [CBIT](IMPORTANT): Beginning GF scan
2014-05-09T23:08:00.748Z,1399676880.748 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/SCPI_on.xml
2014-05-09T23:08:00.748Z,1399676880.748 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/SCPI_on.xml
2014-05-09T23:08:00.766Z,1399676880.766 [MissionManager](INFO): DefineArg SCPI_on.MassDefault = 0.000000 n/a
2014-05-09T23:08:00.768Z,1399676880.768 [SCPI_on:A.Pitch](DEBUG): Construct.
2014-05-09T23:08:00.816Z,1399676880.816 [SCPI_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2014-05-09T23:08:00.819Z,1399676880.819 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Sensor="Tethys/Sensor"
       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/Sensor http://aosn.mbari.org/tethys/Xml/Sensor.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>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="TestDrive">

        <Sequence/>

        <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>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>2</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2014-05-09T23:08:00.829Z,1399676880.829 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/SCPI_on.xml
2014-05-09T23:08:19.834Z,1399676899.834 [CBIT](IMPORTANT): No ground fault detected
2014-05-09T23:08:47.307Z,1399676927.307 [SBIT](IMPORTANT): SBIT PASSED
2014-05-09T23:08:47.681Z,1399676927.681 [MissionManager](IMPORTANT): Started mission Startup
2014-05-09T23:08:47.681Z,1399676927.681 [Startup] Running Loop=1
2014-05-09T23:08:47.681Z,1399676927.681 [Startup](INFO): Aggregate::initialize Startup
2014-05-09T23:08:47.681Z,1399676927.681 [Startup:A.GoToSurface] Running Loop=1
2014-05-09T23:08:47.681Z,1399676927.681 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-09T23:08:47.688Z,1399676927.688 [Startup:StartupSatComms] Running Loop=1
2014-05-09T23:08:47.688Z,1399676927.688 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-05-09T23:08:47.701Z,1399676927.701 [Startup:StartupSatComms:A] Running Loop=1
2014-05-09T23:08:48.082Z,1399676928.082 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-09T23:08:48.469Z,1399676928.469 [NAL9602](INFO): Powering up
2014-05-09T23:08:53.661Z,1399676933.661 [NAL9602](IMPORTANT): GPS fix at: 1399676933.65
2014-05-09T23:08:53.711Z,1399676933.711 [Startup:StartupSatComms:A] Stopped
2014-05-09T23:08:53.711Z,1399676933.711 [Startup:StartupSatComms:B] Running Loop=1
2014-05-09T23:08:54.103Z,1399676934.103 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-09T23:08:54.885Z,1399676934.885 [NAL9602](INFO): No messages in MT queue
2014-05-09T23:08:56.498Z,1399676936.498 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20140509T224915/Courier0028.lzma
2014-05-09T23:08:57.194Z,1399676937.194 [DataOverHttps](INFO): Moved sent file to Logs/20140509T224915/Courier0028.lzma.bak
2014-05-09T23:08:57.195Z,1399676937.195 [DataOverHttps](INFO): SBD MOMSN=940198
2014-05-09T23:09:01.901Z,1399676941.901 [NAL9602](INFO): Powering down
2014-05-09T23:09:04.755Z,1399676944.755 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20140509T230729/Courier0000.lzma
2014-05-09T23:09:05.454Z,1399676945.454 [DataOverHttps](INFO): Moved sent file to Logs/20140509T230729/Courier0000.lzma.bak
2014-05-09T23:09:05.454Z,1399676945.454 [DataOverHttps](INFO): SBD MOMSN=940201
2014-05-09T23:09:10.003Z,1399676950.003 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20140509T224915/Express0029.lzma
2014-05-09T23:09:10.678Z,1399676950.678 [DataOverHttps](INFO): Moved sent file to Logs/20140509T224915/Express0029.lzma.bak
2014-05-09T23:09:10.679Z,1399676950.679 [DataOverHttps](INFO): SBD MOMSN=940204
2014-05-09T23:09:11.141Z,1399676951.141 [CommandLine](IMPORTANT): got command show stack
2014-05-09T23:09:11.141Z,1399676951.141 [CommandLine](IMPORTANT): Behavior Stack:

2014-05-09T23:09:11.141Z,1399676951.141 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2014-05-09T23:09:11.142Z,1399676951.142 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2014-05-09T23:09:17.651Z,1399676957.651 [DataOverHttps](INFO): Sending 858 bytes from file Logs/20140509T230729/Express0001.lzma
2014-05-09T23:09:18.421Z,1399676958.421 [DataOverHttps](INFO): Moved sent file to Logs/20140509T230729/Express0001.lzma.bak
2014-05-09T23:09:18.421Z,1399676958.421 [DataOverHttps](INFO): SBD MOMSN=940210
2014-05-09T23:09:18.897Z,1399676958.897 [Startup:StartupSatComms:B] Stopped
2014-05-09T23:09:18.897Z,1399676958.897 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-05-09T23:09:18.897Z,1399676958.897 [Startup:StartupSatComms] Stopped
2014-05-09T23:09:18.897Z,1399676958.897 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-05-09T23:09:18.898Z,1399676958.898 [Startup](INFO): Completed Startup
2014-05-09T23:09:18.898Z,1399676958.898 [Startup] Stopped
2014-05-09T23:09:18.898Z,1399676958.898 [Startup](INFO): Aggregate::uninitialize Startup
2014-05-09T23:09:18.898Z,1399676958.898 [Startup:A.GoToSurface] Stopped
2014-05-09T23:09:18.899Z,1399676958.899 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-09T23:09:19.257Z,1399676959.257 [MissionManager](IMPORTANT): Started mission SCPI_on
2014-05-09T23:09:19.257Z,1399676959.257 [SCPI_on] Running Loop=1
2014-05-09T23:09:19.257Z,1399676959.257 [SCPI_on](INFO): Aggregate::initialize SCPI_on
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:A.Pitch] Running Loop=1
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:A.Pitch](DEBUG): Initialize.
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:TestDrive] Running Loop=1
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:TestDrive](INFO): Aggregate::initialize SCPI_on:TestDrive
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:TestDrive:A] Running Loop=1
2014-05-09T23:09:19.258Z,1399676959.258 [SCPI_on:TestDrive:C.Wait] Running Loop=1
2014-05-09T23:09:19.259Z,1399676959.259 [SCPI_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2014-05-09T23:09:19.264Z,1399676959.264 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:19.264Z,1399676959.264 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:19.264Z,1399676959.264 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:19.267Z,1399676959.267 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:19.267Z,1399676959.267 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:19.267Z,1399676959.267 [SCPI_on:TestDrive:A] Running Loop=1
2014-05-09T23:09:19.268Z,1399676959.268 [SCPI_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense SCPI.sampleSCPI
2014-05-09T23:09:19.282Z,1399676959.282 [SCPI_on:A.Pitch] Running Loop=1
2014-05-09T23:09:20.134Z,1399676960.134 [SCPI](INFO): Powering up
2014-05-09T23:09:20.159Z,1399676960.159 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:20.159Z,1399676960.159 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:20.159Z,1399676960.159 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:20.159Z,1399676960.159 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:20.401Z,1399676960.401 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:20.401Z,1399676960.401 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:20.401Z,1399676960.401 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:20.402Z,1399676960.402 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:20.402Z,1399676960.402 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:20.654Z,1399676960.654 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:20.655Z,1399676960.655 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:20.655Z,1399676960.655 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:20.655Z,1399676960.655 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:21.061Z,1399676961.061 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:21.061Z,1399676961.061 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:21.061Z,1399676961.061 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:21.062Z,1399676961.062 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:21.062Z,1399676961.062 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:21.445Z,1399676961.445 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:21.445Z,1399676961.445 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:21.445Z,1399676961.445 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:21.445Z,1399676961.445 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:21.849Z,1399676961.849 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:21.850Z,1399676961.850 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:21.850Z,1399676961.850 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:21.850Z,1399676961.850 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:21.850Z,1399676961.850 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:22.295Z,1399676962.295 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:22.295Z,1399676962.295 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:22.295Z,1399676962.295 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:22.295Z,1399676962.295 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:22.653Z,1399676962.653 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:22.653Z,1399676962.653 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:22.653Z,1399676962.653 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:22.653Z,1399676962.653 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:22.653Z,1399676962.653 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:23.044Z,1399676963.044 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:23.044Z,1399676963.044 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:23.044Z,1399676963.044 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:23.044Z,1399676963.044 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:23.438Z,1399676963.438 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:23.439Z,1399676963.439 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:23.439Z,1399676963.439 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:23.439Z,1399676963.439 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:23.439Z,1399676963.439 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:23.822Z,1399676963.822 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:23.822Z,1399676963.822 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:23.822Z,1399676963.822 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:23.822Z,1399676963.822 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:24.222Z,1399676964.222 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:24.222Z,1399676964.222 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:24.222Z,1399676964.222 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:24.222Z,1399676964.222 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:24.223Z,1399676964.223 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:24.664Z,1399676964.664 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:24.665Z,1399676964.665 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:24.665Z,1399676964.665 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:24.665Z,1399676964.665 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:25.127Z,1399676965.127 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:25.127Z,1399676965.127 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:25.127Z,1399676965.127 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:25.128Z,1399676965.128 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:25.128Z,1399676965.128 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:25.478Z,1399676965.478 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:25.478Z,1399676965.478 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:25.478Z,1399676965.478 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:25.478Z,1399676965.478 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:25.864Z,1399676965.864 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:25.864Z,1399676965.864 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:25.864Z,1399676965.864 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:25.864Z,1399676965.864 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:25.865Z,1399676965.865 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:26.254Z,1399676966.254 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:26.254Z,1399676966.254 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:26.254Z,1399676966.254 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:26.254Z,1399676966.254 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:26.675Z,1399676966.675 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:26.676Z,1399676966.676 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:26.676Z,1399676966.676 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:26.676Z,1399676966.676 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:26.676Z,1399676966.676 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:27.035Z,1399676967.035 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:27.035Z,1399676967.035 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:27.035Z,1399676967.035 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:27.035Z,1399676967.035 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:27.452Z,1399676967.452 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:27.452Z,1399676967.452 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:27.452Z,1399676967.452 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:27.452Z,1399676967.452 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:27.452Z,1399676967.452 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:27.824Z,1399676967.824 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:27.824Z,1399676967.824 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:27.824Z,1399676967.824 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:27.824Z,1399676967.824 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:28.244Z,1399676968.244 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:28.244Z,1399676968.244 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:28.245Z,1399676968.245 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:28.245Z,1399676968.245 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:28.245Z,1399676968.245 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:28.673Z,1399676968.673 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:28.673Z,1399676968.673 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:28.673Z,1399676968.673 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:28.673Z,1399676968.673 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:29.049Z,1399676969.049 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:29.050Z,1399676969.050 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:29.050Z,1399676969.050 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:29.050Z,1399676969.050 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:29.050Z,1399676969.050 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:29.462Z,1399676969.462 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:29.462Z,1399676969.462 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:29.462Z,1399676969.462 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:29.462Z,1399676969.462 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:29.852Z,1399676969.852 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:29.852Z,1399676969.852 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:29.852Z,1399676969.852 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:29.852Z,1399676969.852 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:29.852Z,1399676969.852 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:30.304Z,1399676970.304 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:30.304Z,1399676970.304 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:30.304Z,1399676970.304 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:30.304Z,1399676970.304 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:30.650Z,1399676970.650 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:30.655Z,1399676970.655 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:30.655Z,1399676970.655 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:30.655Z,1399676970.655 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:30.655Z,1399676970.655 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:31.022Z,1399676971.022 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:31.022Z,1399676971.022 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:31.022Z,1399676971.022 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:31.023Z,1399676971.023 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:31.466Z,1399676971.466 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:31.466Z,1399676971.466 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:31.467Z,1399676971.467 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:31.467Z,1399676971.467 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:31.467Z,1399676971.467 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:31.879Z,1399676971.879 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:31.879Z,1399676971.879 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:31.880Z,1399676971.880 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:31.880Z,1399676971.880 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:32.266Z,1399676972.266 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:32.266Z,1399676972.266 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:32.267Z,1399676972.267 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:32.267Z,1399676972.267 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:32.267Z,1399676972.267 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:32.684Z,1399676972.684 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:32.684Z,1399676972.684 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:32.685Z,1399676972.685 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:32.685Z,1399676972.685 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:33.064Z,1399676973.064 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:33.064Z,1399676973.064 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:33.064Z,1399676973.064 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:33.064Z,1399676973.064 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:33.064Z,1399676973.064 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:33.450Z,1399676973.450 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:33.450Z,1399676973.450 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:33.450Z,1399676973.450 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:33.451Z,1399676973.451 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:33.850Z,1399676973.850 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:33.850Z,1399676973.850 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:33.850Z,1399676973.850 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:33.851Z,1399676973.851 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:33.851Z,1399676973.851 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:34.255Z,1399676974.255 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:34.255Z,1399676974.255 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:34.255Z,1399676974.255 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:34.256Z,1399676974.256 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:34.651Z,1399676974.651 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:34.651Z,1399676974.651 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:34.651Z,1399676974.651 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:34.652Z,1399676974.652 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:34.652Z,1399676974.652 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:35.100Z,1399676975.100 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:35.100Z,1399676975.100 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:35.100Z,1399676975.100 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:35.100Z,1399676975.100 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:35.531Z,1399676975.531 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:35.531Z,1399676975.531 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:35.532Z,1399676975.532 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:35.532Z,1399676975.532 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:35.532Z,1399676975.532 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:35.822Z,1399676975.822 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:35.822Z,1399676975.822 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:35.822Z,1399676975.822 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:35.822Z,1399676975.822 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:36.221Z,1399676976.221 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:36.221Z,1399676976.221 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:36.221Z,1399676976.221 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:36.222Z,1399676976.222 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:36.222Z,1399676976.222 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:36.624Z,1399676976.624 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:36.624Z,1399676976.624 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:36.624Z,1399676976.624 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:36.624Z,1399676976.624 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:37.035Z,1399676977.035 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:37.036Z,1399676977.036 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:37.036Z,1399676977.036 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:37.036Z,1399676977.036 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:37.036Z,1399676977.036 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:37.456Z,1399676977.456 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:37.456Z,1399676977.456 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:37.456Z,1399676977.456 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:37.456Z,1399676977.456 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:37.854Z,1399676977.854 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:37.854Z,1399676977.854 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:37.854Z,1399676977.854 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:37.855Z,1399676977.855 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:37.855Z,1399676977.855 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:38.299Z,1399676978.299 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:38.299Z,1399676978.299 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:38.299Z,1399676978.299 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:38.299Z,1399676978.299 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:38.622Z,1399676978.622 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:38.623Z,1399676978.623 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:38.623Z,1399676978.623 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:38.623Z,1399676978.623 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:38.623Z,1399676978.623 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:39.055Z,1399676979.055 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:39.055Z,1399676979.055 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:39.055Z,1399676979.055 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:39.055Z,1399676979.055 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:39.461Z,1399676979.461 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:39.461Z,1399676979.461 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:39.461Z,1399676979.461 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:39.462Z,1399676979.462 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:39.462Z,1399676979.462 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:39.852Z,1399676979.852 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:39.852Z,1399676979.852 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:39.852Z,1399676979.852 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:39.852Z,1399676979.852 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:40.336Z,1399676980.336 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:40.336Z,1399676980.336 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:40.336Z,1399676980.336 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:40.336Z,1399676980.336 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:40.336Z,1399676980.336 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:40.657Z,1399676980.657 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:40.657Z,1399676980.657 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:40.657Z,1399676980.657 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:40.658Z,1399676980.658 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:41.048Z,1399676981.048 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:41.048Z,1399676981.048 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:41.048Z,1399676981.048 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:41.048Z,1399676981.048 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:41.049Z,1399676981.049 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:41.490Z,1399676981.490 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:41.490Z,1399676981.490 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:41.490Z,1399676981.490 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:41.490Z,1399676981.490 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:41.838Z,1399676981.838 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:41.838Z,1399676981.838 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:41.839Z,1399676981.839 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:41.839Z,1399676981.839 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:41.839Z,1399676981.839 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:42.220Z,1399676982.220 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:42.220Z,1399676982.220 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:42.220Z,1399676982.220 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:42.221Z,1399676982.221 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:42.622Z,1399676982.622 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:42.622Z,1399676982.622 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:42.622Z,1399676982.622 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:42.623Z,1399676982.623 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:42.623Z,1399676982.623 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:43.024Z,1399676983.024 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:43.024Z,1399676983.024 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:43.024Z,1399676983.024 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:43.024Z,1399676983.024 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:43.470Z,1399676983.470 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:43.471Z,1399676983.471 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:43.471Z,1399676983.471 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:43.471Z,1399676983.471 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:43.471Z,1399676983.471 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:43.841Z,1399676983.841 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:43.841Z,1399676983.841 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:43.842Z,1399676983.842 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:43.842Z,1399676983.842 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:44.241Z,1399676984.241 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:44.241Z,1399676984.241 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:44.242Z,1399676984.242 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:44.242Z,1399676984.242 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:44.242Z,1399676984.242 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:44.681Z,1399676984.681 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:44.681Z,1399676984.681 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:44.681Z,1399676984.681 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:44.681Z,1399676984.681 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:45.051Z,1399676985.051 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:45.052Z,1399676985.052 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:45.052Z,1399676985.052 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:45.052Z,1399676985.052 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:45.052Z,1399676985.052 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:45.495Z,1399676985.495 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:45.495Z,1399676985.495 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:45.495Z,1399676985.495 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:45.496Z,1399676985.496 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:45.853Z,1399676985.853 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:45.853Z,1399676985.853 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:45.853Z,1399676985.853 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:45.854Z,1399676985.854 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:45.854Z,1399676985.854 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:46.232Z,1399676986.232 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:46.233Z,1399676986.233 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:46.233Z,1399676986.233 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:46.233Z,1399676986.233 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:46.645Z,1399676986.645 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:46.645Z,1399676986.645 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:46.645Z,1399676986.645 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:46.646Z,1399676986.646 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:46.646Z,1399676986.646 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:47.021Z,1399676987.021 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:47.021Z,1399676987.021 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:47.021Z,1399676987.021 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:47.021Z,1399676987.021 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:47.423Z,1399676987.423 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:47.423Z,1399676987.423 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:47.423Z,1399676987.423 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:47.423Z,1399676987.423 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:47.423Z,1399676987.423 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:47.879Z,1399676987.879 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:47.879Z,1399676987.879 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:47.879Z,1399676987.879 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:47.879Z,1399676987.879 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:48.259Z,1399676988.259 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:48.259Z,1399676988.259 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:48.259Z,1399676988.259 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:48.259Z,1399676988.259 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:48.259Z,1399676988.259 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:48.657Z,1399676988.657 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:48.657Z,1399676988.657 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:48.658Z,1399676988.658 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:48.658Z,1399676988.658 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:49.064Z,1399676989.064 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:49.064Z,1399676989.064 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:49.064Z,1399676989.064 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:49.065Z,1399676989.065 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:49.065Z,1399676989.065 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:49.442Z,1399676989.442 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:49.442Z,1399676989.442 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:49.442Z,1399676989.442 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:49.443Z,1399676989.443 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:49.846Z,1399676989.846 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:49.846Z,1399676989.846 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:49.846Z,1399676989.846 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:49.846Z,1399676989.846 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:49.847Z,1399676989.847 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:50.256Z,1399676990.256 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:50.256Z,1399676990.256 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:50.256Z,1399676990.256 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:50.256Z,1399676990.256 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:50.708Z,1399676990.708 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:50.708Z,1399676990.708 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:50.708Z,1399676990.708 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:50.709Z,1399676990.709 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:50.709Z,1399676990.709 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:51.088Z,1399676991.088 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:51.089Z,1399676991.089 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:51.089Z,1399676991.089 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:51.089Z,1399676991.089 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:51.436Z,1399676991.436 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:51.436Z,1399676991.436 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:51.436Z,1399676991.436 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:51.436Z,1399676991.436 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:51.437Z,1399676991.437 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:51.857Z,1399676991.857 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:51.857Z,1399676991.857 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:51.857Z,1399676991.857 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:51.857Z,1399676991.857 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:52.243Z,1399676992.243 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:52.243Z,1399676992.243 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:52.243Z,1399676992.243 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:52.244Z,1399676992.244 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:52.244Z,1399676992.244 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:52.656Z,1399676992.656 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:52.656Z,1399676992.656 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:52.656Z,1399676992.656 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:52.656Z,1399676992.656 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:53.048Z,1399676993.048 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:53.048Z,1399676993.048 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:53.048Z,1399676993.048 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:53.049Z,1399676993.049 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:53.049Z,1399676993.049 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:53.443Z,1399676993.443 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:53.443Z,1399676993.443 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:53.444Z,1399676993.444 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:53.444Z,1399676993.444 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:53.821Z,1399676993.821 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:53.821Z,1399676993.821 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:53.821Z,1399676993.821 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:53.822Z,1399676993.822 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:53.822Z,1399676993.822 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:54.290Z,1399676994.290 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:54.290Z,1399676994.290 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:54.290Z,1399676994.290 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:54.290Z,1399676994.290 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:54.623Z,1399676994.623 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:54.623Z,1399676994.624 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:54.625Z,1399676994.625 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:54.625Z,1399676994.625 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:54.629Z,1399676994.629 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:55.061Z,1399676995.061 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:55.061Z,1399676995.061 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:55.062Z,1399676995.062 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:55.062Z,1399676995.062 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:55.460Z,1399676995.460 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:55.460Z,1399676995.460 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:55.460Z,1399676995.460 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:55.461Z,1399676995.461 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:55.465Z,1399676995.465 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:55.896Z,1399676995.896 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:55.896Z,1399676995.896 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:55.896Z,1399676995.896 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:55.896Z,1399676995.896 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:56.260Z,1399676996.260 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:56.260Z,1399676996.260 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:56.260Z,1399676996.260 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:56.260Z,1399676996.260 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:56.260Z,1399676996.260 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:56.651Z,1399676996.651 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:56.651Z,1399676996.651 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:56.651Z,1399676996.651 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:56.651Z,1399676996.651 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:57.061Z,1399676997.061 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:57.061Z,1399676997.061 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:57.061Z,1399676997.061 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:57.062Z,1399676997.062 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:57.062Z,1399676997.062 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:57.499Z,1399676997.499 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:57.500Z,1399676997.500 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:57.500Z,1399676997.500 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:57.500Z,1399676997.500 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:57.857Z,1399676997.857 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:57.857Z,1399676997.857 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:57.857Z,1399676997.857 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:57.857Z,1399676997.857 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:57.857Z,1399676997.857 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:58.255Z,1399676998.255 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:58.255Z,1399676998.255 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:58.255Z,1399676998.255 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:58.255Z,1399676998.255 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:58.657Z,1399676998.657 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:58.658Z,1399676998.658 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:58.658Z,1399676998.658 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:58.658Z,1399676998.658 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:58.658Z,1399676998.658 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:59.040Z,1399676999.040 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:59.040Z,1399676999.040 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:59.040Z,1399676999.040 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:59.040Z,1399676999.040 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:09:59.437Z,1399676999.437 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:09:59.438Z,1399676999.438 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:09:59.438Z,1399676999.438 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:09:59.438Z,1399676999.438 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:09:59.438Z,1399676999.438 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:09:59.838Z,1399676999.838 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:09:59.839Z,1399676999.839 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:09:59.839Z,1399676999.839 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:09:59.839Z,1399676999.839 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:00.222Z,1399677000.222 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:00.222Z,1399677000.222 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:00.223Z,1399677000.223 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:00.223Z,1399677000.223 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:00.223Z,1399677000.223 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:00.767Z,1399677000.767 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:00.767Z,1399677000.767 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:00.767Z,1399677000.767 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:00.767Z,1399677000.767 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:01.024Z,1399677001.024 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:01.025Z,1399677001.025 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:01.025Z,1399677001.025 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:01.025Z,1399677001.025 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:01.025Z,1399677001.025 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:01.458Z,1399677001.458 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:01.458Z,1399677001.458 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:01.458Z,1399677001.458 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:01.459Z,1399677001.459 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:01.841Z,1399677001.841 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:01.841Z,1399677001.841 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:01.841Z,1399677001.841 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:01.842Z,1399677001.842 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:01.842Z,1399677001.842 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:02.250Z,1399677002.250 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:02.250Z,1399677002.250 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:02.250Z,1399677002.250 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:02.250Z,1399677002.250 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:02.664Z,1399677002.664 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:02.664Z,1399677002.664 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:02.664Z,1399677002.664 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:02.664Z,1399677002.664 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:02.664Z,1399677002.664 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:03.058Z,1399677003.058 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:03.058Z,1399677003.058 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:03.058Z,1399677003.058 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:03.058Z,1399677003.058 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:03.454Z,1399677003.454 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:03.454Z,1399677003.454 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:03.454Z,1399677003.454 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:03.454Z,1399677003.454 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:03.454Z,1399677003.454 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:03.886Z,1399677003.886 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:03.887Z,1399677003.887 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:03.887Z,1399677003.887 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:03.887Z,1399677003.887 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:04.247Z,1399677004.247 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:04.247Z,1399677004.247 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:04.247Z,1399677004.247 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:04.248Z,1399677004.248 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:04.248Z,1399677004.248 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:04.649Z,1399677004.649 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:04.649Z,1399677004.649 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:04.649Z,1399677004.649 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:04.650Z,1399677004.650 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:05.042Z,1399677005.042 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:05.042Z,1399677005.042 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:05.042Z,1399677005.042 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:05.043Z,1399677005.043 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:05.043Z,1399677005.043 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:05.439Z,1399677005.439 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:05.439Z,1399677005.439 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:05.439Z,1399677005.439 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:05.439Z,1399677005.439 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:05.912Z,1399677005.912 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:05.912Z,1399677005.912 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:05.912Z,1399677005.912 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:05.912Z,1399677005.912 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:05.912Z,1399677005.912 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:06.247Z,1399677006.247 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:06.247Z,1399677006.247 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:06.248Z,1399677006.248 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:06.248Z,1399677006.248 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:06.621Z,1399677006.621 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:06.622Z,1399677006.622 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:06.622Z,1399677006.622 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:06.622Z,1399677006.622 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:06.622Z,1399677006.622 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:07.110Z,1399677007.110 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:07.110Z,1399677007.110 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:07.110Z,1399677007.110 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:07.110Z,1399677007.110 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:07.439Z,1399677007.439 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:07.439Z,1399677007.439 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:07.439Z,1399677007.439 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:07.440Z,1399677007.440 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:07.440Z,1399677007.440 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:07.863Z,1399677007.863 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:07.863Z,1399677007.863 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:07.863Z,1399677007.863 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:07.863Z,1399677007.863 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:08.255Z,1399677008.255 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:08.256Z,1399677008.256 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:08.256Z,1399677008.256 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:08.256Z,1399677008.256 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:08.256Z,1399677008.256 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:08.669Z,1399677008.669 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:08.669Z,1399677008.669 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:08.670Z,1399677008.670 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:08.670Z,1399677008.670 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:09.055Z,1399677009.055 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:09.055Z,1399677009.055 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:09.055Z,1399677009.055 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:09.055Z,1399677009.055 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:09.055Z,1399677009.055 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:09.434Z,1399677009.434 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:09.434Z,1399677009.434 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:09.434Z,1399677009.434 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:09.434Z,1399677009.434 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:09.846Z,1399677009.846 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:09.846Z,1399677009.846 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:09.846Z,1399677009.846 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:09.846Z,1399677009.846 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:09.846Z,1399677009.846 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:10.297Z,1399677010.297 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:10.297Z,1399677010.297 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:10.298Z,1399677010.298 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:10.298Z,1399677010.298 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:10.639Z,1399677010.639 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:10.639Z,1399677010.639 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:10.639Z,1399677010.639 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:10.640Z,1399677010.640 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:10.640Z,1399677010.640 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:11.095Z,1399677011.095 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:11.095Z,1399677011.095 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:11.095Z,1399677011.095 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:11.095Z,1399677011.095 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:11.456Z,1399677011.455 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:11.456Z,1399677011.456 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:11.456Z,1399677011.456 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:11.456Z,1399677011.456 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:11.456Z,1399677011.456 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:11.845Z,1399677011.845 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:11.845Z,1399677011.845 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:11.845Z,1399677011.845 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:11.845Z,1399677011.845 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:12.252Z,1399677012.252 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:12.253Z,1399677012.253 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:12.253Z,1399677012.253 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:12.253Z,1399677012.253 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:12.253Z,1399677012.253 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:12.637Z,1399677012.637 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:12.637Z,1399677012.637 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:12.637Z,1399677012.637 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:12.637Z,1399677012.637 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:13.023Z,1399677013.023 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:13.023Z,1399677013.023 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:13.023Z,1399677013.023 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:13.023Z,1399677013.023 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:13.023Z,1399677013.023 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:13.492Z,1399677013.492 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:13.493Z,1399677013.493 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:13.493Z,1399677013.493 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:13.493Z,1399677013.493 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:13.823Z,1399677013.823 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:13.823Z,1399677013.823 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:13.823Z,1399677013.823 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:13.823Z,1399677013.823 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:13.823Z,1399677013.823 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:14.224Z,1399677014.224 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:14.224Z,1399677014.224 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:14.224Z,1399677014.224 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:14.224Z,1399677014.224 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:14.634Z,1399677014.634 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:14.635Z,1399677014.635 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:14.668Z,1399677014.668 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:14.669Z,1399677014.669 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:14.669Z,1399677014.669 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:15.050Z,1399677015.050 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:15.050Z,1399677015.050 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:15.050Z,1399677015.050 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:15.051Z,1399677015.051 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:15.435Z,1399677015.435 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:15.435Z,1399677015.435 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:15.435Z,1399677015.435 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:15.435Z,1399677015.435 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:15.436Z,1399677015.436 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:15.895Z,1399677015.895 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:15.895Z,1399677015.895 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:15.895Z,1399677015.895 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:15.896Z,1399677015.896 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:16.264Z,1399677016.264 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:16.264Z,1399677016.264 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:16.264Z,1399677016.264 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:16.265Z,1399677016.265 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:16.265Z,1399677016.265 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:16.678Z,1399677016.678 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:16.678Z,1399677016.678 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:16.678Z,1399677016.678 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:16.678Z,1399677016.678 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:17.041Z,1399677017.041 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:17.041Z,1399677017.041 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:17.041Z,1399677017.041 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:17.042Z,1399677017.042 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:17.042Z,1399677017.042 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:17.450Z,1399677017.450 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:17.450Z,1399677017.450 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:17.450Z,1399677017.450 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:17.451Z,1399677017.451 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:17.850Z,1399677017.850 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:17.850Z,1399677017.850 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:17.850Z,1399677017.850 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:17.851Z,1399677017.851 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:17.851Z,1399677017.851 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:18.250Z,1399677018.250 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:18.250Z,1399677018.250 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:18.250Z,1399677018.250 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:18.250Z,1399677018.250 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:18.647Z,1399677018.647 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:18.647Z,1399677018.647 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:18.647Z,1399677018.647 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:18.647Z,1399677018.647 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:18.647Z,1399677018.647 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:19.047Z,1399677019.047 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:19.048Z,1399677019.048 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:19.048Z,1399677019.048 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:19.048Z,1399677019.048 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:19.457Z,1399677019.457 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:19.457Z,1399677019.457 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:19.458Z,1399677019.458 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:19.458Z,1399677019.458 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:19.458Z,1399677019.458 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:20.379Z,1399677020.379 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:20.379Z,1399677020.379 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:20.379Z,1399677020.379 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:20.379Z,1399677020.379 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:20.495Z,1399677020.495 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:20.495Z,1399677020.495 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:20.495Z,1399677020.495 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:20.495Z,1399677020.495 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:20.496Z,1399677020.496 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:20.917Z,1399677020.917 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:20.918Z,1399677020.918 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:20.918Z,1399677020.918 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:20.918Z,1399677020.918 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:21.275Z,1399677021.275 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:21.275Z,1399677021.275 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:21.275Z,1399677021.275 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:21.275Z,1399677021.275 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:21.276Z,1399677021.276 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:21.676Z,1399677021.676 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:21.676Z,1399677021.676 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:21.676Z,1399677021.676 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:21.676Z,1399677021.676 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:22.075Z,1399677022.075 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:22.076Z,1399677022.076 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:22.076Z,1399677022.076 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:22.076Z,1399677022.076 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:22.076Z,1399677022.076 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:22.457Z,1399677022.457 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:22.458Z,1399677022.458 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:22.458Z,1399677022.458 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:22.458Z,1399677022.458 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:22.864Z,1399677022.864 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:22.864Z,1399677022.864 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:22.864Z,1399677022.864 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:22.864Z,1399677022.864 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:22.865Z,1399677022.865 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:23.311Z,1399677023.311 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:23.311Z,1399677023.311 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:23.311Z,1399677023.311 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:23.311Z,1399677023.311 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:23.642Z,1399677023.642 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:23.642Z,1399677023.642 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:23.642Z,1399677023.642 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:23.642Z,1399677023.642 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:23.643Z,1399677023.643 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:24.044Z,1399677024.044 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:24.044Z,1399677024.044 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:24.044Z,1399677024.044 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:24.044Z,1399677024.044 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:24.445Z,1399677024.445 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:24.445Z,1399677024.445 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:24.445Z,1399677024.445 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:24.446Z,1399677024.446 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:24.446Z,1399677024.446 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:24.871Z,1399677024.871 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:24.871Z,1399677024.871 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:24.871Z,1399677024.871 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:24.871Z,1399677024.871 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:25.272Z,1399677025.272 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:25.273Z,1399677025.273 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:25.273Z,1399677025.273 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:25.273Z,1399677025.273 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:25.273Z,1399677025.273 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:25.661Z,1399677025.661 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:25.661Z,1399677025.661 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:25.661Z,1399677025.661 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:25.661Z,1399677025.661 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:26.138Z,1399677026.138 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:26.138Z,1399677026.138 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:26.138Z,1399677026.138 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:26.138Z,1399677026.138 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:26.138Z,1399677026.138 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:26.508Z,1399677026.508 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:26.509Z,1399677026.509 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:26.509Z,1399677026.509 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:26.509Z,1399677026.509 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:26.885Z,1399677026.885 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:26.885Z,1399677026.885 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:26.885Z,1399677026.885 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:26.885Z,1399677026.885 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:26.886Z,1399677026.886 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:27.268Z,1399677027.268 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:27.268Z,1399677027.268 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:27.268Z,1399677027.268 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:27.268Z,1399677027.268 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:27.642Z,1399677027.642 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:27.642Z,1399677027.642 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:27.642Z,1399677027.642 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:27.642Z,1399677027.642 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:27.642Z,1399677027.642 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:28.041Z,1399677028.041 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:28.041Z,1399677028.041 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:28.041Z,1399677028.041 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:28.041Z,1399677028.041 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:28.445Z,1399677028.445 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:28.445Z,1399677028.445 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:28.445Z,1399677028.445 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:28.445Z,1399677028.445 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:28.445Z,1399677028.445 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:28.847Z,1399677028.847 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:28.847Z,1399677028.847 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:28.847Z,1399677028.847 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:28.847Z,1399677028.847 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:29.277Z,1399677029.277 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:29.277Z,1399677029.277 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:29.277Z,1399677029.277 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:29.278Z,1399677029.278 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:29.278Z,1399677029.278 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:29.704Z,1399677029.704 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:29.704Z,1399677029.704 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:29.704Z,1399677029.704 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:29.704Z,1399677029.704 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:30.084Z,1399677030.084 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:30.084Z,1399677030.084 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:30.084Z,1399677030.084 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:30.085Z,1399677030.085 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:30.085Z,1399677030.085 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:30.462Z,1399677030.462 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:30.462Z,1399677030.462 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:30.462Z,1399677030.462 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:30.462Z,1399677030.462 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:30.866Z,1399677030.866 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:30.866Z,1399677030.866 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:30.866Z,1399677030.866 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:30.866Z,1399677030.866 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:30.866Z,1399677030.866 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:31.357Z,1399677031.357 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:31.358Z,1399677031.358 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:31.358Z,1399677031.358 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:31.358Z,1399677031.358 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:31.666Z,1399677031.666 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:31.666Z,1399677031.666 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:31.666Z,1399677031.666 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:31.667Z,1399677031.667 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:31.667Z,1399677031.667 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:32.064Z,1399677032.064 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:32.065Z,1399677032.065 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:32.065Z,1399677032.065 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:32.065Z,1399677032.065 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:32.473Z,1399677032.473 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:32.473Z,1399677032.473 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:32.474Z,1399677032.474 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:32.474Z,1399677032.474 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:32.479Z,1399677032.479 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:32.908Z,1399677032.908 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:32.908Z,1399677032.908 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:32.908Z,1399677032.908 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:32.908Z,1399677032.908 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:33.264Z,1399677033.264 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:33.264Z,1399677033.264 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:33.265Z,1399677033.265 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:33.265Z,1399677033.265 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:33.265Z,1399677033.265 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:33.642Z,1399677033.642 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:33.642Z,1399677033.642 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:33.642Z,1399677033.642 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:33.643Z,1399677033.643 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:34.043Z,1399677034.043 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:34.043Z,1399677034.043 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:34.044Z,1399677034.044 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:34.044Z,1399677034.044 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:34.044Z,1399677034.044 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:34.474Z,1399677034.474 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:34.474Z,1399677034.474 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:34.474Z,1399677034.474 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:34.474Z,1399677034.474 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:34.871Z,1399677034.871 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:34.871Z,1399677034.871 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:34.872Z,1399677034.872 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:34.872Z,1399677034.872 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:34.872Z,1399677034.872 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:35.277Z,1399677035.277 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:35.277Z,1399677035.277 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:35.277Z,1399677035.277 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:35.277Z,1399677035.277 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:35.677Z,1399677035.677 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:35.677Z,1399677035.677 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:35.677Z,1399677035.677 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:35.678Z,1399677035.678 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:35.678Z,1399677035.678 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:36.110Z,1399677036.110 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:36.110Z,1399677036.110 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:36.111Z,1399677036.111 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:36.111Z,1399677036.111 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:36.524Z,1399677036.524 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:36.524Z,1399677036.524 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:36.524Z,1399677036.524 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:36.524Z,1399677036.524 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:36.524Z,1399677036.524 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:36.856Z,1399677036.856 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:36.856Z,1399677036.856 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:36.856Z,1399677036.856 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:36.856Z,1399677036.856 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:37.245Z,1399677037.245 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:37.245Z,1399677037.245 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:37.266Z,1399677037.266 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:37.266Z,1399677037.266 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:37.266Z,1399677037.266 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:37.644Z,1399677037.644 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:37.644Z,1399677037.644 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:37.644Z,1399677037.644 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:37.644Z,1399677037.644 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:38.066Z,1399677038.066 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:38.066Z,1399677038.066 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:38.066Z,1399677038.066 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:38.067Z,1399677038.067 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:38.068Z,1399677038.068 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:38.461Z,1399677038.461 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:38.462Z,1399677038.462 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:38.462Z,1399677038.462 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:38.462Z,1399677038.462 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:38.871Z,1399677038.871 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:38.871Z,1399677038.871 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:38.871Z,1399677038.871 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:38.871Z,1399677038.871 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:38.871Z,1399677038.871 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:39.319Z,1399677039.319 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:39.319Z,1399677039.319 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:39.319Z,1399677039.319 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:39.320Z,1399677039.320 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:39.667Z,1399677039.667 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:39.667Z,1399677039.667 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:39.667Z,1399677039.667 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:39.668Z,1399677039.668 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:39.668Z,1399677039.668 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:40.068Z,1399677040.068 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:40.068Z,1399677040.068 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:40.068Z,1399677040.068 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:40.069Z,1399677040.069 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:40.442Z,1399677040.442 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:40.442Z,1399677040.442 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:40.442Z,1399677040.442 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:40.455Z,1399677040.455 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:40.455Z,1399677040.455 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:40.842Z,1399677040.842 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:40.842Z,1399677040.842 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:40.842Z,1399677040.842 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:40.842Z,1399677040.842 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:41.335Z,1399677041.335 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:41.335Z,1399677041.335 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:41.335Z,1399677041.335 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:41.336Z,1399677041.336 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:41.336Z,1399677041.336 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:41.645Z,1399677041.645 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:41.645Z,1399677041.645 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:41.645Z,1399677041.645 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:41.645Z,1399677041.645 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:42.046Z,1399677042.046 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:42.046Z,1399677042.046 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:42.046Z,1399677042.046 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:42.047Z,1399677042.047 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:42.047Z,1399677042.047 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:42.497Z,1399677042.497 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:42.497Z,1399677042.497 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:42.497Z,1399677042.497 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:42.497Z,1399677042.497 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:42.871Z,1399677042.871 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:42.871Z,1399677042.871 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:42.871Z,1399677042.871 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:42.872Z,1399677042.872 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:42.872Z,1399677042.872 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:43.276Z,1399677043.276 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:43.277Z,1399677043.277 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:43.277Z,1399677043.277 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:43.277Z,1399677043.277 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:43.669Z,1399677043.669 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:43.669Z,1399677043.669 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:43.669Z,1399677043.669 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:43.669Z,1399677043.669 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:43.670Z,1399677043.670 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:44.067Z,1399677044.067 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:44.067Z,1399677044.067 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:44.067Z,1399677044.067 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:44.067Z,1399677044.067 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:44.466Z,1399677044.466 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:44.466Z,1399677044.466 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:44.466Z,1399677044.466 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:44.466Z,1399677044.466 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:44.466Z,1399677044.466 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:44.867Z,1399677044.867 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:44.867Z,1399677044.867 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:44.867Z,1399677044.867 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:44.867Z,1399677044.867 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:45.277Z,1399677045.277 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:45.277Z,1399677045.277 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:45.277Z,1399677045.277 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:45.278Z,1399677045.278 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:45.278Z,1399677045.278 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:45.729Z,1399677045.729 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:45.729Z,1399677045.729 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:45.729Z,1399677045.729 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:45.729Z,1399677045.729 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:46.058Z,1399677046.058 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:46.058Z,1399677046.058 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:46.058Z,1399677046.058 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:46.059Z,1399677046.059 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:46.059Z,1399677046.059 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:46.528Z,1399677046.528 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:46.528Z,1399677046.528 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:46.528Z,1399677046.528 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:46.528Z,1399677046.528 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:46.881Z,1399677046.881 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:46.881Z,1399677046.881 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:46.881Z,1399677046.881 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:46.882Z,1399677046.882 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:46.882Z,1399677046.882 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:47.282Z,1399677047.282 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:47.282Z,1399677047.282 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:47.282Z,1399677047.282 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:47.282Z,1399677047.282 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:47.666Z,1399677047.666 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:47.666Z,1399677047.666 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:47.666Z,1399677047.666 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:47.667Z,1399677047.667 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:47.667Z,1399677047.667 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:48.063Z,1399677048.063 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:48.063Z,1399677048.063 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:48.063Z,1399677048.063 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:48.063Z,1399677048.063 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:48.492Z,1399677048.492 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:48.492Z,1399677048.492 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:48.492Z,1399677048.492 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:48.492Z,1399677048.492 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:48.492Z,1399677048.492 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:48.899Z,1399677048.899 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:48.899Z,1399677048.899 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:48.899Z,1399677048.899 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:48.899Z,1399677048.899 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:49.287Z,1399677049.287 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:49.287Z,1399677049.287 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:49.287Z,1399677049.287 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:49.288Z,1399677049.288 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:49.288Z,1399677049.288 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:49.674Z,1399677049.674 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:49.674Z,1399677049.674 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:49.674Z,1399677049.674 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:49.674Z,1399677049.674 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:50.073Z,1399677050.073 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:50.074Z,1399677050.074 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:50.074Z,1399677050.074 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:50.074Z,1399677050.074 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:50.074Z,1399677050.074 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:50.474Z,1399677050.474 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:50.474Z,1399677050.474 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:50.474Z,1399677050.474 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:50.475Z,1399677050.475 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:50.871Z,1399677050.871 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:50.871Z,1399677050.871 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:50.871Z,1399677050.871 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:50.872Z,1399677050.872 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:50.872Z,1399677050.872 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:51.254Z,1399677051.254 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:51.254Z,1399677051.254 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:51.254Z,1399677051.254 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:51.254Z,1399677051.254 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:51.761Z,1399677051.761 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:51.761Z,1399677051.761 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:51.761Z,1399677051.761 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:51.762Z,1399677051.762 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:51.762Z,1399677051.762 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:52.114Z,1399677052.114 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:52.114Z,1399677052.114 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:52.114Z,1399677052.114 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:52.115Z,1399677052.115 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:52.456Z,1399677052.456 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:52.456Z,1399677052.456 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:52.456Z,1399677052.456 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:52.457Z,1399677052.457 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:52.457Z,1399677052.457 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:52.844Z,1399677052.844 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:52.844Z,1399677052.844 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:52.844Z,1399677052.844 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:52.844Z,1399677052.844 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:53.273Z,1399677053.273 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:53.273Z,1399677053.273 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:53.273Z,1399677053.273 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:53.274Z,1399677053.274 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:53.274Z,1399677053.274 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:53.677Z,1399677053.677 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:53.677Z,1399677053.677 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:53.677Z,1399677053.677 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:53.678Z,1399677053.678 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:54.075Z,1399677054.075 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:54.076Z,1399677054.076 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:54.076Z,1399677054.076 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:54.076Z,1399677054.076 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:54.076Z,1399677054.076 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:54.483Z,1399677054.483 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:54.483Z,1399677054.483 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:54.483Z,1399677054.483 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:54.483Z,1399677054.483 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:54.863Z,1399677054.863 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:54.863Z,1399677054.864 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:54.864Z,1399677054.864 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:54.864Z,1399677054.864 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:54.864Z,1399677054.864 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:55.300Z,1399677055.300 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:55.300Z,1399677055.300 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:55.300Z,1399677055.300 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:55.300Z,1399677055.300 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:55.677Z,1399677055.677 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:55.677Z,1399677055.677 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:55.678Z,1399677055.678 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:55.678Z,1399677055.678 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:55.678Z,1399677055.678 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:56.058Z,1399677056.058 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:56.059Z,1399677056.059 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:56.059Z,1399677056.059 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:56.063Z,1399677056.063 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:56.523Z,1399677056.523 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:56.523Z,1399677056.523 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:56.523Z,1399677056.523 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:56.523Z,1399677056.523 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:56.523Z,1399677056.523 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:56.864Z,1399677056.864 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:56.864Z,1399677056.864 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:56.864Z,1399677056.864 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:56.864Z,1399677056.864 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:57.243Z,1399677057.243 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:57.243Z,1399677057.243 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:57.243Z,1399677057.243 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:57.244Z,1399677057.244 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:57.244Z,1399677057.244 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:57.694Z,1399677057.694 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:57.694Z,1399677057.694 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:57.694Z,1399677057.694 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:57.695Z,1399677057.695 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:58.068Z,1399677058.068 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:58.068Z,1399677058.068 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:58.068Z,1399677058.068 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:58.069Z,1399677058.069 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:58.069Z,1399677058.069 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:58.458Z,1399677058.458 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:58.458Z,1399677058.458 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:58.458Z,1399677058.458 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:58.458Z,1399677058.458 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:58.898Z,1399677058.898 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:58.898Z,1399677058.898 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:58.898Z,1399677058.898 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:58.899Z,1399677058.899 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:58.899Z,1399677058.899 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:10:59.273Z,1399677059.273 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:10:59.273Z,1399677059.273 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:10:59.273Z,1399677059.273 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:10:59.274Z,1399677059.274 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:10:59.663Z,1399677059.663 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:10:59.664Z,1399677059.664 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:10:59.664Z,1399677059.664 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:10:59.664Z,1399677059.664 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:10:59.664Z,1399677059.664 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:00.063Z,1399677060.063 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:00.063Z,1399677060.063 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:00.063Z,1399677060.063 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:00.063Z,1399677060.063 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:00.472Z,1399677060.472 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:00.472Z,1399677060.472 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:00.472Z,1399677060.472 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:00.473Z,1399677060.473 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:00.473Z,1399677060.473 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:00.867Z,1399677060.867 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:00.867Z,1399677060.867 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:00.867Z,1399677060.867 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:00.867Z,1399677060.867 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:01.256Z,1399677061.256 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:01.256Z,1399677061.256 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:01.256Z,1399677061.256 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:01.257Z,1399677061.257 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:01.257Z,1399677061.257 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:01.769Z,1399677061.769 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:01.769Z,1399677061.769 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:01.769Z,1399677061.769 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:01.769Z,1399677061.769 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:02.106Z,1399677062.106 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:02.106Z,1399677062.106 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:02.106Z,1399677062.106 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:02.107Z,1399677062.107 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:02.107Z,1399677062.107 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:02.470Z,1399677062.470 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:02.470Z,1399677062.470 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:02.470Z,1399677062.470 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:02.470Z,1399677062.470 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:02.843Z,1399677062.843 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:02.844Z,1399677062.844 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:02.844Z,1399677062.844 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:02.844Z,1399677062.844 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:02.844Z,1399677062.844 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:03.247Z,1399677063.247 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:03.247Z,1399677063.247 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:03.247Z,1399677063.247 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:03.248Z,1399677063.247 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:03.675Z,1399677063.675 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:03.675Z,1399677063.675 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:03.675Z,1399677063.675 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:03.676Z,1399677063.676 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:03.676Z,1399677063.676 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:04.077Z,1399677064.077 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:04.077Z,1399677064.077 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:04.078Z,1399677064.078 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:04.078Z,1399677064.078 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:04.475Z,1399677064.475 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:04.475Z,1399677064.475 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:04.475Z,1399677064.475 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:04.476Z,1399677064.476 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:04.476Z,1399677064.476 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:04.859Z,1399677064.859 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:04.860Z,1399677064.860 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:04.860Z,1399677064.860 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:04.860Z,1399677064.860 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:05.315Z,1399677065.315 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:05.315Z,1399677065.315 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:05.315Z,1399677065.315 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:05.316Z,1399677065.316 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:05.316Z,1399677065.316 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:05.673Z,1399677065.673 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:05.673Z,1399677065.673 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:05.673Z,1399677065.673 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:05.673Z,1399677065.673 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:06.065Z,1399677066.065 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:06.065Z,1399677066.065 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:06.065Z,1399677066.065 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:06.066Z,1399677066.066 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:06.066Z,1399677066.066 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:06.470Z,1399677066.470 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:06.470Z,1399677066.470 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:06.470Z,1399677066.470 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:06.470Z,1399677066.470 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:06.923Z,1399677066.923 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:06.923Z,1399677066.923 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:06.923Z,1399677066.923 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:06.924Z,1399677066.924 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:06.924Z,1399677066.924 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:07.268Z,1399677067.268 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:07.268Z,1399677067.268 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:07.269Z,1399677067.269 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:07.269Z,1399677067.269 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:07.658Z,1399677067.658 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:07.659Z,1399677067.659 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:07.659Z,1399677067.659 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:07.659Z,1399677067.659 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:07.659Z,1399677067.659 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:08.043Z,1399677068.043 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:08.043Z,1399677068.043 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:08.043Z,1399677068.043 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:08.043Z,1399677068.043 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:08.511Z,1399677068.511 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:08.511Z,1399677068.511 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:08.512Z,1399677068.512 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:08.512Z,1399677068.512 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:08.512Z,1399677068.512 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:08.878Z,1399677068.878 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:08.878Z,1399677068.878 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:08.878Z,1399677068.878 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:08.878Z,1399677068.878 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:09.270Z,1399677069.270 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:09.270Z,1399677069.270 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:09.270Z,1399677069.270 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:09.270Z,1399677069.270 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:09.271Z,1399677069.271 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:09.681Z,1399677069.681 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:09.682Z,1399677069.682 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:09.682Z,1399677069.682 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:09.682Z,1399677069.682 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:10.063Z,1399677070.063 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:10.063Z,1399677070.063 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:10.063Z,1399677070.063 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:10.064Z,1399677070.064 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:10.064Z,1399677070.064 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:10.466Z,1399677070.466 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:10.466Z,1399677070.466 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:10.466Z,1399677070.466 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:10.466Z,1399677070.466 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:10.873Z,1399677070.873 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:10.873Z,1399677070.873 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:10.874Z,1399677070.874 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:10.878Z,1399677070.878 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:10.878Z,1399677070.878 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:11.289Z,1399677071.289 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:11.289Z,1399677071.289 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:11.290Z,1399677071.290 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:11.290Z,1399677071.290 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:11.711Z,1399677071.711 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:11.711Z,1399677071.711 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:11.711Z,1399677071.711 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:11.712Z,1399677071.712 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:11.712Z,1399677071.712 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:12.117Z,1399677072.117 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:12.117Z,1399677072.117 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:12.118Z,1399677072.118 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:12.118Z,1399677072.118 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:12.467Z,1399677072.467 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:12.468Z,1399677072.468 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:12.468Z,1399677072.468 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:12.468Z,1399677072.468 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:12.473Z,1399677072.473 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:12.860Z,1399677072.860 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:12.860Z,1399677072.860 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:12.860Z,1399677072.860 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:12.860Z,1399677072.860 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:13.275Z,1399677073.275 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:13.275Z,1399677073.275 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:13.275Z,1399677073.275 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:13.276Z,1399677073.276 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:13.276Z,1399677073.276 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:13.648Z,1399677073.648 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:13.648Z,1399677073.648 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:13.648Z,1399677073.648 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:13.648Z,1399677073.648 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:14.079Z,1399677074.079 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:14.080Z,1399677074.080 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:14.080Z,1399677074.080 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:14.080Z,1399677074.080 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:14.080Z,1399677074.080 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:14.470Z,1399677074.470 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:14.470Z,1399677074.470 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:14.470Z,1399677074.470 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:14.470Z,1399677074.470 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:14.898Z,1399677074.898 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:14.898Z,1399677074.898 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:14.898Z,1399677074.898 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:14.899Z,1399677074.899 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:14.899Z,1399677074.899 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:15.279Z,1399677075.279 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:15.280Z,1399677075.280 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:15.280Z,1399677075.280 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:15.280Z,1399677075.280 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:15.670Z,1399677075.670 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:15.670Z,1399677075.670 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:15.670Z,1399677075.670 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:15.671Z,1399677075.671 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:15.671Z,1399677075.671 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:16.075Z,1399677076.075 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:16.075Z,1399677076.075 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:16.075Z,1399677076.075 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:16.075Z,1399677076.075 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:16.491Z,1399677076.491 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:16.491Z,1399677076.491 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:16.491Z,1399677076.491 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:16.492Z,1399677076.492 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:16.492Z,1399677076.492 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:16.864Z,1399677076.864 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:16.864Z,1399677076.864 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:16.864Z,1399677076.864 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:16.864Z,1399677076.864 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:17.353Z,1399677077.353 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:17.353Z,1399677077.353 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:17.353Z,1399677077.353 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:17.354Z,1399677077.354 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:17.354Z,1399677077.354 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:17.671Z,1399677077.671 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:17.671Z,1399677077.671 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:17.671Z,1399677077.671 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:17.672Z,1399677077.672 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:18.110Z,1399677078.110 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:18.110Z,1399677078.110 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:18.110Z,1399677078.110 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:18.110Z,1399677078.110 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:18.110Z,1399677078.110 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:18.480Z,1399677078.480 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:18.480Z,1399677078.480 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:18.480Z,1399677078.480 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:18.480Z,1399677078.480 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:18.868Z,1399677078.868 [SCPI_on:TestDrive:Data] Running Loop=1
2014-05-09T23:11:18.869Z,1399677078.869 [SCPI_on:TestDrive:Data](INFO): Aggregate::initialize SCPI_on:TestDrive:Data
2014-05-09T23:11:18.869Z,1399677078.869 [SCPI_on:TestDrive:Data:A] Running Loop=1
2014-05-09T23:11:18.869Z,1399677078.869 [SCPI_on:TestDrive:Data:A] Stopped
2014-05-09T23:11:18.869Z,1399677078.869 [SCPI_on:TestDrive:Data:B] Running Loop=1
2014-05-09T23:11:19.269Z,1399677079.269 [SCPI_on:TestDrive:C.Wait](INFO): Done Waiting.
2014-05-09T23:11:19.269Z,1399677079.269 [SCPI_on:TestDrive:C.Wait] Stopped
2014-05-09T23:11:19.269Z,1399677079.269 [SCPI_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2014-05-09T23:11:19.269Z,1399677079.269 [SCPI_on:TestDrive:Data:B] Stopped
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive:Data](INFO): Completed SCPI_on:TestDrive:Data
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive:Data] Stopped
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive:Data](INFO): Aggregate::uninitialize SCPI_on:TestDrive:Data
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive](INFO): Completed SCPI_on:TestDrive
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive] Stopped
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive](INFO): Aggregate::uninitialize SCPI_on:TestDrive
2014-05-09T23:11:19.270Z,1399677079.270 [SCPI_on:TestDrive:A] Stopped
2014-05-09T23:11:19.271Z,1399677079.271 [SCPI_on](INFO): Completed SCPI_on
2014-05-09T23:11:19.271Z,1399677079.271 [SCPI_on] Stopped
2014-05-09T23:11:19.271Z,1399677079.271 [SCPI_on](INFO): Aggregate::uninitialize SCPI_on
2014-05-09T23:11:19.271Z,1399677079.271 [SCPI_on:A.Pitch] Stopped
2014-05-09T23:11:19.660Z,1399677079.660 [MissionManager](IMPORTANT): Started mission Default
2014-05-09T23:11:19.660Z,1399677079.660 [Default] Running Loop=1
2014-05-09T23:11:19.660Z,1399677079.660 [Default](INFO): Aggregate::initialize Default
2014-05-09T23:11:19.660Z,1399677079.660 [Default:Iridium] Running Loop=1
2014-05-09T23:11:19.660Z,1399677079.660 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-09T23:11:19.660Z,1399677079.660 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-09T23:11:19.660Z,1399677079.660 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-09T23:11:19.661Z,1399677079.661 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-09T23:11:19.661Z,1399677079.661 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-09T23:11:19.667Z,1399677079.667 [Default:Iridium:B.GoToSurface] Stopped
2014-05-09T23:11:19.667Z,1399677079.667 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-09T23:11:19.667Z,1399677079.667 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-09T23:11:19.667Z,1399677079.667 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS] Running Loop=1
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-09T23:11:19.685Z,1399677079.685 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-09T23:11:19.700Z,1399677079.700 [Default:GPS:B.GoToSurface] Stopped
2014-05-09T23:11:19.700Z,1399677079.700 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-09T23:11:19.700Z,1399677079.700 [Default:GPS:Read_GPS] Running Loop=1
2014-05-09T23:11:19.700Z,1399677079.700 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-09T23:11:20.538Z,1399677080.538 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-09T23:11:20.540Z,1399677080.540 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-09T23:11:20.864Z,1399677080.864 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140509T230729/Courier0004.lzma
2014-05-09T23:11:20.868Z,1399677080.868 [NAL9602](INFO): Powering up
2014-05-09T23:11:21.658Z,1399677081.658 [DataOverHttps](INFO): Moved sent file to Logs/20140509T230729/Courier0004.lzma.bak
2014-05-09T23:11:21.659Z,1399677081.659 [DataOverHttps](INFO): SBD MOMSN=940226
2014-05-09T23:11:26.457Z,1399677086.457 [NAL9602](IMPORTANT): GPS fix at: 1399677086.45
2014-05-09T23:11:26.482Z,1399677086.482 [Default:GPS:Read_GPS] Stopped
2014-05-09T23:11:26.482Z,1399677086.482 [Default:GPS:D] Running Loop=1
2014-05-09T23:11:26.879Z,1399677086.879 [Default:GPS:D] Stopped
2014-05-09T23:11:26.879Z,1399677086.879 [Default:GPS](INFO): Completed Default:GPS
2014-05-09T23:11:26.879Z,1399677086.879 [Default:GPS] Stopped
2014-05-09T23:11:26.879Z,1399677086.879 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-09T23:11:26.879Z,1399677086.879 [Default:GPS:A.SetSpeed] Stopped
2014-05-09T23:11:26.880Z,1399677086.880 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-09T23:11:27.701Z,1399677087.701 [NAL9602](INFO): No messages in MT queue
2014-05-09T23:11:28.633Z,1399677088.633 [DataOverHttps](INFO): Sending 732 bytes from file Logs/20140509T230729/Express0005.lzma
2014-05-09T23:11:29.524Z,1399677089.524 [DataOverHttps](INFO): Moved sent file to Logs/20140509T230729/Express0005.lzma.bak
2014-05-09T23:11:29.524Z,1399677089.524 [DataOverHttps](INFO): SBD MOMSN=940228
2014-05-09T23:11:29.857Z,1399677089.857 [Default:Iridium:Read_Iridium] Stopped
2014-05-09T23:11:29.857Z,1399677089.857 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-09T23:11:29.857Z,1399677089.857 [Default:Iridium] Stopped
2014-05-09T23:11:29.858Z,1399677089.858 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-09T23:11:29.858Z,1399677089.858 [Default:Iridium:A.SetSpeed] Stopped
2014-05-09T23:11:29.858Z,1399677089.858 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface] Running Loop=1
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-09T23:11:29.858Z,1399677089.858 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-09T23:11:30.258Z,1399677090.258 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-09T23:11:30.264Z,1399677090.264 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-09T23:11:35.900Z,1399677095.900 [NAL9602](INFO): Powering down
2014-05-09T23:12:00.443Z,1399677120.443 [SCPI](INFO): Powering down
2014-05-09T23:12:11.320Z,1399677131.320 [CommandLine](IMPORTANT): got command quit
2014-05-09T23:12:12.324Z,1399677132.324 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:12.324Z,1399677132.324 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.497Z,1399677132.497 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-05-09T23:12:12.498Z,1399677132.498 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.498Z,1399677132.498 [CommandLine](INFO): Join timeout helper Thread ID is 1282
2014-05-09T23:12:12.499Z,1399677132.499 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-09T23:12:12.499Z,1399677132.499 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.499Z,1399677132.499 [NavChartDb](INFO): Join timeout helper Thread ID is 1283
2014-05-09T23:12:12.710Z,1399677132.710 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:12.710Z,1399677132.710 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.718Z,1399677132.718 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-09T23:12:12.718Z,1399677132.718 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.718Z,1399677132.718 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1284
2014-05-09T23:12:12.754Z,1399677132.754 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:12.755Z,1399677132.755 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.758Z,1399677132.758 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-09T23:12:12.758Z,1399677132.758 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:12.758Z,1399677132.758 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1285
2014-05-09T23:12:13.151Z,1399677133.151 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:13.151Z,1399677133.151 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.159Z,1399677133.159 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-05-09T23:12:13.159Z,1399677133.159 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.159Z,1399677133.159 [AsyncPiEstimator](INFO): Join timeout helper Thread ID is 1286
2014-05-09T23:12:13.235Z,1399677133.235 [AsyncPiEstimator ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:13.235Z,1399677133.235 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-05-09T23:12:13.235Z,1399677133.235 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.240Z,1399677133.240 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-09T23:12:13.240Z,1399677133.240 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.240Z,1399677133.240 [Radio_Freewave](INFO): Join timeout helper Thread ID is 1287
2014-05-09T23:12:13.355Z,1399677133.355 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:13.448Z,1399677133.448 [Radio_Freewave](INFO): Powering down
2014-05-09T23:12:13.852Z,1399677133.852 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.869Z,1399677133.869 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-09T23:12:13.869Z,1399677133.869 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.869Z,1399677133.869 [logger](INFO): Join timeout helper Thread ID is 1289
2014-05-09T23:12:13.880Z,1399677133.880 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:13.880Z,1399677133.880 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.889Z,1399677133.889 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-09T23:12:13.889Z,1399677133.889 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.889Z,1399677133.889 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-09T23:12:13.889Z,1399677133.889 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:13.890Z,1399677133.890 [controlThread](INFO): Join timeout helper Thread ID is 1290
2014-05-09T23:12:15.170Z,1399677135.170 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-09T23:12:15.170Z,1399677135.170 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-09T23:12:15.173Z,1399677135.173 [NAL9602](INFO): Powering down
2014-05-09T23:12:15.174Z,1399677135.174 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-09T23:12:15.175Z,1399677135.175 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-09T23:12:15.176Z,1399677135.176 [Default] Stopped
2014-05-09T23:12:15.176Z,1399677135.176 [Default](INFO): Aggregate::uninitialize Default
2014-05-09T23:12:15.176Z,1399677135.176 [Default:WaitAtTheSurface] Stopped
2014-05-09T23:12:15.176Z,1399677135.176 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-05-09T23:12:15.176Z,1399677135.176 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-05-09T23:12:15.176Z,1399677135.176 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-05-09T23:12:15.177Z,1399677135.177 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-05-09T23:12:15.177Z,1399677135.177 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-09T23:12:15.183Z,1399677135.183 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-09T23:12:15.183Z,1399677135.183 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-09T23:12:15.183Z,1399677135.183 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-09T23:12:15.183Z,1399677135.183 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-09T23:12:15.184Z,1399677135.184 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-09T23:12:15.184Z,1399677135.184 [BuoyancyServo](INFO): Powering down
2014-05-09T23:12:15.198Z,1399677135.198 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-09T23:12:15.198Z,1399677135.198 [ElevatorServo](INFO): Powering down
2014-05-09T23:12:15.199Z,1399677135.199 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-09T23:12:15.199Z,1399677135.199 [MassServo](INFO): Powering down
2014-05-09T23:12:15.200Z,1399677135.200 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-09T23:12:15.200Z,1399677135.200 [RudderServo](INFO): Powering down
2014-05-09T23:12:15.201Z,1399677135.201 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-09T23:12:15.201Z,1399677135.201 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-09T23:12:15.202Z,1399677135.202 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-09T23:12:15.202Z,1399677135.202 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-09T23:12:15.247Z,1399677135.247 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.252Z,1399677135.252 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.307Z,1399677135.307 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.329Z,1399677135.329 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.332Z,1399677135.332 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.360Z,1399677135.360 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-09T23:12:15.414Z,1399677135.414 [logger ThreadHandler](INFO): Thread cancelled.