尝试测量Java对象的销毁时间

抛砖引玉

May 21, 2021 · 35 mins read

Oh, and one more thing: there is a severe performance penalty for using finalizers.

On my machine, the time to create and destroy a simple object is about 5.6 ns. Adding a finalizer increases the time to 2,400 ns.

In other words, it is about 430 times slower to create and destroy objects with finalizers.

——Effective Java Second Edition

很好奇大佬是如何测量时间的。

创建一个简单对象还比较容易精确测量,销毁一个对象的时间就没那么容易精确测量了。因为JVM屏蔽了底层细节,程序员并不知道它什么时候真正的销毁对象并回收资源。你可以提建议,但什么时候听就看GC心情了:sunglasses:

想了一下,大概有这两条路:

  • JVM入手。这应该是我所能想到的最精确的方法,比如在对象创建后或销毁后JVM有个Callback什么的。以上纯属YY,如有雷同,绝非巧合:joy:。时间、精力、脑力确实有限,没有近一步去研究。
  • 回到Java语言本身提供的功能。不求精确的度量时间,只是粗略的测量然后比较一下,能表明有finalizer的对象创建和销毁相对比较耗时就行。比较差异的话,很多因素都可以忽略,比如GC的延迟时间、对象销毁的真正终点,因为比较的双方都是一样的。下面我们尝试走这一条路。

实验环境Win8.1:

java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b15)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)

V1

首先不能依赖finalize()方法来打卡时间点,没有这个方法的简单对象表示臣妾~做不到啊:sob:

后来刚好看到java.lang.ref包,PhantomReference代表最接近生命周期终点的phantom reachable,当GC认为referent,也就是我们的简单对象,变成phantom reachable的时候,它就会将该reference添加到queue中。

由于在Java语言里和GC的交互程度非常有限,那么我们就以这个时间点作为销毁对象的打卡时间点。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
public class WithoutFinalizationV1 {

    public static void main(String[] args) {
        ReferenceQueue<WithoutFinalizationV1> queue = new ReferenceQueue<>();
        long start = System.nanoTime();
        
        PhantomReference<WithoutFinalizationV1> rf = new PhantomReference<>(
                new WithoutFinalizationV1(), queue);
        System.gc();//advise JVM to do GC
        
        Object x = null;
        int waitCount = -1;
        do{
            x = queue.poll();
            waitCount++;
        }while(x == null);
        //only need this time point
        System.out.println("WithoutV1 "+waitCount 
                +" "+(System.nanoTime() - start));
    }
}

在首次尝试中,创建和销毁的时间合在一起测量,结果也比较出乎意料,完全就不在一个数量级啊。后面想了想,因为包含了GC可能的磨蹭时间,这个时间也在情理之中。

运行了几次,最好记录是:5394860 ns:sweat:

给类加上finalize()方法,出来的结果是:5632208 ns,确实要慢一点点:v:

1
2
3
    @Override
    protected void finalize() throws Throwable{
    }

注意到这么个情况,如果finalize()方法体哪怕只有一行程序,比如int i = 0;,就需要调用GC两次。因为只有在下一次GC过程中才会让reference enqueue

V2

为了更贴近一点,我们分开测量创建和销毁时间。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
public class WithoutFinalizationV2 {
    
    public static void main(String[] args) throws Exception {
        long createTime = System.nanoTime();
        WithoutFinalizationV2 o = new WithoutFinalizationV2();
        createTime = System.nanoTime() - createTime;
        
        ReferenceQueue<WithoutFinalizationV2> queue = new ReferenceQueue<>();
        PhantomReference<WithoutFinalizationV2> rf = new PhantomReference<>(
                o, queue);
        
        Object x = null;
        int waitCount = -1;
        o = null;//explicitly clear reference
        long destroyTime = System.nanoTime();
        System.gc();//advise JVM to do GC
        do{
            x = queue.poll();
            waitCount++;
        }while(x == null);
        //only need this time point
        destroyTime = System.nanoTime() - destroyTime;
        System.out.println("WithoutV2 "+waitCount 
                +" "+createTime +" "+ destroyTime);
    }
}

这次的结果稍微精确点儿,但也差不太多:3421+4973193=4973193 ns

finalize()方法的结果是:2993+5631353=5634346 ns

V3

在程序上已经做到尽量贴近测量了,要想进一步提高成绩,只有利用JVM的HotSpot来优化性能。

在官方文档只找到了方法调用次数的阈值,Server VM是一万次调用。网上搜了下,OSR也差不多是这个次数。

这个版本采用先批量构造对象,然后挨个销毁,最后计算平均时间。由于需要循环很多次,我们能用多线程吗?我觉得不能,因为一次GC就可能回收多个对象,测量就更不准了。

在测试中遇到个问题,当运行次数接近五六百次的时候,reference又不enqueue了。推测是GC调用太频繁,罢工了,sleep一下就好了。

然后又尝试运行在-Xcomp模式,不幸的是程序会卡在销毁对象的地方,具体原因就不清楚了,可能优化太激进了吧。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
public class WithoutFinalizationV3 {

    public static void main(String[] args) throws Exception {
        int times = 30*1000;
        long createTime = 0;
        long destroyTime= 0;
        
        WithoutFinalizationV3[] oarray = new WithoutFinalizationV3[times];
        for(int i=0; i<times; i++){//On-Stack Replacement
            long createStart = System.nanoTime();
            WithoutFinalizationV3 o = new WithoutFinalizationV3();
            createTime += System.nanoTime() - createStart;
            oarray[i] = o;
        }
        
        for(int i=0; i<times; i++){//On-Stack Replacement
            ReferenceQueue<WithoutFinalizationV3> queue = new ReferenceQueue<>();
            PhantomReference<WithoutFinalizationV3> rf = new PhantomReference<>(
                    oarray[i], queue);
            Object x = null;
            oarray[i] = null;//explicitly clear reference
            
            long destroyStart = System.nanoTime();
            System.gc();//advise JVM to do GC
            Thread.sleep(0, 1000);
            do{
                x = queue.poll();
            }while(x == null);
            //only need this time point
            destroyTime += System.nanoTime() - destroyStart;
            //indicator that code is running instead of stuck
            System.out.println(i + " Done");
        }
        
        System.out.println("WithoutV3 createTime="+createTime/times);
        System.out.println("WithoutV3 destroyTime="+destroyTime/times);
    }
}

55+8081948=8082003 ns,在大量对象中回收一个确实比较费时。

finalize()方法的结果是:51+8426974=8427025 ns

V4

这个版本改成创建一个对象销毁一个的方式,避免批量创建过多对象。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
public class WithoutFinalizationV4 {

    public static void main(String[] args) throws Exception {
        
        int times = 30*1000;
        long createTime = 0;
        long destroyTime = 0;
        
        for(int i=0; i<times; i++){//On-Stack Replacement
            long createStart = System.nanoTime();
            WithoutFinalizationV4 o = new WithoutFinalizationV4();
            createTime += System.nanoTime() - createStart;
            
            ReferenceQueue<WithoutFinalizationV4> queue = new ReferenceQueue<>();
            PhantomReference<WithoutFinalizationV4> rf = new PhantomReference<>(
                    o, queue);
            
            Object x = null;
            o = null;//explicitly clear reference
            long destroyStart = System.nanoTime();
            System.gc();//advise JVM to do GC
            Thread.sleep(0, 1000);//avoid GC strikes
            do{
                x = queue.poll();
            }while(x == null);
            //only need this time point
            destroyTime += System.nanoTime() - destroyStart;
            //indicator that code is running instead of stuck
            System.out.println(i + " Done");
        }
        
        System.out.println("WithoutV4 createTime="+createTime/times);
        System.out.println("WithoutV4 destroyTime="+destroyTime/times);
    }
}

这次的成绩相对V2版的提高不少:632+3006601=3007233 ns

finalize()方法的结果是:921+3158128=3159049 ns

甩开一切包袱,加上所有Buff,看能跑多快!以这个版本为蓝本,先注释掉销毁对象的部分,然后运行的时候加-Xcomp参数,测量了一下创建一个简单对象最快需要多少时间,得到的最好结果是21 ns:tada:

结论

结论就是没有结论:disappointed:

大佬当时应该是在JRE5测的,至于JRE8有没有优化销毁有finalize()方法的对象就不清楚了,因为我们的测试误差太大了。

如果你有更好的办法,请留言赐教:watermelon:


:clock9:上次更新: 2021-05-21