zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "ASF GitHub Bot (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (ZOOKEEPER-2716) Flaky Test: org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry
Date Thu, 09 Mar 2017 21:52:38 GMT

    [ 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 <hanm@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)

Mime
View raw message