[讨论] jstats统计出负数时间
 |
caoxudong818
2012-01-09
今天在用jstat对程序进行数据统计时，发现gc时间项是负数，不知各位知不知道是什么原因？
不知道怎么发截图，只好贴上来了。 Loaded Bytes Unloaded Bytes Time 4790 5478.2 37 32.0 -62.76 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 47.13 29.41 5.14 53.90 61 -44.652 2 0.187 -44.464 请教，这是为神马？ |
 |
RednaxelaFX
2012-01-09
具体的JDK版本和系统信息是怎样的？
|
|
caoxudong818
2012-01-10
RednaxelaFX 写道 具体的JDK版本和系统信息是怎样的？
抱歉昨天没看到。我是在开发机上进行的测试的。 开发环境是 Windows XP SP3，Intel Core 2 Quad CPU，1.98G内存。 JDK是： java version "1.6.0_29" Java(TM) SE Runtime Environment (build 1.6.0_29-b11) Java HotSpot(TM) Client VM (build 20.4-b02, mixed mode, sharing) Web服务器是： Tomcat-6.0.35 启动参数： -verbose:gc -Xloggc:E:\Temp\guzz\guzzTest.log -XX:+PrintGCDetails -XX:CompileThreshold=1 -XX:+CITime -server -Xmx512m -Xms512m 说明： 设置-XX:CompileThreshold=1是为了尽快触发JIT，但貌似没有效果。有哪位知道原因，请赐教。 |
|
caoxudong818
2012-01-10
补充：
使用jstat对同一应用进行多次统计后，出现的负数的值会慢慢增大，逐渐向正数靠 拢，说明统计出的异常数值是在一个负数的基础上逐渐累加。 如下所示： C:\Documents and Settings\caoxudong>jstat -gcutil 4388 S0 S1 E O P YGC YGCT FGC FGCT GCT 4.28 0.00 85.69 3.95 85.63 416 -271.415 17 -13.131 -284.546 C:\Documents and Settings\caoxudong>jstat -gcutil 4388 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 17.53 4.00 87.64 418 -271.412 18 -12.975 -284.387 但最初的那个负数值是为何出现的，还没找到原因。 上一些图片： 
|
|
caoxudong818
2012-01-10
刚刚继续跑测试，发现有负数的统计还会变小，
C:\Documents and Settings\caoxudong>jstat -gcutil 4388 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 34.04 4.00 87.64 418 -271.412 18 -12.975 -284.387 C:\Documents and Settings\caoxudong>jstat -gcutil 4388 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 3.28 36.07 4.09 87.64 423 -275.321 18 -12.975 -288.296 好吧，偶凌乱了。 |
|
RednaxelaFX
2012-01-10
caoxudong818 写道 说明：
设置-XX:CompileThreshold=1是为了尽快触发JIT，但貌似没有效果。有哪位知道原因，请赐教。 是如何判断“貌似没有效果”的？ 把-XX:+PrintCompilation也打开就可以知道-XX:CompileThreshold=1有没有“效果”了。 如果你是想追求性能提升的话，调这个参数多半不是个好办法。先回答我的问题然后有需要再展开说。 jstat的读数是负数的问题以前还真没见过；主要是在Linux上做这些实验。 不过HotSpot VM在Linux上跟Windows上读时间用的API不同，不太肯定跟这个有没有关系。这个现象会稳定重现是么？ |
|
caoxudong818
2012-01-10
引用 是如何判断“貌似没有效果”的？ 之所以说感觉没有效果，是因为对重复执行的方法进行时间检测，发现方法执行时间并不太大差别（这个被检测的方法对数据库进行修改的操作）。 jstat统计出负数这个情况并不是稳定出现，大部分情况下是正常的，偶尔会出现负 数。但还不能总结出出现负数时的特殊环境。 -XX:+PrintCompilation，下一次的测试会打开这个开关，执行结果后续给出。 多谢R大提醒。 |
|
RednaxelaFX
2012-01-10
caoxudong818 写道 引用 是如何判断“貌似没有效果”的？
之所以说感觉没有效果，是因为对重复执行的方法进行时间检测，发现方法执行时间并不太大差别（这个被检测的方法对数据库进行修改的操作）。 I/O密集型代码本来主要花的时间就不是在Java这边吧？那段Java代码被编译与否或许真的就没啥影响。 |
|
caoxudong818
2012-01-10
RednaxelaFX 写道 caoxudong818 写道 引用 是如何判断“貌似没有效果”的？
之所以说感觉没有效果，是因为对重复执行的方法进行时间检测，发现方法执行时间并不太大差别（这个被检测的方法对数据库进行修改的操作）。 I/O密集型代码本来主要花的时间就不是在Java这边吧？那段Java代码被编译与否或许真的就没啥影响。 说的是。把这个因素忘记了。 |
