在 Go 中發現競態條件 (Race Conditions)
當我意識到我一直在處理和解決的問題有一個專有名詞描述的時候,我總會覺得這事十分有趣。這次出現這種情況的是競爭條件(Race Conditions)。當你處理多個 routine 共享某類資源的時候,不可避免的需要考慮到這個。如果你未曾在你的程式碼中考慮過這個問題,現在就是一個不錯的時候。
競爭條件是:當兩個或兩個以上的 routines 訪問相同資源的時候,例如一個變數或者結構體,並且在不考慮其他 Gorutines 的情況下對資源進行讀/寫。這類程式碼能夠造成你所能見到的最令人頭疼,最隨機的 bugs。通常需要大量的日誌和一些運氣才能找到這些型別的錯誤。這麼多年來,我完善了我的日誌的技能,以便識別這些問題。
Go 工具套件在 Go 版本 1.1 引入了一個競態檢測工具(race detector)。這個競態檢測工具是在編譯流程中內建到你程式的程式碼。一旦你的程式開始執行,它能夠發現和報告任何他所檢測到的競態情況。 這是非常棒的功能, 為識別缺陷程式碼做出了非常重要的工作。
讓我們寫一個非常的簡單的包含競態條件內建競態檢測程式碼的程式。
package main import ( "fmt" "sync" ) var Wait sync.WaitGroup var Counter int = 0 func main() { for routine := 1; routine <= 2; routine++ { Wait.Add(1) go Routine(routine) } Wait.Wait() fmt.Printf("Final Counter: %d\n", Counter) } func Routine(id int) { for count := 0; count < 2; count++ { value := Counter value++ Counter = value } Wait.Done() }
這個程式看起來沒有問題。它建立了兩個協程,每一個協程都會增加全域性變數 Counter 兩次。當他們都執行結束後,程式顯示全域性變數 Counter 的值。當我執行這個程式的時候,他會顯示正確答案 4。所以這個程式工作正常,但真的嗎?
讓我們通過 Go 競態檢測執行這個程式碼,看看它會發現什麼? 在程式碼所在的目錄開啟終端,以 -race 引數編譯程式碼。
go build -race
然後程式輸出
================== WARNING: DATA RACE Read by goroutine 5: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:29 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Previous write by goroutine 4: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:33 +0x65 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Goroutine 5 (running) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:17 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 Goroutine 4 (finished) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:17 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 ================== Final Counter: 4 Found 1 data race(s)
看起來,工具在程式碼中檢測到競爭條件。如果你檢視上面的競爭條件報告,你會看到針對程式的輸出。全域性變數 Counter 的值是 4。這就是這類的 bug 的難點所在,程式碼大部分情況是工作正常的,但錯誤的情況會隨機產生。競爭檢測告訴我們隱藏在程式碼中的糟糕問題。
警告報告告訴我們問題發生的準確位置:
Read by goroutine 5: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:29 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f value := Counter Previous write by goroutine 4: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:33 +0x65 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Counter = value Goroutine 5 (running) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:17 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 go Routine(routine)
你能發現競爭檢測器指出兩行讀和寫全域性變數 Counter 的程式碼。同時也指出生成協程的程式碼。
讓我們對程式碼進行簡單修改,讓競爭情況更容易暴露出來。
package main import ( "fmt" "sync" "time" ) var Wait sync.WaitGroup var Counter int = 0 func main() { for routine := 1; routine <= 2; routine++ { Wait.Add(1) go Routine(routine) } Wait.Wait() fmt.Printf("Final Counter: %d\n", Counter) } func Routine(id int) { for count := 0; count < 2; count++ { value := Counter time.Sleep(1 * time.Nanosecond) value++ Counter = value } Wait.Done() }
我在迴圈中增加了一個納秒的暫停。這個暫停正好位於協程讀取全域性變數 Couter 儲存到本地副本之後。讓我們執行這個程式看看在這種修改之後,全域性變數 Counter 的值是什麼?
Final Counter: 2
迴圈中的暫停導致程式的失敗。Counter 變數的值不再是 4 而是 2。發生了什麼? 讓我們深挖程式碼看看為什麼這個納秒的暫停會導致這個 Bug。
在沒有暫停的情況下,程式碼執行如下圖:
沒有暫停的情況下,第一個協程被生成,並且完成執行,緊接著第二個協程才開始執行。這就是為什麼程式看起來像正確執行的原因,因為它在我的電腦上執行速度非常快,以至於程式碼自行排隊執行。
讓我們看看在有暫停的情況下,程式碼如何執行:
上圖已經展示了所有必要的資訊,因此我就沒有把他全部畫出來。這個暫停導致執行的兩個協程之間進行了一次上下文切換。這次我們有一個完全不同的情況。讓我們看看圖中展示的程式碼:
value := Counter time.Sleep(1 * time.Nanosecond) value++ Counter = value
在每一次迴圈的迭代過程中,全域性變數 Counter 的值都被暫存到本地變數 value,本地的副本自增後,最終寫回全域性變數 Counter。如果這三行程式碼在沒有中斷的情況下,沒有立即執行,那麼程式就會出現問題。上面的圖片展示了全域性變數 Counter 的讀取和上下文切換是如何導致問題的。
在這幅圖中,在被協程 1 增加的變數被寫回全域性變數 Counter 之前,協程 2 被喚醒並讀取全域性變數 Counter。實質上,這兩個協程對全域性Counter變數執行完全相同的讀寫操作,因此最終的結果才是 2。
為了解決這個問題,你也許認為我們只需要將增加全域性變數 Counter 的三行程式碼改寫減少到一行即可。
package main import ( "fmt" "sync" "time" ) var Wait sync.WaitGroup var Counter int = 0 func main() { for routine := 1; routine <= 2; routine++ { Wait.Add(1) go Routine(routine) } Wait.Wait() fmt.Printf("Final Counter: %d\n", Counter) } func Routine(id int) { for count := 0; count < 2; count++ { Counter = Counter + 1 time.Sleep(1 * time.Nanosecond) } Wait.Done() }
當我們執行這個版本的程式碼的時候,我們會再次得到正確的結果:
Final Counter: 4
如果我們啟動競爭檢測來執行該程式碼,上面出現的問題應該會消失:
go build -race
並且輸出為:
================== WARNING: DATA RACE Write by goroutine 5: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:30 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Previous write by goroutine 4: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:30 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Goroutine 5 (running) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:18 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 Goroutine 4 (running) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:18 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 ================== Final Counter: 4 Found 1 data race(s)
然而,在這三十行程式碼的程式中,我們仍然檢測到一個競爭條件。
Write by goroutine 5: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:30 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Counter = Counter + 1 Previous write by goroutine 4: main.Routine() /Users/bill/Spaces/Test/src/test/main.go:30 +0x44 gosched0() /usr/local/go/src/pkg/runtime/proc.c:1218 +0x9f Counter = Counter + 1 Goroutine 5 (running) created at: main.main() /Users/bill/Spaces/Test/src/test/main.go:18 +0x66 runtime.main() /usr/local/go/src/pkg/runtime/proc.c:182 +0x91 go Routine(routine)
使用一行程式碼進行增加操作的程式正確地運行了。但為什麼程式碼仍然有一個競態條件? 不要被我們用於遞增 Counter 變數的一行Go程式碼所欺騙。讓我們看看這一行程式碼生成的彙編程式碼:
0064 (./main.go:30) MOVQ Counter+0(SB),BX ; Copy the value of Counter to BX 0065 (./main.go:30) INCQ ,BX; Increment the value of BX 0066 (./main.go:30) MOVQ BX,Counter+0(SB) ; Move the new value to Counter
實際上是執行這三行彙編程式碼增加 counter 變數。他們十分詭異地看起來像最初的 Go 程式碼。上下文切換可能發生在這三行彙編的中的任意一行後面。儘管這個程式正常工作了,但嚴格來說,Bug 仍然存在。
儘管我使用的例子非常簡單,它還是體現發現這種 Bug 的複雜性。任何一行由 Go 編譯器產生的彙編程式碼都有可能因為下文切換而停止執行。我們的 Go 程式碼也許看起來能夠安全地訪問資源,實際上底層彙編程式碼可能漏洞百出。
為了解決這類問題,我們需要確保讀寫全域性變數 Counter 總是在任何其他協程訪問該變數之前完成。管道(channle)能夠幫助我們有序地訪問資源。這一次,我會使用一個互斥鎖(Mutex):
package main import ( "fmt" "sync" "time" ) var Wait sync.WaitGroup var Counter int = 0 var Lock sync.Mutex func main() { for routine := 1; routine <= 2; routine++ { Wait.Add(1) go Routine(routine) } Wait.Wait() fmt.Printf("Final Counter: %d\n", Counter) } func Routine(id int) { for count := 0; count < 2; count++ { Lock.Lock() value := Counter time.Sleep(1 * time.Nanosecond) value++ Counter = value Lock.Unlock() } Wait.Done() }
以競態檢測的模式,編譯程式,檢視執行結果:
go build -race ./test Final Counter: 4
這一次,我們得到了正確的結果,並且沒有發現任何競態條件。這個程式是沒有問題的。互斥鎖保護了在 Lock 和 Unlock 之間的程式碼,確保了一次只有一個協程執行該段程式碼。
你可以通過以下文章學習更多例子,更好地理解 Go 競態檢測器:
http://blog.golang.org/race-detector
如果你使用了多個協程,那麼使用競態檢測器測試你的程式碼是個不錯的建議。它會在單元測試和質量保證測試中,為你節省大量的時間和麻煩。Go 開發人員能有這樣的工具是很幸運地,所以值得學習一下。