Hologres:Get and analyze slow query logs

hg_query_log tablosu

Tablo, aynı şemayı paylaşan ancak farklı anlamlara sahip iki tür kayıt içerir:

duration dökümünü anlama:

duration alanı toplam sorgu süresini temsil eder ve üç aşamadan oluşur:

Bu üç aşamanın ötesinde ek zamanlama ayrıntıları için extended_cost kullanın.

-- SPM
CALL spm_grant('<db_name>_admin', 'Alibaba Cloud account ID');

-- SLPM
CALL slpm_grant('<db_name>.admin', 'Alibaba Cloud account ID');

HoloWeb'de görüntüleme

1. HoloWeb konsolunda oturum açın.

2. Üst gezinme çubuğunda, Diagnostics and Optimization seçeneğine tıklayın.

3. Sol gezinme bölmesinde, Historical Slow Query seçeneğine tıklayın.

4. Historical Slow Query sayfasının üst kısmındaki sorgu koşullarını ayarlayın. Parametrelerin açıklaması için bkz. Geçmiş Yavaş Sorgular.

5. Search seçeneğine tıklayın. Sonuçlar iki alanda görünür:

   • Sorgu Eğilimi Analizi: Zaman içinde yavaş ve başarısız sorguların sıklığını göstererek sorunlu dönemleri belirlemenize yardımcı olur.

   • Sorgular: Her yavaş veya başarısız sorgu için ayrıntılı bilgileri listeler. Görüntülenecek sütunları seçmek için Customize Columns seçeneğine tıklayın.

SQL ile sorgulama

Tam esneklik için hologres.hg_query_log tablosunu doğrudan sorgulayın. Hazır SQL örnekleri için bkz. Sorguları teşhis etme.

SELECT count(*) FROM hologres.hg_query_log;

 count
-------
    44
(1 row)

SELECT usename AS "User",
       count(1) AS "Query count"
FROM hologres.hg_query_log
GROUP BY usename
ORDER BY count(1) DESC;

        User         | Query count
---------------------+-------------
 1111111111111111    |          27
 2222222222222222    |          11
 3333333333333333    |           4
 4444444444444444    |           2
(4 rows)

SELECT * FROM hologres.hg_query_log WHERE query_id = '13001450118416xxxx';

SELECT status           AS "Status",
       duration         AS "Duration (ms)",
       query_start      AS "Start time",
       (read_bytes / 1048576)::text || ' MB'  AS "Data read",
       (memory_bytes / 1048576)::text || ' MB' AS "Memory",
       (shuffle_bytes / 1048576)::text || ' MB' AS "Shuffle",
       (cpu_time_ms / 1000)::text || ' s'    AS "CPU time",
       physical_reads   AS "Disk reads",
       query_id         AS "Query ID",
       query::char(30)
FROM hologres.hg_query_log
WHERE query_start >= now() - interval '10 min'
ORDER BY duration DESC,
         read_bytes DESC,
         shuffle_bytes DESC,
         memory_bytes DESC,
         cpu_time_ms DESC,
         physical_reads DESC
LIMIT 100;

 Status  | Duration (ms) |       Start time       | Data read | Memory | Shuffle | CPU time | Disk reads |       Query ID     |         query
---------+---------------+------------------------+-----------+--------+---------+----------+------------+--------------------+--------------------------------
 SUCCESS |           149 | 2021-03-30 23:45:01+08 | 0 MB      | 25 MB  | 454 MB  | 321 s    |          0 | 13001450118416xxxx | explain analyze SELECT  * FROM
 SUCCESS |           137 | 2021-03-30 23:49:18+08 | 247 MB    | 21 MB  | 213 MB  | 803 s    |       7771 | 13001491818416xxxx | explain analyze SELECT  * FROM
 FAILED  |            53 | 2021-03-30 23:48:43+08 | 0 MB      | 0 MB   | 0 MB    | 0 s      |          0 | 13001484318416xxxx | SELECT ds::bigint / 0 FROM pub
(3 rows)

SELECT status              AS "Status",
       duration            AS "Duration (ms)",
       optimization_cost   AS "Optimization cost (ms)",
       start_query_cost    AS "Startup cost (ms)",
       get_next_cost       AS "Execution cost (ms)",
       duration - optimization_cost - start_query_cost - get_next_cost AS "Other cost (ms)",
       query_id            AS "Query ID",
       query::char(30)
FROM hologres.hg_query_log
WHERE query_start >= now() - interval '10 min'
ORDER BY duration DESC,
         start_query_cost DESC,
         optimization_cost,
         get_next_cost DESC,
         duration - optimization_cost - start_query_cost - get_next_cost DESC
LIMIT 100;

 Status  | Duration (ms) | Optimization cost (ms) | Startup cost (ms) | Execution cost (ms) | Other cost (ms) |       Query ID     |         query
---------+---------------+------------------------+-------------------+---------------------+-----------------+--------------------+--------------------------------
 SUCCESS |          4572 |                    521 |               320 |                3726 |               5 | 6000260625679xxxx  | -- /* user: wang ip: xxx.xx.x
 SUCCESS |          1490 |                    538 |                98 |                 846 |               8 | 12000250867886xxxx | -- /* user: lisa ip: xxx.xx.x
 SUCCESS |          1230 |                    502 |                95 |                 625 |               8 | 26000512070295xxxx | -- /* user: zhang ip: xxx.xx.
(3 rows)

SELECT date_trunc('hour', query_start) AS query_start,
       count(1)           AS query_count,
       sum(read_bytes)    AS read_bytes,
       sum(cpu_time_ms)   AS cpu_time_ms
FROM hologres.hg_query_log
WHERE query_start >= now() - interval '3 h'
GROUP BY 1;

SELECT query_date,
       count(1)           AS query_count,
       sum(read_bytes)    AS read_bytes,
       sum(cpu_time_ms)   AS cpu_time_ms
FROM hologres.hg_query_log
WHERE query_start >= now() - interval '3 h'
GROUP BY query_date
UNION ALL
SELECT query_date,
       count(1)           AS query_count,
       sum(read_bytes)    AS read_bytes,
       sum(cpu_time_ms)   AS cpu_time_ms
FROM hologres.hg_query_log
WHERE query_start >= now() - interval '1d 3h'
  AND query_start <= now() - interval '1d'
GROUP BY query_date;

SELECT status              AS "Status",
       regexp_replace(message, '\n', ' ')::char(150) AS "Error message",
       duration            AS "Duration (ms)",
       query_start         AS "Start time",
       query_id            AS "Query ID",
       query::char(100)    AS "Query"
FROM hologres.hg_query_log
WHERE query_start BETWEEN '2021-03-25 17:00:00'::timestamptz
                      AND '2021-03-25 17:42:00'::timestamptz + interval '2 min'
  AND status = 'FAILED'
ORDER BY query_start ASC
LIMIT 100;

 Status |                        Error message                        | Duration (ms) |       Start time       |      Query ID      | Query
--------+--------------------------------------------------------------+---------------+------------------------+--------------------+-------
 FAILED | Query:[1070285448673xxxx] code: kActorInvokeError msg: "..." |          1460 | 2021-03-25 17:28:54+08 | 1070285448673xxxx  | S...
 FAILED | Query:[1016285560553xxxx] code: kActorInvokeError msg: "..." |           131 | 2021-03-25 17:28:55+08 | 1016285560553xxxx  | S...
(2 rows)

SELECT COUNT(1)
FROM (
    SELECT DISTINCT t1.digest
    FROM hologres.hg_query_log t1
    WHERE t1.query_start >= CURRENT_DATE - INTERVAL '1 day'
      AND t1.query_start < CURRENT_DATE
      AND NOT EXISTS (
          SELECT 1
          FROM hologres.hg_query_log t2
          WHERE t2.digest = t1.digest
            AND t2.query_start < CURRENT_DATE - INTERVAL '1 day'
      )
      AND digest IS NOT NULL
) AS a;

 count
-------
    10
(1 row)

SELECT a.command_tag,
       COUNT(1)
FROM (
    SELECT DISTINCT t1.digest, t1.command_tag
    FROM hologres.hg_query_log t1
    WHERE t1.query_start >= CURRENT_DATE - INTERVAL '1 day'
      AND t1.query_start < CURRENT_DATE
      AND NOT EXISTS (
          SELECT 1
          FROM hologres.hg_query_log t2
          WHERE t2.digest = t1.digest
            AND t2.query_start < CURRENT_DATE - INTERVAL '1 day'
      )
      AND t1.digest IS NOT NULL
) AS a
GROUP BY 1
ORDER BY 2 DESC;

 command_tag | count
-------------+-------
 INSERT      |     8
 SELECT      |     2
(2 rows)

SELECT a.usename, a.status, a.query_id, a.digest,
       a.datname, a.command_tag, a.query, a.cpu_time_ms, a.memory_bytes
FROM (
    SELECT DISTINCT
        t1.usename, t1.status, t1.query_id, t1.digest,
        t1.datname, t1.command_tag, t1.query, t1.cpu_time_ms, t1.memory_bytes
    FROM hologres.hg_query_log t1
    WHERE t1.query_start >= CURRENT_DATE - INTERVAL '1 day'
      AND t1.query_start < CURRENT_DATE
      AND NOT EXISTS (
          SELECT 1
          FROM hologres.hg_query_log t2
          WHERE t2.digest = t1.digest
            AND t2.query_start < CURRENT_DATE - INTERVAL '1 day'
      )
      AND t1.digest IS NOT NULL
) AS a;

SELECT to_char(a.query_start, 'HH24') AS query_start_hour,
       a.command_tag,
       COUNT(1)
FROM (
    SELECT DISTINCT t1.query_start, t1.digest, t1.command_tag
    FROM hologres.hg_query_log t1
    WHERE t1.query_start >= CURRENT_DATE - INTERVAL '1 day'
      AND t1.query_start < CURRENT_DATE
      AND NOT EXISTS (
          SELECT 1
          FROM hologres.hg_query_log t2
          WHERE t2.digest = t1.digest
            AND t2.query_start < CURRENT_DATE - INTERVAL '1 day'
      )
      AND t1.digest IS NOT NULL
) AS a
GROUP BY 1, 2
ORDER BY 3 DESC;

 query_start_hour | command_tag | count
------------------+-------------+-------
               21 | INSERT      |     8
               11 | SELECT      |     1
               13 | SELECT      |     1
(3 rows)

SELECT digest,
       command_tag,
       count(1)
FROM hologres.hg_query_log
WHERE query_start >= CURRENT_DATE - INTERVAL '1 day'
  AND query_start < CURRENT_DATE
GROUP BY 1, 2
ORDER BY 3 DESC;

SELECT digest,
       avg(cpu_time_ms)
FROM hologres.hg_query_log
WHERE query_start >= CURRENT_DATE - INTERVAL '1 day'
  AND query_start < CURRENT_DATE
  AND digest IS NOT NULL
  AND usename != 'system'
  AND cpu_time_ms IS NOT NULL
GROUP BY 1
ORDER BY 2 DESC
LIMIT 10;

SELECT digest,
       avg(memory_bytes)
FROM hologres.hg_query_log
WHERE query_start >= CURRENT_DATE - INTERVAL '7 day'
  AND query_start < CURRENT_DATE
  AND digest IS NOT NULL
  AND memory_bytes IS NOT NULL
GROUP BY 1
ORDER BY 2 DESC
LIMIT 10;

log_min_duration_statement

Günlüğe kaydetme için minimum sorgu süresini kontrol eder.

• Varsayılan: 100 ms (V2.2.7'den itibaren; önceki sürümlerde varsayılan 1.000 ms'dir).

• Minimum değer: 100 ms.

• Yavaş sorgu günlüklerini tamamen devre dışı bırakmak için -1 olarak ayarlayın.

• Yalnızca superuser'lar bunu veritabanı düzeyinde değiştirebilir. Normal kullanıcılar bunu oturum düzeyinde değiştirebilir.

• Değişiklikler yalnızca yeni sorgular için geçerlidir.

-- Database level (superuser only)
ALTER DATABASE dbname SET log_min_duration_statement = '250ms';

-- Session level
SET log_min_duration_statement = '250ms';

log_min_duration_query_stats

Bir sorgu için yürütme istatistiklerinin yakalanıp yakalanmayacağını kontrol eder.

• Varsayılan: 10 saniyeden uzun süren sorgular için istatistikleri kaydeder.

• İstatistik toplamayı devre dışı bırakmak için -1 olarak ayarlayın.

• İstatistikler önemli depolama alanı kullanır. Bu değeri yalnızca hedefli sorun giderme için düşürün; ardından geri yükleyin.

• Değişiklikler yalnızca yeni sorgular için geçerlidir.

-- Database level (superuser only)
ALTER DATABASE dbname SET log_min_duration_query_stats = '20s';

-- Session level
SET log_min_duration_query_stats = '20s';

log_min_duration_query_plan

Bir sorgu için yürütme planının yakalanıp yakalanmayacağını kontrol eder.

• Varsayılan: 10 saniyeden uzun süren sorgular için planları kaydeder.

• Plan yakalamayı devre dışı bırakmak için -1 olarak ayarlayın.

• Geçici sorun giderme için bunun yerine EXPLAIN kullanın; planı günlüğe kaydetmeden anında döndürür.

• Değişiklikler yalnızca yeni sorgular için geçerlidir.

-- Database level (superuser only)
ALTER DATABASE dbname SET log_min_duration_query_plan = '10s';

-- Session level
SET log_min_duration_query_plan = '10s';

ALTER DATABASE <db_name> SET hg_query_log_retention_time_sec = 2592000;

Bir Hologres iç tablosuna dışa aktarma

-- Step 1: Create the target table
CREATE TABLE query_log_download (
    usename text,
    status text,
    query_id text,
    datname text,
    command_tag text,
    duration integer,
    message text,
    query_start timestamp with time zone,
    query_date text,
    query text,
    result_rows bigint,
    result_bytes bigint,
    read_rows bigint,
    read_bytes bigint,
    affected_rows bigint,
    affected_bytes bigint,
    memory_bytes bigint,
    shuffle_bytes bigint,
    cpu_time_ms bigint,
    physical_reads bigint,
    pid integer,
    application_name text,
    engine_type text[],
    client_addr text,
    table_write text,
    table_read text[],
    session_id text,
    session_start timestamp with time zone,
    trans_id text,
    command_id text,
    optimization_cost integer,
    start_query_cost integer,
    get_next_cost integer,
    extended_cost text,
    plan text,
    statistics text,
    visualization_info text,
    query_detail text,
    query_extinfo text[]
);

-- Step 2: Export logs for a specific date
INSERT INTO query_log_download
SELECT
    usename, status, query_id, datname, command_tag, duration, message,
    query_start, query_date, query, result_rows, result_bytes, read_rows,
    read_bytes, affected_rows, affected_bytes, memory_bytes, shuffle_bytes,
    cpu_time_ms, physical_reads, pid, application_name, engine_type,
    client_addr, table_write, table_read, session_id, session_start,
    trans_id, command_id, optimization_cost, start_query_cost, get_next_cost,
    extended_cost, plan, statistics, visualization_info, query_detail, query_extinfo
FROM hologres.hg_query_log
WHERE query_start >= '2022-08-03'
  AND query_start < '2022-08-04';

Bir MaxCompute yabancı tablosuna dışa aktarma

1. MaxCompute'te, verileri almak için bölümlenmiş bir tablo oluşturun:

   CREATE TABLE IF NOT EXISTS mc_holo_query_log (
       username        STRING COMMENT 'The username for the query',
       status          STRING COMMENT 'The final status of the query: success or failed',
       query_id        STRING COMMENT 'The query ID',
       datname         STRING COMMENT 'The name of the database for the query',
       command_tag     STRING COMMENT 'The type of query',
       duration        BIGINT COMMENT 'The query duration in milliseconds (ms)',
       message         STRING COMMENT 'The error message',
       query           STRING COMMENT 'The text content of the query',
       read_rows       BIGINT COMMENT 'The number of rows read by the query',
       read_bytes      BIGINT COMMENT 'The number of bytes read by the query',
       memory_bytes    BIGINT COMMENT 'The peak memory consumption on a single node (not exact)',
       shuffle_bytes   BIGINT COMMENT 'The estimated number of bytes for data shuffle (not exact)',
       cpu_time_ms     BIGINT COMMENT 'The total CPU time in milliseconds (not exact)',
       physical_reads  BIGINT COMMENT 'The number of physical reads',
       application_name STRING COMMENT 'The query application type',
       engine_type     ARRAY<STRING> COMMENT 'The engine used for the query',
       table_write     STRING COMMENT 'The table to which the SQL statement writes data',
       table_read      ARRAY<STRING> COMMENT 'The table from which the SQL statement reads data',
       plan            STRING COMMENT 'The execution plan for the query',
       optimization_cost BIGINT COMMENT 'The time to generate the query execution plan',
       start_query_cost  BIGINT COMMENT 'The query startup time',
       get_next_cost     BIGINT COMMENT 'The query execution duration',
       extended_cost   STRING COMMENT 'Other detailed costs of the query',
       query_detail    STRING COMMENT 'Other extended information about the query (JSON format)',
       query_extinfo   ARRAY<STRING> COMMENT 'Other extended information about the query (ARRAY format)',
       query_start     STRING COMMENT 'The query start time',
       query_date      STRING COMMENT 'The query start date'
   ) COMMENT 'Hologres instance query log'
   PARTITIONED BY (ds STRING COMMENT 'stat date')
   LIFECYCLE 365;
   
   ALTER TABLE mc_holo_query_log ADD PARTITION (ds=20220803);

2. Hologres'te, MaxCompute tablosunu bir yabancı tablo olarak içe aktarın ve günlükleri dışa aktarın:

   IMPORT FOREIGN SCHEMA project_name LIMIT TO (mc_holo_query_log)
   FROM SERVER odps_server INTO public;
   
   INSERT INTO mc_holo_query_log
   SELECT
       usename AS username, status, query_id, datname, command_tag, duration,
       message, query, read_rows, read_bytes, memory_bytes, shuffle_bytes,
       cpu_time_ms, physical_reads, application_name, engine_type,
       table_write, table_read, plan, optimization_cost, start_query_cost,
       get_next_cost, extended_cost, query_detail, query_extinfo,
       query_start, query_date,
       '20220803'
   FROM hologres.hg_query_log
   WHERE query_start >= '2022-08-03'
     AND query_start < '2022-08-04';

-- Database level (recommended — set once per database)
ALTER DATABASE <db_name> SET hg_experimental_force_sync_collect_execution_statistics = ON;

-- Session level
SET hg_experimental_force_sync_collect_execution_statistics = ON;