[讨论] 想获得当前JVM所有线程的CPU时间却有问题
 |
michael9527
2012-03-15
主要代码如下：
for(ThreadInfo ti:threadInfo) {
long id = ti.getThreadId();
// long userCpuTime = threadXMbean.getThreadUserTime(id);
long userCpuTime = threadXMbean.getThreadCpuTime(id);
totalCpuTime += userCpuTime;
}
其中新起了一个线程，执行一个死循环，之后由一个后台线程检查当前JVM的所有线程CPU时间，检查间隔是每10秒一次。 这里获得的 totalCpuTime 是毫微秒级的，当然这个不是重点， 重点是这个值居然会不断的增大。 我打出来的结果就是： 3078 10000 13078 19953 23015 29937 33000 39906 42968 49906 52968 59859 62968 69781 72968 79765 82953 89765 92937 99703 102921 109687 按理说应该是一个固定的值，至少波动不会很大，但是打出来的值却是明显在不断增长，这就很奇怪了。 |
 |
RednaxelaFX
2012-03-15
感觉上下文不足…为什么你的测试的输出应该是个固定的值？
http://docs.oracle.com/javase/6/docs/api/java/lang/management/ThreadMXBean.html?is-external=true#getThreadCpuTime(long) 引用 Returns: the total CPU time for a thread of the specified ID if the thread of the specified ID exists, the thread is alive, and CPU time measurement is enabled; -1 otherwise. 只要某个线程有在跑，它的CPU time肯定是不断增加的。没看懂你想得到的是什么数据… |
|
michael9527
2012-03-16
呵呵，没说明白，我整理一下。
假设现在JVM里面只有2个我自己产生的线程，一个main线程，用于执行消耗CPU计算的一些任务，另外一个定时线程，每10秒检查一下当前JVM中所有线程的cpu时间，它会将所有线程的CPU时间相加，然后打印出来。 那个消耗CPU计算的线程执行了一些复杂的运算，首先随机产生10位的字符串，然后对这个字符串的每一位字符执行一些异或操作，再对其中的字符进行一些加加减减。这些运JVM应该不至于能优化掉。整个执行过程是一个while(true)，所以大体来说这个线程消耗的时间应该相对固定，比如执行10秒钟，此线程会消耗三秒的CPU时间。 不过我打印出来，这个时间是会增长的，ok，那就减去。 public static final long _10SECOND = 10*1000L;
private static final int DIV_TIME_UNIT = 1000 * 1000;
long result = totalCpuTime/DIV_TIME_UNIT;
System.out.println("原始值:"+result+" 减去后的值:"+(result - _10SECOND * cycle++));由于调用JMX获取的时间是毫微秒的所以需要除以 1000*1000。 最后打印的时间是: 原始值:2921 减去后的值:2921 原始值:12593 减去后的值:2593 原始值:22296 减去后的值:2296 原始值:31890 减去后的值:1890 原始值:41468 减去后的值:1468 原始值:51203 减去后的值:1203 原始值:60953 减去后的值:953 原始值:70531 减去后的值:531 原始值:80281 减去后的值:281 原始值:89859 减去后的值:-141 原始值:99578 减去后的值:-422 不清楚这个CPU时间增长是按照什么规律增长的。从前几次看这个线程每10秒 大约会消耗3秒左右的CPU时间。 |
|
RednaxelaFX
2012-03-16
首先，你的totalCpuTime是累计了所有线程的还是只累计了一个目标线程的CPU时间？希望是前者，不然最初的数据就已经无意义了。
其次，本来最初几轮跑得就是会慢一些的。最初所有Java方法都在解释器里跑，逐渐有些方法被动态编译了，跑得会快些。减去固定的“单位时间”×cycle数没啥意义，这模型本身就不对。 |
|
michael9527
2012-03-16
累计的是所有线程的值，获取了所有线程的cpu时间，当然相加。
我的目的就是想获得一个固定时间内，比如10秒，60秒内，JVM中所有线程的CPU时间。 所以需要减去一个固定的值。我试了一下启动的时候加了-Xint结果还是一样的，还是不断减小：（每十秒输出一次） 原始值:3171 减去后的值:3171 原始值:13015 减去后的值:3015 原始值:22984 减去后的值:2984 原始值:32937 减去后的值:2937 原始值:42906 减去后的值:2906 原始值:52828 减去后的值:2828 原始值:62796 减去后的值:2796 原始值:72796 减去后的值:2796 原始值:82781 减去后的值:2781 原始值:92781 减去后的值:2781 原始值:102781 减去后的值:2781 原始值:112781 减去后的值:2781 原始值:122765 减去后的值:2765 原始值:132718 减去后的值:2718 原始值:142640 减去后的值:2640 杯具，请教下RednaxelaFX ，如果想达到最初的目的，统计10秒内整个JVM中的所有线程CPU时间，这个实现应该怎么做好呢？ |
|
RednaxelaFX
2012-03-16
实在是无法理解…抱歉，我可能帮不上忙了，得找能理解你的需求的真正的高手上阵才行
无法理解的是你为什么要减去一个固定的值。那个值又没有足够的依据说明它是有意义的。得出的数据是什么来的？ 为什么不每次记录下这次收集到的总时间，减去上次收集到的总时间得到一个差值，并根据收集数据两个时间点之间的时间间隔来调整输出，然后再输出结果？ 如果这个结果有浮动，那可以再讨论。 另外执行的时间要足够长，前几轮的结果全部抛弃掉。如果是我来测的话我或许会抛弃掉头3分钟的结果。如果你的测试本身连半分钟都不到那我也不知道你想看的是什么… |
|
michael9527
2012-03-16
即便是有一段时间的热身，输出的值还是有点怪异。
启动2个线程，一个消耗CPU的线程，一个计算所有线程CPU时间的线程。 计算CPU时间的线程是过了5分钟再启动的，之后每10秒打印一次结果。打印内容是这次计算的所有线程CPU时间总和 - 上次计算的所有线程CPU时间总和 。打印的结果是一个慢慢增加的： 288218 9500 297656 19171 307093 28843 316640 38437 326296 48062 336078 57500 345718 67281 355312 76734 364937 86328 374531 95921 384109 105484 393703 115000 403296 124671 412828 134156 422312 143906 431843 153500 441562 163156 451062 172796 460750 182468 470187 192078 479843 201765 489671 211250 499265 220718 508812 230125 518265 239718 527843 249421 537421 259156 547046 268781 556500 278515 566046 两次打印间隔就是10秒，看这个结果奇数次会大些，偶数次会小些，总体都不断变大。 因为是一个死循环执行一些耗时任务，所以每次的CPU时间应该不会差别很大，应该是在一个范围之内的，不过这个打印结果来看，可能还是我的计算方式不对。 |
