26

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

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

第一个屏幕截图显示了萤火虫控制台,在服务主页时,网站的加载在开始时被卡住了。 在此处输入图像描述 第二个屏幕截图显示提琴手控制台,当 2 个静态资源未加载时。

在此处输入图像描述

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

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

我怀疑NettyPlay 框架使用了一些问题。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。这是应用程序的相同生产主机、相同数据库和相同用户。

4

2 回答 2

1

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

于 2012-12-04T20:15:40.103 回答
1

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

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

另请参阅“类似问题”以了解有关该课程的问题数量。

于 2012-12-08T18:58:51.690 回答