Play framework/Netty 不释放socket

Posted 2023-02-16

【中文标题】Play framework/Netty 不释放socket

【英文标题】：Play framework/Netty does not release socket

【发布时间】：2012-10-31 02:56:27

【问题描述】：

已经问过类似的问题，但删除了它，因为我以为我修复了它，但我错了。

我正在为我的一个 Web 项目在生产环境中使用 Play 框架。 Play 有时不呈现主页或不返回某些静态内容文件。

第一个屏幕截图显示了 firebug 控制台，在服务主页时，网站的加载在开始时被卡住了。 第二个屏幕截图显示提琴手控制台，当 2 个静态资源未加载时。

最初应用程序运行良好，它必须工作 5-7 天，我可以看到这个问题。很难重现，它发生了 15 次中的 1 次，我必须删除缓存数据并重新加载页面。 （在 FF 中按 CRTL-F5）。问题可以在来自不同机器和操作系统的大多数浏览器中重现。最初，我认为托管服务提供商存在一些问题。但我已经改变了它，问题还没有消失。

该剧版本为1.2.5。也尝试了 1.2.2。 Play 在 CentOS-5-32 位上作为独立服务器运行。

我怀疑 Play 框架使用的 Netty 存在一些问题。 Play 使用 Netty 3.5.7 final jar。

cd /proc/28761/fd
ls -l | wc -l
337

这几天打开的文件描述符数从 140 增长到 350。请注意，网站在开始和之后的平均负载是相同的。

可以看到进程打开了很多socket，后面没有释放。

lrwx------ 1 root root 64 Nov 11 10:34 300 -> socket:[1079566]
lrwx------ 1 root root 64 Nov 11 10:34 301 -> socket:[1079568]
lrwx------ 1 root root 64 Nov 11 10:34 302 -> socket:[1149958]
lrwx------ 1 root root 64 Nov 11 10:34 303 -> socket:[1160807]
lrwx------ 1 root root 64 Nov 11 10:34 304 -> socket:[1160605]
lrwx------ 1 root root 64 Nov 11 10:34 305 -> socket:[1157435]
lrwx------ 1 root root 64 Nov 11 10:34 306 -> socket:[1160607]
lrwx------ 1 root root 64 Nov 11 10:34 307 -> socket:[1160609]
lrwx------ 1 root root 64 Nov 11 10:34 308 -> socket:[1155542]
lrwx------ 1 root root 64 Nov 11 10:34 309 -> socket:[1120231]

更新

应用程序启动时打开的 TCP 连接数（运行几个小时）为 63。

Total: 150 (kernel 181)
TCP:   63 (estab 38, closed 5, orphaned 0, synrecv 0, timewait 3/0), ports 44

Transport Total     IP        IPv6
*         181       -         -
RAW       0         0         0
UDP       7         4         3
TCP       58        9         49
INET      65        13        52
FRAG      0         0         0

运行2天后，打开的TCP连接数为490。

[root@82711-2 fd]# ss -s
Total: 459 (kernel 490)
TCP:   378 (estab 271, closed 23, orphaned 0, synrecv 0, timewait 9/0), ports 37

Transport Total     IP        IPv6
*         490       -         -
RAW       0         0         0
UDP       7         4         3
TCP       355       12        343
INET      362       16        346
FRAG      0         0         0

所有打开的 TCP 连接都是 http 连接（不是数据库或任何其他连接）。网站上的平均负载一直相同，但打开的文件描述符和打开的套接字的数量一直在增长，直到too many open files exception

最初应用程序以 9-15 个新 I/O 线程（Netty 工作者）启动。所有 Netty 线程大部分时间都处于运行状态。以及约 16 个处于等待状态的播放线程。

经过几天的运行，Netty 工人的数量变成了 27。我不是 Netty 专家，不确定这是否是正常行为。

很少有线程陷入僵局：1 个 Play 线程和 1 个 Netty 线程。还有另一个 Play 线程被第一个 Play 线程锁定。所以总共3个锁定线程。我敢肯定，这种死锁不是问题的根本原因，但根本原因可能是相同的

Name: New I/O  worker #21
State: BLOCKED on org.jboss.netty.handler.stream.ChunkedWriteHandler@15e057 owned by: play-thread-2
Total blocked: 44  Total waited: 9

Stack trace: 
org.jboss.netty.handler.stream.ChunkedWriteHandler.flush(ChunkedWriteHandler.java:188)
org.jboss.netty.handler.stream.ChunkedWriteHandler.handleUpstream(ChunkedWriteHandler.java:140)
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
org.jboss.netty.channel.SimpleChannelUpstreamHandler.channelClosed(SimpleChannelUpstreamHandler.java:212)
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:93)
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:792)
org.jboss.netty.handler.codec.replay.ReplayingDecoder.cleanup(ReplayingDecoder.java:636)
org.jboss.netty.handler.codec.replay.ReplayingDecoder.channelClosed(ReplayingDecoder.java:533)
org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:93)
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
org.jboss.netty.channel.Channels.fireChannelClosed(Channels.java:476)
org.jboss.netty.channel.socket.nio.AbstractNioWorker.close(AbstractNioWorker.java:631)
org.jboss.netty.channel.socket.nio.NioserverSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:109)
org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:66)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:780)
org.jboss.netty.handler.codec.oneone.OneToOneEncoder.handleDownstream(OneToOneEncoder.java:55)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:785)
org.jboss.netty.handler.stream.ChunkedWriteHandler.handleDownstream(ChunkedWriteHandler.java:111)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:582)
org.jboss.netty.channel.Channels.close(Channels.java:821)
org.jboss.netty.channel.AbstractChannel.close(AbstractChannel.java:194)
org.jboss.netty.channel.ChannelFutureListener$1.operationComplete(ChannelFutureListener.java:41)
org.jboss.netty.channel.DefaultChannelFuture.notifyListener(DefaultChannelFuture.java:399)
org.jboss.netty.channel.DefaultChannelFuture.notifyListeners(DefaultChannelFuture.java:385)
org.jboss.netty.channel.DefaultChannelFuture.setSuccess(DefaultChannelFuture.java:334)
org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:493)
   - locked java.lang.Object@3b7e28
org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:431)
org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:364)
org.jboss.netty.channel.socket.nio.AbstractNioWorker.processWriteTaskQueue(AbstractNioWorker.java:349)
org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:245)
org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:38)
org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:102)
org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
java.lang.Thread.run(Thread.java:662)

第二个线程：

Name: play-thread-2
State: BLOCKED on java.lang.Object@3b7e28 owned by: New I/O  worker #21
Total blocked: 23  Total waited: 34 778

Stack trace: 
org.jboss.netty.channel.socket.nio.AbstractNioWorker.cleanUpWriteBuffer(AbstractNioWorker.java:654)
org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromUserCode(AbstractNioWorker.java:408)
org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.handleAcceptedSocket(NioServerSocketPipelineSink.java:127)
org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink.eventSunk(NioServerSocketPipelineSink.java:66)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:780)
org.jboss.netty.handler.codec.oneone.OneToOneEncoder.handleDownstream(OneToOneEncoder.java:63)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendDownstream(DefaultChannelPipeline.java:785)
org.jboss.netty.channel.Channels.write(Channels.java:733)
org.jboss.netty.handler.stream.ChunkedWriteHandler.flush(ChunkedWriteHandler.java:262)
   - locked org.jboss.netty.handler.stream.ChunkedWriteHandler@15e057
org.jboss.netty.handler.stream.ChunkedWriteHandler.handleDownstream(ChunkedWriteHandler.java:121)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:591)
org.jboss.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:582)
org.jboss.netty.channel.Channels.write(Channels.java:712)
org.jboss.netty.channel.Channels.write(Channels.java:679)
org.jboss.netty.channel.AbstractChannel.write(AbstractChannel.java:245)
play.server.PlayHandler.serveStatic(PlayHandler.java:886)
play.server.PlayHandler$NettyInvocation.init(PlayHandler.java:182)
play.Invoker$Invocation.run(Invoker.java:276)
play.server.PlayHandler$NettyInvocation.run(PlayHandler.java:229)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
java.util.concurrent.FutureTask.run(FutureTask.java:138)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
java.lang.Thread.run(Thread.java:662)

更新

我将相同的 Play 应用程序部署到 Tomcat 7 的相同环境。24 小时过去了，问题已经解决，打开的 TCP 连接数保持不变。打开的文件描述符的数量不超过 ~70。这是应用程序的相同生产主机、相同数据库和相同用户。

【问题讨论】：

请求是直接到达 Play 应用还是通过代理（Apache 等）？

不使用代理，请求直接进入播放

你有没有在服务器端做任何线程转储，可能服务器上挂了一些东西阻止播放重用线程

您是否能够通过使用 ApacheBench 或类似工具的负载测试来重现此问题？

看起来 ChunkedWriteHandler 中的死锁是前一段时间反复出现的问题。 one、two、three。将此报告为错误可能是个好主意。

【参考方案1】：

在 ChunkedWriteHandler 中有几个死锁问题。所有这些似乎都在您的 Netty 版本中得到解决。无论如何，那段代码似乎正在吸引这种问题。我建议你向 Netty 人提出问题。

https://issues.jboss.org/browse/NETTY-384

另请参阅“类似问题”以了解该课程存在多少问题。

【参考方案2】：

我实际上遇到了一个类似的错误，但不是在播放中，而是在 JVM（播放运行）中，因此指向文件句柄的关闭通道不会被释放，直到通过关闭 JVM 强制释放。唉，我不记得我是如何找到错误报告的，或者我会链接到它，但它是 JVM 中的一个已知错误。我最终不得不解决它。我可以建议的最好的事情是重写您的代码以尽可能使用相同的通道/文件句柄。

【讨论】：

似乎不太可能，因为这会影响任何类型的 Java Web 应用程序，但我们经常看到这没有问题。