gRPC(Go)でタイムアウト時にio.EOFエラーになる件を調査した
WEB+DB PRESS Vol.110のgRPC特集がおもしろくて手を動かしながら読んでいる。
タイムアウト設定の事も書かれていて、そこに
設定した期限を過ぎた場合、クライアントスタブは応答を待ち受けるのをやめてステータスコードDeadlineExceeded(4)として処理を終了します。
とあったので試したところ、想定と異なった挙動になったのでメモしておく。
現象
一部省略するが、メインとなるコードは下記である。
c := pb.NewFileServiceClient(conn)
ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
defer cancel()
stream, err := c.Upload(ctx)
if err != nil {
log.Fatalf("Could not upload file: %v.", err)
}
buf := make([]byte, 1000*1024)
for {
n, err := fs.Read(buf)
if err == io.EOF {
break
} else if err != nil {
log.Fatalf("Could not read file: %v.", err)
}
if err := stream.Send(&pb.FileRequest{Name: filepath.Base(name), Data: buf[:n]}); err != nil {
log.Fatalf("Could not send file: %v.", err)
}
}
res, err := stream.CloseAndRecv()
if err != nil {
log.Fatalf("Could not receive response file: %v.", err)
}
この時、私は stream.Send の部分で DeadlineExceeded エラーが返ると期待していたが実際は io.EOF エラーだった。
調査
気になったのでgrpc-goのコードを辿って調査した。
長くなるので重要だと思った箇所を記載する。
また、私の解釈としてStreaming RPCには接続保持側とストリーミング通信側があると解釈しているので2つに分けて記載する。
例えば上記コードで言うと Upload() が接続保持側で Send() がストリーミング通信側である。
接続保持側
Contextのハンドリングをしているのはこちら側
ctx.Done()をハンドリングしている所。- stream.go#L323
- まずここで
contextからタイムアウトの通知を受け取る。 - そして
cs.finish(toRPCErr(ctx.Err()))が実行される。 - ここで渡されているエラーは
DeadlineExceededである。
- まずここで
- stream.go#L323
CloseStream()- stream.go#L928
- ここで
ClientTransportのStreamを閉じている。 - 実装は
internal/transport/http2_client.goにある。
- ここで
- stream.go#L928
s.swapState(streamDone)- internal/transport/http2_client.go#L698
Streamはstateを持っている。- その
Streamを Doneに書き換えている。 stateはWriteが開始される前に見るだけなのでDoneに書き換えてもWrite中の処理を止めることはできない。
- internal/transport/http2_client.go#L698
close(s.done)- internal/transport/http2_client.go#L751
- Write中の処理を止めるため
close(s.done)を行う。
- Write中の処理を止めるため
- internal/transport/http2_client.go#L751
ここまでで接続保持側の終了処理が完了。
ストリーミング通信側
SendMsg()- stream.go#L663
Sendが呼んでいる関数。
- stream.go#L663
Write()- stream.go#L828
- ここから
internal/transport/http2_client.goに飛ぶ。
- ここから
- stream.go#L828
if s.getState() != streamActive- internal/transport/http2_client.go#L822
stateがActiveでない場合はここに入ってerrStreamDoneが返る。- ここに入るのはWrite開始前の場合。
- internal/transport/http2_client.go#L822
get- internal/transport/http2_client.go#L840
- Write中の場合はここに来る。
- ここから
internal/transport/flowcontrol.goに飛ぶ。
- internal/transport/http2_client.go#L840
case <-w.done- internal/transport/flowcontrol.go#L62
- 接続保持側で
close(s.done)するとここに入ってerrStreamDoneが返る。
- 接続保持側で
- internal/transport/flowcontrol.go#L62
上記のように DeadlineExceeded ではないエラーが返り終了する。
ストリーミング通信側はContextを見るのではなく、接続保持側からの操作によって終了する。
解決策
Send でエラーが返ってきた場合、 Fatal 等で終了させずに break させて CloseAndRecv() まで実行してエラーハンドリングを行うと良い。
Send のエラーは警告くらいの気持ちで Print だけしておけば良いと思う。
for { n, err := fs.Read(buf) if err == io.EOF { break } else if err != nil { log.Fatalf("Could not read file: %v.", err) } if err := stream.Send(&pb.FileRequest{Name: filepath.Base(name), Data: buf[:n]}); err != nil { log.Printf("Could not send file: %v.", err) break } } res, err := stream.CloseAndRecv() if err != nil { log.Fatalf("Could not receive response file: %v.", err) }
変更箇所は2行。
if err := stream.Send(&pb.FileRequest{Name: filepath.Base(name), Data: buf[:n]}); err != nil {
- log.Fatalf("Could not send file: %v.", err)
+ log.Printf("Could not send file: %v.", err)
+ break
}
するとこんな感じでログが出る。
2019/04/29 08:18:57 Could not send file: EOF. 2019/04/29 08:18:57 Could not receive response file: rpc error: code = DeadlineExceeded desc = context deadline exceeded. exit status 1
これでタイムアウトのときに DeadlineExceeded が返るようになった。
まとめ
- タイムアウトだった場合でも
Send()のエラーはio.EOFが返る。 Send()でエラーが出てもそこで終了せずにCloseAndRecv()まで実行してエラーを確認。- タイムアウトの場合は
CloseAndRecv()のエラーでDeadlineExceededエラーが取れる。
私はgRPCを仕事でも使ったのだが、protoファイルを書くだけでサーバのインタフェースとクライアントのAPIコール関数を生成してくれる。
サーバはインタフェースの実装を書くだけだし、クライアントは関数を呼び出す感覚でAPIコールができる。
これはすごく楽なのではないだろうか。
特にマイクロサービスアーキテクチャを採用している場合にはおすすめです!