ApsaraDB for ClickHouse:クエリログの分析

クイックリファレンス

前提条件

開始する前に、クエリログ記録が有効化されていることを確認してください。

デフォルトでは、ApsaraDB for ClickHouse でクエリログ記録が有効化されています。確認方法は以下のとおりです。

SHOW settings like 'log_queries';

結果が 1 の場合、クエリログ記録は有効化されています。結果が 0 の場合は、以下のステートメントを実行して有効化してください。

SET GLOBAL ON CLUSTER default log_queries = 1;

注意事項

• クエリログには機密情報が含まれる可能性があります。そのため、system.query_log テーブルへのアクセスは適切に管理してください。

• 過剰なログ蓄積を防ぐため、クエリログを定期的にクリーンアップおよびアーカイブしてください。

• デフォルトでは、query_log テーブルの生存時間（TTL）は 15 日です。15 日を超えたログは自動的に削除されます。

• ディスク領域の使用量を削減するには、ApsaraDB for ClickHouse コンソールの [パラメーター設定] ページで TTL を調整します。トラブルシューティングに十分な履歴を保持するために、TTL を少なくとも 7 日間以上に設定してください。詳細については、「config.xml ファイルでのパラメーター設定」をご参照ください。

仕組み

本トピックのすべてのクエリでは、QueryStart イベント（type != 'QueryStart'）を除外するため、各クエリは最終ステータスとともに結果に 1 回だけ表示されます。

各ノードが自身のクエリログデータのみを保存するため、すべてのクエリで clusterAllReplicas('default', system.query_log) を使用して、全ノードにわたる結果を集約します。substring(hostname(), 38, 8) を使用すると、特定のノード名で結果をフィルターできます。

ノード名を確認するには、次のコマンドを実行します。

SELECT * FROM system.clusters;

または、ApsaraDB for ClickHouse コンソールの [クラスターモニタリング] タブを確認してください。詳細については、「クラスターのモニタリング情報を表示する」をご参照ください。

本トピックの例では、ノード名として s-2-r-0 を使用しています。実際のノード名に置き換えてください。

エラーを含むクエリの表示

指定されたタイムウィンドウ内で失敗したクエリを特定するには、このクエリを使用します。エラーログにより、以下のような作業が可能になります。

• exception フィールドから、問題の根本原因を直接特定できます。

• システム全体の問題を示す反復的な失敗を検出できます。

• SQL インジェクションや不正アクセス試行などの潜在的なセキュリティ問題を特定できます。

クエリテンプレート

SELECT
    written_rows,
    written_bytes,
    query_duration_ms,
    event_time,
    exception
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time >= '2021-11-22 22:00:00'
  AND event_time <= '2021-11-22 23:00:00'
  AND lowerUTF8(query) LIKE '%insert into sdk_event_record_local%'
  AND type != 'QueryStart'
  AND exception_code != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
ORDER BY event_time DESC
LIMIT 30

パラメーター

例

2021 年 11 月 22 日の 22:00:00 ～ 23:00:00 の間に、s-2-r-0 ノードで発生したエラーを表示し、最新の 30 件を取得します。

SELECT
    written_rows,
    written_bytes,
    query_duration_ms,
    event_time,
    exception
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time >= '2021-11-22 22:00:00'
  AND event_time <= '2021-11-22 23:00:00'
  AND lowerUTF8(query) LIKE '%insert into sdk_event_record_local%'
  AND type != 'QueryStart'
  AND exception_code != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
ORDER BY event_time DESC
LIMIT 30

頻繁に実行されるクエリの検出

指定されたタイムウィンドウ内で、最小実行回数を超える非書き込みクエリを特定します。結果は平均持続時間でソートされるため、高頻度かつ遅延の大きいクエリを容易に特定できます。

クエリテンプレート

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE event_time > toDateTime('<startTime>')
      AND event_time < toDateTime('<endTime>')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = '<nodeName>'
    GROUP BY SQL
    ORDER BY avgTime DESC
)
WHERE queryNum > <queryNum>
[LIMIT <x>]

パラメーター

例

2022 年 9 月 23 日の 12:00:00 ～ 17:00:00 の間に、s-2-r-0 ノードで 1,000 回以上実行された非書き込みクエリを検出します。

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE event_time > toDateTime('2022-09-23 12:00:00')
      AND event_time < toDateTime('2022-09-23 17:00:00')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = 's-2-r-0'
    GROUP BY SQL
    ORDER BY avgTime DESC
)
WHERE queryNum > 1000
LIMIT 50

時間間隔別実行統計の表示

クエリ数および平均持続時間を、時間単位または分単位で集計します。これらのクエリを使用すると、時間経過に伴うトラフィックスパイクおよびレイテンシー劣化を検出できます。

-- 時間単位の実行統計を表示
SELECT
    toHour(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('<startTime>')
  AND event_time < toDateTime('<endTime>')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY t
[LIMIT <x>]

-- 時間単位の実行統計を表示
SELECT
    toHour(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('2022-09-23 08:00:00')
  AND event_time < toDateTime('2022-09-23 17:00:00')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY t
LIMIT 50

-- 分単位の実行統計を表示
SELECT
    toMinute(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('<startTime>')
  AND event_time < toDateTime('<endTime>')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY t
[LIMIT <x>]

-- 分単位の実行統計を表示
SELECT
    toMinute(event_time) AS t,
    count() AS queryNum,
    sum(query_duration_ms) AS totalTime,
    totalTime / queryNum AS avgTime
FROM clusterAllReplicas('default', system.query_log) ql
WHERE event_time > toDateTime('2022-09-23 12:00:00')
  AND event_time < toDateTime('2022-09-23 13:00:00')
  AND query NOT LIKE '%INSERT INTO%'
  AND query LIKE '%Faulty container%'
  AND read_rows != 0
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY t
LIMIT 50

JOIN クエリのカウント

指定されたタイムウィンドウ内で実行された JOIN クエリのボリュームおよび平均持続時間を表示します。このクエリを使用して、JOIN 操作がクラスターのパフォーマンスに与える影響を評価できます。

クエリテンプレート

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE query LIKE '%JOIN%'
      AND read_rows != 0
      AND event_time > toDateTime('<startTime>')
      AND event_time < toDateTime('<endTime>')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = '<nodeName>'
    GROUP BY SQL
    ORDER BY queryNum DESC
)

パラメーター

例

2024 年 6 月 25 日の 12:00:00 ～ 15:00:00 の間に、s-2-r-0 ノードで実行された JOIN クエリをカウントします。

SELECT *
FROM (
    SELECT
        LEFT(query, 100) AS SQL,
        count() AS queryNum,
        sum(query_duration_ms) AS totalTime,
        totalTime / queryNum AS avgTime
    FROM clusterAllReplicas('default', system.query_log) ql
    WHERE query LIKE '%JOIN%'
      AND read_rows != 0
      AND event_time > toDateTime('2024-06-25 12:00:00')
      AND event_time < toDateTime('2024-06-25 15:00:00')
      AND query NOT LIKE '%INSERT INTO%'
      AND substring(hostname(), 38, 8) = 's-2-r-0'
    GROUP BY SQL
    ORDER BY queryNum DESC
)

クエリ数によるユーザーのランキング

前日の非書き込みクエリ実行数が最も多いユーザーを表示します。読み取られた行数およびバイト数の合計も併せて表示されます。

クエリテンプレート

SELECT
    user,
    count(1) AS query_times,
    sum(read_bytes) AS query_bytes,
    sum(read_rows) AS query_rows
FROM clusterAllReplicas('default', system.query_log)
WHERE event_date = yesterday()
  AND is_initial_query = 1
  AND query NOT LIKE 'INSERT INTO%'
  AND substring(hostname(), 38, 8) = '<nodeName>'
GROUP BY user
ORDER BY query_times DESC
[LIMIT <x>]

パラメーター

例

前日の s-2-r-0 ノードにおける、非書き込みクエリ実行数の上位 10 位のユーザーを表示します。

SELECT
    user,
    count(1) AS query_times,
    sum(read_bytes) AS query_bytes,
    sum(read_rows) AS query_rows
FROM clusterAllReplicas('default', system.query_log)
WHERE event_date = yesterday()
  AND is_initial_query = 1
  AND query NOT LIKE 'INSERT INTO%'
  AND substring(hostname(), 38, 8) = 's-2-r-0'
GROUP BY user
ORDER BY query_times DESC
LIMIT 10

次のステップ

• config.xml ファイルでパラメーターを設定する — query_log の TTL およびその他のログ関連のパラメーターを調整します

• クラスターのモニタリング情報を表示する — ノード名とクラスターの健全性メトリックを確認する