#debugging

Najpierw: pg_stat_statements

Bez tego punkt 2 nie ruszy. Rozszerzenie nie jest domyślnie włączone.

W postgresql.conf:

shared_preload_libraries = 'pg_stat_statements'

Wymaga restartu — pg_reload_conf() nie wystarczy. Potem w bazie:

CREATE EXTENSION pg_stat_statements;

Trzyma 5000 unikalnych zapytań (pg_stat_statements.max). Wyzerowanie liczników:

SELECT pg_stat_statements_reset();

1. Aktywne zapytania

SELECT
    a.pid,
    a.datname,
    a.usename,
    a.application_name,
    a.client_addr,
    a.state,
    a.wait_event_type,
    a.wait_event,
    now() - a.xact_start AS xact_age,
    now() - a.query_start AS query_age,
    now() - a.state_change AS state_age,
    pg_blocking_pids(a.pid) AS blocked_by,
    a.query
FROM pg_stat_activity a
WHERE a.pid <> pg_backend_pid()
  AND a.backend_type = 'client backend'
  AND a.state IS DISTINCT FROM 'idle'
ORDER BY COALESCE(a.xact_start, a.query_start, a.backend_start) ASC;

pg_blocking_pids mówi, kto kogo blokuje — pusta tablica znaczy, że ten backend na nic nie czeka.

state IS DISTINCT FROM 'idle' wycina bezczynne połączenia, ale zostawia idle in transaction. I to zwykle one są problemem.

Ubicie:

-- Anuluje zapytanie, połączenie zostaje
SELECT pg_cancel_backend(12345);

-- Zrywa połączenie
SELECT pg_terminate_backend(12345);

Najpierw cancel.

2. Wolne zapytania

SELECT
    s.queryid,
    d.datname,
    s.calls,
    round((s.total_exec_time / 1000.0)::numeric, 1) AS total_sec,
    round(s.mean_exec_time::numeric, 2) AS mean_ms,
    round(s.max_exec_time::numeric, 2) AS max_ms,
    round(s.stddev_exec_time::numeric, 2) AS stddev_ms,
    round((100.0 * s.total_exec_time / NULLIF(sum(s.total_exec_time) OVER (), 0))::numeric, 1) AS pct_of_total_time,
    s.rows,
    round(s.rows::numeric / NULLIF(s.calls, 0), 1) AS rows_per_call,
    round((100.0 * s.shared_blks_hit / NULLIF(s.shared_blks_hit + s.shared_blks_read, 0))::numeric, 1) AS cache_hit_percent,
    pg_size_pretty(s.shared_blks_read * current_setting('block_size')::bigint) AS disk_read,
    pg_size_pretty(s.temp_blks_read * current_setting('block_size')::bigint) AS temp_read,
    pg_size_pretty(s.temp_blks_written * current_setting('block_size')::bigint) AS temp_written,
    pg_size_pretty(s.wal_bytes::bigint) AS wal_generated,
    round(s.shared_blk_read_time::numeric, 1) AS io_read_ms,
    round(s.shared_blk_write_time::numeric, 1) AS io_write_ms,
    s.query
FROM pg_stat_statements s
LEFT JOIN pg_database d ON d.oid = s.dbid
WHERE d.datname = current_database()
ORDER BY s.total_exec_time DESC
LIMIT 50;

Patrz na pct_of_total_time, nie na mean_ms. Zapytanie po 5 ms puszczone milion razy waży więcej niż jedno trzysekundowe.

temp_written powyżej zera = sortuje na dysku, podnieś work_mem. Niski cache_hit_percent = czyta z dysku zamiast z cache. Wysoki stddev_ms = plan sypie się przy niektórych parametrach.

3. Indeksy

SELECT
    n.nspname AS schema_name,
    t.relname AS table_name,
    i.relname AS index_name,
    am.amname AS index_type,
    ix.indisunique AS is_unique,
    ix.indisprimary AS is_primary_key,
    (ix.indisvalid AND ix.indisready AND ix.indislive) AS is_valid,
    ix.indnkeyatts AS key_columns,
    ix.indnatts - ix.indnkeyatts AS included_columns,
    ix.indpred IS NOT NULL AS is_partial,
    NULLIF(t.reltuples, -1)::bigint AS row_count_estimate,
    round(pg_relation_size(i.oid) / 1024.0 / 1024, 2) AS index_size_mb,
    COALESCE(sui.idx_scan, 0) AS num_of_scans,
    sui.last_idx_scan,
    COALESCE(sui.idx_tup_read, 0) AS index_entries_read,
    COALESCE(sui.idx_tup_fetch, 0) AS heap_rows_fetched,
    COALESCE(sut.n_tup_ins, 0) AS table_inserts,
    COALESCE(sut.n_tup_upd, 0) AS table_updates,
    COALESCE(sut.n_tup_hot_upd, 0) AS hot_updates,
    GREATEST(COALESCE(sut.n_tup_upd, 0) - COALESCE(sut.n_tup_hot_upd, 0), 0) AS non_hot_updates,
    COALESCE(sut.n_tup_del, 0) AS table_deletes,
    sd.stats_reset AS counters_since,
    pg_get_expr(ix.indpred, ix.indrelid) AS predicate,
    pg_get_indexdef(i.oid) AS index_definition
FROM pg_index ix
JOIN pg_class i ON i.oid = ix.indexrelid
JOIN pg_class t ON t.oid = ix.indrelid
JOIN pg_namespace n ON n.oid = t.relnamespace
JOIN pg_am am ON am.oid = i.relam
LEFT JOIN pg_stat_user_indexes sui ON sui.indexrelid = i.oid
LEFT JOIN pg_stat_user_tables sut ON sut.relid = t.oid
CROSS JOIN (
    SELECT stats_reset
    FROM pg_stat_database
    WHERE datname = current_database()
) sd
WHERE n.nspname NOT IN ('pg_catalog', 'information_schema', 'pg_toast')
  AND t.relkind IN ('r', 'm', 'p')
ORDER BY pg_relation_size(i.oid) DESC;

num_of_scans = 0 to kandydat do wywalenia — ale najpierw zerknij na counters_since. Ta kolumna jest tu właśnie po to, żeby nie skasować indeksu na podstawie licznika wyzerowanego wczoraj.

is_valid = false to niedokończone CREATE INDEX CONCURRENTLY. Taki indeks nie jest używany, a i tak kosztuje przy każdym zapisie — skasować i zbudować od nowa.

non_hot_updates to update’y, które musiały ruszyć indeksy. Dużo = wysoki koszt utrzymania.

last_idx_scan wymaga PG 16.

4. Martwe krotki i nieaktualne statystyki

SELECT
    s.schemaname,
    s.relname,
    s.n_live_tup,
    s.n_dead_tup,
    round(100.0 * s.n_dead_tup / NULLIF(s.n_live_tup + s.n_dead_tup, 0), 1) AS dead_percent,
    s.n_mod_since_analyze,
    s.n_ins_since_vacuum,
    age(c.relfrozenxid) AS xid_age,
    s.last_vacuum,
    s.last_autovacuum,
    s.last_analyze,
    s.last_autoanalyze,
    pg_size_pretty(pg_table_size(s.relid)) AS table_size,
    c.reloptions
FROM pg_stat_user_tables s
JOIN pg_class c ON c.oid = s.relid
WHERE s.n_dead_tup > 1000
   OR s.n_mod_since_analyze > 1000
ORDER BY dead_percent DESC NULLS LAST;

Wysoki dead_percent = autovacuum nie nadąża i tabela puchnie.

Wysoki n_mod_since_analyze = planner liczy na nieaktualnych statystykach i dobiera złe plany. Zwykle boli bardziej niż samo bloat.

xid_age dobijający do 200 mln (autovacuum_freeze_max_age) = zbliża się wraparound.

5. Rozmiary

SELECT
    n.nspname AS schema_name,
    c.relname AS table_name,
    NULLIF(c.reltuples, -1)::bigint AS row_count_estimate,
    pg_size_pretty(pg_total_relation_size(c.oid)) AS total_size,
    pg_size_pretty(pg_table_size(c.oid)) AS table_size,
    pg_size_pretty(pg_relation_size(c.oid)) AS main_fork_size,
    pg_size_pretty(pg_indexes_size(c.oid)) AS indexes_size,
    pg_size_pretty(
        CASE
            WHEN c.reltoastrelid = 0 THEN 0
            ELSE pg_total_relation_size(c.reltoastrelid)
        END
    ) AS toast_size,
    round(100.0 * pg_total_relation_size(c.oid) / NULLIF(pg_database_size(current_database()), 0), 2) AS pct_of_database
FROM pg_class c
JOIN pg_namespace n ON n.oid = c.relnamespace
WHERE c.relkind IN ('r', 'm')
  AND n.nspname NOT IN ('pg_catalog', 'information_schema', 'pg_toast')
ORDER BY pg_total_relation_size(c.oid) DESC;

pg_total_relation_size = tabela + indeksy + TOAST. pg_table_size to samo bez indeksów, pg_relation_size sam główny fork.

row_count_estimate to szacunek z ostatniego ANALYZE, nie COUNT(*). -1 znaczy „nigdy nie analizowana”.

Całe bazy na serwerze:

SELECT
    datname,
    pg_size_pretty(pg_database_size(datname)) AS database_size
FROM pg_database
WHERE NOT datistemplate
ORDER BY pg_database_size(datname) DESC;

1. Trwające zapytania

SELECT 
	sqltext.TEXT,
	session_id,
	STATUS,
	command,
	cpu_time,
	total_elapsed_time,
	wait_type
FROM sys.dm_exec_requests req
CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS sqltext
WHERE req.session_id <> @@SPID AND req.session_id > 50

Duży total_elapsed_time przy małym cpu_time = zapytanie czeka, nie liczy. Wtedy patrz w wait_type. Czasy w milisekundach.

2. Fragmentacja

SELECT
    S.name AS [Schema],
    T.name AS [Table],
    I.name AS [Index],
    DDIPS.index_type_desc AS [IndexType],
    DDIPS.avg_fragmentation_in_percent AS [FragmentationPercent],
    DDIPS.page_count AS [PageCount],
    DDIPS.page_count * 8.0 / 1024 AS [SizeMB]
FROM sys.dm_db_index_physical_stats(
    DB_ID(),
    NULL,
    NULL,
    NULL,
    'LIMITED'
) AS DDIPS 
INNER JOIN sys.tables T ON T.object_id = DDIPS.object_id
INNER JOIN sys.schemas S ON T.schema_id = S.schema_id
INNER JOIN sys.indexes I ON I.object_id = DDIPS.object_id AND I.index_id = DDIPS.index_id
WHERE
    DDIPS.database_id = DB_ID()
    AND T.is_ms_shipped = 0
    AND I.index_id > 0
    AND I.name IS NOT NULL
    AND DDIPS.page_count >= 100
    AND DDIPS.avg_fragmentation_in_percent > 10
ORDER BY
    DDIPS.avg_fragmentation_in_percent DESC;

Fragmentacja	Co z tym
poniżej 5%	olej
5–30%	REORGANIZE
powyżej 30%	REBUILD

page_count >= 100, bo mniejsze indeksy i tak siedzą w pamięci — przebudowa to strata czasu i logu.

'LIMITED' zostaw. 'DETAILED' czyta każdą stronę indeksu i potrafi zajechać produkcję.

3. Rozmiary indeksów

SELECT
    SCHEMA_NAME(t.schema_id) AS [SchemaName],
    t.name AS [TableName],
    i.name AS [IndexName],
    i.type_desc AS [IndexType],
    SUM(ps.used_page_count) * 8.0 / 1024 AS [IndexSizeMB],
    SUM(ps.row_count) AS [RowCount]
FROM sys.dm_db_partition_stats ps
JOIN sys.indexes i ON ps.object_id = i.object_id AND ps.index_id = i.index_id
JOIN sys.tables t ON ps.object_id = t.object_id
WHERE i.index_id > 0
GROUP BY
    t.schema_id, t.name, i.object_id, i.index_id, i.name, i.type_desc
HAVING SUM(ps.used_page_count) * 8.0 / 1024 > 1
ORDER BY [IndexSizeMB] DESC;

* 8.0 / 1024 — strona ma 8 KB

index_id > 0 wycina sterty. index_id = 1 to klaster, czyli same dane tabeli — zawsze na górze listy, nie ma co się przejmować.

4. Indeksy i użycie

S Tier do debugowania

Opus magnum optymalizatora ms sql, zamieszczam je jako ostatnie, bo godni go są tylko Ci, którzy poświęcili czas na przeczytanie poprzednich zapytań

SELECT
    SCHEMA_NAME(T.schema_id) AS Schema_Name,
    T.name AS Table_Name,
    IX.name AS Index_Name,
    IX.type_desc AS Index_Type,
    IX.is_unique AS IsUnique,
    IX.is_primary_key AS IsPrimaryKey,
    IX.is_unique_constraint AS IsUniqueConstraint,
    SUM(PS.row_count) AS 'RowCount',
    SUM(PS.used_page_count) * 8 AS IndexSizeKB,
    SUM(PS.used_page_count) * 8.0 / 1024 AS IndexSizeMB,
    ISNULL(IXUS.user_seeks, 0) AS NumOfSeeks,
    ISNULL(IXUS.user_scans, 0) AS NumOfScans,
    ISNULL(IXUS.user_lookups, 0) AS NumOfLookups,
    ISNULL(IXUS.user_updates, 0) AS NumOfUpdates,
    IXUS.last_user_seek AS LastSeek,
    IXUS.last_user_scan AS LastScan,
    IXUS.last_user_lookup AS LastLookup,
    IXUS.last_user_update AS LastUpdate
FROM sys.indexes IX
JOIN sys.tables T ON T.object_id = IX.object_id
JOIN sys.dm_db_partition_stats PS ON PS.object_id = IX.object_id AND PS.index_id = IX.index_id
LEFT JOIN sys.dm_db_index_usage_stats IXUS ON IXUS.database_id = DB_ID() AND IXUS.index_id = IX.index_id AND IXUS.object_id = IX.object_id
WHERE T.is_ms_shipped = 0 AND IX.index_id > 0
GROUP BY
    T.schema_id, T.name, IX.name, IX.type_desc, IX.is_unique, IX.is_primary_key, IX.is_unique_constraint, IXUS.user_seeks, IXUS.user_scans,
	IXUS.user_lookups, IXUS.user_updates, IXUS.last_user_seek, IXUS.last_user_scan, IXUS.last_user_lookup, IXUS.last_user_update
ORDER BY IndexSizeMB DESC;

TL;DR:

dużo seeks     → zazwyczaj indeks jest użyteczny
dużo scans     → trzeba sprawdzić, dlaczego skanuje
dużo lookups   → trzeba sprawdzić, czy indeksy są covering
dużo updates   → koszt utrzymania indeksu

W większości przypadków:

Operacja	Typowo	Co oznacza
Index Seek	🟢 dobrze	SQL Server trafia w konkretny zakres indeksu
Index Scan	🟡 zależy	czyta dużą część albo cały indeks
Table Scan / Heap Scan	🟡/🔴 zależy	czyta tabelę bez użytecznego indeksu
Key/Bookmark Lookup	🟡/🔴	po znalezieniu rekordów w indeksie musi osobno dociągać kolumny z tabeli/clustered indexu (spróbuj INCLUDE)

Najważniejsze: sys.dm_db_index_usage_stats zeruje się przy restarcie usługi. Zero odczytów nie znaczy „nieużywany” — może znaczyć „serwer wstał wczoraj”.

Sprawdź, od kiedy w ogóle liczy:

SELECT sqlserver_start_time FROM sys.dm_os_sys_info;