[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-2924?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16269299#comment-16269299
 ] 

ASF GitHub Bot commented on ZOOKEEPER-2924:
-------------------------------------------

Github user phunt commented on a diff in the pull request:

    https://github.com/apache/zookeeper/pull/420#discussion_r153591342
  
    --- Diff: src/java/test/org/apache/zookeeper/test/LoadFromLogTest.java ---
    @@ -18,77 +18,58 @@
     
     package org.apache.zookeeper.test;
     
    -import java.io.ByteArrayOutputStream;
     import java.io.File;
    -import java.io.FileInputStream;
     import java.io.IOException;
    -import java.nio.ByteBuffer;
    -import java.util.ArrayList;
    -import java.util.List;
    -
    -import org.apache.zookeeper.common.Time;
    -import org.apache.jute.BinaryInputArchive;
    -import org.apache.jute.BinaryOutputArchive;
    -import org.apache.jute.Record;
    +
     import org.apache.zookeeper.CreateMode;
     import org.apache.zookeeper.KeeperException.NoNodeException;
    -import org.apache.zookeeper.PortAssignment;
    -import org.apache.zookeeper.ZKTestCase;
     import org.apache.zookeeper.ZooDefs.Ids;
    -import org.apache.zookeeper.ZooDefs.OpCode;
     import org.apache.zookeeper.ZooKeeper;
     import org.apache.zookeeper.data.Stat;
    -import org.apache.zookeeper.server.DataNode;
    -import org.apache.zookeeper.server.DataTree;
     import org.apache.zookeeper.server.ServerCnxnFactory;
     import org.apache.zookeeper.server.SyncRequestProcessor;
     import org.apache.zookeeper.server.ZooKeeperServer;
    -import org.apache.zookeeper.server.persistence.FileHeader;
     import org.apache.zookeeper.server.persistence.FileTxnLog;
     import org.apache.zookeeper.server.persistence.FileTxnSnapLog;
     import org.apache.zookeeper.server.persistence.Util;
     import org.apache.zookeeper.server.persistence.FileTxnLog.FileTxnIterator;
     import org.apache.zookeeper.server.persistence.TxnLog.TxnIterator;
    -import org.apache.zookeeper.txn.CreateTxn;
    -import org.apache.zookeeper.txn.DeleteTxn;
    -import org.apache.zookeeper.txn.MultiTxn;
    -import org.apache.zookeeper.txn.Txn;
     import org.apache.zookeeper.txn.TxnHeader;
    +import org.eclipse.jetty.util.SocketAddressResolver;
    +import org.junit.After;
     import org.junit.Assert;
    +import org.junit.Before;
     import org.junit.Test;
     import org.slf4j.Logger;
     import org.slf4j.LoggerFactory;
     
    -public class LoadFromLogTest extends ZKTestCase {
    -    private static final String HOST = "127.0.0.1:";
    -    private static final int CONNECTION_TIMEOUT = 3000;
    +public class LoadFromLogTest extends ClientBase {
         private static final int NUM_MESSAGES = 300;
         protected static final Logger LOG = 
LoggerFactory.getLogger(LoadFromLogTest.class);
     
         // setting up the quorum has a transaction overhead for creating and 
closing the session
         private static final int TRANSACTION_OVERHEAD = 2;
         private static final int TOTAL_TRANSACTIONS = NUM_MESSAGES + 
TRANSACTION_OVERHEAD;
     
    +    @Before
    +    public void setUp() throws Exception {
    +        SyncRequestProcessor.setSnapCount(100);
    --- End diff --
    
    Unfortunately this is going to have the side-effect that all servers of all 
the tests in this class will be started with a snapCount of 100. Subsequently 
setting this value in the test itself will have no effect as the server has 
already been started (syncprocessor thread running). Unless the server is 
restarted of course.
    
    See comments below and please verify this finding yourself.
    
    I'm thinking that you might need to make this setup empty, and call setUp 
from the very beginning of the test after setting the count explicitly.


> 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)

Reply via email to