Open5

SQLメモ

Yuuki TakahashiYuuki Takahashi

カレンダーを作る

MySQL

SELECT date_format(date_sub(current_date(), interval num day), '%Y/%m/%d') as day
FROM (SELECT row_number() OVER (ORDER BY TABLE_NAME) - 1 as num
      FROM information_schema.COLUMNS
      LIMIT 35) as nums
order by day;

PostgreSQL

SELECT to_char(generate_series, 'YYYY/MM/DD') as day
FROM generate_series(current_date - interval '35 days', current_date, '24 hours')
ORDER BY day;

Athena

select date_format(t.d, '%Y/%m/%d') as day
from (select sequence(current_date - interval '35' day,
                      current_date,
                      interval '1' day
             ) dates),
     unnest(dates) as t(d)
order by day;
Yuuki TakahashiYuuki Takahashi

クエリタイムアウトのテスト

MySQL

SET SESSION max_execution_time=1000;

WITH mysleep(value) AS (SELECT SLEEP(3)) SELECT * FROM mysleep;

PostgreSQL

set statement_timeout to 1000;

SELECT pg_sleep(3);
Yuuki TakahashiYuuki Takahashi

印象深かったINDEXチューニング

訳あってバージョンの古いRundeckのパフォーマンスチューニングが必要だった時に知ったこと
バックエンドはPostgreSQLなので他のケースでも有用なときがあるかも

Performance InsightsのトップSQLとして挙がってきたものの、待機イベントを見ただけだと遅い理由がよくわからない時にこれで解決できた

紫は DataFileRead 緑は CPU

当該SQLのEXPLAINを見てみる
削除対象のレコードのカラム自体にはIndexが貼られている状態

begin;
explain (costs off, analyze on, verbose on)
delete
from workflow_step
where id = 10466387
  and version = 0;
rollback;

結果は以下
verbose on にしたことで Trigger RI_ConstraintTrigger_ ~ と見慣れない表示が出ている

Delete on public.workflow_step (actual time=0.044..0.045 rows=0 loops=1)
  ->  Index Scan using workflow_step_pkey on public.workflow_step (actual time=0.018..0.019 rows=1 loops=1)
        Output: ctid
        Index Cond: (workflow_step.id = 10466387)
        Filter: (workflow_step.version = 0)
Planning Time: 0.059 ms
Trigger RI_ConstraintTrigger_a_16521 for constraint fkipk3uik8eqp54cf0ul996bu4o: time=790.544 calls=1
Trigger RI_ConstraintTrigger_a_16536 for constraint fkrln65du8n7hwu3qbinnea748g: time=0.156 calls=1
Execution Time: 790.767 ms

上記について、外部キー制約に伴ってCASCADEでレコードが消えているっぽいことがわかる
具体的にどのレコードが消えうるか確認するには以下

SELECT
  base.namespace_name
  , base.constraint_name
  , base.table_name
  , array_agg(pg_attribute.attname ORDER BY base.order) AS column_names
FROM (
  SELECT
    pg_constraint.conname AS constraint_name
    , pg_constraint.conrelid
    , pg_namespace.nspname AS namespace_name
    , pg_constraint.contype
    , pg_class.relname AS table_name
    , unnest(pg_constraint.conkey) AS conkey
    , generate_subscripts(pg_constraint.conkey, 1) AS order
  FROM
    pg_constraint
    INNER JOIN pg_class
      ON (pg_constraint.conrelid = pg_class.oid)
    INNER JOIN pg_namespace
      ON (pg_class.relnamespace = pg_namespace.oid)
) base
  INNER JOIN pg_attribute
    ON (base.conrelid = pg_attribute.attrelid AND base.conkey = pg_attribute.attnum)
WHERE
  base.contype = 'f' -- FKで絞る
GROUP BY
  base.namespace_name
  , base.constraint_name
  , base.table_name
;

以下が出てくる
一つ一つのテーブルのカラムにINDEXが貼ってあることを確認する

無いものがあった

上記に対して手動でインデックスを設定
なお、本来はこちらが取り込まれたバージョンで動かしていれば避けられた問題ではある

以下の方法でインデックスを作るとロックを取らずに済む
その代わり更新時に失敗する可能性がある
ref: https://tech.unifa-e.com/entry/2023/12/13/090000

CREATE INDEX CONCURRENTLY issue_xxxxx_workflow_step_error_handler_id on workflow_step (error_handler_id);
Yuuki TakahashiYuuki Takahashi

レコードロックの調査(MySQL v8~)

デッドロックは INNODB ENGINE SHOW STATUS で確認できるが、レコードロックのタイムアウトは発生してもロギングされないので調査するには定期的にDB状態をチェックするか相応のツールを用意する必要がある
https://qiita.com/h-oikawa/items/91e2401fad5d93262f6f

https://www.datadoghq.com/ja/blog/troubleshoot-blocking-queries-with-database-monitoring/

以下クエリを本番のwriterに一定秒数毎に発行する
MySQLの innodb_lock_wait_timeout はデフォルトで50秒なので、そこに引っかかるクエリを探したいなら30秒おきなどでも検出できる

https://dev.mysql.com/doc/refman/8.0/ja/innodb-parameters.html#sysvar_innodb_lock_wait_timeout

select
    w.*,
    w_trx.*,
    b_t.THREAD_ID as blocking_thread_id,
    w_t.THREAD_ID as waiting_thread_id
from
    sys.innodb_lock_waits w
left join
    information_schema.INNODB_TRX as b_trx
on
    w.blocking_trx_id = b_trx.trx_id
left join
    performance_schema.threads as b_t
on
    b_trx.trx_mysql_thread_id = b_t.PROCESSLIST_ID
left join
    information_schema.INNODB_TRX as w_trx
on
    w.waiting_trx_id = w_trx.trx_id
left join
    performance_schema.threads as w_t
on
    w_trx.trx_mysql_thread_id = w_t.PROCESSLIST_ID
-- 一定秒以上待ってるものに絞りたいなら
where w.wait_age > 3
order by
    w.waiting_trx_id;

上記のクエリで、 w.waiting_query ないし w.blocking_query を見るとクエリが確認できるが、内容が省略されるのと、クエリを打った瞬間に実行状態にあったクエリしか出てこないので、それだけだと原因把握がしづらい
待っている側のクエリ内容は w_trx.trx_query で確認できるが、待たせている側は多くの場合トランザクションを貼って複数クエリを打ちながらCPU処理もしているため、トランザクションに対して過去発行されたクエリが分かるとイメージがしやすくなる

より詳細な情報が知りたい場合、出てきた blocking_thread_id ないし waiting_thread_id について以下テーブルを調べる
digest_text を読むと、それぞれのトランザクションで直近発行されたn件のクエリが参照できる
events_statements_history はデフォルトで10件までしか記録されないため、それ以上の履歴が必要なら要チューニング

SELECT *
FROM performance_schema.events_statements_history
WHERE thread_id = {blocking_thread_id or waiting_thread_id}
order by event_id desc
limit 5;

有効状態は以下で確認可能だが、今回使うものはRDS MySQL 8.0ではデフォルトで有効になっている模様

https://dev.mysql.com/doc/refman/8.0/ja/performance-schema-statement-tables.html

select * from performance_schema.setup_consumers where NAME like '%events_statements%';
NAME ENABLED
events_statements_cpu NO
events_statements_current YES
events_statements_history YES
events_statements_history_long NO
SHOW VARIABLES LIKE 'performance_schema_events_statements_%';
Variable_name Value
performance_schema_events_statements_history_long_size 10000
performance_schema_events_statements_history_size 10

参考

https://gihyo.jp/dev/serial/01/mysql-road-construction-news/0148

https://blog.kinto-technologies.com/posts/2024-03-05-aurora-mysql-stats-collector-for-blocking/

https://blog.smartbank.co.jp/entry/mysql_lock_block_timeout_busters

Yuuki TakahashiYuuki Takahashi

レコードロックの調査(PostgreSQL)

以下のクエリを pg_stat_activity テーブルに対して定期的に発行することでMySQLと同様の調査ができる
pg_blocking_pids 関数の呼び出しによりロックマネージャーに排他ロックがかかるため、頻繁に実行することはパフォーマンス低下の原因になりえるため注意すること

https://www.postgresql.org/docs/9.6/functions-info.html#:~:text=Unix-domain socket.-,pg_blocking_pids,-returns an array

Frequent calls to this function could have some impact on database performance, because it needs exclusive access to the lock manager's shared state for a short time.

select
    waiting.pid as w_pid,
    waiting.usename as w_username,
    now() - waiting.query_start as w_age,
    waiting.query as w_query,
    blocking.pid as b_pid,
    blocking.usename as b_username,
    now() - blocking.query_start as b_age,
    blocking.query as b_query
from (
    select distinct
        *,
        unnest(pg_blocking_pids(pid)) as blocking_pid
    from
        pg_stat_activity
    -- 一定秒以上待ってるものに絞りたいなら
    where now() - waiting.query_start > 3
) as waiting
left join
    pg_stat_activity as blocking
on
    waiting.blocking_pid = blocking.pid
order by
    waiting.pid,
    waiting.query,
    blocking.pid,
    blocking.query;

出てきた pid をもとに pg_locks にアクセスするとどのテーブルに対してロックをかけているか確認できる

select
 l.pid,
 l.locktype,
 c.relname as table_name,
 l.page,
 l.tuple,
 l.transactionid,
 l.mode,
 l.granted,
 s.state
from
 pg_locks l
 left join pg_class c  on (l.relation=c.oid)
 left join pg_stat_activity s on (l.pid=s.pid)
where
 l.mode <> 'AccessShareLock'
 and
 l.pid  = {w_pid}
order by
 l.pid,
 l.locktype,
 c.relname,
 l.page,
 l.tuple,
 l.mode,
 l.granted,
 s.state;

events_statements_history 相当のテーブルは存在せず、実行されているプロセスごとのクエリの実行ログをテーブルに照会して取得する方法はない

https://stackoverflow.com/questions/68477211/join-pg-stat-activity-with-pg-stat-statements

クエリごとの実行時間の統計としての pg_stat_statements というテーブルは存在するが、利用するには拡張機能を有効化する必要がある

https://qiita.com/Esfahan/items/2f0c5ad85671d435f209

参考

https://www.insight-ltd.co.jp/tech_blog/postgresql/pg-knowledge/750/

https://qiita.com/behiron/items/571562ea33b8212a4c32