こちらは、Gopher道場 Advent Calendar 2018の19日目の記事です。
私は、MySQLデータベースを用いるAPIサーバの実装において、疎通確認のエンドポイントを作成するために、*sql.DB.Pingを利用したのですが、その利用に際して、設定チューニングが必要な事例があったので紹介したいと思います。
何にはまったの
database/sqlパッケージは皆さんよく使いますよね。その中で疎通確認する際に、DB.Pingを利用するかと思います。例えば、次のようなヘルスチェックのエンドポイントを作るとします。
// DeepCheck is health check handler whether database connection is alive.
func (c *HealthCheckController) DeepCheck(w http.ResponseWriter, r *http.Request) {
if err := c.DB.Ping(); err != nil {
log.Printf("failed to ping by error '%#v'", err)
w.WriteHeader(http.StatusInternalServerError)
return
}
w.WriteHeader(http.StatusOK)
}
このエンドポイントを叩くと、DBへの疎通が取れている場合200、疎通が取れていない場合は500になることになります。
ここでハマった点は、初回のDB.Pingは成功していて、DB.Queryなどの実行も失敗しないのに、DB.Pingのみ次のようなエラーが発生して失敗する事象があり原因調査しました。
failed to ping by error 'bad connection'
同様の事象としては次のIssueが類似例としてあげられます。
database/sql: Ping after statement reports good connection when it has failed #7619
上のIssueは、後の解決の手がかり情報として有用だったの、後でも引用します。
解決の手がかり
そもそものdatabase/sql・go-sql-driver/mysql周りの仕様が手がかりでした。
sql.DBとは
解決の手がかりは、sql.DBの設定について解説された次の記事にありました。
A sql.DB object is a pool of many database connections which contains both 'open' and 'idle' connections. A connection is marked open when you are using it to perform a database task, such as executing a SQL statement or querying rows. When the task is complete the connection becomes idle.
そもそも、*sql.DBは大前提としてconnection poolingで、*sql.DBにはopen状態・idle状態のconnectionを保持しています。
When you instruct sql.DB to perform a database task, it will first check if any idle connections are already available in the pool. If one is available then Go will reuse the existing connection and mark it as open for the duration of the task. If there are no idle connections in the pool when you need one then Go will create a new additional connection and 'open' it.
そして、idle状態のconnectionがある場合それを再利用し、idle状態のconnectionがなければ新規にconnectionをopenします。
DB.Pingの仕様
上記のsql.DBの前提を踏まえた上で、再度冒頭で上げたIssueを見てみます。
ここでは、DB.Pingの仕様について次のように解説されています。
This appears to have been fixed in Go 1.3 via 3662d56e2402.
But it's not clear what you're trying to achieve by calling Ping() after the query in
the first place. As far as I can tell, what nil error from Ping() means is that "there
is at least one connection to the database which we don't yet know to be bad, or a new
connection was successfully established". I don't see where this information would be
valuable except perhaps right after sql.Open().
DB.Pingは、「保持している最低限一つのコネクションがbad connectionではない、もしくは新規コネクションの確立に成功した」ことをもってnilが返ってくるようです。
つまり、「保持している最低限一つのコネクションがbad connection」である場合、error型のbad connectionが返ってくる仕様。
以上から、保持しているidle connectionの最低一つがbad connectionになっていることが推測されました。
では、なぜ保持しているidle connectionがbad connectionになるのか。原因を知る上で次のエントリが非常に参考になりました。
Re: Configuring sql.DB for Better Performance
"Configuring sql.DB for Better Performance" で紹介されたとおり、 MySQL では wait_timeout という設定で接続がサーバーから切られる恐れがあります。また、OSやルーターが長時間利用されていないTCP接続を切断することもあります。どのケースでも、 go-sql-driver/mysql はクエリを送信した後、レスポンスを受信しようとして初めてTCPが切断されたことを知ります。切断を検知するのに何十秒もかかるかもしれませんし、送信したクエリが実行されたかどうかを知ることもできないので安全なリトライもできません。
こういった危険をなるべく避けるためには、長時間使われていなかった接続を再利用せずに切断し、新しい接続を使うべきです。 SetConnMaxLifetime() は接続の寿命を設定するAPIですが、寿命を10秒に設定しておけば、10秒使われていなかった接続を再利用することもありません。
今回のケースで利用していたのは、MySQLでした。そのため上記の記事での言及がある通り、サーバからの接続が切られたconnectionを保持していたことになります。
その上、go-sql-driver/mysqlは、レスポンス受信時に切断に気づくということなので、一度使用したコネクションに切断されたことにdb.Pingが検知してerrorを返しているようでした。
解決策
Re: Configuring sql.DB for Better Performanceで書いてあるとおり、次の3つのパラメータを設定しましょう。
- SetMaxOpenConns
- SetMaxIdleConns
- SetConnMaxLifetime
今回のケースで特にきいてくるのは、SetConnMaxLifetimeです。SetConnMaxLifetimeについてはコード内で次のように説明されています。
// SetConnMaxLifetime sets the maximum amount of time a connection may be reused.
//
// Expired connections may be closed lazily before reuse.
//
// If d <= 0, connections are reused forever.
func (db *DB) SetConnMaxLifetime(d time.Duration) {
connectionの再利用時間を設定することができるので、例えば次のように10秒とした場合は10秒経過したコネクションは再利用されなくなります。
db.SetConnMaxLifetime(time.Second * 10)
実際に、どのくらいの時間に設定すればいいかという点については、Re: Configuring sql.DB for Better Performanceにて説明していただいているので参考にしていただくと良いと思います。
最後に
今回は、*sql.DB.Pingについてハマった点について調べた記録を書かせていただきました。一つ事例として参考になれば幸いです。