java程序启动时cpu和负载高探索

这两天协助运维定位1个监控程序CPU占用率达到150%的问题,过程曲折,结论简单,很有意思:)

首先我们来看一下cpu高时候截图:

可以看到红色框中的监控程序CPU占用率都很高,但其实这些监控程序的实现很简单:发送1个http请求,收到响应后简单判断一下响应码,然后打印监控结果,打印完成就退出了。每次监控都会重新由daemon程序拉起运行。

这么简单的业务占用这么高的cpu,怎么感觉都不太可能,于是拿到监控程序的源码开始定位。

第一个想到的是VisualVm、JConsole等工具,但由于程序很快就运行完成了,这两个工具都还没有连接上就结束了,而且拿到的数据也没法看出具体是什么原因导致cpu高,尝试了一下就放弃了。

第二个尝试是用strace去跟踪程序的调用,结果摘录如下(省略很多):

17572 14:08:43.552199 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9949000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.562857 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.563029 clock_gettime(CLOCK_REALTIME, {1423721323, 563056000}) = 0
17572 14:08:43.563119 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9936000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.573913 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.574159 clock_gettime(CLOCK_REALTIME, {1423721323, 574214000}) = 0
17572 14:08:43.574253 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9925000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.584885 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.585055 clock_gettime(CLOCK_REALTIME, {1423721323, 585081000}) = 0
17572 14:08:43.585147 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9936000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.595900 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.596170 clock_gettime(CLOCK_REALTIME, {1423721323, 596206000}) = 0
17572 14:08:43.596245 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9947000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.606960 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.607139 clock_gettime(CLOCK_REALTIME, {1423721323, 607167000}) = 0
17572 14:08:43.607232 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9935000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.617875 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.618119 clock_gettime(CLOCK_REALTIME, {1423721323, 618209000}) = 0
17572 14:08:43.618249 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9890000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.628960 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.629140 clock_gettime(CLOCK_REALTIME, {1423721323, 629168000}) = 0
17572 14:08:43.629231 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9935000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.639865 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.640134 clock_gettime(CLOCK_REALTIME, {1423721323, 640167000}) = 0
17572 14:08:43.640206 futex(0x580497a4, FUTEX_WAIT_PRIVATE, 1, {0, 9946000}) = -1 ETIMEDOUT (Connection timed out)
17572 14:08:43.650868 futex(0x58049028, FUTEX_WAKE_PRIVATE, 1) = 0
17572 14:08:43.651139 unlink("/tmp/hsperfdata_gamedata/17559") = 0
17572 14:08:43.651324 exit_group(0)     = ?   

怎么那么多futex,google一查“futex connection time out”,嘿,还真有很多结果,最典型的就是leap second,中文翻译为“闰秒”,但仔细一看,上一次闰秒发生是2012年06月份,现在都2015年了,而且天天cpu都高,应该不是这个问题

工具指望不上,只好看代码,代码看了后怀疑几个地方:

1)CountDownLatch:因为这个最有可能用到futex了,但实际想了想和验证了一下,这个东东不可能导致cpu这么高,真有这个问题,这东东完全就没法用了

2)多线程:看了代码,没有几个线程,而且业务就是一发一收,不可能多线程导致的

问题陷入僵局,怎么办呢? 只好用终极大招了:分段注释!

1)注释响应处理的代码 —— 不行,cpu占用100%

2)注释发送请求的代码 —— 还是不行,,cpu占用100%

      这不坑爹嘛,请求都不发,响应也没有了,你咋还这么慢?

3)干脆注释所有代码, 只在main里面打印Hello world —— 还是不行,,cpu占用100%

      这下就蛋疼了,没有任何业务,你cpu还高,这不坑我嘛

4)自己写个Hello world —— 咦,这次可以了,cpu占用1%左右

     咋回事,同样都是打印Hello world,为啥cpu差别那么大?

左思右想,突然灵光一闪:难道是和jvm加载类文件有关 ?

jvm在启动的时候会装载并连接所有除反射以外的类,而class文件是二进制的文件,需要从磁盘加载到内存然后解析,这种解析是很耗费cpu的,那么class文件越多,cpu耗费就越高,这正好解释了为什么同样输出Hello world,不同程序cpu占用率差别很大。

这个推论正好也解释了之前遇到的另外一个线上项目的现象:每次启动后有大约1分钟左右系统的cpu和负载很高,过了1分钟后就恢复正常了。

【建议】

需要重复运行的监控类程序,如果用java写,最好不要做成每次都要重新启动,而是在程序里面循环或者定时运行;

如果一定要每次都要重新启动,频率又很频繁的话,建议用shell、python之类的来写,否则一台机器运行太多java类的工具程序,会导致cpu和负载飙升

===============2015.02.13补充====================================

昨晚完成博客后,脑海中梳理整个流程发现还是有一点疑问:java虚拟机都是按需加载类的,那么我的main函数里面完全没有用到任何其它类,为何还是会加载呢?

今天针对这个问题继续查阅相关资料,发现原来所谓的“使用”,并不单单指我们通常编码所说看到的new、方法调用,而且还包括“依赖”。

举个简单例子:

package common;

import java.util.*;

public class CommonTester {

    public static void main(String[] args) {
        System.out.println("Hello, world......");
    }

    /**
     * 这个函数在main里面并没有调用,但jvm还是会加载ArrayList类,因为CommonTester内依赖了ArrayList类
     * @return
     */
    public List<String> createStringList(){
        return new ArrayList<String>(100);
    }
}

以上这个例子中,CommonTester类在main函数中并没有调用crateStringList方法,但因为CommonTester类依赖ArrayList类,那么在加载CommonTester的时候发现其依赖ArrayList类,就会先加载ArrayList类。

所以,jvm最开始启动的时候肯定是先加载main函数所在的类,但是在加载这个类的时候发现依赖其它类,就会先加载其它类;加载其它类的时候也是这样处理,就像一个链式反应一样,所以基本上除了反射的类外,大部分类在jvm启动后,运行main函数前就已经加载完毕了。

为了验证这个推论,重新做了验证:

1)main函数所在的类注释所有其它代码,只保留main函数里面的打印语句

      验证结果:cpu占用和自己写的简单的hello world程序一样,占用率大约1%左右

2)main函数所在的类注释所有其它代码,但保留import语句和main函数里面的打印语句

     验证结果:和上面的一样,这个也很好理解,只保留import语句,因为这些语句并没有用,编译的时候这些语句都被优化掉了

==============2015.02.13第二次补充===========================

组内分享后,有同学又提出了一个疑问:jvm加载类的时候是多线程还是单线程 ?

为了回答这个问题,先后看了一些电子书和java官方的jvm规范,但都没有找到答案,于是决定自己来验证一下。

经过一番探索,终于找到1个很好的方法来判断类加载是单线程还是多线程。方法具体如下:

1)使用java -verbose启动程序,这样程序运行时就会打印加载的类

2)使用strace跟踪,就可以知道哪些线程加载了类

具体的命令为:strace -T -f -q -s 1024 -o strace.txt java -verbose .............(省略号代表具体的程序运行相关参数)

通过查看strace输出的结果,发现如下现象:

1)多个线程都会去加载类

2)同一线程需要用到的类如果还没有加载,则自己会去加载,不会再委托给其它线程加载

注:验证环境的jvm信息如下,不同的虚拟机可能有不同的实现:

java version "1.6.0_31"
Java(TM) SE Runtime Environment (build 1.6.0_31-b04)
Java HotSpot(TM) 64-Bit Server VM (build 20.6-b01, mixed mode)

=============2015.07.13补充==================================

对于java6,有一个选项可以加快启动过程:-XX:CICompilerCount,对于线上业务,如果没有预热,启动后立刻有大量请求涌入,此时会出现cpu负载高,原因在于刚开始运行时Java都是解释执行,速度较慢,然后才逐渐用JIT将代码编译为本机二进制代码,JIT默认线程数只有2个,处理较慢。通过这个选项可以加快JIT的执行速度,降低启动后CPU负载高的时间。

但这个选项对于工具类java程序不能这样配置,同一台机器运行太多工具类,如果同时启动的话,因为线程数太多,负载会非常高

java7有一个自适应的选项:-XX:+TieredCompilation,能够根据CPU核数自动调整,有兴趣的同学可以研究一下

=======================================================

转载请注明出处:http://blog.csdn.net/yunhua_lee/article/details/43765371

时间: 2024-10-29 22:40:26

java程序启动时cpu和负载高探索的相关文章

tomcat启动时 过高-linux环境下tomcat启动时CPU过高

问题描述 linux环境下tomcat启动时CPU过高 我从tomcat官方网站上下载了一个tomcat7,然后上传到linux环境下解压,然后启动tomcat(没有部署任何项目), CPU瞬间就达到100%,请高手帮忙解释下,是什么原因 解决方案 性能调优:http://blog.chinaunix.net/uid-26204366-id-3896703.html 解决方案二: http://www.linuxidc.com/linux/2014-07/104753.htm 解决方案三: ht

Linux系统小技巧(1):/dev/random设备可能导致java程序启动慢或者操作耗时不正常

致因 Linux系统上的设备/dev/random和/dev/urandom是不同的.这点可以使用下面的命令测试出来(执行会耗费几分钟时间,请有心理准备) for dev in /dev/random /dev/urandom;do echo "test ${dev}: " time dd if=${dev} bs=512 count=1 > /dev/null 2>&1 time dd if=${dev} bs=512 count=1 > /dev/null

图标不重合-win7任务栏的图标创建后,程序启动时的图标没有与创建好的重合

问题描述 win7任务栏的图标创建后,程序启动时的图标没有与创建好的重合 通过::ShellExecute(NULL, L"TaskBarPin", strLnkFileName, NULL, NULL, SW_SHOW)把创建的程序快捷方式锁定到任务栏后,启动程序时图标没有与创建好的图标重合,出现同一个程序两个相同图标同时存在于任务栏的情况. 把图标锁定到任务栏的方法除了使用TaskBarPin以外还有谁知道有其他方法吗? 解决方案 delphi编的程序好像一定不能重合...

Linux问题情报分享(1):内核Stack Clash补丁导致Java程序启动失败

关于Stack Clash,缺少耐心的读者,请参考Stack Clash 漏洞正粉碎 Linux 防御危及 root 权限,较全面的介绍请参考Stack Guard Page Circumvention Affecting Multiple Packages. 各个Linux发行版都已经发布了升级,合并了上游补丁. 上游补丁通过增大stack guard gap(堆栈保护措施,更多请参考Buffer overflow protection)尺寸到1M的方式,修复了Linux Kernel Sta

debug-关于c#程序启动时闪一下的问题

问题描述 关于c#程序启动时闪一下的问题 我做了一个winform程序 从别的程序调用这个winform 当右键项目属性时添加参数debug时 程序能启动 当不添加任何参数时 启动项目时winform只是闪了一下 请大神给个解决思路 解决方案 在program.cs中看下main函数,是怎么读取参数的.参数是干嘛的. 解决方案二: 因为没有参数,也许就进不了main函数了

Web程序启动时弹出如下图错误,怎么办?仅ie弹出,其他的浏览器都正常

问题描述 Web程序启动时弹出如下图错误,怎么办?仅ie弹出,其他的浏览器都正常 只有IE浏览器打开时弹出这个,其他浏览器都正常. 解决方案 可能是js写的不规范吧. 解决方案二: js操作IE浏览器弹出浏览文件夹js操作IE浏览器弹出浏览文件夹

对话框的顺序-FC对话框应用程序中如何修改程序启动时默认的对话

问题描述 FC对话框应用程序中如何修改程序启动时默认的对话 我在程序中新建了多个对话框,如dialog1,dialog2,不想让默认的那个对话框作为启动时显示的,而想让dialog2作为第一个显示的对话框,有办法吗? 解决方案 App类的InitInstance函数中修改一下,添加DoModal()你的对话框,删除m_pMainWnd = &XXXXDlg;语句(如果有的话) 解决方案二: 求指导!

下面的java程序运行时为什么没有结果

问题描述 下面的java程序运行时为什么没有结果 package sql; import java.awt.*; import java.awt.event.*; import java.sql.*; import javax.swing.*; class liaotian extends JFrame implements ActionListener{ JPanel jpanel1; TextArea textArea1; TextField textField3; JButton jBut

java swing启动时窗口最大化

Java swing启动时窗口最大化 Java代码   setExtendedState( this.getExtendedState()|JFrame.MAXIMIZED_BOTH );