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コールができる。
これはすごく楽なのではないだろうか。
特にマイクロサービスアーキテクチャを採用している場合にはおすすめです!