2015年4月5日 星期日

理解 Finalizer

原文網址：https://plumbr.eu/blog/debugging-to-understand-finalizer

這篇文章涵蓋了一個 Java 的內建功能：Finalizer。這個功能實際上廣為人知卻也鮮為人知，取決於你是否仔細看過 java.lang.Object。在 java.lang.Object 中有一個叫做 finalize() 的 method。它沒有實際的內容，但是它的威能與危險程度都取決於 JVM 內部如何處置這個 method。

當 JVM 偵測到 class 有 finalize() 這個 method，黑魔法就開始了。所以，我們來弄一個有不同 finalize() 的 class，這樣我們就能知道在這種狀況下 JVM 會如何處理這個 object。

可 finalize 的 class 範例

import java.util.concurrent.atomic.AtomicInteger;

class Finalizable {
    static AtomicInteger aliveCount = new AtomicInteger(0);

    Finalizable() {
        aliveCount.incrementAndGet();
    }

    @Override
    protected void finalize() throws Throwable {
        Finalizable.aliveCount.decrementAndGet();
    }

    public static void main(String args[]) {
        for (int i = 0;; i++) {
            Finalizable f = new Finalizable();
            if ((i % 100_000) == 0) {
                System.out.format("After creating %d objects, %d are still alive.%n", new Object[] {i, Finalizable.aliveCount.get() });
            }
        }
    }
}

這個程式在一個無窮迴圈中建立新的 object。這些 object 用 aliveCount 這個 static 變數來追蹤已經創造出來的 instance 數量。當建立一個新的 instance 時，aliveCount 會增加；在 GC 之後呼叫 finalize()，aliveCount 就會減少。

你覺得這段程式會有什麼結果？如果新建立的 object 沒有被 reference，那應該馬上變成可被 GC 的候選人。所以，你可能期望這個程式會一直跑下去，然後有類似這樣的輸出結果：

After creating 345,000,000 objects, 0 are still alive.
After creating 345,100,000 objects, 0 are still alive.
After creating 345,200,000 objects, 0 are still alive.
After creating 345,300,000 objects, 0 are still alive.

真實情況跟你的期望完全不一樣。以我的 Mac OS X + JDK 1.7.0_51 為樣本，程式在大約 1.2M 個 object 建立之後就炸了 java.lang.OutOfMemoryError: GC overhead limitt exceeded。

After creating 900,000 objects, 791,361 are still alive.
After creating 1,000,000 objects, 875,624 are still alive.
After creating 1,100,000 objects, 959,024 are still alive.
After creating 1,200,000 objects, 1,040,909 are still alive.
Exception in thread "main" java.lang.OutOfMemoryError: GC overhead limit exceeded
    at java.lang.ref.Finalizer.register(Finalizer.java:90)
    at java.lang.Object.(Object.java:37)
    at eu.plumbr.demo.Finalizable.(Finalizable.java:8)
    at eu.plumbr.demo.Finalizable.main(Finalizable.java:19)

GC 行為

要搞清楚發生什麼事情，我們必須觀察程式在執行期的樣子。所以我們加上 -XX:+PrintGCDetails 參數來執行程式：

[GC [PSYoungGen: 16896K->2544K(19456K)] 16896K->16832K(62976K), 0.0857640 secs] [Times: user=0.22 sys=0.02, real=0.09 secs] 
[GC [PSYoungGen: 19440K->2560K(19456K)] 33728K->31392K(62976K), 0.0489700 secs] [Times: user=0.14 sys=0.01, real=0.05 secs] 
[GC-- [PSYoungGen: 19456K->19456K(19456K)] 48288K->62976K(62976K), 0.0601190 secs] [Times: user=0.16 sys=0.01, real=0.06 secs] 
[Full GC [PSYoungGen: 16896K->14845K(19456K)] [ParOldGen: 43182K->43363K(43520K)] 60078K->58209K(62976K) [PSPermGen: 2567K->2567K(21504K)], 0.4954480 secs] [Times: user=1.76 sys=0.01, real=0.50 secs] 
[Full GC [PSYoungGen: 16896K->16820K(19456K)] [ParOldGen: 43361K->43361K(43520K)] 60257K->60181K(62976K) [PSPermGen: 2567K->2567K(21504K)], 0.1379550 secs] [Times: user=0.47 sys=0.01, real=0.14 secs] 
--- cut for brevity---
[Full GC [PSYoungGen: 16896K->16893K(19456K)] [ParOldGen: 43351K->43351K(43520K)] 60247K->60244K(62976K) [PSPermGen: 2567K->2567K(21504K)], 0.1231240 secs] [Times: user=0.45 sys=0.00, real=0.13 secs] 
[Full GCException in thread "main" java.lang.OutOfMemoryError: GC overhead limit exceeded
 [PSYoungGen: 16896K->16866K(19456K)] [ParOldGen: 43351K->43351K(43520K)] 60247K->60218K(62976K) [PSPermGen: 2591K->2591K(21504K)], 0.1301790 secs] [Times: user=0.44 sys=0.00, real=0.13 secs] 
    at eu.plumbr.demo.Finalizable.main(Finalizable.java:19)

從 log 中我們可以看到在幾次 minor GC 清除 Eden 之後，JVM 開始作一堆貴鬆鬆 Full GC 去清除 tenured 跟 old 空間。為什麼會這樣？如果 object 沒有人 reference，不是應該所有 instance 老早在 Eden 就死翹翹了嗎？我們的程式出了什麼問題？

原因就在 GC 的所作所為當中，要瞭解這一點，我們來作一些小變動：移除 finalize()。現在 JVM 認定這個 class 不需要 finalize 了，行為回歸到「正常」。檢視 GC log，我們只看到便宜的 minor GC 一直在運作。

修改後的程式裡，Eden（所有 object 的出生地）中的 object 都沒人 reference，GC 可以很有效率、一次就把整個 Eden 砍掉重練。所以 Eden 馬上就清空了，無窮迴圈也就可以無窮迴圈下去。

另一方面，在原本的程式當中就不是這麼回事。雖然 object 都沒有任何 reference，JVM 為每一個可被 finalize 的 instance 建立各自的 watchdog。這 watchdog 是 Finalizer 的 instance。Finalizer class 會 reference 這些 instance，因為有這 reference 鏈在，所以整團 object 都會存活著。

現在 Eden 已經滿了、所有的 object 也還被 reference，GC 沒有選擇餘地只能把所有東西複製到 Survivor 那裡去。更糟糕的是，如果 Survivor 的剩餘空間有限，就會擴散到 Tenured 去。你可能還記得，GC 在處理 Tenured 是頭完全不一樣的野獸，跟清理 Eden 那種「統統丟掉」的方法相比，付出的代價昂貴非常多。

Finalizer queue

只有在 GC 結束之後，JVM 才會知道除了 Finalizer 以外沒有其他人 reference 到我們的 instance，它就會把所有 Finalizer 指向的 instance 標記成「已經準備好可以處理」的狀態。所以 GC 內部會把所有 Finalizer object 加進 java.lang.ref.Finalizer.ReferenceQueue 這個特別的 queue 中。

只有所有麻煩都搞定，我們的主要 thread 才能進行實際的工作。現在我們對其中一個 thread 特別有興趣：Finalizer daemon thread。你可以用 jstack 作 thread dump 來看一下這個 thread：

My Precious:~ demo$ jps
1703 Jps
1702 Finalizable
My Precious:~ demo$ jstack 1702

--- cut for brevity ---
"Finalizer" daemon prio=5 tid=0x00007fe33b029000 nid=0x3103 runnable [0x0000000111fd4000]
   java.lang.Thread.State: RUNNABLE
    at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
    at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:101)
    at java.lang.ref.Finalizer.access$100(Finalizer.java:32)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:190)
--- cut for brevity ---

從上面這段我們可以看到 Finalizer daemon thread 正在執行中。Finalizer 的責任很單純，用一個無窮迴圈等待新的 instance 出現在 java.lang.ref.Finalizer.ReferenceQueue 這個 queue 裡頭。當 Finalizer thread 偵測到 queue 中有新的 object，它會取出這個 object、呼叫 finalize()、並移除來自 Finalizer 的 reference。所以在下一次 GC 執行 Finalizer，這個 object 就可以被 GC 掉。

於是，我們有兩個無窮迴圈在兩個不同的 thread 上頭運作著。主 thread 忙著製造新的 object；這些 object 都有他們自己名為 Finalizer 的 watchdog、都被 GC 加到 java.lang.ref.Finalizer.ReferenceQueue 中。而 Finalizer thread 正在處理這個 queue、把所有 queue 中的 instance 取出來呼叫他們的 finalize()。

大多數時候，你可以躲過這件事。呼叫 finalize() 完畢的速度應該要比我們產生新的 instance 的速度快。所以在很多情況下，Finalizer thread 可以趕得上、並在下一次 GC 倒入更多 Finalizer 之前清空 queue。這件事情顯然沒有發生在我們的程式中。

為什麼會這樣？Finalizer thread 的執行優先等級比主 thread 低。這代表它能獲得的 CPU 時間較少，讓它無法趕上 object 建立的步調。我們的程式碼就是這麼回事──object 建立的速度比 Finalizer thread 呼叫各個 finalize() 的速度快，導致所有可用的 heap 都被吃光光。結果就是看到老朋友 java.lang.OutOfMemoryError。

如果你還是不相信，拿一個 heap dump 出來看看。舉例來說，當我們的程式啟動時加這個參數：-XX:+HeapDumpOnOutOfMemoryError，會在 Eclipse MAT Dominator Tree 看到這張圖：

從這張圖可以看到，64M 大的 heap 幾乎都被 Finalizer 給塞滿。

結論

可 finalize object 的生命週期跟標準行為是完全不同的：

  1. JVM 建立 可 finalize class 的 instance。
  2. JVM 建立 java.lang.ref.Finalizer 的 instance，指向我們新建立的 instance。
  3. java.lang.ref.Finalizer 會保有剛剛建立的 java.lang.ref.Finalizer instance。這會阻擋下一次 minor GC 收割我們的 object、使它保持在存活的狀態。
  4. minor GC 無法清空 Eden，並延伸到 Survivor 與/或 Tenured 空間。
  5. GC 判定這些 object 有 finalize 的資格，把它們加到 java.lang.ref.Finalizer.ReferenceQueue 中。
  6. Finalizer thread 會處理 queue，一個接著一個取出 object 然後呼叫它們的 finalize()。
  7. finalize() 被呼叫之後，Finalizer thread 把 Finalizer class 中的 reference 移除，所以下一次 GC 時，object 就有被 GC 掉的資格。
  8. Finalizer thread 會跟我們的主 thread 競爭，但是它的優先等級比較低，所以永遠趕不上。
  9. 程式把所有資源吃乾抹淨，炸了 OutOfMemoryError。

這個故事告訴我們什麼？下次當你認為 finalize() 會比一般的清除、teardown 或是 finally block 還要優先執行時，再想一下吧。你可能會對你製造出來的乾淨程式碼感到欣慰，但是 queue 中不斷增加的 可 finalize object 會塞爆你的 tenured 與 old generation 空間。這意味著你需要重新想一想。

分類： ,
於 07:07

沒有留言:

張貼留言

訂閱： 張貼留言 (Atom)