12
8

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 3 years have passed since last update.

ZOZOテクノロジーズ #4Advent Calendar 2020

Day 10

ローカルでMySQLコンテナに大量INSERTしていたら"unexpected EOF"になった時の話

Last updated at Posted at 2020-12-09

はじめに

データ削除バッチのベンチマークを取るため、ローカルのMySQLコンテナにデータを800万レコードほどINSERTしていたところ、 packets.go:36: unexpected EOF というエラーに遭遇しました。その時に調べたことや対処したことなどをまとめます。

環境:

  • Go 1.15.2
  • go-sql-driver/mysql v1.4.1
  • MySQL 5.7.30

対処と原因

MaxLifetimeを設定する

packets.go:36: unexpected EOF でぐぐってみると、結構ヒットしたので比較的よくある現象のようです。それらによると、 SetConnMaxLifetime を設定すれば解消するとのことでした。

SetConnMaxLifetime に関してはこちらの記事で説明されています。その名の通り、接続の寿命を設定するもののようです。
Re: Configuring sql.DB for Better Performance

MySQL では wait_timeout という設定で接続がサーバーから切られる恐れがあります。また、OSやルーターが長時間利用されていないTCP接続を切断することもあります。どのケースでも、 go-sql-driver/mysql はクエリを送信した後、レスポンスを受信しようとして初めてTCPが切断されたことを知ります。切断を検知するのに何十秒もかかるかもしれませんし、送信したクエリが実行されたかどうかを知ることもできないので安全なリトライもできません。
こういった危険をなるべく避けるためには、長時間使われていなかった接続を再利用せずに切断し、新しい接続を使うべきです。 SetConnMaxLifetime() は接続の寿命を設定するAPIですが、寿命を10秒に設定しておけば、10秒使われていなかった接続を再利用することもありません。

引数に与える秒数に関しては、

SetConnMaxLifetime() は最大接続数 × 1秒 程度に設定する。多くの環境で1秒に1回接続する程度の負荷は問題にならない。

とあったため、とりあえず1秒を設定しました。

つまり、こんな感じの実装です。

db.SetConnMaxLifetime(time.Second)

これにより、エラーは発生しなくなりました!!

なぜこの設定で問題解消されるのか

MaxLifetime の値はデフォルトでは無制限です。
一見すると、コネクションはできるだけ使いまわした方が再接続のオーバーヘッドも少なく、良いように思われるのですが、接続時間が長すぎることのデメリットも多くあるようです。いくつかの記事でそのことが説明されていますが、例えば、こちらの記事ではこのように説明されていました。

コネクション回数が減る代わりにアイドルのコネクションが必要なくなってもキープし続ける負荷があったり、DB起因でコネクションが中断されたり、フェイルオーバしたりした際に、外部要因で既に切れたコネクションを持ち続けて切断の検知に時間がかかったり、新しいコネクションに切り替えて欲しい際に切り替えがなかなか起こらないというリスクを含んでしまいます

sql.DBのチューニング方法

つまり、今回は「大量INSERT中になにかしらのDBコンテナ側の起因でコネクションが中断された」と推測されます。
DB側でコネクションが中断されても、GoクライアントはFIN通知を受け取るわけではないのでそのコネクションは生きていると判断します。Goクライアントからクエリパケットを送る際に初めてパケット喪失をして気づき、 unexpected EOF のエラーを受け取る格好になります。
このようにならない為に、Goクライアント側で MaxLifeTime の設定をし、Goクライアント側で接続を1秒毎に切っておく対処を追加することで解消されるのかと。

なぜMySQLでエラーが発生したのか

ここまででは、 unexpected EOF が発生する理由と解決方法はわかったのですが、そもそもなぜMySQLでエラーが発生してしまったのかという根本原因が分かっていません。

MySQLコンテナ内のログを確認してみると、 ibuf cursor restoration fails というエラーログがでていることが分かりました。これ自体の意味はよく分かっていないのですが、 MySQL5.7.31でfixされたようです。
https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-31.html

最終的な解決手段

そこで、当時最新であったMySQL5.7.32にアップデート(ローカルにある5.7のimagreをいったんrmして、再起動)して、 SetConnMaxLifetime の実装を削除して、無事動作することを確認しました。
つまり、バージョン上げるだけで解決しました。

これから

本番環境やステージング環境ではAWSのAuroraを使っており、Auroraでも同様の問題が発生してしまうのかの確認が必要です。
それはこれからの話なので、進展ありましたら、記載します。

12
8
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
12
8

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?