はじめに
データ削除バッチのベンチマークを取るため、ローカルの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起因でコネクションが中断されたり、フェイルオーバしたりした際に、外部要因で既に切れたコネクションを持ち続けて切断の検知に時間がかかったり、新しいコネクションに切り替えて欲しい際に切り替えがなかなか起こらないというリスクを含んでしまいます
つまり、今回は「大量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でも同様の問題が発生してしまうのかの確認が必要です。
それはこれからの話なので、進展ありましたら、記載します。