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/03/09 21:52:38 UTC
[jira] [Commented] (ZOOKEEPER-2716) Flaky Test:
org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry
[ https://issues.apache.org/jira/browse/ZOOKEEPER-2716?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15903908#comment-15903908 ]
ASF GitHub Bot commented on ZOOKEEPER-2716:
-------------------------------------------
GitHub user hanm opened a pull request:
https://github.com/apache/zookeeper/pull/187
ZOOKEEPER-2716: fix flaky test testAddSessionAfterSessionExpiry.
We can't let the gate open until we increase the closed session count. Otherwise depends on timing, the test thread might see old session close count value between gate open and the session count actually gets increased.
You can merge this pull request into a Git repository by running:
$ git pull https://github.com/hanm/zookeeper ZOOKEEPER-2716
Alternatively you can review and apply these changes as the patch at:
https://github.com/apache/zookeeper/pull/187.patch
To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:
This closes #187
----
commit f16fe3a98718f3eb45812bd53b9afee96c76a589
Author: Michael Han <ha...@apache.org>
Date: 2017-03-09T21:51:36Z
ZOOKEEPER-2716: fix flaky test testAddSessionAfterSessionExpiry.
We can't let the gate open until we increase the closed session count. Otherwise depends on timing, the test thread might see old session
close count value between gate open and the session count actually gets increased.
----
> Flaky Test: org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry
> -------------------------------------------------------------------------------------------
>
> Key: ZOOKEEPER-2716
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2716
> Project: ZooKeeper
> Issue Type: Test
> Components: server, tests
> Affects Versions: 3.4.9, 3.5.2
> Reporter: Michael Han
> Assignee: Michael Han
> Labels: flaky, flaky-build, flaky-test
> Fix For: 3.5.3, 3.6.0
>
>
> This test fail once in a while because the test logic has time assumptions that should be fixed. PR in a minute. Sample log when it fails:
> {noformat}
> Error Message
> Duplicate session expiry request has been generated expected:<1> but was:<0>
> Stacktrace
> junit.framework.AssertionFailedError: Duplicate session expiry request has been generated expected:<1> but was:<0>
> at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry(SessionTrackerTest.java:82)
> at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.lang.Thread.run(Thread.java:745)
> Standard Output
> 2017-03-04 19:25:16,141 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods.
> 2017-03-04 19:25:16,358 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods.
> 2017-03-04 19:25:16,419 [myid:] - INFO [main:ZKTestCase$1@58] - STARTING testAddSessionAfterSessionExpiry
> 2017-03-04 19:25:16,430 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testAddSessionAfterSessionExpiry
> 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:zookeeper.version=3.5.3-alpha-SNAPSHOT-6d9fc04c052adbc79bbbb1c63f3f00c816fb8e56, built on 03/04/2017 19:24 GMT
> 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:host.name=jenkins-ubuntu3.apache.org
> 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.version=1.8.0_121
> 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.vendor=Oracle Corporation
> 2017-03-04 19:25:16,582 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.home=/usr/local/asfpackages/java/jdk1.8.0_121/jre
> 2017-03-04 19:25:16,587 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-http-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-util-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/slf4j-log4j12-1.7.5.jar:/usr/local/asfpackages/ant/apache-ant-1.10.1/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar
> 2017-03-04 19:25:16,588 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2017-03-04 19:25:16,588 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.io.tmpdir=/tmp
> 2017-03-04 19:25:16,589 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:java.compiler=<NA>
> 2017-03-04 19:25:16,590 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.name=Linux
> 2017-03-04 19:25:16,590 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.arch=amd64
> 2017-03-04 19:25:16,592 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.version=4.4.0-31-generic
> 2017-03-04 19:25:16,603 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:user.name=jenkins
> 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:user.home=/home/jenkins
> 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test
> 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.memory.free=347MB
> 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.memory.max=455MB
> 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109] - Server environment:os.memory.total=362MB
> 2017-03-04 19:25:16,624 [myid:] - INFO [Time-limited test:ZooKeeperServer@907] - minSessionTimeout set to 6000
> 2017-03-04 19:25:16,624 [myid:] - INFO [Time-limited test:ZooKeeperServer@916] - maxSessionTimeout set to 60000
> 2017-03-04 19:25:16,625 [myid:] - INFO [Time-limited test:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tmp/test1620981504756158168.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tmp/test1620981504756158168.junit.dir/version-2
> 2017-03-04 19:25:20,434 [myid:] - INFO [SessionTracker:ZooKeeperServer@391] - Expiring session 0x52fbc, timeout of 3000ms exceeded
> 2017-03-04 19:25:20,450 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@98] - TEST METHOD FAILED testAddSessionAfterSessionExpiry
> java.lang.AssertionError: Duplicate session expiry request has been generated expected:<1> but was:<0>
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.failNotEquals(Assert.java:834)
> at org.junit.Assert.assertEquals(Assert.java:645)
> at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry(SessionTrackerTest.java:82)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
> at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.lang.Thread.run(Thread.java:745)
> 2017-03-04 19:25:20,457 [myid:] - INFO [main:ZKTestCase$1@73] - FAILED testAddSessionAfterSessionExpiry
> java.lang.AssertionError: Duplicate session expiry request has been generated expected:<1> but was:<0>
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.failNotEquals(Assert.java:834)
> at org.junit.Assert.assertEquals(Assert.java:645)
> at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry(SessionTrackerTest.java:82)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
> at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.lang.Thread.run(Thread.java:745)
> 2017-03-04 19:25:20,457 [myid:] - INFO [main:ZKTestCase$1@63] - FINISHED testAddSessionAfterSessionExpiry
> 2017-03-04 19:25:20,462 [myid:] - INFO [main:ZKTestCase$1@58] - STARTING testCloseSessionRequestAfterSessionExpiry
> 2017-03-04 19:25:20,475 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testCloseSessionRequestAfterSessionExpiry
> 2017-03-04 19:25:20,476 [myid:] - INFO [Time-limited test:ZooKeeperServer@907] - minSessionTimeout set to 6000
> 2017-03-04 19:25:20,476 [myid:] - INFO [Time-limited test:ZooKeeperServer@916] - maxSessionTimeout set to 60000
> 2017-03-04 19:25:20,476 [myid:] - INFO [Time-limited test:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tmp/test8565681305854282002.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tmp/test8565681305854282002.junit.dir/version-2
> 2017-03-04 19:25:26,431 [myid:] - INFO [SessionTracker:ZooKeeperServer@391] - Expiring session 0x52fbc, timeout of 3000ms exceeded
> 2017-03-04 19:25:26,431 [myid:] - INFO [SessionTracker:ZooKeeperServer@391] - Expiring session 0x52fbc, timeout of 3000ms exceeded
> 2017-03-04 19:25:26,432 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 25301
> 2017-03-04 19:25:26,432 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 11
> 2017-03-04 19:25:26,432 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testCloseSessionRequestAfterSessionExpiry
> 2017-03-04 19:25:26,432 [myid:] - INFO [main:ZKTestCase$1@68] - SUCCEEDED testCloseSessionRequestAfterSessionExpiry
> 2017-03-04 19:25:26,432 [myid:] - INFO [main:ZKTestCase$1@63] - FINISHED testCloseSessionRequestAfterSessionExpiry
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)