こんにちは、ECプラットフォーム部の権守です。普段はID基盤やAPI Gatewayの開発を行い、ZOZOTOWNのリプレイスに携わっています。 本記事では、ID基盤で開発・導入したMySQL実行計画の簡易検査を行うツールを紹介します。 ツール開発の経緯 RDBにおけるテーブル設計は利用するクエリに応じて適切なインデックスを設定するなど専門的な知識を必要とし、設計できる人が限られてきます。しかし、アプリケーション上で利用されるクエリは機能の追加・改修に伴って日々変化していくため、それら全てに目を通し、漏れなく適切な設計することは困難です。そこで、専門的な知識がなくても設計に問題がないかの簡易的な検査を行えるツールを開発し、CIに組み込むことで自動的に問題を検出できるようにしました。 ツール開発のアプローチ ID基盤ではDBMSとしてAmazon Aurora MySQLを使用しています。そのため、ツールはMySQL向けのものとして開発しました。また、 Amazon Aurora MySQL 2.0がMySQL 5.7.12によるバグ修正までを取り込んでいる 背景から、動作検証もMySQL 5.7.12で行っています。 スロークエリログを用いたアプローチ スロークエリログ を監視することで、テーブル設計の不備を検知できる場合があります。MySQLのスロークエリログはクエリの所要時間が設定した値を超えている、または行参照にインデックスを使用していない場合にそのクエリを出力できます。 前者は、レコード数が増加し、クエリの所要時間が増えてきて初めて検知できるため、パフォーマンスの劣化を未然に防ぐには手間がかかります。具体的には、テスト環境に本番同等のスペックと十分なレコード数を用意し、検証する必要があります。 一方、後者の場合は、有用な情報ではありますが、問題を検知できないパターンがあります。次のような定義のテーブルとクエリを例に考えてみます。 CREATE TABLE `events` ( `id` INT NOT NULL AUTO_INCREMENT, `name` VARCHAR ( 32 ) NOT NULL , `from_date` DATE NOT NULL , ` to_date ` DATE NOT NULL , PRIMARY KEY(`id`), INDEX `idx_events_from_date_to_date`(`from_date`, ` to_date `) ); SELECT `id` FROM `events` WHERE ` to_date ` < " 2021-04-01 " ; この場合、MySQLのオプティマイザは idx_events_from_date_to_date インデックスを使用する可能性がありますが、その場合のスキャン範囲はインデックス全体となります。なぜなら、このインデックスは下に示す表のように from_date を優先する順序でインデックスツリーが構成されているため、 to_date に関する比較は全体を見る必要があるからです。スロークエリログはこのようなスキャン範囲が全体に及ぶような場合であってもインデックスを使用したということでログには出力されません。 from_date to_date 2020-04-01 2021-08-01 2020-08-01 2021-03-31 2020-10-01 2021-04-30 2020-12-01 2021-02-28 EXPLAINステートメントを用いたアプローチ EXPLAINステートメントを用いることで、クエリの実行計画に関する情報を知ることができます。実行計画とは、クエリが実行されるに当たり、どのようにテーブルのスキャンや結合、ソートなどが行われるかを示したものです。これを見ることでインデックスの使用の有無を知ることができ、どこにインデックスを追加するとパフォーマンスを改善できるかといったことが分かります。 このアプローチを採用するには次の課題があります。 検査対象のクエリの管理 EXPLAINステートメントの出力結果を元に、設計に不備がないかを判断するロジックの開発 スロークエリログを使ったアプローチであれば、クエリの実行に伴って自動的にログが出力されるため、検査対象を別途取得する必要がありません。一方、こちらのアプローチでは明示的にEXPLAINステートメントにクエリを与える必要があるため、そのクエリを管理しなければいけません。また、EXPLAINステートメントの結果は独自の出力フォーマットであるため、そのままでは前提知識のない人が見ても、結果に問題があるのかの判断ができません。 しかし、これらの課題を解決できれば、前述したスロークエリログを用いたアプローチでは対応できなかったパターンにも対応できるようになります。そのため、今回はこちらのアプローチを採用しました。 検査対象のクエリの管理 EXPLAINステートメントの対象とするクエリを管理する必要がありますが、そのための設定ファイルを作ってしまうと、アプリケーションコード中に記述されているものと二重管理になってしまいます。その結果、クエリを追加・変更するような機能の改修が入った際に設定ファイルの更新も必要になってしまい、漏れなく管理することは困難です。そのため、二重管理しないで済む方法を検討しました。 検査対象の取得 シンプルに考えると「アプリケーションコードを解析して抽出する方法」があります。しかし、プレースホルダーを含むクエリの場合には、クエリに与える引数の動的解析が必要となり実装が複雑になります。そこで、MySQLの 一般クエリログ に注目しました。一般クエリログはMySQLサーバーが受け取ったSQLステートメントを記録したものです。今回はテストコードを実行した際に出力される一般クエリログを用いて、検査対象のクエリを取得するようにしました。 検査対象の選別 テスト実行によって出力された一般クエリログを利用することで、アプリケーション上で利用されるクエリを取得できます。しかし、それらのクエリの中には検査対象外としたいクエリが含まれることもあります。例えば、書き込み操作が多いテーブルでは、インデックスを意図的に追加していない場合もあります。そのような場合を考慮し、除外するクエリを判別するためのアノテーションをアプリケーションコード中に与えることを考えました。なお、詳細は後述しますが、アプリケーションコードにはGo言語を利用しています。 // @mydctr:skip q := "SELECT * FROM `users` WHERE `name` = ?" 上記のコードのコメント部分がアノテーションに相当し、このクエリを検査対象外とすることを示しています。 mydctr は開発したツールの名称で、アノテーションのプレフィックスとして記述しています。 EXPLAINステートメントの出力結果の判断ロジック まず、EXPLAINステートメントの 出力フォーマット の理解が必要です。今回は type カラムと Extra カラムに注目しました。 type カラムはテーブルへのレコードアクセスをどのように行っているかを、 Extra カラムはオプティマイザがどのような戦略を選択したかなどの追加情報を示しています。 今回のツールでは、検査によって以下の2つのパターンを検出したいと考えました。 検索条件の解決に適切なインデックスがなく、テーブル全体もしくはインデックスツリー全体のスキャンが行われるパターン ソートをインデックスのみで解決できず、クイックソートが行われるパターン 1つの目のパターンを判断するには、まず、 type カラムの値に注目します。 type カラムが ALL の場合にはテーブル全体を、 index の場合にはインデックスツリー全体をスキャンしていることが分かります。しかし、これだけで判断すると WHERE 句を利用していないクエリでもテーブル全体、またはインデックスツリー全体をスキャンするため、警告が出力されてしまいます。そこで、 Extra カラムに Using where の値が含まれているかどうかも合わせて確認する必要があります。 Using where があれば行がフェッチされた後に、 WHERE 句によって絞り込まれていることが分かります。そのため、 WHERE 句を利用していないクエリを対象から除外できます。 2つ目のパターンを判断するには、 Extra カラムの値に Using filesort の値が含まれているかどうかを確認することで判断できます。 ツールの実装とCIへの組み込み ツールの具体的な実装方法を紹介します。 開発言語にはID基盤の技術スタックと同じGo言語を採用しました。採用した理由は、ID基盤を構成するGoプログラムからアノテーションを抽出する際に、 go/parser パッケージを用いることで簡単にGoプログラムを構文解析できるからです。 一般クエリログからのクエリ取得 まず、一般クエリログのフォーマットを簡単に説明します。 ログファイルには以下のように各行に操作時刻、接続ID、コマンド、コマンド引数が順に記録されています。 2021-05-24T07:36:41.773817+09:00 1 Query SELECT `name` FROM `users` WHERE `id` = 1 プリペアドステートメントを利用した場合は次のように出力されます。 2021-05-24T07:38:02.260023+09:00 1 Prepare SELECT `name` FROM `users` WHERE `id` = ? 2021-05-24T07:38:02.260696+09:00 1 Execute SELECT `name` FROM `users` WHERE `id` = 1 2021-05-24T07:38:02.262475+09:00 1 Close stmt また、接続時には次のようにログが記録されます。 2021-05-24T07:37:41.808776+09:00 3 Connect user@host on db using TCP/IP 一般クエリログにはシステムデータベースの作成といった初期化のクエリも含まれます。テスト実行中に出力されたクエリだけを取得するために、初期化のクエリをスキップします。初期化のクエリはrootユーザーで実行されるため、テスト内で利用されるユーザーによる接続ログまでスキップすることで、初期化のクエリを取り除けます。 テスト実行中のログにも検査に利用しないログが多く含まれています。ここから検査に利用するクエリを抽出するにはコマンドが Query もしくは Execute であるログのクエリだけに絞ればよいので、その条件を表す正規表現を用います。 具体的な実装の例を以下に示します。 func extractQueries(user string , generalLog io.Reader ) ([] string , error ) { re, e := regexp.Compile( ` (Execute|Query)\t(.+)$` ) if e != nil { return nil , e } queries := [] string {} scanner := bufio.NewScanner(generalLog) skipped := false stopper := fmt.Sprintf( "Connect \t %v@" , user) for scanner.Scan() { line := scanner.Text() if !skipped && !strings.Contains(line, stopper) { continue } skipped = true matches := re.FindStringSubmatch(line) if len (matches) > 1 { queries = append (queries, matches[ 2 ]) } } if e := scanner.Err(); e != nil { return nil , e } return queries, nil } Goプログラム中のアノテーションの抽出 ID基盤ではGo言語を用いて開発しているため、Goプログラム中のアノテーションの抽出を実装しました。 まず、検査対象とするアプリケーション配下のGoファイルのファイルパス一覧を取得します。次に、各Goファイルからコメント部分を取得するために構文解析し、取得したコメントを正規表現でアノテーションのフォーマットに一致するコメントだけに絞り込みます。アノテーションコメントを絞り込んだ後は、コメントが掛かっている変数への代入文を取得し、代入しているSQLのクエリ文字列を抽出します。コメントに書かれたアノテーションの種類毎にクエリの一覧を作成し、最終的にJSON形式で出力します。 例えば、アプリケーションコード中に次のような記述があるとします。 // @mydctr:skip q1 := "SELECT * FROM `users` WHERE `name` = ?" // @mydctr:skip q2 := "SELECT * FROM `users` WHERE `age` > ?" この場合、次のようなJSONが出力されます。 { " skip ": [ " SELECT * FROM `users` WHERE `name` = ? "," SELECT * FROM `users` WHERE `age` > ? " ]} 具体的な実装は以下の通りです。 type annotation string const ( annotationSkip annotation = "skip" annotationTodo annotation = "todo" annotationAll annotation = "all" annotationFilesort annotation = "filesort" annotationTemporary annotation = "temporary" annotationPrefix = "@mydctr:" ) var annotationExpression = regexp.MustCompile(annotationPrefix + "(.+)" ) func NewAnnotation(a string ) (annotation, error ) { switch annotation(a) { case annotationAll, annotationSkip, annotationTodo, annotationFilesort, annotationTemporary: return annotation(a), nil } return "" , errors.New( "invalid annotation" ) } func ExtractAnnotatedQueries(dir string ) ([] byte , error ) { annotatedQueries := map [annotation][] string {} // 指定したディレクトリ配下のファイル・ディレクトリに対する処理 e := filepath.Walk(dir, func (path string , info os.FileInfo, e error ) error { if e != nil { return e } // Goファイルのみに処理を限定 if !strings.HasSuffix(info.Name(), ".go" ) { return nil } queries, e := extractAnnotatedQueries(path) if e != nil { return e } for k, v := range queries { annotatedQueries[k] = append (annotatedQueries[k], v...) } return nil }) if e != nil { return nil , e } return json.Marshal(annotatedQueries) } func extractAnnotatedQueries(filename string ) ( map [annotation][] string , error ) { annotatedQueries := map [annotation][] string {} fset := token.NewFileSet() // Goファイルを構文解析 f, e := parser.ParseFile(fset, filename, nil , parser.ParseComments) if e != nil { return nil , e } // コメントとその対象の関連付けを取得 commentMap := ast.NewCommentMap(fset, f, f.Comments) for node, commentGroups := range commentMap { annotationComment := func () string { for _, commentGroup := range commentGroups { for _, comment := range commentGroup.List { // 正規表現を用いてアノテーションコメントのみを取得 matches := annotationExpression.FindStringSubmatch(comment.Text) if len (matches) <= 1 { continue } return matches[ 1 ] } } return "" }() if annotationComment == "" { continue } // コメントに記述されたアノテーションの検証 annotation, e := NewAnnotation(annotationComment) if e != nil { return nil , e } // コメントの対象が代入文であることをチェック if stmt, ok := node.(*ast.AssignStmt); ok { // 複数代入の場合には右辺も複数になる for _, expr := range stmt.Rhs { // 右辺に文字列の結合が含まれる場合にも対応 joined, e := joinStringExpression(expr) if e != nil { return nil , e } annotatedQueries[annotation] = append (annotatedQueries[annotation], joined) } } } return annotatedQueries, nil } func joinStringExpression(expr ast.Expr) ( string , error ) { switch expression := expr.( type ) { case *ast.BinaryExpr: // 文字列結合の場合には再帰的に呼び出し if expression.Op != token.ADD { return "" , errors.New( "contains not add operator" ) } x, e := joinStringExpression(expression.X) if e != nil { return "" , e } y, e := joinStringExpression(expression.Y) if e != nil { return "" , e } return x + y, nil case *ast.BasicLit: if expression.Kind != token.STRING { return "" , errors.New( "contains not string literal" ) } fset := token.NewFileSet() // \nなどにも対応するためにEvalを利用 evaluated, e := types.Eval(fset, nil , token.NoPos, expression.Value) if e != nil { return "" , e } return constant.StringVal(evaluated.Value), nil } return "" , errors.New( "contains not supported expression" ) } EXPLAINステートメント結果の解析 EXPLAINステートメントを実行する前に一般クエリログから抽出したクエリに対し、アノテーションの存在有無を確認します。Goプログラムから抽出したクエリはプレースホルダーを含むものなので、実行された具体的な値を伴うクエリと比較する際には正規表現における任意の文字列を表す表記に置き換えて比較します。 例えば、次のようなアノテーションが抽出されたとします。 { " skip ": [ " SELECT * FROM `users` WHERE `name` = ? " ]} この場合、次のような正規表現に置き換えて比較されます。 "SELECT * FROM `users` WHERE `name` = .+" 実装は以下の通りです。 var annotatedQueries map [annotation][] string e := json.NewDecoder(annotationReader).Decode(&annotatedQueries) if e != nil { return e } // プレースホルダーを含むクエリを正規表現に変換 annotationPatterns := map [annotation][]*regexp.Regexp{} for a, queries := range annotatedQueries { patterns := []*regexp.Regexp{} for _, q := range queries { pattern, e := regexp.Compile(strings.ReplaceAll(regexp.QuoteMeta(q), `\?` , ".+" )) if e != nil { return e } patterns = append (patterns, pattern) } annotationPatterns[a] = patterns } func findAnnotations(query string , patternMap map [annotation][]*regexp.Regexp) map [annotation] struct {} { annotations := map [annotation] struct {}{} for a, patterns := range patternMap { found := func (query string , patterns []*regexp.Regexp) bool { for _, pattern := range patterns { matched := pattern.MatchString(query) if matched { return true } } return false }(query, patterns) if found { annotations[a] = struct {}{} } } return annotations } skip アノテーション、もしくは todo アノテーションが存在した場合にはクエリを検査対象外とします。それ以外の場合にEXPLAINステートメントを実行していきます。 todo アノテーションは修正予定のあるものに、 skip アノテーションはテストコード内でのみ利用されるクエリなどの修正予定がないものに使う想定です。 EXPLAINステートメントの出力結果を元に、修正を要する可能性があるものに対して警告を出力します。本記事の執筆時点では警告の種類は次のものを実装しています。 全体のスキャン ファイルソート 一時テーブル 「EXPLAINステートメントの出力結果の判断ロジック」の章で挙げたパターンに加え、一時テーブルの使用に関しても警告を出力するようにしました。 全体のスキャンに関する警告は適切なインデックスが設定されておらず、テーブル全体もしくはインデックスツリー全体のスキャンが行われる場合に出力されます。 ここで注意すべき点は、テーブル内のデータに依存してEXPLAINステートメントの出力結果が変わることです。例えば、適切にインデックスが設定されており、インデックスの範囲検索が有効となる条件文を含むクエリがあるとします。この場合、通常は条件に一致する範囲のみをスキャンするのでインデックスツリー全体のスキャンとはなりません。しかし、条件の値が全件を取得するような値であった場合、EXPLAINステートメントの出力結果はインデックスツリー全体のスキャンを表すこととなり、警告が出力されてしまいます。 この問題を回避するには、実際のクエリ実行時に格納されているデータと近い傾向のデータをダミーデータとして検査実行前にテーブルへ挿入しておくことが必要です。また、テーブル内のレコード数が数件しかない場合には、オプティマイザがインデックスを使うよりテーブル全体をスキャンした方が速いと判断する場合もあります。これに関してはダミーデータをある程度入れておくことで誤った警告が出力されることを回避できます。実装上、本当に全体のスキャンが必要な場合にはツールにそれを知らせるために all アノテーションを使います。これにより、この警告の対象外にできます。 ファイルソートの警告はソート時にインデックスを利用できずソート処理が実行される場合に出力されます。ソートのためのインデックスをあえて追加しない場合には、 filesort アノテーションを使うことでこの警告の対象外にできます。 一時テーブルの警告はクエリの実行中に一時テーブルを必要とする場合に出力されます。一時テーブルはその大きさが小さい場合はメモリ上に作成されますが、大きくなった場合にはディスク上に作成されます。ディスク上へテーブル作成するコストを考慮すると、一時テーブルを必要としている場合には何らかの対応を求められる可能性が高いです。 具体的な対応としては、クエリの改善やメモリ上に作成する一時テーブルの最大サイズを設定する tmp_table_size 変数の調整が必要になる場合があります。この警告は実装の容易さに対して、有用な情報であると判断したので、追加で実装しました。 集計用のクエリなど一時テーブルの利用を許容する場合には、 temporary アノテーションを使うことでこの警告の対象外にできます。 実装は以下の通りです。 type DSN struct { User string Password string Host string Port int DB string } type explainResult struct { id int selectType sql.NullString table sql.NullString partitions sql.NullString joinType sql.NullString possibleKeys sql.NullString key sql.NullString keyLen sql.NullInt32 ref sql.NullString rows sql.NullInt64 filtered sql.NullFloat64 extra sql.NullString } func Examine(generalLog io.Reader , annotationReader io.Reader , dsn DSN) error { // ... プレースホルダーを含むクエリの正規表現変換処理 db, e := sql.Open( "mysql" , fmt.Sprintf( "%v:%v@tcp(%v:%d)/%v" , dsn.User, dsn.Password, dsn.Host, dsn.Port, dsn.DB)) if e != nil { return e } defer db.Close() queries, e := extractQueries(dsn.User, generalLog) if e != nil { return e } for _, q := range queries { // 検査対象をSELECT、UPDATE、DELETEに限定 if !strings.HasPrefix(q, "SELECT" ) && !strings.HasPrefix(q, "UPDATE" ) && !strings.HasPrefix(q, "DELETE" ) { continue } annotations := findAnnotations(q, annotationPatterns) if _, ok := annotations[annotationSkip]; ok { continue } if _, ok := annotations[annotationTodo]; ok { continue } // EXPLAINステートメントの実行 rows, e := db.Query( "EXPLAIN " + q) if e != nil { panic (e) } defer rows.Close() // EXPLAINステートメントの出力結果を元に警告を作成 warnings := [] string {} results := []explainResult{} for rows.Next() { var r explainResult e = rows.Scan(&r.id, &r.selectType, &r.table, &r.partitions, &r.joinType, &r.possibleKeys, &r.key, &r.keyLen, &r.ref, &r.rows, &r.filtered, &r.extra) if e != nil { panic (e) } if r.joinType.Valid && (r.joinType.String == "ALL" || r.joinType.String == "index" ) && r.extra.Valid && strings.Contains(r.extra.String, "Using where" ) { if _, ok := annotations[annotationAll]; !ok { warnings = append (warnings, "絞り込みに必要なインデックスが不足している可能性があります" ) } } if strings.Contains(r.extra.String, "Using filesort" ) { if _, ok := annotations[annotationFilesort]; !ok { warnings = append (warnings, "インデックスが用いられていないソート処理が行われています" ) } } if strings.Contains(r.extra.String, "Using temporary" ) { if _, ok := annotations[annotationTemporary]; !ok { warnings = append (warnings, "クエリの実行に一時テーブルを必要としています" ) } } results = append (results, r) } if e := rows.Close(); e != nil { panic (e) } if e := rows.Err(); e != nil { panic (e) } if len (warnings) == 0 { continue } // 警告がある場合に、クエリとEXPLAINステートメントの出力結果を伴って出力 fmt.Println(q) table := tablewriter.NewWriter(os.Stdout) table.SetHeader([] string { "id" , "select_type" , "table" , "partitions" , "type" , "possible_keys" , "key" , "key_len" , "ref" , "rows" , "filtered" , "extra" }) for _, r := range results { table.Append([] string { strconv.Itoa(r.id), mapFromNullString(r.selectType), mapFromNullString(r.table), mapFromNullString(r.partitions), mapFromNullString(r.joinType), mapFromNullString(r.possibleKeys), mapFromNullString(r.key), mapFromNullInt32(r.keyLen), mapFromNullString(r.ref), mapFromNullInt64(r.rows), mapFromNullFloat64(r.filtered), mapFromNullString(r.extra), }) } table.Render() for _, warning := range warnings { fmt.Println(warning) } fmt.Println( "" ) } return nil } func mapFromNullString(s sql.NullString) string { if !s.Valid { return "NULL" } return s.String } func mapFromNullInt32(s sql.NullInt32) string { if !s.Valid { return "NULL" } return strconv.Itoa( int (s.Int32)) } func mapFromNullInt64(s sql.NullInt64) string { if !s.Valid { return "NULL" } return strconv.Itoa( int (s.Int64)) } func mapFromNullFloat64(s sql.NullFloat64) string { if !s.Valid { return "NULL" } return fmt.Sprintf( "%f" , s.Float64) } CIへの組み込み CIへの組み込みは次のような操作で実現できます。 テストコード実行 テスト用データベース内のデータクリア ダミーデータの挿入 アノテーション抽出 検査実行 既存テストは、プルリクエストの作成・更新・マージのタイミングで実行するようしています。上記の操作は既存テストに追加する形で実行されるように組み込んだので、同様にプルリクエストの作成・更新・マージのタイミングで実行されます。 アノテーションの抽出は、現状はGo言語にしか対応していないため、他の言語によって実装されたアプリケーションで利用する場合は 4. のステップを省略しています。ただし、アノテーションはシンプルなJSONで表現されているため、手動で管理することによって検査ツールにアノテーションを与えることは可能です。 まとめ MySQLの実行計画を簡易的に検査するためのツールを開発し、CIに組み込みました。それによってリリース前に問題のある実行計画をある程度把握できるようになりました。 今後の改善点は、一般クエリログに同様のクエリが存在した場合に同じ警告を重複して出力しないようにまとめあげる点などが挙げられます。また、開発して間もないので運用を通して改善した後にOSSとして公開できればと考えています。 最後に、ZOZOテクノロジーズでは、一緒にサービスを作り上げてくれる仲間を募集中です。ご興味のある方は、以下のリンクからぜひご応募ください! tech.zozo.com