golan raceについて試してみた

-raceをつけることで、競合チェックができる

race.go

package main

import "fmt"

func main() {
	c := make(chan bool)
	m := make(map[string]string)
	go func() {
		m["1"] = "a" // First conflicting access.
		c <- true
	}()
	m["2"] = "b" // Second conflicting access.
	<-c
	for k, v := range m {
		fmt.Println(k, v)
	}
}

結果

$ go run -race race.go 
==================
WARNING: DATA RACE
Write at 0x00c00011c180 by goroutine 7:
  runtime.mapassign_faststr()
      /usr/local/Cellar/go/1.14.2_1/libexec/src/runtime/map_faststr.go:202 +0x0
  main.main.func1()
      /Users/nagasaki/development/go/src/race/race.go:9 +0x5d

Previous write at 0x00c00011c180 by main goroutine:
  runtime.mapassign_faststr()
      /usr/local/Cellar/go/1.14.2_1/libexec/src/runtime/map_faststr.go:202 +0x0
  main.main()
      /Users/nagasaki/development/go/src/race/race.go:12 +0xc6

Goroutine 7 (running) created at:
  main.main()
      /Users/nagasaki/development/go/src/race/race.go:8 +0x97
==================
2 b
1 a
Found 1 data race(s)
exit status 66

参考

golang Data Race detector

日本語訳(2020/5/2４時点では、なんとかコピペ翻訳して、自分解説もしてみた。少しずつ更新、加筆してみたい）見出しは、### を青バックに、###にしたけど、原文ではh2なので、## に直そうかな。

イントロ

データレースは、並行システムのバグの中で最も一般的でデバッグの難しいタイプの一つです。データ競合は、2つのゴルーチンが同時に同じ変数にアクセスし、アクセスのうち少なくとも1つが書き込みである場合に発生します。詳細については、「Go Memory Model」を参照してください。

ここでは、クラッシュやメモリ破損につながるデータ競合の例を示します。

func main() {
	c := make(chan bool)
	m := make(map[string]string)
	go func() {
		m["1"] = "a" // First conflicting access.
		c <- true
	}()
	m["2"] = "b" // Second conflicting access.
	<-c
	for k, v := range m {
		fmt.Println(k, v)
	}
}

使用方法

このようなバグを診断するのに役立つように、Goにはデータ競合検出器が組み込まれています。これを使用するには、go コマンドに -race フラグを追加します。

レポートフォーマット

競合検出器は、プログラム内でデータ競合を見つけると、レポートを表示します。レポートには、競合するアクセスのスタックトレースと、関係するゴローチンが作成されたスタックが含まれています。以下に例を示します。

WARNING: DATA RACE
Read by goroutine 185:
  net.(*pollServer).AddFD()
      src/net/fd_unix.go:89 +0x398
  net.(*pollServer).WaitWrite()
      src/net/fd_unix.go:247 +0x45
  net.(*netFD).Write()
      src/net/fd_unix.go:540 +0x4d4
  net.(*conn).Write()
      src/net/net.go:129 +0x101
  net.func·060()
      src/net/timeout_test.go:603 +0xaf

Previous write by goroutine 184:
  net.setWriteDeadline()
      src/net/sockopt_posix.go:135 +0xdf
  net.setDeadline()
      src/net/sockopt_posix.go:144 +0x9c
  net.(*conn).SetDeadline()
      src/net/net.go:161 +0xe3
  net.func·061()
      src/net/timeout_test.go:616 +0x3ed

Goroutine 185 (running) created at:
  net.func·061()
      src/net/timeout_test.go:609 +0x288

Goroutine 184 (running) created at:
  net.TestProlongTimeout()
      src/net/timeout_test.go:618 +0x298
  testing.tRunner()
      src/testing/testing.go:301 +0xe8

オプション

GORACE環境変数は、レース検出器のオプションを設定します。フォーマットは以下の通りです。

GORACE="option1=val1 option2=val2"

オプションは以下の通りです。

log_path（デフォルトは標準エラー）:レース検出器は、レポートを log_path.pid という名前のファイルに書き出します。特別な名前 stdout と stderr は、それぞれ標準出力と標準エラーにレポートを書き出します。
exitcode（デフォルト66）。競合が検出された後に終了するときに使用する終了ステータス。
strip_path_prefix (デフォルト ""): 報告されたすべてのファイルからこの接頭辞を削除します。レポートをより簡潔にするために、報告されたすべてのファイルパスからこの接頭辞を取り除きます。
history_size (デフォルトは1):goroutineごとのメモリアクセス履歴は32K * 2**history_size要素です。この値を大きくすると、メモリ使用量の増加を犠牲にして、レポートでの "スタックの復元に失敗しました" エラーを回避することができます。
halt_on_error (デフォルトは0):最初のデータ競合を報告した後にプログラムが終了するかどうかを制御します。
atexit_sleep_ms (default 1000): 最初のデータレースを報告した後にプログラムが終了するかどうかを制御する。終了する前にメインゴローチンでスリープするミリ秒数。

例

$ GORACE="log_path=/tmp/race/report strip_path_prefix=/my/go/sources/" go test -race

Excluding Tests テストを除く（なんだろこれ？意味わからないな）

// +build !race

package foo

// The test contains a data race. See issue 123.
func TestFoo(t *testing.T) {
	// ...
}

// The test fails under the race detector due to timeouts.
func TestBar(t *testing.T) {
	// ...
}

// The test takes too long under the race detector.
func TestBaz(t *testing.T) {
	// ...
}

使い方

開始するには、レース検出器を使用してテストを実行します (go test -race)。競合検出器は実行時に発生する競合のみを検出するので、実行されないコードパスの競合は検出できません。テストのカバレッジが不完全な場合は、現実的な作業負荷の下で -race を使ってビルドされたバイナリを実行することで、より多くのレースを見つけることができるでしょう。

典型的なデータレース

ここでは、代表的なデータレースをいくつか紹介します。これらはすべてレース検出器で検出することができます。

ループカウンターでのレース

func main() {
	var wg sync.WaitGroup
	wg.Add(5)
	for i := 0; i < 5; i++ {
		go func() {
			fmt.Println(i) // Not the 'i' you are looking for.
			wg.Done()
		}()
	}
	wg.Wait()
}

(自分解説：これだと、５回処理が終わったときに、iを出力しようとすると、iが5になっているので、全部5が出力される。下記だと、jは１つ１つのgoroutineの中で使われているローカル変数なので、競合することなく、12345と表示される）
関数リテラル内の変数 i はループで使用されるのと同じ変数なので、ループのインクリメントに合わせて goroutine での読み込みが競合します（このプログラムは通常 01234 ではなく 55555 を表示します）。このプログラムは、変数のコピーを作成することで修正することができます。

func main() {
	var wg sync.WaitGroup
	wg.Add(5)
	for i := 0; i < 5; i++ {
		go func(j int) {
			fmt.Println(j) // Good. Read local copy of the loop counter.
			wg.Done()
		}(i)
	}
	wg.Wait()
}

誤って共有された変数

// ParallelWrite writes data to file1 and file2, returns the errors.
func ParallelWrite(data []byte) chan error {
	res := make(chan error, 2)
	f1, err := os.Create("file1")
	if err != nil {
		res <- err
	} else {
		go func() {
			// This err is shared with the main goroutine,
			// so the write races with the write below.
			_, err = f1.Write(data)
			res <- err
			f1.Close()
		}()
	}
	f2, err := os.Create("file2") // The second conflicting write to err.
	if err != nil {
		res <- err
	} else {
		go func() {
			_, err = f2.Write(data)
			res <- err
			f2.Close()
		}()
	}
	return res
}

修正点は、goroutinesに新しい変数を導入することです（:=の使用に注意してください）。

			...
			_, err := f1.Write(data)
			...
			_, err := f2.Write(data)
			...

保護されていないグローバル変数

以下のコードが複数の goroutine から呼び出されると、サービスマップ上で競合が発生します。同じマップの同時読み書きは安全ではありません。

var service map[string]net.Addr

func RegisterService(name string, addr net.Addr) {
	service[name] = addr
}

func LookupService(name string) net.Addr {
	return service[name]
}

コードを安全にするには、アクセスをミューテックスで保護します。
（自分解説：でたミューテックス！よくわかってない）

var (
	service   map[string]net.Addr
	serviceMu sync.Mutex
)

func RegisterService(name string, addr net.Addr) {
	serviceMu.Lock()
	defer serviceMu.Unlock()
	service[name] = addr
}

func LookupService(name string) net.Addr {
	serviceMu.Lock()
	defer serviceMu.Unlock()
	return service[name]
}

原始的な保護されていない変数

この例のように、プリミティブ型の変数（bool、int、int64 など）でもデータ競合が発生することがあります。

type Watchdog struct{ last int64 }

func (w *Watchdog) KeepAlive() {
	w.last = time.Now().UnixNano() // First conflicting access.
}

func (w *Watchdog) Start() {
	go func() {
		for {
			time.Sleep(time.Second)
			// Second conflicting access.
			if w.last < time.Now().Add(-10*time.Second).UnixNano() {
				fmt.Println("No keepalives for 10 seconds. Dying.")
				os.Exit(1)
			}
		}
	}()
}

このような「無害な」データ競合であっても、メモリアクセスの非原子性、コンパイラの最適化への干渉、プロセッサメモリへのアクセスの順序変更の問題などにより、デバッグが困難な問題が発生することがあります。

この競合に対する一般的な対処法は、チャネルまたはミューテックスを使用することです。ロックフリーな動作を維持するために、sync/atomic パッケージを使用することもできます。

type Watchdog struct{ last int64 }

func (w *Watchdog) KeepAlive() {
	atomic.StoreInt64(&w.last, time.Now().UnixNano())
}

func (w *Watchdog) Start() {
	go func() {
		for {
			time.Sleep(time.Second)
			if atomic.LoadInt64(&w.last) < time.Now().Add(-10*time.Second).UnixNano() {
				fmt.Println("No keepalives for 10 seconds. Dying.")
				os.Exit(1)
			}
		}
	}()
}

Supported Systems

レースディテクタは、linux/amd64、linux/ppc64le、linux/arm64、freebsd/amd64、netbsd/amd64、darwin/amd64、windows/amd64で動作します。

ランタイムオーバーヘッド

競合検出のコストはプログラムによって異なりますが、一般的なプログラムの場合、メモリ使用量が5～10倍、実行時間が2～20倍になることがあります。

競合検出器は現在、ディフェールおよびリカバリ文ごとに8バイトの余分なバイトを割り当てています。これらの余分な割り当ては、goroutineが終了するまで回復されません。これは、長期的に実行されているゴローチンがdeferとrecover呼び出しを定期的に発行している場合、プログラムのメモリ使用量が制限なく増加する可能性があることを意味しています。これらのメモリ割り当ては、runtime.ReadMemStatsやruntime/pprofの出力には表示されません。