已经问过类似的问题,但删除了它,因为我以为我修复了它,但我错了。
我在生产中为我的一个 Web 项目使用 Play 框架。Play 有时不呈现主页或不返回某些静态内容文件。
第一个屏幕截图显示了萤火虫控制台,在服务主页时,网站的加载在开始时被卡住了。 第二个屏幕截图显示提琴手控制台,当 2 个静态资源未加载时。
最初应用程序运行良好,它必须工作 5-7 天,我可以看到这个问题。很难重现,它发生了 15 次中的 1 次,我必须删除缓存数据并重新加载页面。(在 FF 中按 CRTL-F5)。问题可以在来自不同机器和操作系统的大多数浏览器中重现。最初,我认为托管服务提供商存在一些问题。但我已经改变了它,问题还没有消失。
该剧的版本是1.2.5。也尝试了 1.2.2。Play 在 CentOS-5-32 位上作为独立服务器运行。
我怀疑Netty
Play 框架使用了一些问题。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。这是应用程序的相同生产主机、相同数据库和相同用户。