You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "ASF GitHub Bot (JIRA)" <ji...@apache.org> on 2017/12/01 23:42:00 UTC
[jira] [Commented] (ZOOKEEPER-2924) Flaky Test:
org.apache.zookeeper.test.LoadFromLogTest.testRestoreWithTransactionErrors
[ 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)