Uploaded image for project: 'ZooKeeper'
  1. ZooKeeper
  2. ZOOKEEPER-2716

Flaky Test: org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry

    Details

      Description

      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:

      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
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                hanm Michael Han
                Reporter:
                hanm Michael Han
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: