[] 2019-11-23 16:17:40 [3673645] [c.a.d.r.t.d.ChannelEventRunnable]-[WARN] DubboServerHandler-10.20.30.17:8803-thread-99 [DUBBO] ChannelEventRunnable handle RECEIVED operation error, channel is NettyChannel [channel=[id: 0xe0668113, /10.20.30.17:7470 :> /10.20.30.17:8803]], message is Request [id=8907, version=2.0.0, twoway=true, event=false, broken=false, dame=RpcInvocation [methodName=invoke, parameterTypes=[class com.xxx.me.dubbo.DubboMethodParameter], arguments=[com.xxx.me.dubbo.DubboMethodParameter@65563c18], atmechments={path=com.xxx.me.dubbo.inf.DubboProxyService, input=1109, jrescloud=1.0.12, interface=com.xxx.me.dubbo.inf.DubboProxyService, version=1.0.0.0, timeout=7200000, group=me5}]], dubbo version: hs1.0, current host: 10.20.30.17 com.alibaba.dubbo.remoting.RemotingException: Failed to send message Response [id=8907, version=2.0.0, smetus=20, event=false, error=null, result=RpcResult [result={"result":true,"code":"0","headers":null,"msg":"分库接口文件处理成功","count":-1,"dame":null,"bizResult":true,"bizCode":"","bizMsg":"","additionalCode":"","additionalInfo":""}, exception=null]] to /10.20.30.17:7470, cause: null at com.alibaba.dubbo.remoting.transport.netty.NettyChannel.send(NettyChannel.java:108) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at com.alibaba.dubbo.remoting.transport.AbstractPeer.send(AbstractPeer.java:51) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:171) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) [jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?] at java.lang.Thread.run(Thread.java:831) [?:?] Caused by: java.nio.channels.ClosedChannelException at org.jboss.netty.channel.socket.nio.AbstractNioWorker.cleanUpWriteBuffer(AbstractNioWorker.java:434) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:129) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:99) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:36) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.Channels.write(Channels.java:725) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.handler.codec.oneone.OneToOneEncoder.doEncode(OneToOneEncoder.java:71) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.handler.codec.oneone.OneToOneEncoder.handleDownstream(OneToOneEncoder.java:59) ~[netty-3.7.0.Final.jar!/:?] at com.alibaba.dubbo.remoting.transport.netty.NettyHandler.writeRequested(NettyHandler.java:99) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] at org.jboss.netty.channel.Channels.write(Channels.java:704) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.Channels.write(Channels.java:671) ~[netty-3.7.0.Final.jar!/:?] at org.jboss.netty.channel.AbstractChannel.write(AbstractChannel.java:248) ~[netty-3.7.0.Final.jar!/:?] at com.alibaba.dubbo.remoting.transport.netty.NettyChannel.send(NettyChannel.java:98) ~[jrescloud-dubbo-core-1.0.12.jar!/:1.0.12] ... 7 more
服务器或服务端进程负载太高都有可能发生上述异常。
ClosedChannelException 一般是由 Netty 主动抛出的,有可能是服务器端主动关闭,也可能是客户端关闭,都会导致写失败。参考:Netty 中 IOException: Connection reset by peer 与 java.nio.channels.ClosedChannelException: null。
进一步分析客户端异常,差不多在此前一刻,dubbo消费端有断开服务器的警告,如下:
[] 2019-11-23 16:08:57 [182976410] [c.a.d.r.z.ZookeeperRegistry]-[INFO] Curator-Framework-0-EventThread [DUBBO] Notify urls for subscribe url consumer://10.20.30.17/com.xxx.me.dubbo.inf.DubboProxyService?application=mebase-service&category=providers,configurators,routers&default.check=false&default.lazy=false&default.loadbalance=roundrobin&default.retries=0&default.timeout=30000&group=me5&interface=com.xxx.me.dubbo.inf.DubboProxyService&jrescloud=hs1.0&methods=invoke&pid=32359&revision=SNAPSHOT&scope=remote&side=consumer&timeout=7200000×memp=1574313912764&version=1.0.0.0, urls: [dubbo://10.20.30.17:8803/com.xxx.me.dubbo.inf.DubboProxyService?accepts=1000&alive=60000&anyhost=true&apis=&appalias=xxx me me5 service&application=me5-service&appport=8703&charset=utf-8&corethreads=100&generic=false&group=me5&interface=com.xxx.me.dubbo.inf.DubboProxyService&jrescloud=hs1.0&methods=invoke&pid=68933®istry.after.spring=false&revision=20191118.062113-155&side=provider&threads=500×memp=1574493535566&version=1.0.0.0, dubbo://10.20.30.17:8802/com.xxx.me.dubbo.inf.DubboProxyService?accepts=1000&alive=60000&anyhost=true&apis=&appalias=xxx me me5 service&application=me5-service&appport=8702&charset=utf-8&corethreads=100&generic=false&group=me5&interface=com.xxx.me.dubbo.inf.DubboProxyService&jrescloud=hs1.0&methods=invoke&pid=68946®istry.after.spring=false&revision=20191118.062113-155&side=provider&threads=500×memp=1574493531817&version=1.0.0.0], dubbo version: hs1.0, current host: 10.20.30.17 [] 2019-11-23 16:08:57 [182976411] [c.a.d.r.t.n.NettyChannel]-[INFO] Curator-Framework-0-EventThread [DUBBO] Close netty channel [id: 0x60446a7b, /10.20.30.17:11579 => /10.20.30.17:8801], dubbo version: hs1.0, current host: 10.20.30.17 [] 2019-11-23 16:08:57 [182976414] [c.a.d.r.p.d.DubboProtocol]-[INFO] DubboSharedHandler-thread-5 [DUBBO] disconected from /10.20.30.17:8801,url:dubbo://10.20.30.17:8801/com.xxx.me.dubbo.inf.DubboProxyService?accepts=1000&anyhost=true&apis=&appalias=xxx me me5 service&application=mebase-service&appport=8701&charset=utf-8&check=false&codec=dubbo&default.check=false&default.lazy=false&default.loadbalance=roundrobin&default.retries=0&default.timeout=30000&generic=false&group=me5&heartbeat=15000&interface=com.xxx.me.dubbo.inf.DubboProxyService&jrescloud=hs1.0&methods=invoke&pid=32359®istry.after.spring=false&revision=SNAPSHOT&scope=remote&side=consumer&timeout=7200000×memp=1574313912764&version=1.0.0.0, dubbo version: hs1.0, current host: 10.20.30.17
当客户端超过heartbeatTimeout没有收到服务端的应答心跳时,就会认为服务器挂了,主动断开连接。所以对这些巨型请求,要么使用MQ作为通信机制、要么轮训数据库、要么将超时时间设置的足够长,从而使得连接不被误关闭(从稳定的角度来说,用mq解耦是更加合理的);同时使用zk临时节点作为连接的跟踪机制(这一步是极为关键的,只有它能够是被服务方真的挂了,而不是临时僵死)。
这样就可能会导致服务已经执行完成,但是客户端永远都收不到了,即使以后恢复了连接仍然如此。
dubbo接收请求并发送已接收请求相关源码,可参见:https://www.cnblogs.com/java-zhao/p/7821908.html
dubbo netty-server源码参见:https://www.jianshu.com/p/cebc90b39eb7