See https://builds.apache.org/job/ZooKeeper-trunk-solaris/1345/
###################################################################################
########################## LAST 60 LINES OF THE CONSOLE
###########################
[...truncated 423486 lines...]
[junit] 2016-10-12 08:36:03,987 [myid:2] - INFO
[LearnerHandler-/127.0.0.1:36213:LearnerHandler@683] - Synchronizing with
Follower sid: 0 maxCommittedLog=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0
peerLastZxid=0x0
[junit] 2016-10-12 08:36:03,987 [myid:2] - INFO
[LearnerHandler-/127.0.0.1:36213:LearnerHandler@727] - Sending DIFF zxid=0x0
for peer sid: 0
[junit] 2016-10-12 08:36:03,988 [myid:0] - INFO
[QuorumPeer[myid=0](plain=localhost/127.0.0.1:11222)(secure=0.0.0.0/0.0.0.0:11223):Learner@366]
- Getting a diff from the leader 0x0
[junit] 2016-10-12 08:36:03,996 [myid:1] - INFO
[QuorumPeer[myid=1](plain=localhost/127.0.0.1:11226)(secure=0.0.0.0/0.0.0.0:11227):Learner@366]
- Getting a diff from the leader 0x0
[junit] 2016-10-12 08:36:04,060 [myid:0] - INFO
[QuorumPeer[myid=0](plain=localhost/127.0.0.1:11222)(secure=0.0.0.0/0.0.0.0:11223):Learner@509]
- Learner received NEWLEADER message
[junit] 2016-10-12 08:36:04,064 [myid:1] - INFO
[QuorumPeer[myid=1](plain=localhost/127.0.0.1:11226)(secure=0.0.0.0/0.0.0.0:11227):Learner@509]
- Learner received NEWLEADER message
[junit] 2016-10-12 08:36:04,066 [myid:0] - INFO
[QuorumPeer[myid=0](plain=localhost/127.0.0.1:11222)(secure=0.0.0.0/0.0.0.0:11223):FileTxnSnapLog@306]
- Snapshotting: 0x0 to
/zonestorage/hudson_solaris/home/hudson/hudson-slave/workspace/ZooKeeper-trunk-solaris/build/test/tmp/test8404542827607570036.junit.dir/data/version-2/snapshot.0
[junit] 2016-10-12 08:36:04,090 [myid:1] - INFO
[QuorumPeer[myid=1](plain=localhost/127.0.0.1:11226)(secure=0.0.0.0/0.0.0.0:11227):FileTxnSnapLog@306]
- Snapshotting: 0x0 to
/zonestorage/hudson_solaris/home/hudson/hudson-slave/workspace/ZooKeeper-trunk-solaris/build/test/tmp/test8057401874635179817.junit.dir/data/version-2/snapshot.0
[junit] 2016-10-12 08:36:04,111 [myid:2] - INFO
[QuorumPeer[myid=2](plain=localhost/127.0.0.1:11230)(secure=0.0.0.0/0.0.0.0:11231):Leader@1255]
- Have quorum of supporters, sids: [ [0, 2],[0, 2] ]; starting up and setting
last processed zxid: 0x100000000
[junit] 2016-10-12 08:36:06,511 [myid:127.0.0.1:11234] - WARN
[main-SendThread(127.0.0.1:11234):ClientCnxn$SendThread@1181] - Client session
timed out, have not heard from server in 3007ms for sessionid 0x0
[junit] 2016-10-12 08:36:06,511 [myid:127.0.0.1:11234] - INFO
[main-SendThread(127.0.0.1:11234):ClientCnxn$SendThread@1229] - Client session
timed out, have not heard from server in 3007ms for sessionid 0x0, closing
socket connection and attempting reconnect
[junit] 2016-10-12 08:36:06,564 [myid:] - INFO [New I/O worker
#4:ClientCnxnSocketNetty$ZKClientHandler@384] - channel is disconnected: [id:
0x8d571a1c, /127.0.0.1:36215 :> 127.0.0.1/127.0.0.1:11234]
[junit] 2016-10-12 08:36:06,565 [myid:] - INFO [New I/O worker
#4:ClientCnxnSocketNetty@208] - channel is told closing
[junit] 2016-10-12 08:36:06,664 [myid:2] - INFO
[QuorumPeer[myid=2](plain=localhost/127.0.0.1:11230)(secure=0.0.0.0/0.0.0.0:11231):CommitProcessor@319]
- Configuring CommitProcessor with 8 worker threads.
[junit] 2016-10-12 08:36:06,786 [myid:2] - INFO
[QuorumPeer[myid=2](plain=localhost/127.0.0.1:11230)(secure=0.0.0.0/0.0.0.0:11231):ContainerManager@64]
- Using checkIntervalMs=60000 maxPerMinute=10000
[junit] 2016-10-12 08:36:06,787 [myid:1] - INFO
[QuorumPeer[myid=1](plain=localhost/127.0.0.1:11226)(secure=0.0.0.0/0.0.0.0:11227):Learner@493]
- Learner received UPTODATE message
[junit] 2016-10-12 08:36:06,787 [myid:0] - INFO
[QuorumPeer[myid=0](plain=localhost/127.0.0.1:11222)(secure=0.0.0.0/0.0.0.0:11223):Learner@493]
- Learner received UPTODATE message
[junit] 2016-10-12 08:36:06,899 [myid:1] - INFO
[QuorumPeer[myid=1](plain=localhost/127.0.0.1:11226)(secure=0.0.0.0/0.0.0.0:11227):CommitProcessor@319]
- Configuring CommitProcessor with 8 worker threads.
[junit] 2016-10-12 08:36:06,901 [myid:0] - INFO
[QuorumPeer[myid=0](plain=localhost/127.0.0.1:11222)(secure=0.0.0.0/0.0.0.0:11223):CommitProcessor@319]
- Configuring CommitProcessor with 8 worker threads.
[junit] 2016-10-12 08:36:07,016 [myid:-1] - INFO [New I/O worker
#69:X509AuthenticationProvider@157] - Authenticated Id
'CN=localhost,OU=ZooKeeper,O=Apache,L=Unknown,ST=Unknown,C=Unknown' for Scheme
'x509'
[junit] 2016-10-12 08:36:08,701 [myid:127.0.0.1:11234] - INFO
[main-SendThread(127.0.0.1:11234):ClientCnxn$SendThread@1113] - Opening socket
connection to server 127.0.0.1/127.0.0.1:11234. Will not attempt to
authenticate using SASL (unknown error)
[junit] 2016-10-12 08:36:09,594 [myid:127.0.0.1:11234] - INFO
[main-SendThread(127.0.0.1:11234):ClientCnxnSocketNetty$ZKClientPipelineFactory@370]
- SSL handler added for channel: null
[junit] 2016-10-12 08:36:09,596 [myid:] - INFO [New I/O worker
#8:ClientCnxn$SendThread@948] - Socket connection established, initiating
session, client: /127.0.0.1:36216, server: 127.0.0.1/127.0.0.1:11234
[junit] 2016-10-12 08:36:09,597 [myid:] - INFO [New I/O worker
#8:ClientCnxnSocketNetty$1@153] - channel is connected: [id: 0x5fd7df86,
/127.0.0.1:36216 => 127.0.0.1/127.0.0.1:11234]
[junit] 2016-10-12 08:36:09,604 [myid:-1] - INFO [New I/O server boss
#85:NettyServerCnxnFactory@384] - SSL handler added for channel: null
[junit] 2016-10-12 08:36:09,720 [myid:-1] - INFO [New I/O worker
#70:X509AuthenticationProvider@157] - Authenticated Id
'CN=localhost,OU=ZooKeeper,O=Apache,L=Unknown,ST=Unknown,C=Unknown' for Scheme
'x509'
[junit] 2016-10-12 08:36:09,784 [myid:-1] - INFO [New I/O worker
#69:ZooKeeperServer@995] - Client attempting to establish new session at
/127.0.0.1:36215
[junit] 2016-10-12 08:36:09,787 [myid:-1] - INFO [New I/O worker
#70:ZooKeeperServer@995] - Client attempting to establish new session at
/127.0.0.1:36216
[junit] 2016-10-12 08:36:09,906 [myid:-1] - INFO
[SyncThread:0:FileTxnLog@204] - Creating new log file: log.1
[junit] 2016-10-12 08:36:11,907 [myid:-1] - INFO
[SyncThread:0:ZooKeeperServer@709] - Established session 0x124350393620000 with
negotiated timeout 8000 for client /127.0.0.1:36215
[junit] 2016-10-12 08:36:11,949 [myid:-1] - INFO
[SyncThread:0:ZooKeeperServer@709] - Established session 0x124350393620001 with
negotiated timeout 8000 for client /127.0.0.1:36216
[junit] 2016-10-12 08:36:11,950 [myid:] - INFO [New I/O worker
#8:ClientCnxn$SendThread@1381] - Session establishment complete on server
127.0.0.1/127.0.0.1:11234, sessionid = 0x124350393620001, negotiated timeout =
8000
[junit] 2016-10-12 08:36:14,480 [myid:-1] - INFO [ProcessThread(sid:0
cport:-1)::PrepRequestProcessor@605] - Processed session termination for
sessionid: 0x124350393620001
[junit] 2016-10-12 08:36:14,500 [myid:] - INFO
[main:ClientCnxnSocketNetty@208] - channel is told closing
[junit] 2016-10-12 08:36:14,501 [myid:-1] - INFO
[SyncThread:0:MBeanRegistry@128] - Unregister MBean
[org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=Connections,name2=127.0.0.1,name3=0x124350393620001]
[junit] 2016-10-12 08:36:14,502 [myid:] - INFO
[main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for
session: 0x124350393620001
[junit] 2016-10-12 08:36:14,501 [myid:] - INFO [main:ZooKeeper@1315] -
Session: 0x124350393620001 closed
[junit] 2016-10-12 08:36:14,502 [myid:] - INFO [New I/O worker
#8:ClientCnxnSocketNetty$ZKClientHandler@384] - channel is disconnected: [id:
0x5fd7df86, /127.0.0.1:36216 :> 127.0.0.1/127.0.0.1:11234]
[junit] 2016-10-12 08:36:14,503 [myid:] - INFO [New I/O worker
#8:ClientCnxnSocketNetty@208] - channel is told closing
[junit] 2016-10-12 08:36:15,011 [myid:] - INFO
[main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 25352
[junit] 2016-10-12 08:36:15,011 [myid:] - INFO
[main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 171
[junit] 2016-10-12 08:36:15,011 [myid:] - INFO
[main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD
testSecureStandaloneServer
[junit] 2016-10-12 08:36:15,011 [myid:] - INFO [main:ZKTestCase$1@65] -
SUCCEEDED testSecureStandaloneServer
[junit] 2016-10-12 08:36:15,012 [myid:] - INFO [main:ZKTestCase$1@60] -
FINISHED testSecureStandaloneServer
[junit] Tests run: 2, Failures: 1, Errors: 0, Time elapsed: 38.018 sec
[junit] Test org.apache.zookeeper.test.SSLTest FAILED
[junit] Running org.apache.zookeeper.test.SaslAuthDesignatedClientTest
[junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 0 sec
BUILD FAILED
/zonestorage/hudson_solaris/home/hudson/hudson-slave/workspace/ZooKeeper-trunk-solaris/build.xml:1219:
Process fork failed.
Total time: 80 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
###################################################################################
############################## FAILED TESTS (if any)
##############################
5 tests failed.
FAILED: org.apache.zookeeper.test.ObserverTest.testObserver
Error Message:
waiting for server 1 being up
Stack Trace:
junit.framework.AssertionFailedError: waiting for server 1 being up
at
org.apache.zookeeper.test.ObserverTest.testObserver(ObserverTest.java:88)
at
org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
FAILED: org.apache.zookeeper.test.SSLTest.testSecureQuorumServer
Error Message:
waiting for server 0 being up
Stack Trace:
junit.framework.AssertionFailedError: waiting for server 0 being up
at
org.apache.zookeeper.test.SSLTest.testSecureQuorumServer(SSLTest.java:96)
at
org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
FAILED: org.apache.zookeeper.test.SaslAuthDesignatedClientTest.unknown
Error Message:
Forked Java VM exited abnormally. Please note the time in the report does not
reflect the time until the VM exit.
Stack Trace:
junit.framework.AssertionFailedError: Forked Java VM exited abnormally. Please
note the time in the report does not reflect the time until the VM exit.
FAILED:
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPortLeader
Error Message:
client could not connect to reestablished quorum: giving up after 30+ seconds.
Stack Trace:
junit.framework.AssertionFailedError: client could not connect to reestablished
quorum: giving up after 30+ seconds.
at
org.apache.zookeeper.test.ReconfigTest.testNormalOperation(ReconfigTest.java:173)
at
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPort(ReconfigTest.java:732)
at
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPortLeader(ReconfigTest.java:662)
at
org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
FAILED:
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPortFollower
Error Message:
client could not connect to reestablished quorum: giving up after 30+ seconds.
Stack Trace:
junit.framework.AssertionFailedError: client could not connect to reestablished
quorum: giving up after 30+ seconds.
at
org.apache.zookeeper.test.ReconfigTest.testNormalOperation(ReconfigTest.java:173)
at
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPort(ReconfigTest.java:732)
at
org.apache.zookeeper.test.ReconfigTest.testPortChangeToBlockedPortFollower(ReconfigTest.java:658)
at
org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
