MySQLとPostgreSQLにおける重い処理をシステムテーブル(view)から確認する方法

MySQL, PostgreSQLそれぞれ運用するなかで、遅い処理を確認する為にlog_min_duration_statementやslow_query_logを利用して該当のSQLをログに出力して適宜SQLをチューニングする等の対応されていると思います。ここでは、その他にMySQLとPostgreSQLでそれぞれ提供されている、管理用のVIEWを利用して実行されたSQLとその処理の詳細を確認しています。

log_min_duration_statement@PostgreSQL

このパラメータに設定した時間(ミリ秒)以上の処理時間を要したSQLは、そのSQL文とその所要時間をログに出力します。
例えば 10秒以上かかるクエリを特定するには、設定ファイルpostgresql.conf にて以下のように設定を行います。

log_min_duration_statement=10000

long_query_time@MySQL

slow_query_logとslow_query_log_fileシステム変数を使用します。slow_query_logログを無効にするには0に設定し有効にするには1に設定します。設定ファイル my.cnf にて以下のようにlong_query_timeにて所要時間(秒)の設定を行います。また、slow_query_log_fileログファイルの名前を指定するように設定します。これらは、動的パラメータなので稼働中もSETコマンドで設定する事が可能です。

slow_query_log = 1
slow_query_log_file = /usr/local/mysql/data/host-ip-slow.log
long_query_time = 10

sys.statement_analysis@MySQL

これらのビューは統計を集計し正規化したステートメントをリストします。デフォルトで行は合計レイテンシを降順にソートされています。

27.4.3.35 The statement_analysis and x$statement_analysis Views


[sys]> select db,query,full_scan,exec_count,err_count,warn_count,total_latency,max_latency,avg_latency,lock_latency,rows_sent,tmp_disk_tables,sort_merge_passes from statement_analysis limit 10;
+-------+-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+--------------+-----------+--------------
| db    | query                                                             | full_scan | exec_count | err_count | warn_count | total_latency | max_latency | avg_latency | lock_latency | rows_sent | tmp_disk_tabl
+-------+-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+--------------+-----------+--------------
| APP   | SELECT `WORD` FROM `INFORMATIO ... INNODB_FT_INDEX_TABLE` LIMIT ? | *         |          1 |         0 |          0 | 11.84 min     | 11.84 min   | 11.84 min   | 7.95 ms      |        10 |              
| APP   | SELECT `WORD` , COUNT ( `WORD` ...  ORDER BY `total` DESC LIMIT ? | *         |          1 |         1 |          0 | 9.24 min      | 9.24 min    | 9.24 min    | 153.00 us    |         0 |              
| APP   | COMMIT                                                            |           |      14300 |         0 |          0 | 3.02 min      | 850.07 ms   | 12.66 ms    |   0 ps       |         0 |              
| APP   | SELECT SQL_NO_CACHE * FROM `FTS_dbdata`                           | *         |          3 |         0 |          3 | 29.54 s       | 11.67 s     | 9.85 s      | 6.14 ms      |    833154 |              
| myosm | SELECT SQL_NO_CACHE * FROM `nodes`                                | *         |          3 |         0 |          3 | 23.93 s       | 15.15 s     | 7.98 s      | 137.00 us    |   1486554 |              
| APP   | INSERT IGNORE INTO `FTS_dbdata ... TEM_USER , TEXT ) VALUES (...) |           |      14300 |         0 |          0 | 20.06 s       | 895.94 ms   | 1.40 ms     | 5.07 s       |         0 |              
| myosm | SELECT SQL_NO_CACHE * FROM `nodetags`                             | *         |          3 |         0 |          3 | 19.41 s       | 6.57 s      | 6.47 s      | 127.00 us    |   8332701 |              
| APP   | SELECT SQL_NO_CACHE * FROM `FTS_dbda`                             | *         |          3 |         0 |          3 | 17.62 s       | 6.21 s      | 5.87 s      | 130.00 us    |    852759 |              
| APP   | SELECT SQL_NO_CACHE * FROM `FTS_dbdaa`                            | *         |          3 |         0 |          3 | 9.96 s        | 4.23 s      | 3.32 s      | 131.00 us    |    455574 |              
| APP   | SET NAMES ? COLLATE ?                                             |           |      14300 |         0 |          0 | 7.77 s        | 198.99 ms   | 543.57 us   |   0 ps       |         0 |              
+-------+-------------------------------------------------------------------+-----------+------------+-----------+------------+---------------+-------------+-------------+--------------+-----------+--------------
10 rows in set (0.00 sec)

statement_analysisはevents_statements_summary_by_digestを参照しているので、テーブルに格納されるステートメントは以下のサイズに依存しています。


[sys]> show global variables like 'performance_schema_digests_size';
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| performance_schema_digests_size | 10000 |
+---------------------------------+-------+

補足: MySQL SYS Schema


pg_stat_statements@PostgreSQL

pg_stat_statementsモジュールはサーバで実行されたすべてのSQL文の実行時の統計情報を記録する手段を提供します。このモジュールは追加の共有メモリを必要とするため、postgresql.confのshared_preload_librariesにpg_stat_statementsを追加してモジュールをロードしなければなりません。 このことは、このモジュールを追加もしくは削除するにはサーバを再起動する必要があるということを意味しています。

pg_stat_statementsはロードされると、サーバのデータベース全体に渡って統計情報を記録します。 この統計情報にアクセスしたり操作したりするために、このモジュールはビューpg_stat_statementsとユーティリティ関数pg_stat_statements_reset、pg_stat_statementsを提供します。 これらはサーバー全体で利用可能ではなく、CREATE EXTENSION pg_stat_statementsで特定のデータベースで利用可能になります。

参照: F.29. pg_stat_statements

postgresql.confの設定変更(サービスの再起動が必要)


shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.max = 1000
pg_stat_statements.track = top
pg_stat_statements.save = on

設定と確認

app=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION

app=# \dx
                                        インストール済みの拡張一覧
        名前        | バージョン |  スキーマ  |                           説明                            
--------------------+------------+------------+-----------------------------------------------------------
 pg_freespacemap    | 1.2        | public     | examine the free space map (FSM)
 pg_stat_statements | 1.7        | public     | track execution statistics of all SQL statements executed
 plpgsql            | 1.0        | pg_catalog | PL/pgSQL procedural language
(3 行)

app=# SELECT * FROM pg_available_extensions WHERE name = 'pg_stat_statements';
        name        | default_version | installed_version |                          comment                          
--------------------+-----------------+-------------------+-----------------------------------------------------------
 pg_stat_statements | 1.7             | 1.7               | track execution statistics of all SQL statements executed
(1 行)


app=# select name, setting, unit from pg_settings where name like 'pg_stat_statements%';
               name               | setting | unit 
----------------------------------+---------+------
 pg_stat_statements.max           | 5000    | 
 pg_stat_statements.save          | on      | 
 pg_stat_statements.track         | top     | 
 pg_stat_statements.track_utility | on      | 
(4 行)

実際に記録されたステートメントの確認


app=# \pset pager
「ページャーを使う」は off です。
app=# select userid,dbid,queryid,left(query,30),calls,total_time,min_time,max_time,mean_time,stddev_time,shared_blks_hit,shared_blks_read from pg_stat_statements order by total_time desc;
 userid | dbid  |       queryid        |              left              | calls |      total_time      |       min_time        |       max_time       |      mean_time       |      stddev_time       | shared_blks_hit | shared_blks_read 
--------+-------+----------------------+--------------------------------+-------+----------------------+-----------------------+----------------------+----------------------+------------------------+-----------------+------------------
     10 | 49596 |  5910544648824246769 | select * from memo where id =  |    16 |   352.84530299999994 |              0.016142 |   351.54439399999995 |   22.052831437500004 |      85.07473611928185 |              44 |                4
     10 | 49596 |  6711476591887504002 | explain select * from memo     |     2 |           105.592792 |              0.074625 |           105.518167 |            52.796396 |     52.721771000000004 |              40 |               12
     10 | 49596 |  1258245615633632122 | explain select * from memo whe |     6 |    61.98016300000001 |              0.084408 |            61.497362 |   10.330027166666667 |      22.88272889325042 |               4 |                9
     10 | 49596 |  5761671877250351757 | select name,setting,category f |     3 |   5.1763959999999996 |              1.102193 |             2.606261 |   1.7254653333333332 |     0.6404653712024995 |               0 |                0
     10 | 49596 |    -3158048787087772 | select userid,dbid,queryid,lef |     3 |              0.41186 |   0.13373200000000002 |  0.14129799999999998 |  0.13728666666666667 |  0.0031056397444362608 |               0 |                0
     10 | 49596 |   956172393795458702 | select * from pg_stat_statemen |     3 |  0.26237699999999997 |  0.009907000000000001 |             0.129361 |             0.087459 |   0.054896911898575866 |               0 |                0
     10 | 49596 | -9208585654704159892 | explain select * from memo ord |     3 |             0.250689 |              0.073775 |             0.097503 |             0.083563 |   0.010122049331368954 |               4 |                0
     10 | 49596 |  3231151743520748149 | select userid,dbid,queryid,que |     2 |  0.21030100000000002 |              0.102633 |             0.107668 |  0.10515050000000001 |  0.0025174999999999954 |               0 |                0
     10 | 49596 |  8685157009571086729 | select userid,dbid,queryid,lef |     1 |  0.15841100000000002 |   0.15841100000000002 |  0.15841100000000002 |  0.15841100000000002 |                      0 |               3 |                0
     10 | 49596 |  4048041203833672862 | LOAD 'auto_explain'            |     1 |             0.125106 |              0.125106 |             0.125106 |             0.125106 |                      0 |               0 |                0
     10 | 49596 | -7547750407391136812 | explain select * from memo ord |     1 |             0.098115 |              0.098115 |             0.098115 |             0.098115 |                      0 |               0 |                0
     10 | 49596 |  6755220269130009187 | explain select * from memo ord |     1 |             0.087065 |              0.087065 |             0.087065 |             0.087065 |                      0 |               0 |                0
     10 | 49596 | -1920304080562092233 | SET auto_explain.log_min_durat |     3 |             0.064131 |              0.006951 |             0.049859 |             0.021377 |   0.020140381790489142 |               0 |                0
     10 | 49596 |  9022527725580902277 | select relname,relpages,reltup |     3 |             0.062013 |  0.017379000000000002 |             0.026977 | 0.020671000000000002 |   0.004460459468111628 |               9 |                0
     10 | 49596 | -7365002070969254732 | SELECT tablename,attname,corre |     1 | 0.051623999999999996 |  0.051623999999999996 | 0.051623999999999996 | 0.051623999999999996 |                      0 |              15 |                0
     10 | 49596 | -2189995260333419544 | select ($1 * $2) + ($3 * $4) " |     3 |             0.028727 | 0.0046240000000000005 |             0.019399 | 0.009575666666666666 |    0.00694622239462253 |               0 |                0
     10 | 49596 | -6203021216765832473 | SET auto_explain.log_min_durat |     3 | 0.022913999999999997 |              0.007163 |             0.007885 |             0.007638 | 0.00033596527598349574 |               0 |                0
     10 | 49596 |  2065125607359684573 | SET auto_explain.log_min_durat |     2 |             0.015098 |              0.007356 |             0.007742 |             0.007549 |  0.0001929999999999998 |               0 |                0
     10 | 49596 |  7413539732739831561 | SET auto_explain.log_min_durat |     1 |             0.007563 |              0.007563 |             0.007563 |             0.007563 |                      0 |               0 |                0
     10 | 49596 |  6161394367587035080 | SET auto_explain.log_analyze = |     1 |             0.007052 |              0.007052 |             0.007052 |             0.007052 |                      0 |               0 |                0
     10 | 49596 |  8733460176246631674 | select ($1 * $2) + ($3 * $4) + |     1 |             0.005196 |              0.005196 |             0.005196 |             0.005196 |                      0 |               0 |                0
(21 行)

app=# 


pg_stat_statements.maxは、このモジュールによって記録されるSQL文の最大数(すなわち、pg_stat_statementsビューにおける行の最大数)です。
これを超えて異なるSQL文を検出した場合は、最も実行回数の低いSQL文の情報が捨てられます。 デフォルトは5000です。 このパラメータはサーバの起動時にのみ指定できます。

app=# select name,setting,unit,context,category,short_desc from pg_settings where name like 'pg_stat_statements%';
               name               | setting | unit |  context   |    category    |                              short_desc                              
----------------------------------+---------+------+------------+----------------+----------------------------------------------------------------------
 pg_stat_statements.max           | 5000    |      | postmaster | 独自オプション | Sets the maximum number of statements tracked by pg_stat_statements.
 pg_stat_statements.save          | on      |      | sighup     | 独自オプション | Save pg_stat_statements statistics across server shutdowns.
 pg_stat_statements.track         | top     |      | superuser  | 独自オプション | Selects which statements are tracked by pg_stat_statements.
 pg_stat_statements.track_utility | on      |      | superuser  | 独自オプション | Selects whether utility commands are tracked by pg_stat_statements.
(4 行)

Comments are closed.

Post Navigation