ECSへ移行したらマシンリソースを使い果たした問題がnet/httpのhttp.Transportの使い方の誤りにあった話


はじめに

はじめまして。Kyashでサーバサイドエンジニアを担当しているhirobeです。
ブログ記事発信の一環として書かせていただきます。

Kyashでは、約30ほどのマイクロサービスが動いてます。

そのなかで比較的新しいサービスについては開発環境、本番環境ともにAWSのECS(AWSのコンテナオーケストレーションサービス)を利用していますが、数年前から存在するような古いサービスはいまだにEC2で動いているものも多く、それらはECSに移行しつつあります。

検証環境において、あるマイクロサービスをEC2からECSへ移行したところ、接続元のサービスのマシンリソースを使い果たしサービスがかなり不安定になる問題が発生しました。

当初はアプリケーションのコード修正に問題があると皆で調査していたのですが、リソースを使うようなコード修正もありませんでした。半ばあきらめかけていたのですが、偶然私がGoのnet/httpのソースコードを以前から読んでおり1処理の概要を把握していたので、net/httpのhttp.Transportの使い方が問題なのではとふと思いつき解決することができました。

その時の知見を、http.Transportの詳細に触れながら共有したいと思います。
なお、Kyashでは比較的新しいサービスではgRPCを採用していますがまだ少数派です。本記事では、マイクロサービス間通信はHTTP/1.1を想定し、httpsではなくhttpを想定します。

TL;DR

  • Goのクライアント実装では、http.Transportは必ず使いまわしましょう。リクエストごとに初期化していたら今すぐ修正しましょう。
  • 現状問題なくても予期せぬタイミングで将来問題になりえます。今回は、サーバのインフラ構成が変わり、ALBからECSサービスディスカバリーへ移行したタイミングでidleなコネクションが切断されなくなり、クライアント/サーバのリソースが解放されなくなってしまいました。
  • DefaultTransportを使わない場合は、http.Transportを自前で初期化することになりますが、明示的に指定しない構造体フィールドはDefaultTransportと等しくならずゼロ値のままの扱いになるのでちゃんと一つずつ指定しましょう。

何が起きたか

検証環境において、2021/5/19 (水)にサーバ側をECSに移行しました。その後、移行したサービスへ接続するサービスの動作が不安定になったため、dailyでデプロイし直す運用をしていました。その後、2021/6/1 (火)にhttp.Transportを利用するコードに修正に手を加え、解決しました。

下記は、クライアントのgoroutineの数の様子です。
5/19以降グラフが上下しているのはデプロイしているためです。

  • ECS化前: 2000-6000
  • ECS化後:100000 per day(1.2 per second)ほど増える
  • 対応後: 30-40

下記は、クライアントのメモリの様子です。
5/19以降グラフが上下しているのはデプロイしているためです。
mem_stats.allocがheapにallocateしたメモリ、mem_stats.sysがheap,stack含めOSから取得したメモリです。

mem_stats.alloc/mem_stats.sys表記で、

  • ECS化前: 150MB/300MB
  • ECS化後:0.7GB/1.4GB per day(8KB/16KB per second)ほど増える
  • 対応後: 30MB/100MB

http.Transportとは

Goを書く人でも、そもそもhttp.Transportって何?っていう人もそれなりにいるかもしれません。
そういう人は、暗黙的にhttp.DefaultTransportを利用しているのではと思います。

こういうやつです。
ここでhttp.Client初期化時にtransportを渡していますが、とくに指定しないとhttp.DefaultTransportを指定するのと同義になります。

  var request *Request
  transport := &http.Transport{
    MaxIdleConns: 128,
    MaxIdleConnPerHost: 32,
    ...
  }
  client := &http.Client{
    Timeout:   time.Duration(timeout) * time.Second,
    Transport: transport,
  }
  return client.Do(request)

goのソースでいうと、ここです。ソースコメントから引用しちゃいます。

// Transport is an implementation of RoundTripper that supports HTTP,
// HTTPS, and HTTP proxies (for either HTTP or HTTPS with CONNECT).
//
// By default, Transport caches connections for future re-use.
// This may leave many open connections when accessing many hosts.
// This behavior can be managed using Transport's CloseIdleConnections method
// and the MaxIdleConnsPerHost and DisableKeepAlives fields.
//
// Transports should be reused instead of created as needed.
// Transports are safe for concurrent use by multiple goroutines.

Transport is an implementation of RoundTripper です。

RoundTripperは何かでいうと、goのソースでいうとここです。同じく引用すると、

// RoundTripper is an interface representing the ability to execute a
// single HTTP transaction, obtaining the Response for a given Request.
//
// A RoundTripper must be safe for concurrent use by multiple
// goroutines.
.
RoundTrip(*Request) (*Response, error)

とあるように、httpのクライアント処理の根幹部分をほぼ担っているといっても過言ではありません。http.Client自体は実はほとんど仕事してません。

今回のhttp.Transportの使い方のどこに問題があったのか、先に書いてしまうと、「Transports should be reused instead of created as needed.」が守られてませんでした。

つまり、http.Transportは必ず使いまわすべきなのですが、リクエストのたびに初期化していたのです。

この記事では、http.Transportがどのような挙動をしているのかを簡単に紹介した上で、上記を守らないことがいかにやばいことかを実感をもって理解できるようにしたいと思います。

http.Transportの挙動

せっかくなので、ネット上に情報が少なくあまり理解されていないであろうhttp.Transportの設定値や挙動を紹介しながらhttp.Transportを説明したいと思います。

正直、ここは説明が雑です。ちゃんと説明しようとしたら大変です。ある程度詳しい方向けになってしまうと思うので大まかに理解したい人は図が登場する部分までスキップしちゃっていいと思います。

Connectionを要求するとき

  • 利用可能なpoolしているidle connectionがあればそれを利用して返して終了
  • idleConnWait(Hostごとのidle connection取得待ちキュー)2に入れる
    • 他のgoroutineがコネクションを使い終わり、他用途に使える状態になったときに、このキューから取り出し、コネクションを渡してくれる
  • Dialを試みる
    • MaxConnsPerHostの制限にひっかかれば、connsPerHostWait(hostごとのdial実行権限取得待ちキュー。dial未実施のものが入る)に入れてgoroutineとしては一旦終了
      • 他のgoroutineがコネクションを使い終わり、closeし、ホストごとのコネクションが減ったときに、このキューから取り出し、新しい専用goroutineとして以下を起動してくれる
    • 別goroutineにて
      • Dialする(tcp接続する)
      • readBuffer 4KB
      • writeBuffer 4KB
      • go readLoop()
      • go writeLoop()
  • チャネルで待機し、idleConnWaitとDialのどちらか先に取得できたコネクションを返す

上記はgetConnメソッドにて行われます。

難しく見えるかもしれませんが、大雑把に言ってしまえば、idleConnectionがすぐに利用できればそれを使い、そうでない場合は新しく接続しようとする。新しい接続が完了するか、利用可能なidleConnectionが発生すればそれをすぐに利用する

DialよりidleConnWaitからの取得の方が早い場合がありますが、そのときは新規のコネクションをプールにいれるなど試みるので、無駄にはなりません。

readLoop/writeLoopはそれぞれ専用goroutineで起動されるメソッドです。後ほど説明します。

使い終わったConnectionを再利用するとき

  • idleConnWait(Hostごとのidle connection取得待ちキュー)があれば、コネクションをそこに渡してあげて終了
  • MaxIdleConnsPerHostの制限(ホストごとの制限)に引っかかればコネクションは捨てて終了
  • MaxIdleConnsの制限(全体の制限)に引っかかれば最も古いコネクションをcloseして捨てる
    • つまり、今使い終わったばかりのconnectionを優先する
  • コネクションに対してIdleConnTimeoutのタイマーを設定しつつ、poolする。

実は、MaxIdleConnsPerHostのデフォルト値は2です。これはものすごく小さい値に思えるかもしれませんが、そんなことはありません。
connectionを使い終わった時、idleConnWaitがあればすぐにconnectionを渡す実装になっているためです。

やけに凝った実装になっていると思います。

これは完全に推測ですが、http.Transportの設計者はidle connectionのプール数に依存せずに安定的にコネクションを提供できる仕組みを作ろうとしたのではと思ってます。

コネクションプール数を大きくしそれをできるだけ利用しようとする戦略の場合、コネクションプールでまかなえる間は安定して高速ですがリクエストが増加し、コネクションプールでまかなえなくなった途端にパフォーマンスが劣化します。3

一方、http.Transportの実装ではコネクションプールでまかなえるかに依存せず、利用できるコネクションが安定的に存在することになります。

また、副次的な効果かもしれませんが、コネクションプール内が新しいコネクションにrefreshされる機会も増えます。4

readLoop/writeLoop

  • writeLoop
    • 無限ループで、渡されたhttp.RequestをひたすらsocketにWriteするだけ
    • Writeでerrorおきるかコネクションがcloseされるまでずっとループする
  • readLoop
    • 無限ループの最初で_, err := pc.br.Peek(1)5している。
      • ソケットからデータがくるかconnectionがcloseされて動き始める。それまでblock
    • http.Responseへの読み込みをレスポンスヘッダまで実行する。
      • コネクションがcloseされていたり、読み込みに失敗したら終了
    • Response.BodyをアプリケーションがReadでエラーを出すか、最後まで読むか、Closeするまで待機し、終わったらidleConnectionに入れようとする。
      • ただし、入れようとするのは、正常に書き込みやら読み込みやらが終わった場合のみ。正常に終わらなかったらreadLoop 終了
      • アプリケーションには既に処理が戻っていることに注意してください。アプリケーションは例えばステータスコードを確認できますし、(まだクラアントサーバに全て届いておらずブロックされる可能性はありますが)レスポンスボディを読むことができます。
    • idleConnectionから取り出され仕事するまではデータがこないので無限ループの最初でずっと待つことになる

writeLoop/readLoopともに言えることですが、エラーがおきるとコネクションをcloseし、他方のgoroutineも終了されるような制御がされています。

Goだとわりとこのような処理が多い気がしますが、慣れていないと混乱すると思います。writeLoop/readLoopそれぞれが専用のgoroutineを持ちます。

ポイントとしては、writeLoop/readLoopも自分自身がいつのリクエストの処理をしているのか全く意識していないということです。実際にリクエストに利用されている最中かもしれませんし、コネクションプールに入っているかもしれません。「何のためなのかわからないけどひたすらsocketをwrite/readしていくマシン」のようなイメージです。

goroutineがお互いに協調しあっており、かなり複雑です。この記事を書くにあたって改めてソースコードを眺めたところ、ソースコードのコメントにgoroutineの協調の仕方について誤りがあり修正PRをあげたりもしました。

図にしてみると

http.Transportをちゃんと使いまわしている場合はこんなイメージです。

> 8KBとあるのは利用メモリ8KB以上という意味です。readBuffer/writeBufferだけでそれぞれ4KBあるのでこう書いてますが実際にはもっと利用されています。
readLoopwriteLoopはそれぞれ専用goroutineで実行されます。
下にあるApplicationレイヤのロジックからnet/httpの処理が呼ばれる様子となってます。

次に、リクエストを行う度に生成している場合です。

リクエストするたびにhttp.Transportが生まれ、要素一個のidleConnectionがサーバから明示的にコネクションをcloseされるまで永遠に残ります。また上記で紹介したhttp.Transportの難しい制御や実装工夫の意味はすべて無駄となってます。

ECSへの移行で何が起こったのか

ここまで複雑な話を読んでいただき、ありがとうございます。

http.Transportを使い回さないとリソースがleakするのはわかったけど、クライアントの接続先サーバがECSになったのとどう関係あるんだ」という疑問が残っている状態だと思います。

事情が複雑なのです。ここまで説明してやっと説明できるようになりました。その疑問に答えていきたいと思います。

まず、クライアントのhttp.Transportはどのような定義だったのかというと以下です。

transport := &http.Transport{
        MaxIdleConns:        128,
        MaxIdleConnsPerHost: 32,
}

非常にレガシーなマイクロサービスなので、このように設定している経緯を知っているメンバーは在籍していないのですが、おそらく2つ勘違いをしていたのだと思います。

既出ですが、デフォルトのMaxIdleConnsPerHost=2は少ないように思えてしまいますが全く問題ないです。
それを「idleconnectionをホストごとに2つしか持たないってやばいぞ」となってDefaultTransportを使わずにhttp.Transportを明示的に指定するようになったのかと思います。
勘違いして欲しくないのはMaxIdleConnsPerHost=32でも全然問題ないです。指定することによってhttp.Transportを毎回初期化するというミスを誘発した点が問題です。
ただ、これは正直しょうがないと思います。ソースを読んでない人はそう思うでしょう。

もう一点は、http.Transportの指定しないフィールドはDefaultTransportと同等になるだろうと思ったのでしょう。これは誤りで、指定しないフィールドはそのままゼロ値として扱われます。「構造体で指定しないフィールドをデフォルト設定で補完するか」はGoの各ライブラリによって思想が異なる気がしますが、http.Transportについては補完しません。参考までにDefaultTransportの実装は以下です。

var DefaultTransport RoundTripper = &Transport{
    Proxy: ProxyFromEnvironment,
    DialContext: (&net.Dialer{
        Timeout:   30 * time.Second,
        KeepAlive: 30 * time.Second,
    }).DialContext,
    ForceAttemptHTTP2:     true,
    MaxIdleConns:          100,
    IdleConnTimeout:       90 * time.Second,
    TLSHandshakeTimeout:   10 * time.Second,
    ExpectContinueTimeout: 1 * time.Second,
}

また、追加情報として、今回ECSへ移行するにあたってALBからECSサービスディスカバリーへ移行しました。ここまでくれば何がおきたか説明できます。

前章で説明しましたが、http.Transportを使い回さない実装では、クライアントもしくはサーバが明示的にコネクションをcloseしない限り、2個のgoroutineと8KB以上のメモリが永遠に解放されません。その間、それらのリソースは何にも使われないのにかかわらず。

DefaultTransport.IdleConnTimeoutは90秒なのでデフォルト設定では90秒あれば切断され、解放される状況のはずでしたが、不必要にhttp.Transportを指定し、さらにその時IdleConnTimeoutを指定し忘れたため、クライアントから接続を明示的に切る機会が失われていた状況でした。

さらに、ECS移行前はALBのidle.timeoutが400秒(デフォルト60秒)に設定されており、400秒あればクライアントからみればサーバからのコネクション切断によりリソースが解放される状況でした。

ECSへ移行する際にECSサービスディスカバリー6へ移行したので、サーバからのコネクション切断も起こらなくなり、サーバ/クライアント両方からコネクションが切断されなくなったため、リソースが永遠に解放されなくなっていたということがわかります。

対応後

http.Transportを使い回すようにしたところ、大幅に改善されました。序盤のグラフの通りです。また、今回の騒動を通して、ECS化前と比べてもgoroutine数は2000-6000個だったのが30-40個、メモリは300MBから100MBとなり、大幅にリソースに余裕ができました。Goのスケジュールに申し訳ないことをしていたという気持ちになりました。

また、今回はクライアントが圧倒的に影響を受けており、クライアント側にフォーカスして話しましたが、goのnet/httpサーバ実装でもリクエストごとにgoroutineを割り当てるため、サーバ側もリークしており、解決することができました。

おわりに

私はわりとdeepな部分の実装が気になり読むことが多いのですが、膨大なソースコードや複雑さに負けそうになり、「こんなことして役に立つのか?コスパはとりあえずとても悪いぞ!」と思うことが何度かありました。

今回の問題はサーバのインフラ変更によってクライアントが影響を受けていたという大変気付きにくい問題でした。たまたまnet/httpのソースを読んでいて挙動に詳しかったため、もしやと思いつくことができました。実際に反映してみて負荷が落ち着いたのは感動しましたし、意味があるのかわからないと思っていたことが業務に役立ちよかったです。

Kyashではエンジニアの皆様を募集しております。このような苦労を一緒に地道に乗り越えるメンバーと一緒に働きたいです!
もしご興味ありましたら、以下のリンクをご覧ください!


  1. コードでいうと1万-1.5万弱行ほど時間でいうと20-30時間ほど読んでいる。大まかな実装は把握しているつもりだが、TLS関連の処理は全て読み飛ばしている。 

  2. このキューはRussCoxにより書かれており、めちゃくちゃかっこいい実装になってます。興味ある方は以前書いたので参考までに。https://qiita.com/behiron/items/12e0236d5538f9f49e68#twolistslice 

  3. コネクションプールでまかなえない場合は新規のコネクションが張られるのを待つという単純な実装を想定 

  4. 改めてですが、自分がそう思っているだけでissue等で見かけたわけではありません。間違っているかもしれません。ただどういう意図でこう書いたのだろうと推測しながら素晴らしいコードを読むのは楽しいものです。 

  5. 読み込み位置を変更せずにsocketのreadbufferからreadする 

  6. AWSに詳しくない人むけに、https://dev.classmethod.jp/articles/ecs-service-discovery/ がわかりやすいです!dnsレコードを利用して負荷分散する仕組みのため、idleconnectionのタイムアウトという概念すら存在しません。