0

I am trying to upgrad netty version 3.2.5 to 3.6.6. One of my tests fails with version 3.5.9 and works with 3.5.8. It’s the same test output is below. For some reason the response of the server is not received.

Message sending is triggered by the timeout of the idle handler. Server log (below) looks always the same. I can’t find any issue in github. Do I miss something? Thx! joël

ChannelPipelineFactory

public ChannelPipeline getPipeline() throws Exception {
            ChannelPipeline pipeline = Channels.pipeline();
            // logging handler
            pipeline.addLast("LOGGER", new LoggingHandler());
            // responsible for observing idle timeout - Netty
            pipeline.addLast("idleTimeout", new NettyIdleHandler(this.context, this.timer, 0, 0, this.context.getIdleTimeoutSeconds()));
            // responsible for reading until SCMP frame is complete
            pipeline.addLast("framer", new NettySCMPFrameDecoder());
            // executer to run NettyTcpRequesterResponseHandler in own thread
            pipeline.addLast("executor", new ExecutionHandler(AppContext.getSCWorkerThreadPool()));
            // responsible for handle response - Stabilit
            pipeline.addLast("requesterResponseHandler", new NettyTcpRequesterResponseHandler());
            return pipeline;
}

3.2.5.Final (currently used)

2013-06-27 15:13:27.908+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff] OPEN    
2013-06-27 15:13:27.918+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff] CONNECT: localhost/127.0.0.1:9000    
2013-06-27 15:13:27.968+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] BOUND: /127.0.0.1:1365    
2013-06-27 15:13:27.968+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] CONNECTED: localhost/127.0.0.1:9000    
2013-06-27 15:13:28.930+0200 [Hashed wheel timer #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22) - (HEXDUMP: 4b5251203030303030303020303030303020312e320a)    
2013-06-27 15:13:28.960+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] WRITTEN_AMOUNT: 22    
2013-06-27 15:13:28.970+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22) - (HEXDUMP: 4b5253203030303030303020303030303020312e320a)    
2013-06-27 15:13:29.380+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 => localhost/127.0.0.1:9000] DISCONNECT    
2013-06-27 15:13:29.380+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 :> localhost/127.0.0.1:9000] DISCONNECTED    
2013-06-27 15:13:29.380+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 :> localhost/127.0.0.1:9000] UNBOUND    
2013-06-27 15:13:29.380+0200 [New I/O client worker #1-1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 :> localhost/127.0.0.1:9000] CLOSED    
2013-06-27 15:13:29.390+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:39) - [id: 0x001cdeff, /127.0.0.1:1365 :> localhost/127.0.0.1:9000] CLOSE

3.5.8.Final (still working)

2013-06-27 15:02:38.388+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e] OPEN    
2013-06-27 15:02:38.388+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e] CONNECT: localhost/127.0.0.1:9000    
2013-06-27 15:02:38.418+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] BOUND: /127.0.0.1:1349    
2013-06-27 15:02:38.418+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] CONNECTED: localhost/127.0.0.1:9000    
2013-06-27 15:02:39.440+0200 [Hashed wheel timer #2] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 4b 52 51 20 30 30 30 30 30 30 30 20 30 30 30 30 |KRQ 0000000 0000|
|00000010| 30 20 31 2e 32 0a                               |0 1.2.          |
+--------+-------------------------------------------------+----------------+    
2013-06-27 15:02:39.440+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] WRITTEN_AMOUNT: 22    
2013-06-27 15:02:39.460+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 4b 52 53 20 30 30 30 30 30 30 30 20 30 30 30 30 |KRS 0000000 0000|
|00000010| 30 20 31 2e 32 0a                               |0 1.2.          |
+--------+-------------------------------------------------+----------------+    
2013-06-27 15:02:39.820+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 => localhost/127.0.0.1:9000] DISCONNECT    
2013-06-27 15:02:39.830+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 :> localhost/127.0.0.1:9000] DISCONNECTED    
2013-06-27 15:02:39.830+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 :> localhost/127.0.0.1:9000] UNBOUND    
2013-06-27 15:02:39.830+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 :> localhost/127.0.0.1:9000] CLOSED    
2013-06-27 15:02:39.830+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x33e9778e, /127.0.0.1:1349 :> localhost/127.0.0.1:9000] CLOSE

3.5.9.Final (test fails)

2013-06-27 15:17:00.984+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde] OPEN    
2013-06-27 15:17:00.995+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde] CONNECT: localhost/127.0.0.1:9000    
2013-06-27 15:17:01.015+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 => localhost/127.0.0.1:9000] BOUND: /127.0.0.1:4332    
2013-06-27 15:17:01.015+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 => localhost/127.0.0.1:9000] CONNECTED: localhost/127.0.0.1:9000    
2013-06-27 15:17:02.016+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 => localhost/127.0.0.1:9000] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 4b 52 51 20 30 30 30 30 30 30 30 20 30 30 30 30 |KRQ 0000000 0000|
|00000010| 30 20 31 2e 32 0a                               |0 1.2.          |
+--------+-------------------------------------------------+----------------+    
2013-06-27 15:17:02.016+0200 [New I/O  worker #1] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 => localhost/127.0.0.1:9000] WRITTEN_AMOUNT: 22

?????

2013-06-27 15:17:02.417+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 => localhost/127.0.0.1:9000] DISCONNECT    
2013-06-27 15:17:02.427+0200 [main] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0xacb50bde, /127.0.0.1:4332 :> localhost/127.0.0.1:9000] CLOSE

Server log (3.5.9.Final)

2013-06-27 15:17:01.005+0200 [New I/O server boss #2 ([id: 0x08e17840, /127.0.0.1:9000])] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] OPEN    
2013-06-27 15:17:01.005+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] BOUND: /127.0.0.1:9000    
2013-06-27 15:17:01.005+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] CONNECTED: /127.0.0.1:4332    
2013-06-27 15:17:02.026+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] RECEIVED: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 4b 52 51 20 30 30 30 30 30 30 30 20 30 30 30 30 |KRQ 0000000 0000|
|00000010| 30 20 31 2e 32 0a                               |0 1.2.          |
+--------+-------------------------------------------------+----------------+    
2013-06-27 15:17:02.036+0200 [SC_WORKER thread-3] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] WRITE: BigEndianHeapChannelBuffer(ridx=0, widx=22, cap=22)
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 4b 52 53 20 30 30 30 30 30 30 30 20 30 30 30 30 |KRS 0000000 0000|
|00000010| 30 20 31 2e 32 0a                               |0 1.2.          |
+--------+-------------------------------------------------+----------------+    
2013-06-27 15:17:02.036+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, /127.0.0.1:4332 => /127.0.0.1:9000] WRITTEN_AMOUNT: 22
2013-06-27 15:17:02.417+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, localhost/127.0.0.1:4332 :> /127.0.0.1:9000] DISCONNECTED
2013-06-27 15:17:02.417+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, localhost/127.0.0.1:4332 :> /127.0.0.1:9000] UNBOUND
2013-06-27 15:17:02.417+0200 [New I/O  worker #431] DEBUG (org.jboss.netty.handler.logging.LoggingHandler:33) - [id: 0x0a003af2, localhost/127.0.0.1:4332 :> /127.0.0.1:9000] CLOSED
4

1 回答 1

0

发现问题。阻塞线程是个坏主意：/。在新线程中运行空闲过程可以解决问题。猜猜它是因为 IdleStateEvent 现在由工作线程处理，因为它已在 3.5.9 中根据以下内容进行了更改： https ://github.com/netty/netty/issues/641 https://issues.jboss.org/browse /NETTY-362

为什么 idleStateEvent 没有移交给我自己在管道中指定为执行程序“ExecutionHandler”的工作线程之一？还是我的conf错了？谢谢！

于 2013-07-04T13:54:51.860 回答