前言

這是三篇系列文章中的第三篇。該系列文章提供了一種對 Go 垃圾回收背後的機制和概念的理解。本篇的主要內容是 GC 如何控制自己的步調。

三篇文章的索引:

1) Go 垃圾回收:第一部分 - 概念

2) Go 垃圾回收:第二部分 - GC 追蹤

3) Go 垃圾回收:第三部分 - GC 的步調

簡介

在第二篇文章裏,我向你展示了垃圾回收器的行爲以及如何使用工具查看回收器給你的運行程序帶來的延遲。我帶着你運行了一個真實的 web 應用並向你展示瞭如何生成 GC 追蹤和應用性能分析。接着我還向你展示瞭如何解讀這些工具的輸出,以便你找到提高應用程序性能的方法。

第二篇文章的結論與第一篇相同:如果你減少了堆上的壓力,就可以降低延遲成本,從而提高應用程序的性能。對回收器友好的最佳策略就是減少每個任務所需內存分配的次數或大小。本篇中,我將向你展示步調算法是如何持續找出給定工作壓力下的最優步調的。

併發示例代碼

我將使用位於該鏈接處的代碼:https://github.com/ardanlabs/gotraining/tree/master/topics/go/profiling/trace

這個程序將找出某個特定主題在一組 RSS 新聞摘要文檔中的出現頻率。程序中包含了不同版本的查找算法以測試不同的併發模式。我將主要關注 freqfreqConcurrentfreqNumCPU 這幾個版本。

注:我是在一臺 Macbook Pro 上使用 go1.12.7 運行的代碼,該機配備了一個具有 12 個硬件線程的 Intel i9 處理器。在不同的體系架構、操作系統和 Go 版本下,你會看到不同的結果,但本篇的核心結論應該保持不變。

我首先從 freq 版本開始。它表示這個程序的非併發串行版本,並將爲下文的併發版本提供一個基準。

清單 1

01 func freq(topic string, docs []string) int {
02     var found int
03
04     for _, doc := range docs {
05         file := fmt.Sprintf("%s.xml", doc[:8])
06         f, err := os.OpenFile(file, os.O_RDONLY, 0)
07         if err != nil {
08             log.Printf("Opening Document [%s] : ERROR : %v", doc, err)
09             return 0
10         }
11         defer f.Close()
12
13         data, err := ioutil.ReadAll(f)
14         if err != nil {
15             log.Printf("Reading Document [%s] : ERROR : %v", doc, err)
16             return 0
17         }
18
19         var d document
20         if err := xml.Unmarshal(data, &d); err != nil {
21             log.Printf("Decoding Document [%s] : ERROR : %v", doc, err)
22             return 0
23         }
24
25         for _, item := range d.Channel.Items {
26             if strings.Contains(item.Title, topic) {
27                 found++
28                 continue
29             }
30
31             if strings.Contains(item.Description, topic) {
32                 found++
33             }
34        }
35     }
36
37     return found
38 }

清單 1 展示的是 freq 函數。這個串行版本遍歷一個文件名集合並執行 4 種操作:打開文件、讀取文件、解碼和檢索。它對每個文件執行上述操作,一次一個。

在我的機器上運行這個版本的 freq 時,我得到了如下的結果:

清單 2

$ time ./trace
2019/07/02 13:40:49 Searching 4000 files, found president 28000 times.
./trace  2.54s user 0.12s system 105% cpu 2.512 total

time 的輸出中可以看到,程序處理 4000 個文件用了大約 2.5 秒。能看到垃圾回收在其中所佔的比例當然是很好的,你可以通過查看程序的追蹤結果做到這點。由於這是一個啓動並完成的程序,你可以使用 trace 包生成一個追蹤。

清單 3

03 import "runtime/trace"
04
05 func main() {
06     trace.Start(os.Stdout)
07     defer trace.Stop()

清單 3 展示的是從程序生成追蹤所需的代碼。從標準庫的 runtime 文件夾裏導入 trace 包後,調用 trace.Starttrace.Stop 。將追蹤輸出定向到 os.Stdout 只是簡化了代碼。

有了這段代碼,現在你可以重新編譯和運行這個程序了。不要忘了把標準輸出重定向到一個文件。

清單 4

$ go build
$ time ./trace > t.out
Searching 4000 files, found president 28000 times.
./trace > t.out  2.67s user 0.13s system 106% cpu 2.626 total

運行時間增加了 100 毫秒多一點,但這是意料之中的。追蹤捕捉了每次函數調用,進入和退出,直到微秒精度。重要的是現在有了一個名爲 t.out 的文件,裏面有追蹤數據。

爲了查看追蹤結果,需要使用追蹤工具來運行追蹤數據。

清單 5

$ go tool trace t.out

執行以上命令會啓動 Chrome 瀏覽器並顯示以下內容:

注:追蹤工具使用了 Chrome 瀏覽器內置的工具,所以它只能在 Chrome 裏工作。

圖 1

圖 1 展示的是追蹤工具啓動時顯示的 9 個鏈接。當下最重要的是第一個標着 View trace 的鏈接。點擊之後,你就會看到與下圖類似的畫面:

圖 2

圖 2 展示的是在我的機器上運行程序時的完整追蹤窗口。本篇中,我會重點關注與垃圾回收器相關的部分,即標着 Heap 的第二部分和標着 GC 的第四部分。

圖 3

圖 3 更詳細地展示了追蹤的前 200 毫秒。注意觀察 Heap (綠色和橙色區域)和 GC (底部的藍線)。 Heap 部分向你展示了兩個信息:橙色區域代表在每個微秒時刻對應的堆上正在使用的空間,綠色代表觸發下次回收的堆使用量。這就是爲什麼每當橙色區域到達綠色區域的頂端就會發生一次垃圾回收的原因。藍線表示一次垃圾回收。

在這個版本的程序整個運行過程中,堆上內存使用量一直保持在大約 4 MB。要想查看每次垃圾回收時的統計數據,你可以使用選擇工具在所有藍線周圍繪製一個框。

圖 4

圖 4 展示的是如何使用箭頭工具在藍線周圍繪製藍框。你應該想要框住每一條線。框中的數字表示選中的項目消耗的總時間。上圖中,有接近 316 毫秒(ms,μs,ns)的區域被選中。當所有的藍色線條被選中時,就得到了如下的統計結果:

圖 5

圖 5 顯示所有的藍線都在 15.911 毫秒標記到 2.596 秒標記之間。一共有 232 次垃圾回收,共消耗 64.524 毫秒,平均每次消耗 287.121 微秒。而程序運行需要 2.626 秒,這就意味着垃圾回收只佔總運行時間的 2%。基本上,垃圾回收是運行該程序的一個微不足道的成本。

有了這個基準,可以使用併發算法完成相同的工作,以期加快程序的速度。

清單 6

01 func freqConcurrent(topic string, docs []string) int {
02     var found int32
03
04     g := len(docs)
05     var wg sync.WaitGroup
06     wg.Add(g)
07
08     for _, doc := range docs {
09         go func(doc string) {
10             var lFound int32
11             defer func() {
12                 atomic.AddInt32(&found, lFound)
13                 wg.Done()
14             }()
15
16             file := fmt.Sprintf("%s.xml", doc[:8])
17             f, err := os.OpenFile(file, os.O_RDONLY, 0)
18             if err != nil {
19                 log.Printf("Opening Document [%s] : ERROR : %v", doc, err)
20                 return
21             }
22             defer f.Close()
23
24             data, err := ioutil.ReadAll(f)
25             if err != nil {
26                 log.Printf("Reading Document [%s] : ERROR : %v", doc, err)
27                 return
28             }
29
30             var d document
31             if err := xml.Unmarshal(data, &d); err != nil {
32                 log.Printf("Decoding Document [%s] : ERROR : %v", doc, err)
33                 return
34             }
35
36             for _, item := range d.Channel.Items {
37                 if strings.Contains(item.Title, topic) {
38                     lFound++
39                     continue
40                 }
41
42                 if strings.Contains(item.Description, topic) {
43                     lFound++
44                 }
45             }
46         }(doc)
47     }
48
49     wg.Wait()
50     return int(found)
51 }

清單 6 展示的是 freq 的一個可能的併發版本。這個版本的核心設計模式是使用扇出模式。對於 docs 集合中的每個文件,都會創建一個 goroutine 來處理。如果有 4000 個文檔要處理,就要使用 4000 個 goroutine。這個算法的優點就是它是利用併發性的最簡單方法。每個 goroutine 處理一個且僅處理一個文件。可以使用 WaitGroup 執行等待處理每個文檔的編排,並且原子指令可以使計數器保持同步。

這個算法的缺點在於它不能很好地適應文檔或 CPU 核心的數量。所有的 goroutine 在程序啓動的時候就開始運行,這意味着很快就會消耗大量內存。由於在第 12 行使用了 found 變量,它還導致了緩存一致性的問題。由於每個核心共享這個變量的高速緩存行,這將導致內存抖動。隨着文件或核心數量的增加,這會變得更糟。

有了代碼,現在你可以重新編譯和運行這個程序了。

清單 7

$ go build
$ time ./trace > t.out
Searching 4000 files, found president 28000 times.
./trace > t.out  6.49s user 2.46s system 941% cpu 0.951 total

從清單 7 中的輸出可以看到,現在程序花了 951 毫秒來處理相同的 4000 個文件。這是大約 64% 的性能提升。看一下追蹤結果。

圖 6

圖 6 展示了這個版本的程序在我的機器上運行時是怎樣佔用了比之前多得多的 CPU。圖中的開始部分有很多密集的線條,這是因爲所有的 goroutine 都被創建之後,它們運行並且開始嘗試從堆上分配內存。很快的,前 4 MB 內存被分配了,緊接着就有一個 GC 啓動了。在這次 GC 當中,每個 goroutine 都有時間運行,大部分由於在堆上申請內存而被置於等待狀態。至少有 9 個 goroutine 繼續運行並在 GC 結束時將堆增長到大約 26 MB。

圖 7

圖 7 展示了在首次 GC 的大部分時間裏有很多 goroutine 處於已就緒(Runnable)和運行中(Running)的狀態以及這一幕是如何再次快速發生的。請注意,堆性能概要(profile)看起來不規則並且垃圾回收也不像之前那樣有規律。如果你仔細看,就會發現第二次 GC 幾乎是在第一次 GC 結束之後就立即開始了。

如果選中了所有的垃圾回收,你就能看到下面的一幕:

圖 8

圖 8 顯示圖中所有的藍線都在 4.828 毫秒標記到 906.939 毫秒標記之間。一共有 23 次垃圾回收,共佔用 284.447 毫秒,平均每次佔用 12.367 毫秒。知道程序運行需要 951 毫秒,垃圾回收在整個運行時間裏佔用了大約 34%。

這與串行版本在性能和 GC 時間上有顯著差異。並行運行更多的 goroutine 讓工作時間縮短了大約 64%。代價就是大幅增加了機器上各種資源的佔用。不幸的是,堆上內存的佔用最高達到了大約 200 MB。

有了這個併發的基準,下一個併發算法試圖更有效率的使用資源。

清單 8

01 func freqNumCPU(topic string, docs []string) int {
02     var found int32
03
04     g := runtime.NumCPU()
05     var wg sync.WaitGroup
06     wg.Add(g)
07
08     ch := make(chan string, g)
09
10     for i := 0; i < g; i++ {
11         go func() {
12             var lFound int32
13             defer func() {
14                 atomic.AddInt32(&found, lFound)
15                 wg.Done()
16             }()
17
18             for doc := range ch {
19                 file := fmt.Sprintf("%s.xml", doc[:8])
20                 f, err := os.OpenFile(file, os.O_RDONLY, 0)
21                 if err != nil {
22                     log.Printf("Opening Document [%s] : ERROR : %v", doc, err)
23                     return
24                 }
25
26                 data, err := ioutil.ReadAll(f)
27                 if err != nil {
28                     f.Close()
29                     log.Printf("Reading Document [%s] : ERROR : %v", doc, err)
23                     return
24                 }
25                 f.Close()
26
27                 var d document
28                 if err := xml.Unmarshal(data, &d); err != nil {
29                     log.Printf("Decoding Document [%s] : ERROR : %v", doc, err)
30                     return
31                 }
32
33                 for _, item := range d.Channel.Items {
34                     if strings.Contains(item.Title, topic) {
35                         lFound++
36                         continue
37                     }
38
39                     if strings.Contains(item.Description, topic) {
40                         lFound++
41                     }
42                 }
43             }
44         }()
45     }
46
47     for _, doc := range docs {
48         ch <- doc
49     }
50     close(ch)
51
52     wg.Wait()
53     return int(found)
54 }

清單 8 展示的是 freqNumCPU 版本的程序。該版本的核心設計模式是池模式。由一個基於邏輯處理器數目的 goroutine 池來處理所有的文件。如果有 12 個邏輯處理器可以使用,就使用 12 個 goroutine。這個算法的優點是它從頭到尾保持了資源佔用的一致性。由於使用了固定數量的 goroutine,所以只需要分配那 12 個 goroutine 運行所需的內存。這也解決了高速緩存一致性問題導致的內存抖動。這是因爲第 14 行調用的原子指令只會發生一個很小的固定次數。

該算法的缺點就是它更復雜了。它額外使用了一個 channel 來給 goroutine 池分發工作。要想在每次使用池模式時都爲池子指定一個“正確”數量的 goroutine 是非常複雜的。作爲一個通常的做法,我爲池子啓動了與邏輯處理器相同數量的 goroutine。然後通過壓力測試或者使用生產指標,可以計算出一個最終的池子大小。

有了代碼,現在你可以重新編譯和運行這個程序了。

清單 9

$ go build
$ time ./trace > t.out
Searching 4000 files, found president 28000 times.
./trace > t.out  6.22s user 0.64s system 909% cpu 0.754 total

從清單 9 中的輸出可以看到,現在程序花了 754 毫秒來處理相同的 4000 個文件。程序快了大約 200 毫秒,對於這樣一個小的工作量而言,這是一個很大的提升。看一下追蹤結果。

圖 9

圖 9 顯示了這個版本的程序運行時也同樣使用了我機器上所有的 CPU。仔細看的話,你就會發現一個固定的節奏在這個程序裏又出現了,跟串行版本很像。

圖 10

圖 10 展示的是程序運行前 20 毫秒的核心指標的一個特寫。與串行版本相比,垃圾回收肯定佔用了更長的時間,但是有 12 個 goroutine 同時在運行。使用的堆內存在整個程序的運行當中一直保持在 4 MB 左右,這又與串行版本一樣了。

如果選中了所有的垃圾回收,你就能看到下面的一幕:

圖 11

圖 11 顯示圖中所有的藍線都位於 3.055 毫秒標記到 719.928 毫秒標記之間。共有 467 次垃圾回收,耗時 177.709 毫秒,平均每次花費 380.535 微秒。知道程序運行需要 754 毫秒,這意味着垃圾回收在總的運行時間裏佔了大約 25%,相比另一個併發版本降低了 9%。

這個版本的併發算法看起來可以適應更多的文件和核心。我認爲它增加的複雜性成本是值得的。可以使用列表切片來代替 channel 將每個 goroutine 的任務放到一個桶裏。這必然會增加複雜度,儘管它可以減少由 channel 帶來的延遲成本。雖然隨着文件和核心的增多,這個收益可能會不容忽視,但是它帶來的複雜度成本還是需要衡量的。這是你可以自己嘗試的東西。

結語

我喜歡比較算法的三個版本就是要看看 GC 如何處理每種情況。處理文件所需的內存總量並不隨程序版本而變化,不同的是程序如何分配內存。

當只有一個 goroutine 時,只需要最起碼的 4 MB 堆內存。當程序一次性分派了所有的工作,GC 採取的策略是使堆增長,減少收集的次數,但是每次運行更長的時間。當程序限制了並行處理的文件數量時,GC 又採取了保持一個小堆的策略,增加回收的次數,但是每次運行更少的時間。基本上,GC 採取的每個策略都是爲了使 GC 對程序運行的影響最小。

| Algorithm  | Program | GC Time  | % Of GC | # of GC’s | Avg GC   | Max Heap |
|------------|---------|----------|---------|-----------|----------|----------|
| freq       | 2626 ms |  64.5 ms |     ~2% |       232 |   278 μs |    4 meg |
| concurrent |  951 ms | 284.4 ms |    ~34% |        23 |  12.3 ms |  200 meg |
| numCPU     |  754 ms | 177.7 ms |    ~25% |       467 | 380.5 μs |    4 meg |

就兩個併發版本而言, freqNumCPU 版本帶來的額外好處是更好的處理高速緩存一致性的問題,這很有幫助。然而,每個程序在 GC 上花費的總時間差別不大,大約 284.4 毫秒對大約 177.7 毫秒。有時在我的機器上運行這些程序,這些數字會更加接近。使用 go 1.13.beta1 版本做了一些實驗,我甚至看到這兩個算法運行了相同的時間。這可能意味着新版的 go 有一些改進能夠讓 GC 更好的預測如何運行。

所有這些都讓我有信心在程序運行時拋出大量任務。一個例子就是一個使用 50000 goroutine 的 web 服務,這就是一個本質上與第一個併發算法類似的扇出模式。GC 會研究工作量併爲服務找到最優的步調來避開它。至少對我而言,使用 GC 是值得的,因爲不用去考慮所有這些。

相關文章