[
https://issues.apache.org/jira/browse/ZOOKEEPER-2924?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16275195#comment-16275195
]
ASF GitHub Bot commented on ZOOKEEPER-2924:
-------------------------------------------
Github user phunt commented on the issue:
https://github.com/apache/zookeeper/pull/420
> I don't think most of these tests make any assertions that could be
impacted by the snapCount.
This is an ambiguous statement to me. You do see that some of the tests are
impacted though, right?
e.g.:
// Verify that we have at least NUM_MESSAGES / SNAPCOUNT txnlog
etc....
I am I missing something? In testLoadFailure we need at least two log files
or otw the test will fail. Not setting the snapcount appropriately (small
relative to num messages) would be an issue, no?
> 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
> Labels: flaky, flaky-test
> 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
> Test where original issue happens:
> {noformat}
> ...
> [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)
> {noformat}
> Test #2 where port is already in use:
> {noformat}
> [junit] 2017-10-12 15:05:33,899 [myid:] - INFO [main:ZKTestCase$1@59] -
> STARTING testReloadSnapshotWithMissingParent
> [junit] 2017-10-12 15:05:33,899 [myid:] - INFO
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD
> testReloadSnapshotWithMissingParent
> [junit] 2017-10-12 15:05:33,900 [myid:] - INFO
> [main:ZooKeeperServer@173] - Created server with tickTime 3000
> minSessionTimeout 6000 maxSessionTimeout 60000 datadir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_openjdk7/$
> [junit] 2017-10-12 15:05:33,900 [myid:] - INFO
> [main:ServerCnxnFactory@117] - Using
> org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory
> [junit] 2017-10-12 15:05:33,900 [myid:] - INFO
> [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11221
> [junit] 2017-10-12 15:05:33,901 [myid:] - INFO
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@74] - TEST METHOD FAILED
> testReloadSnapshotWithMissingParent
> [junit] java.net.BindException: Address already in use
> [junit] at sun.nio.ch.Net.bind0(Native Method)
> [junit] at sun.nio.ch.Net.bind(Net.java:463)
> [junit] at sun.nio.ch.Net.bind(Net.java:455)
> [junit] at
> sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
> [junit] at
> sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
> [junit] at
> sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:67)
> [junit] at
> org.apache.zookeeper.server.NIOServerCnxnFactory.configure(NIOServerCnxnFactory.java:90)
> [junit] at
> org.apache.zookeeper.server.ServerCnxnFactory.createFactory(ServerCnxnFactory.java:137)
> [junit] at
> org.apache.zookeeper.server.ServerCnxnFactory.createFactory(ServerCnxnFactory.java:130)
> [junit] at
> org.apache.zookeeper.test.LoadFromLogTest.testReloadSnapshotWithMissingParent(LoadFromLogTest.java:412)
> [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)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
