Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id DC402200C32 for ; Thu, 9 Mar 2017 22:46:43 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id DAC7A160B75; Thu, 9 Mar 2017 21:46:43 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id D7088160B5F for ; Thu, 9 Mar 2017 22:46:42 +0100 (CET) Received: (qmail 87922 invoked by uid 500); 9 Mar 2017 21:46:42 -0000 Mailing-List: contact dev-help@zookeeper.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@zookeeper.apache.org Delivered-To: mailing list dev@zookeeper.apache.org Received: (qmail 87911 invoked by uid 99); 9 Mar 2017 21:46:41 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd4-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 09 Mar 2017 21:46:41 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd4-us-west.apache.org (ASF Mail Server at spamd4-us-west.apache.org) with ESMTP id 7A9E1C5B84 for ; Thu, 9 Mar 2017 21:46:41 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 0.651 X-Spam-Level: X-Spam-Status: No, score=0.651 tagged_above=-999 required=6.31 tests=[RP_MATCHES_RCVD=-0.001, SPF_NEUTRAL=0.652] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd4-us-west.apache.org [10.40.0.11]) (amavisd-new, port 10024) with ESMTP id 1mn-_tDbKv8G for ; Thu, 9 Mar 2017 21:46:39 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id C64925F1EE for ; Thu, 9 Mar 2017 21:46:38 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 33976E0156 for ; Thu, 9 Mar 2017 21:46:38 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id E0E1A24369 for ; Thu, 9 Mar 2017 21:46:37 +0000 (UTC) Date: Thu, 9 Mar 2017 21:46:37 +0000 (UTC) From: "Michael Han (JIRA)" To: dev@zookeeper.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (ZOOKEEPER-2716) Flaky Test: org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSessionExpiry MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 09 Mar 2017 21:46:44 -0000 Michael Han created ZOOKEEPER-2716: -------------------------------------- Summary: Flaky Test: org.apache.zookeeper.server.SessionTracke= rTest.testAddSessionAfterSessionExpiry Key: ZOOKEEPER-2716 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2716 Project: ZooKeeper Issue Type: Test Components: server, tests Affects Versions: 3.5.2, 3.4.9 Reporter: Michael Han Assignee: Michael Han 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> =09at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSes= sionExpiry(SessionTrackerTest.java:82) =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(J= Unit4ZKTestRunner.java:79) =09at java.util.concurrent.FutureTask.run(FutureTask.java:266) =09at java.lang.Thread.run(Thread.java:745) Standard Output 2017-03-04 19:25:16,141 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No t= est.method specified. using default methods. 2017-03-04 19:25:16,358 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No t= est.method specified. using default methods. 2017-03-04 19:25:16,419 [myid:] - INFO [main:ZKTestCase$1@58] - STARTING t= estAddSessionAfterSessionExpiry 2017-03-04 19:25:16,430 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunn= er$LoggedInvokeMethod@77] - RUNNING TEST METHOD testAddSessionAfterSessionE= xpiry 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:zookeeper.version=3D3.5.3-alpha-SNAPSHOT-6d9fc04c052a= dbc79bbbb1c63f3f00c816fb8e56, 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=3Djenkins-ubuntu3.apache.org 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:java.version=3D1.8.0_121 2017-03-04 19:25:16,581 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:java.vendor=3DOracle Corporation 2017-03-04 19:25:16,582 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:java.home=3D/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=3D/home/jenkins/jenkins-slave/workspa= ce/ZooKeeper_branch35_jdk8/build/test/classes:/home/jenkins/jenkins-slave/w= orkspace/ZooKeeper_branch35_jdk8/build/test/lib/antlr-2.7.7.jar:/home/jenki= ns/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/antlr4-ru= ntime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_= jdk8/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspa= ce/ZooKeeper_branch35_jdk8/build/test/lib/commons-beanutils-1.9.2.jar:/home= /jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/com= mons-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-sl= ave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/commons-lang3-3.4.jar:= /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/li= b/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/wo= rkspace/ZooKeeper_branch35_jdk8/build/test/lib/hamcrest-core-1.3.jar:/home/= jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/lib/juni= t-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/bu= ild/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/Zo= oKeeper_branch35_jdk8/build/classes:/home/jenkins/jenkins-slave/workspace/Z= ooKeeper_branch35_jdk8/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/l= atest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_= jdk8/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/Zo= oKeeper_branch35_jdk8/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/j= enkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jackson-mapper-asl= -1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/b= uild/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch3= 5_jdk8/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/wo= rkspace/ZooKeeper_branch35_jdk8/build/lib/jetty-http-9.2.18.v20160721.jar:/= home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jett= y-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_b= ranch35_jdk8/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/je= nkins-slave/workspace/ZooKeeper_branch35_jdk8/build/lib/jetty-server-9.2.18= .v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk= 8/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/jl= ine-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/jenki= ns/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/l= atest/lib/ant-junit4.jar 2017-03-04 19:25:16,588 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:java.library.path=3D/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=3D/tmp 2017-03-04 19:25:16,589 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:java.compiler=3D 2017-03-04 19:25:16,590 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.name=3DLinux 2017-03-04 19:25:16,590 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.arch=3Damd64 2017-03-04 19:25:16,592 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.version=3D4.4.0-31-generic 2017-03-04 19:25:16,603 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:user.name=3Djenkins 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:user.home=3D/home/jenkins 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:user.dir=3D/home/jenkins/jenkins-slave/workspace/ZooK= eeper_branch35_jdk8/build/test 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.memory.free=3D347MB 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.memory.max=3D455MB 2017-03-04 19:25:16,604 [myid:] - INFO [Time-limited test:Environment@109]= - Server environment:os.memory.total=3D362MB 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 maxSessionT= imeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch= 35_jdk8/build/test/tmp/test1620981504756158168.junit.dir/version-2 snapdir = /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tm= p/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:JUnit4ZKTestRunn= er$LoggedInvokeMethod@98] - TEST METHOD FAILED testAddSessionAfterSessionEx= piry java.lang.AssertionError: Duplicate session expiry request has been generat= ed expected:<1> but was:<0> =09at org.junit.Assert.fail(Assert.java:88) =09at org.junit.Assert.failNotEquals(Assert.java:834) =09at org.junit.Assert.assertEquals(Assert.java:645) =09at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSes= sionExpiry(SessionTrackerTest.java:82) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framework= Method.java:50) =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCal= lable.java:12) =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMe= thod.java:47) =09at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMet= hod.java:17) =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(J= Unit4ZKTestRunner.java:79) =09at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement= .call(FailOnTimeout.java:298) =09at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement= .call(FailOnTimeout.java:292) =09at java.util.concurrent.FutureTask.run(FutureTask.java:266) =09at java.lang.Thread.run(Thread.java:745) 2017-03-04 19:25:20,457 [myid:] - INFO [main:ZKTestCase$1@73] - FAILED tes= tAddSessionAfterSessionExpiry java.lang.AssertionError: Duplicate session expiry request has been generat= ed expected:<1> but was:<0> =09at org.junit.Assert.fail(Assert.java:88) =09at org.junit.Assert.failNotEquals(Assert.java:834) =09at org.junit.Assert.assertEquals(Assert.java:645) =09at org.apache.zookeeper.server.SessionTrackerTest.testAddSessionAfterSes= sionExpiry(SessionTrackerTest.java:82) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framework= Method.java:50) =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCal= lable.java:12) =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMe= thod.java:47) =09at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMet= hod.java:17) =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(J= Unit4ZKTestRunner.java:79) =09at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement= .call(FailOnTimeout.java:298) =09at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement= .call(FailOnTimeout.java:292) =09at java.util.concurrent.FutureTask.run(FutureTask.java:266) =09at java.lang.Thread.run(Thread.java:745) 2017-03-04 19:25:20,457 [myid:] - INFO [main:ZKTestCase$1@63] - FINISHED t= estAddSessionAfterSessionExpiry 2017-03-04 19:25:20,462 [myid:] - INFO [main:ZKTestCase$1@58] - STARTING t= estCloseSessionRequestAfterSessionExpiry 2017-03-04 19:25:20,475 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunn= er$LoggedInvokeMethod@77] - RUNNING TEST METHOD testCloseSessionRequestAfte= rSessionExpiry 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 maxSessionT= imeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch= 35_jdk8/build/test/tmp/test8565681305854282002.junit.dir/version-2 snapdir = /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch35_jdk8/build/test/tm= p/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:JUnit4ZKTestRunn= er$LoggedInvokeMethod@82] - Memory used 25301 2017-03-04 19:25:26,432 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunn= er$LoggedInvokeMethod@87] - Number of threads 11 2017-03-04 19:25:26,432 [myid:] - INFO [Time-limited test:JUnit4ZKTestRunn= er$LoggedInvokeMethod@102] - FINISHED TEST METHOD testCloseSessionRequestAf= terSessionExpiry 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 t= estCloseSessionRequestAfterSessionExpiry {noformat} -- This message was sent by Atlassian JIRA (v6.3.15#6346)