zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Andor Molnar (JIRA)" <j...@apache.org>
Subject [jira] [Created] (ZOOKEEPER-2924) Flaky Test: org.apache.zookeeper.test.LoadFromLogTest.testRestoreWithTransactionErrors
Date Thu, 26 Oct 2017 14:32:00 GMT
Andor Molnar created ZOOKEEPER-2924:
---------------------------------------

             Summary: Flaky Test: org.apache.zookeeper.test.LoadFromLogTest.testRestoreWithTransactionErrors
                 Key: ZOOKEEPER-2924
                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2924
             Project: ZooKeeper
          Issue Type: Bug
          Components: server, tests
            Reporter: Andor Molnar
            Assignee: Andor Molnar
             Fix For: 3.4.12


>From https://builds.apache.org/job/ZooKeeper_branch34_openjdk7/1682/

Same issue happens in jdk8 and jdk9 builds as well.

Issue has already been fixed by https://issues.apache.org/jira/browse/ZOOKEEPER-2484 , but
I believe that the root cause here is that test startup / cleanup code is included in the
tests instead of using try-finally block or Before-After methods.

As a consequence, when exception happens during test execution, ZK test server doesn't get
shutdown properly and still listening on the port bound to the test class.

As mentioned above there could be 2 approaches to address this:
#1 Wrap cleanup code block with finally
#2 Use JUnit's Before-After methods for initialization and cleanup

{{  ...   
     [junit] 2017-10-12 15:05:20,135 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:create cxid:0x8c
zxid:0x8d txntype:-1 req$
     [junit] 2017-10-12 15:05:20,137 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:create cxid:0x8d
zxid:0x8e txntype:-1 req$
     [junit] 2017-10-12 15:05:20,139 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:create cxid:0x8e
zxid:0x8f txntype:-1 req$
     [junit] 2017-10-12 15:05:20,142 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:create cxid:0x8f
zxid:0x90 txntype:-1 req$
     [junit] 2017-10-12 15:05:20,144 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:create cxid:0x90
zxid:0x91 txntype:-1 req$
     [junit] 2017-10-12 15:05:30,479 [myid:] - INFO  [SessionTracker:ZooKeeperServer@354]
- Expiring session 0x104cd7b190c0000, timeout of 6000ms exceeded
     [junit] 2017-10-12 15:05:32,996 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@653]
- Got user-level KeeperException when processing sessionid:0x104cd7b190c0000 type:ping cxid:0xfffffffffffffffe
zxid:0xfffff$
     [junit] 2017-10-12 15:05:24,147 [myid:] - WARN  [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1111]
- Client session timed out, have not heard from server in 4002ms for sessionid 0x104cd7b190c0000
     [junit] 2017-10-12 15:05:32,996 [myid:] - INFO  [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1159]
- Client session timed out, have not heard from server in 4002ms for sessionid 0x104cd7b190c0000,
closing socket connectio$
     [junit] 2017-10-12 15:05:21,479 [myid:] - INFO  [SessionTracker:SessionTrackerImpl@163]
- SessionTrackerImpl exited loop!
     [junit] 2017-10-12 15:05:32,998 [myid:] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn@376]
- Unable to read additional data from client sessionid 0x104cd7b190c0000, likely client has
closed socket
     [junit] 2017-10-12 15:05:33,067 [myid:] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn@1040]
- Closed socket connection for client /127.0.0.1:45735 which had sessionid 0x104cd7b190c0000
     [junit] 2017-10-12 15:05:32,996 [myid:] - INFO  [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@487]
- Processed session termination for sessionid: 0x104cd7b190c0000
     [junit] 2017-10-12 15:05:33,889 [myid:] - INFO  [main:ZooKeeper@687] - Session: 0x104cd7b190c0000
closed
     [junit] 2017-10-12 15:05:33,890 [myid:] - INFO  [main-EventThread:ClientCnxn$EventThread@520]
- EventThread shut down for session: 0x104cd7b190c0000
     [junit] 2017-10-12 15:05:33,891 [myid:] - INFO  [main:JUnit4ZKTestRunner$LoggedInvokeMethod@74]
- TEST METHOD FAILED testRestoreWithTransactionErrors
     [junit] org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode
= ConnectionLoss for /invaliddir/test-
     [junit]     at org.apache.zookeeper.KeeperException.create(KeeperException.java:102)
     [junit]     at org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
     [junit]     at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:786)
     [junit]     at org.apache.zookeeper.test.LoadFromLogTest.testRestoreWithTransactionErrors(LoadFromLogTest.java:368)
     [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     [junit]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
     [junit]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
     [junit]     at java.lang.reflect.Method.invoke(Method.java:606)
     [junit]     at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
     [junit]     at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
     [junit]     at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
     [junit]     at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
     [junit]     at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55)
     [junit]     at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48)
     [junit]     at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
     [junit]     at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
     [junit]     at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
     [junit]     at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
     [junit]     at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
     [junit]     at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
     [junit]     at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
     [junit]     at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
     [junit]     at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
     [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
     [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
     [junit]     at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)}}



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message