Quando si lavora con database OLTP (OnLine Transaction Processing), le prestazioni delle query sono fondamentali in quanto influiscono direttamente sull'esperienza dell'utente. Query lente significano che l'applicazione non risponde e lenta e ciò si traduce in tassi di conversione scadenti, utenti insoddisfatti e tutti i set di problemi.
OLTP è uno dei casi d'uso comuni di PostgreSQL, quindi vuoi che le tue query vengano eseguite il più agevolmente possibile. In questo blog vorremmo parlare di come identificare i problemi con le query lente in PostgreSQL.
Capire il registro lento
In generale, il modo più tipico per identificare i problemi di prestazioni con PostgreSQL è raccogliere query lente. Ci sono un paio di modi in cui puoi farlo. Innanzitutto, puoi abilitarlo su un singolo database:
pgbench=# ALTER DATABASE pgbench SET log_min_duration_statement=0;
ALTER DATABASEDopo questo, tutte le nuove connessioni al database 'pgbench' verranno registrate nel registro di PostgreSQL.
È anche possibile abilitarlo a livello globale aggiungendo:
log_min_duration_statement = 0alla configurazione di PostgreSQL e quindi ricarica la configurazione:
pgbench=# SELECT pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)Ciò abilita la registrazione di tutte le query su tutti i database nel tuo PostgreSQL. Se non vedi alcun registro, potresti voler abilitare anche logging_collector =on. I log includeranno tutto il traffico in arrivo alle tabelle di sistema PostgreSQL, rendendolo più rumoroso. Per i nostri scopi, atteniamoci alla registrazione a livello di database.
Quello che vedrai nel registro sono voci come di seguito:
2020-02-21 09:45:39.022 UTC [13542] LOG: duration: 0.145 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 29817899;
2020-02-21 09:45:39.022 UTC [13544] LOG: duration: 0.107 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 11782597;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.065 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 16318529;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.082 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + 3063 WHERE tid = 3244;
2020-02-21 09:45:39.022 UTC [13526] LOG: duration: 16.450 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 1359 WHERE bid = 195;
2020-02-21 09:45:39.023 UTC [13523] LOG: duration: 15.824 ms statement: UPDATE pgbench_accounts SET abalance = abalance + -3726 WHERE aid = 5290358;
2020-02-21 09:45:39.023 UTC [13542] LOG: duration: 0.107 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -2716 WHERE tid = 1794;
2020-02-21 09:45:39.024 UTC [13544] LOG: duration: 0.112 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3814 WHERE tid = 278;
2020-02-21 09:45:39.024 UTC [13526] LOG: duration: 0.060 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (4876, 195, 39955137, 1359, CURRENT_TIMESTAMP);
2020-02-21 09:45:39.024 UTC [13529] LOG: duration: 0.081 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 3063 WHERE bid = 369;
2020-02-21 09:45:39.024 UTC [13523] LOG: duration: 0.063 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
2020-02-21 09:45:39.024 UTC [13542] LOG: duration: 0.100 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + -2716 WHERE bid = 210;
2020-02-21 09:45:39.026 UTC [13523] LOG: duration: 0.092 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3726 WHERE tid = 67;
2020-02-21 09:45:39.026 UTC [13529] LOG: duration: 0.090 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (3244, 369, 16318529, 3063, CURRENT_TIMESTAMP);Puoi vedere le informazioni sulla query e la sua durata. Non molto altro, ma è sicuramente un buon punto di partenza. La cosa principale da tenere a mente è che non tutte le query lente sono un problema. A volte le query devono accedere a una quantità significativa di dati e si prevede che impieghino più tempo per accedere e analizzare tutte le informazioni richieste dall'utente. Un'altra domanda è cosa significa "lento"? Questo dipende principalmente dall'applicazione. Se parliamo di applicazioni interattive, molto probabilmente si nota qualcosa di più lento di un secondo. Idealmente, tutto viene eseguito entro un limite di 100 - 200 millisecondi.
Sviluppo di un piano di esecuzione delle query
Una volta stabilito che una determinata query è effettivamente qualcosa che vogliamo migliorare, dovremmo dare un'occhiata al piano di esecuzione della query. Prima di tutto, può succedere che non ci sia nulla che possiamo fare al riguardo e dovremo accettare che una determinata query sia solo lenta. In secondo luogo, i piani di esecuzione delle query possono cambiare. Gli ottimizzatori cercano sempre di scegliere il piano di esecuzione più ottimale, ma prendono le decisioni basandosi solo su un campione di dati, pertanto è possibile che il piano di esecuzione delle query cambi nel tempo. In PostgreSQL puoi controllare il piano di esecuzione in due modi. Innanzitutto, il piano di esecuzione stimato, utilizzando EXPLAIN:
pgbench=# EXPLAIN SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4)
Index Cond: (aid = 5290358)Come puoi vedere, ci si aspetta che accediamo ai dati utilizzando la ricerca della chiave primaria. Se vogliamo ricontrollare come verrà eseguita esattamente la query, possiamo utilizzare EXPLAIN ANALYZE:
pgbench=# EXPLAIN ANALYZE SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4) (actual time=0.046..0.065 rows=1 loops=1)
Index Cond: (aid = 5290358)
Planning time: 0.053 ms
Execution time: 0.084 ms
(4 rows)Ora, PostgreSQL ha eseguito questa query e può dirci non solo le stime ma anche i numeri esatti quando si tratta del piano di esecuzione, il numero di righe a cui si accede e così via. Tieni presente che la registrazione di tutte le query potrebbe diventare un serio sovraccarico per il tuo sistema. Dovresti anche tenere d'occhio i registri e assicurarti che siano ruotati correttamente.
Pg_stat_statements
Pg_stat_statements è l'estensione che raccoglie le statistiche di esecuzione per diversi tipi di query.
pgbench=# select query, calls, total_time, min_time, max_time, mean_time, stddev_time, rows from public.pg_stat_statements order by calls desc LIMIT 10;
query | calls | total_time | min_time | max_time | mean_time | stddev_time | rows
------------------------------------------------------------------------------------------------------+-------+------------------+----------+------------+---------------------+---------------------+-------
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 30437 | 6636.83641200002 | 0.006533 | 83.832148 | 0.218051595492329 | 1.84977058799388 | 30437
BEGIN | 30437 | 231.095600000001 | 0.000205 | 20.260355 | 0.00759258796859083 | 0.26671126085716 | 0
END | 30437 | 229.483213999999 | 0.000211 | 16.980678 | 0.0075396134310215 | 0.223837608828596 | 0
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 30437 | 290021.784321001 | 0.019568 | 805.171845 | 9.52859297305914 | 13.6632712046825 | 30437
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 30437 | 6667.27243200002 | 0.00732 | 212.479269 | 0.219051563294674 | 2.13585110968012 | 30437
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 30437 | 3702.19730600006 | 0.00627 | 38.860846 | 0.121634763807208 | 1.07735927551245 | 30437
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4, CURRENT_TIMESTAMP) | 30437 | 2349.22475800002 | 0.003218 | 61.372127 | 0.0771831901304325 | 0.971590327400244 | 30437
SELECT $1 | 6847 | 60.785467 | 0.002321 | 7.882384 | 0.00887767883744706 | 0.105198744982906 | 6847
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 5000 | 18.592042 | 0.001572 | 0.741427 | 0.0037184084 | 0.0137660355678027 | 5000
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 3000 | 7.323788 | 0.001598 | 0.40152 | 0.00244126266666667 | 0.00834442591085048 | 3000
(10 rows)Come puoi vedere dai dati sopra, abbiamo un elenco di diverse query e informazioni sui loro tempi di esecuzione:questa è solo una parte dei dati che puoi vedere in pg_stat_statements ma è sufficiente per capiamo che la nostra ricerca della chiave primaria a volte richiede quasi 39 secondi per essere completata:questo non sembra buono ed è sicuramente qualcosa su cui vogliamo indagare.
Se non hai abilitato pg_stat_statements, puoi farlo in modo standard. O tramite il file di configurazione e
shared_preload_libraries = 'pg_stat_statements'Oppure puoi abilitarlo tramite la riga di comando di PostgreSQL:
pgbench=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSIONUtilizzo di ClusterControl per eliminare le query lente
Se ti capita di utilizzare ClusterControl per gestire il tuo database PostgreSQL, puoi usarlo per raccogliere dati su query lente.
Come puoi vedere, raccoglie dati sull'esecuzione della query - righe inviate e esaminato, statistiche sui tempi di esecuzione e così via. Con esso puoi facilmente individuare le query più costose e vedere quali sono i tempi di esecuzione medi e massimi. Per impostazione predefinita, ClusterControl raccoglie le query il cui completamento ha richiesto più di 0,5 secondi, puoi modificarlo nelle impostazioni:
Conclusione
Questo breve blog non copre in alcun modo tutti gli aspetti e gli strumenti utili per identificare e risolvere i problemi di prestazioni delle query in PostgreSQL. Ci auguriamo che sia un buon inizio e che ti aiuti a capire cosa puoi fare per individuare la causa principale delle query lente.
