Netty close the channel internally, I can't figure out why

fujohnwang(王福强) fujohnwang at gmail.com
Tue Nov 16 04:49:23 EST 2010 

hi,Trustin

I have tried to print the stack trace when the close is called or after the
close is called , but still I can't figure out why the channel is closed
normally, if the peer close the connection, in which way can I find it out? 

I have add a listener to the close future and override the channelClosed
method of the channel handler to print the stack trace, the printing is
listed below, but I can't find any useful information, do u have any other
ideas to find out why the channel is closed without explicitly calling?



16:56:51.432 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ChanelStateResetHelper - first startup for this
channel:EChannel-channel-/172.29.50.81:3311
16:56:51.441 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ErosaChannelRunnable - start working channel which is connected
to :qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311
16:56:51.443 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ErosaChannelRunnable - start standby channel which is connected
to:qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311
16:56:51.449 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ErosaChannelRunnable - start Failover monitor.
16:56:51.450 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ErosaChannelRunnable - failover monitor is started for current
channel with slaveId='11'
16:56:51.450 [EChannel-channel-/172.29.50.81:3311] INFO 
c.a.e.common.ErosaChannelRunnable - all of the necessary internal channels
are started.
16:56:51.503 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogFormatValidationRequestHandler - query command: show
variables like 'binlog_format' has been sent.
16:56:51.503 [Old I/O client worker ([id: 0x09931579, /172.29.9.106:54206 =>
qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311])] INFO 
c.a.e.i.m.n.h.BinlogFormatValidationRequestHandler - query command: show
variables like 'binlog_format' has been sent.
16:56:51.510 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogFormatValidationResultAndWaitTimeoutSetRequestHandler -
try to set session wait_timeout to a max large value, say 9999999
16:56:51.510 [Old I/O client worker ([id: 0x09931579, /172.29.9.106:54206 =>
qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311])] INFO 
c.a.e.i.m.n.h.BinlogFormatValidationResultOnlyHandler - expected 'row'
binlog format on master:[id: 0x09931579, /172.29.9.106:54206 =>
qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311]
16:56:51.511 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogFormatValidationResultAndWaitTimeoutSetRequestHandler -
set session wait_timeout request is sent out.
16:56:51.511 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogDumpRequestPacketHandler - send binlog dump command
packet.
16:56:51.512 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogDumpRequestPacketHandler - Send Binlog Dump
CommandPacket:BinlogDumpCommandPacket [command number=18,
binlogFileName=mysql-bin.000029, binlogPosition=125444810, slaveServerId=11]
16:56:51.512 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.BinlogDumpRequestPacketHandler - binlog dump command is sent
out.
16:56:51.528 [worker thread for loosely coupled stages] INFO 
c.a.e.i.m.b.h.i.MasterBinlogHandler - INFO ## switch to next log
file:mysql-bin.000029
16:56:51.528 [worker thread for loosely coupled stages] INFO 
c.a.e.i.m.b.h.i.MasterBinlogHandler - INFO ## now this erosa will not
extractor FormatDescriptionLogEvent
16:56:53.745 [worker thread for loosely coupled stages] INFO 
c.a.e.c.i.FileStorageLogPositionGetterAndPersister - create Archiver for
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311 - 11
16:56:56.588 [Old I/O client worker ([id: 0x09931579, /172.29.9.106:54206 =>
qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311])] INFO 
c.a.e.c.i.FileStorageLogPositionGetterAndPersister - create Archiver for
qd-cn-db1b.hst.qda.cn.alidc.net/172.29.50.82:3311 - 11
16:59:34.876 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.c.ErosaWorkingChannelRunnable - stack trace for
close:java.lang.Throwable
	at
com.alibaba.erosa.common.ErosaWorkingChannelRunnable$1.operationComplete(ErosaWorkingChannelRunnable.java:65)
	at
org.jboss.netty.channel.DefaultChannelFuture.notifyListener(DefaultChannelFuture.java:381)
	at
org.jboss.netty.channel.DefaultChannelFuture.notifyListeners(DefaultChannelFuture.java:372)
	at
org.jboss.netty.channel.DefaultChannelFuture.setSuccess(DefaultChannelFuture.java:316)
	at
org.jboss.netty.channel.AbstractChannel$ChannelCloseFuture.setClosed(AbstractChannel.java:359)
	at
org.jboss.netty.channel.AbstractChannel.setClosed(AbstractChannel.java:196)
	at
org.jboss.netty.channel.socket.oio.OioSocketChannel.setClosed(OioSocketChannel.java:107)
	at org.jboss.netty.channel.socket.oio.OioWorker.close(OioWorker.java:180)
	at org.jboss.netty.channel.socket.oio.OioWorker.run(OioWorker.java:100)
	at
org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
	at
org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:619)

16:59:34.877 [Old I/O client worker ([id: 0x737c2891, /172.29.9.106:41131 =>
qd-cn-db1a.hst.qda.cn.alidc.net/172.29.50.81:3311])] INFO 
c.a.e.i.m.n.h.ErosaMySQLBinlogPacketHandler - channel close call
stack:java.lang.Throwable
	at
com.alibaba.erosa.inbound.mysql.networking.handlers.ErosaMySQLBinlogPacketHandler.channelClosed(ErosaMySQLBinlogPacketHandler.java:34)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelHandler.channelClosed(SimpleChannelHandler.java:228)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.handler.timeout.IdleStateAwareChannelHandler.handleUpstream(IdleStateAwareChannelHandler.java:48)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.handler.timeout.IdleStateHandler.channelClosed(IdleStateHandler.java:269)
	at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:98)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelHandler.channelClosed(SimpleChannelHandler.java:228)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelHandler.channelClosed(SimpleChannelHandler.java:228)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelHandler.channelClosed(SimpleChannelHandler.java:228)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelHandler.channelClosed(SimpleChannelHandler.java:228)
	at
org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:118)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.channelClosed(SimpleChannelUpstreamHandler.java:208)
	at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:98)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:754)
	at
org.jboss.netty.handler.codec.frame.FrameDecoder.cleanup(FrameDecoder.java:344)
	at
org.jboss.netty.handler.codec.frame.FrameDecoder.channelClosed(FrameDecoder.java:232)
	at
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:98)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:545)
	at
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:540)
	at org.jboss.netty.channel.Channels.fireChannelClosed(Channels.java:404)
	at org.jboss.netty.channel.socket.oio.OioWorker.close(OioWorker.java:194)
	at org.jboss.netty.channel.socket.oio.OioWorker.run(OioWorker.java:100)
	at
org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
	at
org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:619)

-- 
View this message in context: http://netty-forums-and-mailing-lists.685743.n2.nabble.com/Re-Netty-close-the-channel-internally-I-can-t-figure-out-why-tp5719646p5743165.html
Sent from the Netty User Group mailing list archive at Nabble.com.

More information about the netty-users mailing list