最近在测试过程中,遇到每次的轮次中的服务器的cpu使用都超高,细看一下,原来是cpu中是sys使用率过高。详见下图,可以看到图中sys已经达到了50%以上,而usr40%左右:
一般来说,sys表示内核态的cpu使用,以下的情况中sys消耗高是可以接受的:
1. 如果cpu是满载的,诸如下面这样的配比:
user time:65%~70%;system time:30%~35%;idle time:0%~5%
2. 上下文切换的数量和CPU负载直接相关。如果CPU的负载一直保持在之前可接受的平衡范围内,那么数目特别大的上下文切换是可接受的;
踩坑经历:
1. 根据上面的两个可以接受的情况,查看usr的使用明显要小于sys的使用;
2. 查看上下文切换以及终端的数量,并不算特别大
3. 使用远程jprofile抓取,99.8%的cpu消耗都在com.caucho.util.ThreadPool.run上面,其中后面浅红色的部分,即箭头所指的部分是这个方法自身消耗的cpu,这其中只有19.9%的是消耗在login2/pwdlogin上了:
4. 服务器上抓取堆栈,waitting的都在com.caucho.util.ThreadPool.run上面:
甚至还有BLOCKED的线程:
"resin-tcp-connection-*:36901-17" - Thread t@104438
java.lang.Thread.State: BLOCKED
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:406)
- waiting to lock <472ac1c6> (a java.net.SocksSocketImpl) owned by "resin-tcp-connection-*:36901-217" t@96886
at java.net.ServerSocket.implAccept(ServerSocket.java:462)
at java.net.ServerSocket.accept(ServerSocket.java:430)
at com.caucho.vfs.QServerSocketWrapper.accept(QServerSocketWrapper.java:97)
at com.caucho.server.port.Port.accept(Port.java:813)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:495)
at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:527)
at com.caucho.util.ThreadPool.run(ThreadPool.java:449)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- None
在仔细查看这个“waiting to lock <472ac1c6>”,是被下面这个线程给锁住了:
"resin-tcp-connection-*:36901-217" - Thread t@96886
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:408)
- locked <472ac1c6> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:462)
at java.net.ServerSocket.accept(ServerSocket.java:430)
at com.caucho.vfs.QServerSocketWrapper.accept(QServerSocketWrapper.java:97)
at com.caucho.server.port.Port.accept(Port.java:813)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:495)
at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:527)
at com.caucho.util.ThreadPool.run(ThreadPool.java:449)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- None
5. 查看resin.jar包的com.caucho.util.ThreadPool.run:
public void run()
{
ClassLoader systemLoader = ClassLoader.getSystemClassLoader();
Thread.currentThread().setContextClassLoader(systemLoader);
try
{
for (int i = 0; i < ThreadPool._minSpareThreads; i++)
startConnection(0L);
} catch (Throwable e) {
e.printStackTrace();
}
while (true)
try
{
startConnection(10000L);
Thread.currentThread(); Thread.yield();
continue;
}
catch (OutOfMemoryError e)
{
System.exit(10);
continue;
}
catch (Throwable e)
{
e.printStackTrace();
}
}
6. 从以上几个步骤可以看出,是并发的线程数过高,resin已经处理不过来了。
解决方案:
1. 增加resin部署的机器个数
2. 减少测试过程中的并发数
总结:虽然这次踩坑的现象看起来很简单,最后解决的思路也比较简单。但在问题解决的过程中可以学习到很多东西。所以以后在测试过程中遇到问题后,还是通过现象看本质,才能顺利解决问题。
本文来自网易实践者社区,经作者齐红方授权发布。