Using Barrier with high load and got the error "Can't add waiter, no barriers" returned
Karn Thiraphat <[email protected]>
| Newsgroups | gmane.comp.java.grinder.user |
|---|---|
| Message-ID | <CAKRKYakLxN53Wob==QpRoTfxq7wTAfBX52tt0Luq2wxxX+JicA@mail.gmail.com> |
Hi,
When I tried to use the grinder (v3.6) to do a multi-thread processing
under a ton of loads using *startWorkerThread()* and *barrier() *to
coordinate all the created threads, I found the error *"Can't add waiter,
no barriers"* returned from the console. I'm not sure whether the way I
implemented the barrier is correct or not but from the error, I understood
that the *await() *may be called after that barrier name has already been
deleted, right? However, I have tried to make the barrier name unique but
still not help. Would anyone help with this please?
I have all 5 servers connecting to a console, which doesn't have an agent
running and configure grinder.properties as follows:
*grinder.processes = 10*
*grinder.threads = 1*
*grinder.run = 0*
*grinder.processIncrement = 1*
*grinder.processIncrementInterval = 30000*
And, below is the simplified script to replicate the issue. It happens
every time, sometime quick, sometime slow. I also attached the last part of
one log gather from 1 server for your quick reference. Observed that the
process stopped right after *"before call await pharse2:.."* so we
suspected that *await()* caused this error.
from net.grinder.script import Test
from net.grinder.script.Grinder import grinder
from datetime import datetime
from datetime import timedelta
from datetime import date
import time
log = grinder.logger.info
def BusinessProcessCombo():
# Get md
try:
grinder.sleep(100)
soapResponse = [1,2]
for m in range(len(soapResponse)):
try:
grinder.sleep(50)
except:
log ("unexpected error from MDHTTP")
except:
log ("unexpected error from MDSOAP")
# Get TimeSeries
try:
grinder.sleep(100)
soapResponse = [1,2,3,4,5,6,7,8,9,10]
for m in range(len(soapResponse)):
grinder.sleep(50)
except:
log("unexpected error from TSSOAP")
class ComboWorkerThread:
def __init__(self, barrierName):
self.isFirst = True
self.barrierName = barrierName
self.phase2CompleteBarrier = grinder.barrier(self.barrierName)
log(" create barrier pharse2: " + self.barrierName)
self.threadId = -1
def __call__(self):
# Get Metadata
if(self.isFirst == True):
self.isFirst = False
try:
log ("sub barrier :" + self.barrierName + " thread id : " +
str(self.threadId))
E2ETASCOMBO()
finally:
try:
log(" before call await pharse2: " +
self.barrierName + ", thread id : " + str(self.threadId) )
self.phase2CompleteBarrier.await()
log(" call await pharse2: " +
self.barrierName + ", thread id : " + str(self.threadId) )
except Exception, e:
log ("ERROR" + self.barrierName + " thread id : " +
str(self.threadId))
log ("Exception : "+ e)
log ("sub await :" + self.barrierName + " thread id : " +
str(self.threadId))
log (" thread id : " + str(self.threadId) + " is killed")
grinder.stopThisWorkerThread()
def callCombo():
tmpPName = grinder.getProcessName()
tmpPID = grinder.getProcessNumber()
tmpTID = grinder.getThreadNumber()
tmpRNum = grinder.getRunNumber()
current_milli_time = str(time.time() * 1000)
barrierName =
tmpPName+str(tmpPID)+str(tmpTID)+str(tmpRNum)+current_milli_time
try:
phase1CompleteBarrier = grinder.barrier(barrierName)
log("create barrier pharse1: " + barrierName)
except Exception, e:
log ("exception, ERROR create barrier :" + e)
log ("create barrier :"+barrierName)
for y in range(15):
log ("y:" + str(y))
workerThread = ComboWorkerThread(barrierName)
yy = grinder.startWorkerThread(workerThread)
workerThread.threadId = yy
try:
phase1CompleteBarrier.await()
log("call await pharse1: " + barrierName)
except Exception, e:
log ("exception phase1: " + e)
log ("call await :" + barrierName)
#Wrap
E2ECOMBO = Test(300,"E2ECOMBO").wrap(callCombo)
E2ETASCOMBO = Test(200,"E2ETASCOMBO").wrap(BusinessProcessCombo)
class TestRunner:
def __call__(self):
TestStartTime = datetime.now()
count = 1
log ("Start TestRunner")
E2ECOMBO()
def __del__(self):
log("End TestRunner")
Thanks so much for your help.
Thiraphat
------------------------------------------------------------------------------
Rapidly troubleshoot problems before they affect your business. Most IT
organizations don't have a clear picture of how application performance
affects their revenue. With AppDynamics, you get 100% visibility into your
Java,.NET, & PHP application. Start your 15-day FREE TRIAL of AppDynamics Pro!
http://pubads.g.doubleclick.net/gampad/clk?id=84349831&iu=/4140/ostg.clktrk
_______________________________________________
grinder-use mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/grinder-use
out.log
(application/octet-stream, 21.8 KB)
17/12/13 11:31:12 (thread 439 run 0 test 200): shut down 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse1: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 439 test 200): finished 0 runs 17/12/13 11:31:12 (thread 447 run 0 test 200): shut down 17/12/13 11:31:12 (thread 446 test 200): finished 0 runs 17/12/13 11:31:12 (thread 450 test 200): finished 0 runs 17/12/13 11:31:12 (thread 441 run 0 test 200): sub await :dtci-tsatmi005-990291.387279871268E12 thread id : 441 17/12/13 11:31:12 (thread 441 run 0 test 200): thread id : 441 is killed 17/12/13 11:31:12 (thread 438 run 0 test 200): shut down 17/12/13 11:31:12 (thread 447 test 200): finished 0 runs 17/12/13 11:31:12 (thread 438 test 200): finished 0 runs 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier :dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 445 test 200): finished 0 runs 17/12/13 11:31:12 (thread 0 run 30 test 300): y:0 17/12/13 11:31:12 (thread 441 run 0 test 200): shut down 17/12/13 11:31:12 (thread 441 test 200): finished 0 runs 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 0 run 30 test 300): y:1 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 451): starting, will run forever 17/12/13 11:31:12 (thread 451 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 451 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 105 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): y:2 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 452): starting, will run forever 17/12/13 11:31:12 (thread 0 run 30 test 300): y:3 17/12/13 11:31:12 (thread 452 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 452 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 104 ms 17/12/13 11:31:12 (thread 453): starting, will run forever 17/12/13 11:31:12 (thread 453 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 453 17/12/13 11:31:12 (thread 0 run 30 test 300): y:4 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 100 ms 17/12/13 11:31:12 (thread 454): starting, will run forever 17/12/13 11:31:12 (thread 454 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 454 17/12/13 11:31:12 (thread 0 run 30 test 300): y:5 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 110 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 455): starting, will run forever 17/12/13 11:31:12 (thread 455 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 455 17/12/13 11:31:12 (thread 0 run 30 test 300): y:6 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 104 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 456): starting, will run forever 17/12/13 11:31:12 (thread 456 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 456 17/12/13 11:31:12 (thread 0 run 30 test 300): y:7 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 109 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 457): starting, will run forever 17/12/13 11:31:12 (thread 457 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 457 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 100 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): y:8 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 458): starting, will run forever 17/12/13 11:31:12 (thread 458 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 458 17/12/13 11:31:12 (thread 0 run 30 test 300): y:9 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 97 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 0 run 30 test 300): y:10 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 459): starting, will run forever 17/12/13 11:31:12 (thread 459 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 459 17/12/13 11:31:12 (thread 0 run 30 test 300): y:11 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 108 ms 17/12/13 11:31:12 (thread 461): starting, will run forever 17/12/13 11:31:12 (thread 0 run 30 test 300): y:12 17/12/13 11:31:12 (thread 461 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 461 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 460): starting, will run forever 17/12/13 11:31:12 (thread 462): starting, will run forever 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 105 ms 17/12/13 11:31:12 (thread 460 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 460 17/12/13 11:31:12 (thread 462 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 462 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 103 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 92 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): y:13 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 463): starting, will run forever 17/12/13 11:31:12 (thread 463 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 463 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 106 ms 17/12/13 11:31:12 (thread 0 run 30 test 300): y:14 17/12/13 11:31:12 (thread 0 run 30 test 300): create barrier pharse2: dtci-tsatmi005-990301.387279872862E12 17/12/13 11:31:12 (thread 464): starting, will run forever 17/12/13 11:31:12 (thread 464 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 464 17/12/13 11:31:12 (thread 465): starting, will run forever 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 89 ms 17/12/13 11:31:12 (thread 465 run 0): sub barrier :dtci-tsatmi005-990301.387279872862E12 thread id : 465 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 97 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 45 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 43 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 44 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 45 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 103 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 99 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 92 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 92 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 99 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 100 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 101 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 103 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 104 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 95 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 103 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 101 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 97 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 100 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 101 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 56 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 44 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 56 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 57 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 45 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 56 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 45 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 44 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 45 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 451 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 452 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 454 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 457 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:12 (thread 455 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 459 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 463 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 460 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 453 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 465 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 464 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:12 (thread 461 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:12 (thread 458 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:12 (thread 462 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:12 (thread 456 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 451 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 452 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:13 (thread 457 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 460 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 463 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 454 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:13 (thread 455 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:13 (thread 459 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:13 (thread 464 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 453 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 465 run 0 test 200): sleeping for 42 ms 17/12/13 11:31:13 (thread 461 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:13 (thread 458 run 0 test 200): sleeping for 57 ms 17/12/13 11:31:13 (thread 462 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 456 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 455 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 452 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:13 (thread 465 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 457 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:13 (thread 460 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 463 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 451 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 459 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 454 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 461 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:13 (thread 453 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 464 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 458 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 462 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 461 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:13 (thread 456 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:13 (thread 454 run 0 test 200): sleeping for 46 ms 17/12/13 11:31:13 (thread 451 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 465 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 460 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:13 (thread 457 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 459 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 452 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 455 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 463 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 458 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 464 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 453 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 462 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:13 (thread 456 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 461 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 454 run 0 test 200): sleeping for 43 ms 17/12/13 11:31:13 (thread 457 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 459 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 455 run 0 test 200): sleeping for 50 ms 17/12/13 11:31:13 (thread 465 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 451 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 463 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 460 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 452 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 453 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 464 run 0 test 200): sleeping for 47 ms 17/12/13 11:31:13 (thread 458 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 462 run 0 test 200): sleeping for 52 ms 17/12/13 11:31:13 (thread 456 run 0 test 200): sleeping for 53 ms 17/12/13 11:31:13 (thread 454 run 0 test 200): sleeping for 51 ms 17/12/13 11:31:13 (thread 461 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 461 17/12/13 11:31:13 (thread 459 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 460 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 451 run 0 test 200): sleeping for 48 ms 17/12/13 11:31:13 (thread 452 run 0 test 200): sleeping for 49 ms 17/12/13 11:31:13 (thread 465 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 465 17/12/13 11:31:13 (thread 463 run 0 test 200): sleeping for 55 ms 17/12/13 11:31:13 (thread 457 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 457 17/12/13 11:31:13 (thread 455 run 0 test 200): sleeping for 54 ms 17/12/13 11:31:13 (thread 453 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 453 17/12/13 11:31:13 (thread 464 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 464 17/12/13 11:31:13 (thread 458 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 458 17/12/13 11:31:13 (thread 462 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 462 17/12/13 11:31:13 (thread 454 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 454 17/12/13 11:31:13 (thread 456 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 456 17/12/13 11:31:13 (thread 452 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 452 17/12/13 11:31:13 (thread 451 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 451 17/12/13 11:31:13 (thread 463 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 463 17/12/13 11:31:13 (thread 460 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 460 17/12/13 11:31:13 (thread 459 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 459 17/12/13 11:31:13 (thread 455 run 0 test 200): before call await pharse2: dtci-tsatmi005-990301.387279872862E12, thread id : 455