はじめに
Redash v8 (8.0.0.b32245) で「あるクエリの定期実行が動かない」という報告を受けて調査を行いました。
その結果、2件のクエリのschedule JSONにキーが欠落していることで、全クエリのスケジュール実行が約6週間にわたって停止していたという事例に遭遇しました。
この記事では、切り分けの過程と原因特定、修正までを順を追って記録します。
環境
- Redash v8 (
8.0.0.b32245) - ECS上で稼働(scheduler / scheduled_worker / adhoc_worker の3コンテナ構成)
- データベース: RDS PostgreSQL
症状
- 定期実行を設定しているクエリが実行されない
- 手動実行は正常に動作する
調査ステップ 1: よくある原因の除外
v8で定期実行が動かない場合の典型的な原因を順に確認しました。
schedule JSONの不正値
GitHub Issue #4163 では、"time": "Invalid date" のような不正値がscheduleに含まれることで outdated_queries() が例外を出し、scheduler全体が止まる問題が報告されています。
SELECT id, name, schedule
FROM queries
WHERE schedule IS NOT NULL
AND (schedule::text LIKE '%Invalid date%'
OR schedule::text LIKE '%NaN%'
OR schedule::text = '""');
こちらのクエリの実行結果は0レコードということで、ひとまず空振りになりました。
クエリ個別の状態確認
定期実行されていない特定クエリ(例としてID: 1234)の状態を確認しました。
SELECT
q.id, q.name, q.schedule, q.schedule_failures, q.user_id,
u.email AS owner_email,
u.disabled_at AS owner_disabled_at,
q.data_source_id,
ds.name AS data_source_name,
q.is_archived, q.is_draft,
q.created_at, q.updated_at
FROM queries q
JOIN users u ON u.id = q.user_id
JOIN data_sources ds ON ds.id = q.data_source_id
WHERE q.id = 1234;
| 項目 | 値 | 判定 |
|---|---|---|
| schedule | {"interval": 604800, "day_of_week": "Monday", "time": "00:00", "until": null} |
正常 |
| schedule_failures | 0 | 健全 |
| owner_disabled_at | NULL | 無効化されていない |
| is_archived / is_draft | false / false | OK |
クエリ自体は問題なさそうです。この時点でスケジューラーを疑っており、次のステップでログを確認することにしました。
調査ステップ 2: schedulerログの確認
CloudWatch Logsでschedulerコンテナのログを確認したところ、毎ループ同じ例外が出続けていました。
File "/app/redash/models/__init__.py", line 559, in outdated_queries
if query.schedule['until'] is not None:
KeyError: 'until'
#4163 と同根のバグですが、最初のSQLで見つからなかったのは、値の不正ではなくキーそのものが存在しないケースだったためです。
調査ステップ 3: 原因クエリの特定
キーが欠落しているクエリを探すSQLを実行しました。
SELECT id, name, schedule
FROM queries
WHERE schedule IS NOT NULL
AND NOT (schedule::jsonb ? 'until');
2件ヒット。
| id | name | schedule |
|---|---|---|
| 5001 | 日次集計レポートA | {"interval": 86400, "time": "00:00"} |
| 5002 | 日次集計レポートB | {"interval": 86400, "time": "00:00"} |
until と day_of_week の2キーが欠落していました。
修正
該当クエリのスケジュールをUIから更新するのが早いです。編集権限がない場合はクエリ作成者に依頼すればいいでしょう。
一応欠落キーをデフォルト値で補うUPDATE文を実行することでも修正できます。
UPDATE queries
SET schedule = (
'{"until": null, "day_of_week": null, "time": null}'::jsonb || schedule::jsonb
)::text
WHERE schedule IS NOT NULL
AND (NOT (schedule::jsonb ? 'until')
OR NOT (schedule::jsonb ? 'day_of_week')
OR NOT (schedule::jsonb ? 'time'));
注意: 今回のケースだと
untilだけ修正して再起動すると、次はKeyError: 'day_of_week'で止まります。必須キー4つ(interval,until,day_of_week,time)を一括で補うのがポイントです。
修正後、schedulerのログに以下が出力され、正常化を確認しました。
Done refreshing queries. Found 20 outdated queries:
[1102, 1205, 1234, 1301, 1415, 1512, 2033, 2148, 2256, 2371,
3045, 3189, 3302, 3478, 4012, 4156, 4389, 4512, 5001, 5002]
定期実行されてなかったクエリが一気にenqueueされました。
根本原因
APIなどUI以外からクエリのscheduleを更新する際、スケジュール実行にはキーが足りない状態のJSONがDBに保存されてしまったことが根本原因でした。
| 処理 | 動作 |
|---|---|
API (POST /api/queries/<id>) |
リクエストボディのscheduleをバリデーションなしでDBに保存 |
scheduler (outdated_queries()) |
4キー揃っている前提で query.schedule['until'] のようにdict参照 |
UIからの更新では4キーすべて送られるので問題になりません。しかしAPI直叩きで部分的なdictを送ると、不完全なscheduleがDBに入り、scheduler全体が停止します。
# これで再現する
curl -X POST "<REDASH_URL>/api/queries/<id>" \
-H "Authorization: Key <user_api_key>" \
-H "Content-Type: application/json" \
-d '{"schedule": {"interval": 86400, "time": "00:00"}}'
後のバージョンでは .get('until') 形式に修正されており、キーが欠落していても KeyError にならないようになっています。
予防策
以下のクエリで不完全なscheduleを持つクエリが存在しないか確認することができます。
しかし、そもそもRedashをアップデートしてしまえばこの問題は起きないため、アップデートまでの一時的な対策としての位置づけになるでしょう。
SELECT id, name, schedule
FROM queries
WHERE schedule IS NOT NULL
AND NOT (schedule::jsonb ?& array['interval','until','day_of_week','time']);
まとめ
今回はRedashの定期実行に関するトラブルシューティングを記事にしました。
Redash v8は2019年リリースで後継バージョンであれば今回の問題は起きないため、古いバージョンを使うことのツケを払う形になってしまいました。
工数を確保して、最新のバージョンにしっかり上げていこうと思います。