It looks to me to be the same issue we've been seeing lately on hudson trunk - testHammer fails randomly. We've tried a bunch of things to reproduce but so far no luck. Even running the test on the hudson machine with the same settings (outside hudson) we can't reproduce. We haven't seen this failure on the patch queue, which is even weirder.

afaict the session creation is stalling in the request processor, but it's not clear where. We may need to create a jira with some instrumented test code to see if we can get more data when it fails on hudson. Take a look though, maybe you'll see something I did not.


Patrick

Henry Robinson wrote:
The failed test is testObserversHammer - I'm having a look to see what might
be wrong.

Henry

On Thu, Nov 19, 2009 at 2:57 AM, Apache Hudson Server <
hud...@hudson.zones.apache.org> wrote:

See <http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/544/changes
Changes:

[mahadev] ZOOKEEPER-368. Observers: core functionality (henry robinson via
mahadev)

[breed] ZOOKEEPER-3. syncLimit has slightly different comments in the class
header, and > inline with the variable.

[breed] ZOOKEEPER-519. Followerhandler should close the socket if it gets
an exception on a write.

[breed] ZOOKEEPER-532. java compiler should be target Java 1.5

------------------------------------------
[...truncated 98279 lines...]
   [junit] 2009-11-19 10:57:31,578 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@929] - Opening
socket connection to server localhost/127.0.0.1:11225
   [junit] 2009-11-19 10:57:31,578 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11225, initiating session
   [junit] 2009-11-19 10:57:31,579 - INFO
 [NIOServerCxn.Factory:11225:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:54182
   [junit] 2009-11-19 10:57:31,579 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@688] - Client attempting to
renew session 0x1250c16f1210000 at /127.0.0.1:54182
   [junit] 2009-11-19 10:57:31,580 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@1131] - Established session
0x1250c16f1210000 for client /127.0.0.1:54182
   [junit] 2009-11-19 10:57:31,580 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c16f1210000
   [junit] 2009-11-19 10:57:31,588 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:31,589 - INFO  [main:nioserverc...@974] -
Closed socket connection for client /127.0.0.1:54182 which had sessionid
0x1250c16f1210000
   [junit] 2009-11-19 10:57:31,589 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@1047] - Unable to
read additional data from server sessionid 0x1250c16f1210000, likely server
has closed socket, closing socket connection and attempting reconnect
   [junit] 2009-11-19 10:57:31,590 - INFO
 [NIOServerCxn.Factory:11225:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:31,590 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:31,590 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:31,590 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:31,690 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:31,690 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:31,691 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11225
   [junit] 2009-11-19 10:57:31,692 - INFO  [main:files...@81] - Reading
snapshot <
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/tmp/test4406575549066528204.junit.dir/version-2/snapshot.5
   [junit] 2009-11-19 10:57:31,694 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 6
   [junit] 2009-11-19 10:57:31,696 - INFO
 [NIOServerCxn.Factory:11225:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:54184
   [junit] 2009-11-19 10:57:31,696 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@782] - Processing stat command
from /127.0.0.1:54184
   [junit] 2009-11-19 10:57:31,697 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:54184 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:33,000 - INFO
 [SessionTracker:sessiontrackeri...@145] - SessionTrackerImpl exited loop!
   [junit] 2009-11-19 10:57:33,586 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@929] - Opening
socket connection to server localhost/127.0.0.1:11225
   [junit] 2009-11-19 10:57:33,586 - INFO
 [NIOServerCxn.Factory:11225:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:54185
   [junit] 2009-11-19 10:57:33,586 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11225, initiating session
   [junit] 2009-11-19 10:57:33,587 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@688] - Client attempting to
renew session 0x1250c16f1210000 at /127.0.0.1:54185
   [junit] 2009-11-19 10:57:33,587 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@1131] - Established session
0x1250c16f1210000 for client /127.0.0.1:54185
   [junit] 2009-11-19 10:57:33,587 - INFO
 [main-SendThread(localhost:11225):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c16f1210000
   [junit] 2009-11-19 10:57:34,598 - INFO
 [ProcessThread:-1:preprequestproces...@385] - Processed session
termination for sessionid: 0x1250c16f1210000
   [junit] 2009-11-19 10:57:34,599 - INFO
 [NIOServerCxn.Factory:11225:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:54185 which had sessionid 0x1250c16f1210000
   [junit] 2009-11-19 10:57:34,599 - INFO  [main:zookee...@524] - Session:
0x1250c16f1210000 closed
   [junit] 2009-11-19 10:57:34,600 - INFO  [main:clientb...@399] -
tearDown starting
   [junit] 2009-11-19 10:57:34,600 - INFO  [main:clientb...@411] - fdcount
after test is: 46
   [junit] 2009-11-19 10:57:34,601 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:34,601 - INFO
 [NIOServerCxn.Factory:11225:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:34,601 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:34,601 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:34,601 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:34,605 - INFO  [main:clientb...@430] -
FINISHED testWatcherAutoResetDisabledWithGlobal
   [junit] 2009-11-19 10:57:34,605 - INFO  [main:clientb...@340] -
STARTING testWatcherAutoResetDisabledWithLocal
   [junit] 2009-11-19 10:57:34,611 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:34,611 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:34,612 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11226
   [junit] 2009-11-19 10:57:34,613 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 0
   [junit] 2009-11-19 10:57:34,614 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38803
   [junit] 2009-11-19 10:57:34,615 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@782] - Processing stat command
from /127.0.0.1:38803
   [junit] 2009-11-19 10:57:34,615 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:38803 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:34,617 - INFO  [main:clientb...@361] - Initial
fdcount is: 46
   [junit] 2009-11-19 10:57:34,617 - INFO  [main:clientb...@365] - Client
test setup finished
   [junit] 2009-11-19 10:57:34,617 - INFO  [main:zookee...@372] -
Initiating client connection, connectString=127.0.0.1:11226sessionTimeout=5000
watcher=org.apache.zookeeper.test.watchertest$mywatc...@200db9
   [junit] 2009-11-19 10:57:34,618 - INFO
 [main-SendThread():clientcnxn$sendthr...@929] - Opening socket connection
to server /127.0.0.1:11226
   [junit] 2009-11-19 10:57:34,619 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38804
   [junit] 2009-11-19 10:57:34,619 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11226, initiating session
   [junit] 2009-11-19 10:57:34,619 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@695] - Client attempting to
establish new session at /127.0.0.1:38804
   [junit] 2009-11-19 10:57:34,625 - INFO  [SyncThread:0:nioserverc...@1131]
- Established session 0x1250c170b950000 for client /127.0.0.1:38804
   [junit] 2009-11-19 10:57:34,625 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c170b950000
   [junit] expect:0x1250c170b950000
   [junit] found:0x1250c170b950000
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=Connections,name2=127.0.0.1,name3=0x1250c170b950000
   [junit] 2009-11-19 10:57:34,632 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:34,633 - INFO  [main:nioserverc...@974] -
Closed socket connection for client /127.0.0.1:38804 which had sessionid
0x1250c170b950000
   [junit] 2009-11-19 10:57:34,633 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@1047] - Unable to
read additional data from server sessionid 0x1250c170b950000, likely server
has closed socket, closing socket connection and attempting reconnect
   [junit] 2009-11-19 10:57:34,634 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:34,634 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:34,634 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:34,634 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:34,734 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:34,734 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:34,735 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11226
   [junit] 2009-11-19 10:57:34,736 - INFO  [main:files...@81] - Reading
snapshot <
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/tmp/test4795966199723253879.junit.dir/version-2/snapshot.0
   [junit] 2009-11-19 10:57:34,737 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 3
   [junit] 2009-11-19 10:57:34,739 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38806
   [junit] 2009-11-19 10:57:34,739 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@782] - Processing stat command
from /127.0.0.1:38806
   [junit] 2009-11-19 10:57:34,740 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:38806 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:35,884 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@929] - Opening
socket connection to server localhost/127.0.0.1:11226
   [junit] 2009-11-19 10:57:35,884 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11226, initiating session
   [junit] 2009-11-19 10:57:35,885 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38807
   [junit] 2009-11-19 10:57:35,885 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@688] - Client attempting to
renew session 0x1250c170b950000 at /127.0.0.1:38807
   [junit] 2009-11-19 10:57:35,885 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@1131] - Established session
0x1250c170b950000 for client /127.0.0.1:38807
   [junit] 2009-11-19 10:57:35,886 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c170b950000
   [junit] 2009-11-19 10:57:35,892 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:35,893 - INFO  [main:nioserverc...@974] -
Closed socket connection for client /127.0.0.1:38807 which had sessionid
0x1250c170b950000
   [junit] 2009-11-19 10:57:35,893 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@1047] - Unable to
read additional data from server sessionid 0x1250c170b950000, likely server
has closed socket, closing socket connection and attempting reconnect
   [junit] 2009-11-19 10:57:35,893 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:35,894 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:35,894 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:35,894 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:35,993 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:35,994 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:35,994 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11226
   [junit] 2009-11-19 10:57:35,995 - INFO  [main:files...@81] - Reading
snapshot <
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/tmp/test4795966199723253879.junit.dir/version-2/snapshot.3
   [junit] 2009-11-19 10:57:35,997 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 5
   [junit] 2009-11-19 10:57:35,999 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38809
   [junit] 2009-11-19 10:57:35,999 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@782] - Processing stat command
from /127.0.0.1:38809
   [junit] 2009-11-19 10:57:36,000 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:38809 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] 2009-11-19 10:57:36,000 - INFO
 [SessionTracker:sessiontrackeri...@145] - SessionTrackerImpl exited loop!
   [junit] 2009-11-19 10:57:36,000 - INFO
 [SessionTracker:sessiontrackeri...@145] - SessionTrackerImpl exited loop!
   [junit] 2009-11-19 10:57:36,001 - INFO
 [SessionTracker:sessiontrackeri...@145] - SessionTrackerImpl exited loop!
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:37,288 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@929] - Opening
socket connection to server localhost/127.0.0.1:11226
   [junit] 2009-11-19 10:57:37,289 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38810
   [junit] 2009-11-19 10:57:37,289 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11226, initiating session
   [junit] 2009-11-19 10:57:37,289 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@688] - Client attempting to
renew session 0x1250c170b950000 at /127.0.0.1:38810
   [junit] 2009-11-19 10:57:37,290 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@1131] - Established session
0x1250c170b950000 for client /127.0.0.1:38810
   [junit] 2009-11-19 10:57:37,290 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c170b950000
   [junit] 2009-11-19 10:57:37,300 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:37,301 - INFO  [main:nioserverc...@974] -
Closed socket connection for client /127.0.0.1:38810 which had sessionid
0x1250c170b950000
   [junit] 2009-11-19 10:57:37,301 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@1047] - Unable to
read additional data from server sessionid 0x1250c170b950000, likely server
has closed socket, closing socket connection and attempting reconnect
   [junit] 2009-11-19 10:57:37,301 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:37,302 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:37,302 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:37,302 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:37,401 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:37,402 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:37,402 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11226
   [junit] 2009-11-19 10:57:37,404 - INFO  [main:files...@81] - Reading
snapshot <
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/tmp/test4795966199723253879.junit.dir/version-2/snapshot.5
   [junit] 2009-11-19 10:57:37,406 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 6
   [junit] 2009-11-19 10:57:37,408 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38812
   [junit] 2009-11-19 10:57:37,408 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@782] - Processing stat command
from /127.0.0.1:38812
   [junit] 2009-11-19 10:57:37,408 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:38812 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:39,000 - INFO
 [SessionTracker:sessiontrackeri...@145] - SessionTrackerImpl exited loop!
   [junit] 2009-11-19 10:57:39,064 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@929] - Opening
socket connection to server localhost/127.0.0.1:11226
   [junit] 2009-11-19 10:57:39,065 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11226, initiating session
   [junit] 2009-11-19 10:57:39,065 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:38813
   [junit] 2009-11-19 10:57:39,065 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@688] - Client attempting to
renew session 0x1250c170b950000 at /127.0.0.1:38813
   [junit] 2009-11-19 10:57:39,066 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@1131] - Established session
0x1250c170b950000 for client /127.0.0.1:38813
   [junit] 2009-11-19 10:57:39,066 - INFO
 [main-SendThread(localhost:11226):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c170b950000
   [junit] 2009-11-19 10:57:40,086 - INFO
 [ProcessThread:-1:preprequestproces...@385] - Processed session
termination for sessionid: 0x1250c170b950000
   [junit] 2009-11-19 10:57:40,087 - INFO
 [NIOServerCxn.Factory:11226:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:38813 which had sessionid 0x1250c170b950000
   [junit] 2009-11-19 10:57:40,087 - INFO  [main:zookee...@524] - Session:
0x1250c170b950000 closed
   [junit] 2009-11-19 10:57:40,088 - INFO  [main:clientb...@399] -
tearDown starting
   [junit] 2009-11-19 10:57:40,088 - INFO  [main:clientb...@411] - fdcount
after test is: 40
   [junit] 2009-11-19 10:57:40,088 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:40,088 - INFO
 [NIOServerCxn.Factory:11226:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:40,089 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:40,089 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] 2009-11-19 10:57:40,089 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:40,092 - INFO  [main:clientb...@430] -
FINISHED testWatcherAutoResetDisabledWithLocal
   [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 30.092 sec
   [junit] 2009-11-19 10:57:40,764 - INFO  [main:portassignm...@31] -
assigning port 11221
   [junit] Running org.apache.zookeeper.test.ZooKeeperQuotaTest
   [junit] 2009-11-19 10:57:40,815 - INFO  [main:clientb...@340] -
STARTING testQuota
   [junit] 2009-11-19 10:57:40,994 - INFO  [main:clientb...@369] -
STARTING server
   [junit] 2009-11-19 10:57:41,006 - INFO  [main:environm...@97] - Server
environment:zookeeper.version=3.3.0-882095, built on 11/19/2009 10:46 GMT
   [junit] 2009-11-19 10:57:41,006 - INFO  [main:environm...@97] - Server
environment:host.name=h8.grid.sp2.yahoo.net
   [junit] 2009-11-19 10:57:41,007 - INFO  [main:environm...@97] - Server
environment:java.version=1.6.0_11
   [junit] 2009-11-19 10:57:41,007 - INFO  [main:environm...@97] - Server
environment:java.vendor=Sun Microsystems Inc.
   [junit] 2009-11-19 10:57:41,008 - INFO  [main:environm...@97] - Server
environment:java.home=/homes/hudson/tools/java/jdk1.6.0_11-32/jre
   [junit] 2009-11-19 10:57:41,009 - INFO  [main:environm...@97] - Server
environment:java.class.path=<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/classes
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/antlr-2.7.6.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/checkstyle-5.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-beanutils-core-1.7.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-cli-1.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-collections-2.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-lang-1.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-logging-1.0.3.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/google-collections-0.9.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/junit-4.7.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/classes
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/src/java/lib/ivy-2.1.0-rc2.jar
:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant.jar:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/lib/jline-0.9.94.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/lib/log4j-1.2.15.jar
:/homes/hudson/tools/clover/latest/lib/clover.jar:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant-launcher.jar:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant-junit.jar
   [junit] 2009-11-19 10:57:41,009 - INFO  [main:environm...@97] - Server
environment:java.library.path=/homes/hudson/tools/java/jdk1.6.0_11-32/jre/lib/i386/server:/homes/hudson/tools/java/jdk1.6.0_11-32/jre/lib/i386:/homes/hudson/tools/java/jdk1.6.0_11-32/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
   [junit] 2009-11-19 10:57:41,010 - INFO  [main:environm...@97] - Server
environment:java.io.tmpdir=/tmp
   [junit] 2009-11-19 10:57:41,010 - INFO  [main:environm...@97] - Server
environment:java.compiler=<NA>
   [junit] 2009-11-19 10:57:41,011 - INFO  [main:environm...@97] - Server
environment:os.name=Linux
   [junit] 2009-11-19 10:57:41,012 - INFO  [main:environm...@97] - Server
environment:os.arch=i386
   [junit] 2009-11-19 10:57:41,012 - INFO  [main:environm...@97] - Server
environment:os.version=2.6.28-15-generic
   [junit] 2009-11-19 10:57:41,013 - INFO  [main:environm...@97] - Server
environment:user.name=hudson
   [junit] 2009-11-19 10:57:41,013 - INFO  [main:environm...@97] - Server
environment:user.home=/homes/hudson
   [junit] 2009-11-19 10:57:41,014 - INFO  [main:environm...@97] - Server
environment:user.dir=<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk>
   [junit] 2009-11-19 10:57:41,022 - INFO  [main:zookeeperser...@160] -
Created server
   [junit] 2009-11-19 10:57:41,041 - INFO  [main:nioservercnxn$fact...@123]
- binding to port 11221
   [junit] 2009-11-19 10:57:41,064 - INFO  [main:filetxnsnap...@208] -
Snapshotting: 0
   [junit] 2009-11-19 10:57:41,099 - INFO
 [NIOServerCxn.Factory:11221:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:47387
   [junit] 2009-11-19 10:57:41,102 - INFO
 [NIOServerCxn.Factory:11221:nioserverc...@782] - Processing stat command
from /127.0.0.1:47387
   [junit] 2009-11-19 10:57:41,104 - INFO
 [NIOServerCxn.Factory:11221:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:47387 (no session established for client)
   [junit] ensureOnly:[InMemoryDataTree, StandaloneServer_port]
   [junit] expect:InMemoryDataTree
   [junit] found:InMemoryDataTree
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
   [junit] expect:StandaloneServer_port
   [junit] found:StandaloneServer_port
org.apache.ZooKeeperService:name0=StandaloneServer_port-1
   [junit] 2009-11-19 10:57:41,110 - INFO  [main:clientb...@361] - Initial
fdcount is: 32
   [junit] 2009-11-19 10:57:41,110 - INFO  [main:clientb...@365] - Client
test setup finished
   [junit] 2009-11-19 10:57:41,117 - INFO  [main:environm...@97] - Client
environment:zookeeper.version=3.3.0-882095, built on 11/19/2009 10:46 GMT
   [junit] 2009-11-19 10:57:41,118 - INFO  [main:environm...@97] - Client
environment:host.name=h8.grid.sp2.yahoo.net
   [junit] 2009-11-19 10:57:41,118 - INFO  [main:environm...@97] - Client
environment:java.version=1.6.0_11
   [junit] 2009-11-19 10:57:41,118 - INFO  [main:environm...@97] - Client
environment:java.vendor=Sun Microsystems Inc.
   [junit] 2009-11-19 10:57:41,119 - INFO  [main:environm...@97] - Client
environment:java.home=/homes/hudson/tools/java/jdk1.6.0_11-32/jre
   [junit] 2009-11-19 10:57:41,119 - INFO  [main:environm...@97] - Client
environment:java.class.path=<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/classes
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/antlr-2.7.6.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/checkstyle-5.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-beanutils-core-1.7.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-cli-1.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-collections-2.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-lang-1.0.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/commons-logging-1.0.3.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/google-collections-0.9.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/test/lib/junit-4.7.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/classes
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/src/java/lib/ivy-2.1.0-rc2.jar
:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant.jar:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/lib/jline-0.9.94.jar
:<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build/lib/log4j-1.2.15.jar
:/homes/hudson/tools/clover/latest/lib/clover.jar:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant-launcher.jar:/homes/hudson/tools/ant/apache-ant-1.7.0/lib/ant-junit.jar
   [junit] 2009-11-19 10:57:41,120 - INFO  [main:environm...@97] - Client
environment:java.library.path=/homes/hudson/tools/java/jdk1.6.0_11-32/jre/lib/i386/server:/homes/hudson/tools/java/jdk1.6.0_11-32/jre/lib/i386:/homes/hudson/tools/java/jdk1.6.0_11-32/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
   [junit] 2009-11-19 10:57:41,120 - INFO  [main:environm...@97] - Client
environment:java.io.tmpdir=/tmp
   [junit] 2009-11-19 10:57:41,121 - INFO  [main:environm...@97] - Client
environment:java.compiler=<NA>
   [junit] 2009-11-19 10:57:41,121 - INFO  [main:environm...@97] - Client
environment:os.name=Linux
   [junit] 2009-11-19 10:57:41,122 - INFO  [main:environm...@97] - Client
environment:os.arch=i386
   [junit] 2009-11-19 10:57:41,122 - INFO  [main:environm...@97] - Client
environment:os.version=2.6.28-15-generic
   [junit] 2009-11-19 10:57:41,123 - INFO  [main:environm...@97] - Client
environment:user.name=hudson
   [junit] 2009-11-19 10:57:41,123 - INFO  [main:environm...@97] - Client
environment:user.home=/homes/hudson
   [junit] 2009-11-19 10:57:41,124 - INFO  [main:environm...@97] - Client
environment:user.dir=<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk>
   [junit] 2009-11-19 10:57:41,125 - INFO  [main:zookee...@372] -
Initiating client connection, connectString=127.0.0.1:11221sessionTimeout=30000
watcher=org.apache.zookeeper.test.clientbase$countdownwatc...@f01771
   [junit] 2009-11-19 10:57:41,141 - INFO
 [main-SendThread():clientcnxn$sendthr...@929] - Opening socket connection
to server /127.0.0.1:11221
   [junit] 2009-11-19 10:57:41,142 - INFO
 [NIOServerCxn.Factory:11221:nioservercnxn$fact...@214] - Accepted socket
connection from /127.0.0.1:47388
   [junit] 2009-11-19 10:57:41,142 - INFO
 [main-SendThread(localhost:11221):clientcnxn$sendthr...@837] - Socket
connection established to localhost/127.0.0.1:11221, initiating session
   [junit] 2009-11-19 10:57:41,146 - INFO
 [NIOServerCxn.Factory:11221:nioserverc...@695] - Client attempting to
establish new session at /127.0.0.1:47388
   [junit] 2009-11-19 10:57:41,172 - INFO  [SyncThread:0:nioserverc...@1131]
- Established session 0x1250c1724d10000 for client /127.0.0.1:47388
   [junit] 2009-11-19 10:57:41,173 - INFO
 [main-SendThread(localhost:11221):clientcnxn$sendthr...@640] - Session
establishment complete, sessionid = 0x1250c1724d10000
   [junit] expect:0x1250c1724d10000
   [junit] found:0x1250c1724d10000
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=Connections,name2=127.0.0.1,name3=0x1250c1724d10000
   [junit] 2009-11-19 10:57:41,233 - INFO  [main:clientb...@399] -
tearDown starting
   [junit] 2009-11-19 10:57:41,233 - INFO  [main:clientb...@411] - fdcount
after test is: 38
   [junit] 2009-11-19 10:57:41,234 - INFO
 [ProcessThread:-1:preprequestproces...@385] - Processed session
termination for sessionid: 0x1250c1724d10000
   [junit] 2009-11-19 10:57:41,235 - INFO  [main:zookee...@524] - Session:
0x1250c1724d10000 closed
   [junit] 2009-11-19 10:57:41,235 - INFO  [main:clientb...@376] -
STOPPING server
   [junit] 2009-11-19 10:57:41,235 - INFO
 [NIOServerCxn.Factory:11221:nioserverc...@974] - Closed socket connection
for client /127.0.0.1:47388 which had sessionid 0x1250c1724d10000
   [junit] 2009-11-19 10:57:41,236 - INFO
 [NIOServerCxn.Factory:11221:nioservercnxn$fact...@241] - NIOServerCnxn
factory exited run method
   [junit] 2009-11-19 10:57:41,236 - INFO  [main:finalrequestproces...@365]
- shutdown of request processor complete
   [junit] 2009-11-19 10:57:41,236 - INFO
 [SyncThread:0:syncrequestproces...@151] - SyncRequestProcessor exited!
   [junit] 2009-11-19 10:57:41,236 - INFO
 [ProcessThread:-1:preprequestproces...@119] - PrepRequestProcessor exited
loop!
   [junit] ensureOnly:[]
   [junit] 2009-11-19 10:57:41,240 - INFO  [main:clientb...@430] -
FINISHED testQuota
   [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.473 sec

BUILD FAILED
<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build.xml>:866:
The following error occurred while executing this line:
<
http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/ws/trunk/build.xml>:777:
Tests failed!

Total time: 10 minutes 53 seconds
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure



Reply via email to