Geekly articles weekly

Una forma de obtener el historial de bloqueo en PostgreSQL

Continuación del artículo " Intentando crear un análogo de ASH para PostgreSQL ".

El artículo se examinará y se mostrará en consultas y ejemplos específicos: qué información útil se puede obtener utilizando el historial de la vista pg_locks.
Advertencia
Debido a la novedad del tema y al período de prueba incompleto, el artículo puede contener errores. Las críticas y los comentarios son fuertemente alentados y esperados.

Datos de entrada


Pg_locks historial de envío


bloqueo_archivo
CREATE TABLE archive_locking ( timepoint timestamp without time zone , locktype text , relation oid , mode text , tid xid , vtid text , pid integer , blocking_pids integer[] , granted boolean , queryid bigint );

De hecho, la tabla es similar a la tabla archive_pg_stat_activity descrita con más detalle aquí: pg_stat_statements + pg_stat_activity + loq_query = pg_ash? y aquí: un intento de crear un análogo de ASH para PostgreSQL.

Para llenar la columna queryid, use la función

update_history_locking_by_queryid
 --update_history_locking_by_queryid.sql CREATE OR REPLACE FUNCTION update_history_locking_by_queryid() RETURNS boolean AS $$ DECLARE result boolean ; current_minute double precision ; start_minute integer ; finish_minute integer ; start_period timestamp without time zone ; finish_period timestamp without time zone ; lock_rec record ; endpoint_rec record ; current_hour_diff double precision ; BEGIN RAISE NOTICE '***update_history_locking_by_queryid'; result = TRUE ; current_minute = extract ( minute from now() ); SELECT * FROM endpoint WHERE is_need_monitoring INTO endpoint_rec ; current_hour_diff = endpoint_rec.hour_diff ; IF current_minute < 5 THEN RAISE NOTICE 'Current time is less than 5 minute.'; start_period = date_trunc('hour',now()) + (current_hour_diff * interval '1 hour'); finish_period = start_period - interval '5 minute' ; ELSE finish_minute = extract ( minute from now() ) / 5 ; start_minute = finish_minute - 1 ; start_period = date_trunc('hour',now()) + interval '1 minute'*start_minute*5+(current_hour_diff * interval '1 hour'); finish_period = date_trunc('hour',now()) + interval '1 minute'*finish_minute*5+(current_hour_diff * interval '1 hour') ; END IF ; RAISE NOTICE 'start_period = %', start_period; RAISE NOTICE 'finish_period = %', finish_period; FOR lock_rec IN WITH act_queryid AS ( SELECT pid , timepoint , query_start AS started , MAX(timepoint) OVER (PARTITION BY pid , query_start ) AS finished , queryid FROM activity_hist.history_pg_stat_activity WHERE timepoint BETWEEN start_period and finish_period GROUP BY pid , timepoint , query_start , queryid ), lock_pids AS ( SELECT hl.pid , hl.locktype , hl.mode , hl.timepoint , MIN ( timepoint ) OVER (PARTITION BY pid , locktype ,mode ) as started FROM activity_hist.history_locking hl WHERE hl.timepoint between start_period and finish_period GROUP BY hl.pid , hl.locktype , hl.mode , hl.timepoint ) SELECT lp.pid , lp.locktype , lp.mode , lp.timepoint , aq.queryid FROM lock_pids lp LEFT OUTER JOIN act_queryid aq ON ( lp.pid = aq.pid AND lp.started BETWEEN aq.started AND aq.finished ) WHERE aq.queryid IS NOT NULL GROUP BY lp.pid , lp.locktype , lp.mode , lp.timepoint , aq.queryid LOOP UPDATE activity_hist.history_locking SET queryid = lock_rec.queryid WHERE pid = lock_rec.pid AND locktype = lock_rec.locktype AND mode = lock_rec.mode AND timepoint = lock_rec.timepoint ; END LOOP; RETURN result ; END $$ LANGUAGE plpgsql;

Explicación: el valor de la columna queryid se actualiza en la tabla history_locking y, al crear una nueva sección para la tabla archive_locking, el valor se guardará en valores históricos.

Pie de imprenta


Información general sobre los procesos en su conjunto.

ESPERANDO CERRADURAS POR LOCKTYPES


Solicitud
 WITH t AS ( SELECT locktype , mode , count(*) as total FROM activity_hist.archive_locking WHERE timepoint between pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND NOT granted GROUP BY locktype , mode ) SELECT locktype , mode , total * interval '1 second' as duration FROM t ORDER BY 3 DESC

Ejemplo
  El |  ESPERANDO CERRADURAS POR LOCKTYPES
 + -------------------- + ---------------------------- - + --------------------
 El |  tipo de bloqueo |  modo |  duración
 + -------------------- + ---------------------------- - + --------------------
 El |  transaccion |  Sharelock |  19:39:26
 El |  tupla |  AccessExclusiveLock |  00:03:35
 + -------------------- + ---------------------------- - + --------------------

TOMA DE CERRADURAS POR LOCKTYPES


Solicitud
 WITH t AS ( SELECT locktype , mode , count(*) as total FROM activity_hist.archive_locking WHERE timepoint between pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND granted GROUP BY locktype , mode ) SELECT locktype , mode , total * interval '1 second' as duration FROM t ORDER BY 3 DESC

Ejemplo
  El |  TOMA DE CERRADURAS POR LOCKTYPES
 + -------------------- + ---------------------------- - + --------------------
 El |  tipo de bloqueo |  modo |  duración
 + -------------------- + ---------------------------- - + --------------------
 El |  relación |  RowExclusiveLock |  51:11:10
 El |  virtualxid |  ExclusiveLock |  48:10:43
 El |  transaccion |  ExclusiveLock |  44:24:53
 El |  relación |  AccessShareLock |  20:06:13
 El |  tupla |  AccessExclusiveLock |  17:58:47
 El |  tupla |  ExclusiveLock |  01:40:41
 El |  relación |  ShareUpdateExclusiveLock |  00:26:41
 El |  objeto |  RowExclusiveLock |  00:00:01
 El |  transaccion |  Sharelock |  00:00:01
 El |  extender |  ExclusiveLock |  00:00:01
 + -------------------- + ---------------------------- - + --------------------

Información detallada sobre consultas queryid específicas

ESPERANDO CERRADURAS POR LOCKTYPES POR QUERYID


Solicitud
 WITH lt AS ( SELECT pid , locktype , mode , timepoint , queryid , blocking_pids , MIN ( timepoint ) OVER (PARTITION BY pid , locktype ,mode ) as started FROM activity_hist.archive_locking WHERE timepoint between pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND NOT granted AND queryid IS NOT NULL GROUP BY pid , locktype , mode , timepoint , queryid , blocking_pids ) SELECT lt.pid , lt.locktype , lt.mode , lt.started , lt.queryid , lt.blocking_pids , COUNT(*) * interval '1 second' as duration FROM lt GROUP BY lt.pid , lt.locktype , lt.mode , lt.started , lt.queryid , lt.blocking_pids ORDER BY 4

Ejemplo
  El |  ESPERANDO CERRADURAS POR LOCKTYPES POR QUERYID
 + ---------- + ------------------------- + ------------ -------- + ------------------------------ + ---------- ---------- + -------------------- + ------------------ -
 El |  pid |  tipo de bloqueo |  modo |  comenzó |  queryid |  Blocking_pids |  duración
 + ---------- + ------------------------- + ------------ -------- + ------------------------------ + ---------- ---------- + -------------------- + ------------------ -
 El |  11288 |  transaccion |  Sharelock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {11092} |  00:03:34
 El |  11626 |  transaccion |  Sharelock |  2019-09-17 10: 00: 21.380921 |  389015618226997618 |  {12380} |  00:00:29
 El |  11626 |  transaccion |  Sharelock |  2019-09-17 10: 00: 21.380921 |  389015618226997618 |  {11092} |  00:03:25
 El |  11626 |  transaccion |  Sharelock |  2019-09-17 10: 00: 21.380921 |  389015618226997618 |  {12213} |  00:01:55
 El |  11626 |  transaccion |  Sharelock |  2019-09-17 10: 00: 21.380921 |  389015618226997618 |  {12751} |  00:00:01
 El |  11629 |  transaccion |  Sharelock |  2019-09-17 10: 00: 24.331935 |  389015618226997618 |  {11092} |  00:03:22
 El |  11629 |  transaccion |  Sharelock |  2019-09-17 10: 00: 24.331935 |  389015618226997618 |  {12007} |  00:00:01
 El |  12007 |  transaccion |  Sharelock |  2019-09-17 10: 05: 03.327933 |  389015618226997618 |  {11629} |  00:00:13
 El |  12007 |  transaccion |  Sharelock |  2019-09-17 10: 05: 03.327933 |  389015618226997618 |  {11092} |  00:01:10
 El |  12007 |  transaccion |  Sharelock |  2019-09-17 10: 05: 03.327933 |  389015618226997618 |  {11288} |  00:00:05
 El |  12213 |  transaccion |  Sharelock |  2019-09-17 10: 06: 07.328019 |  389015618226997618 |  {12007} |  00:00:10

TOMANDO CERRADURAS POR LOCKTYPES POR QUERYID


Solicitud
 WITH lt AS ( SELECT pid , locktype , mode , timepoint , queryid , blocking_pids , MIN ( timepoint ) OVER (PARTITION BY pid , locktype ,mode ) as started FROM activity_hist.archive_locking WHERE timepoint between pg_stat_history_begin+(current_hour_diff * interval '1 hour') AND pg_stat_history_end+(current_hour_diff * interval '1 hour') AND granted AND queryid IS NOT NULL GROUP BY pid , locktype , mode , timepoint , queryid , blocking_pids ) SELECT lt.pid , lt.locktype , lt.mode , lt.started , lt.queryid , lt.blocking_pids , COUNT(*) * interval '1 second' as duration FROM lt GROUP BY lt.pid , lt.locktype , lt.mode , lt.started , lt.queryid , lt.blocking_pids ORDER BY 4

Ejemplo
  El |  TOMANDO CERRADURAS POR LOCKTYPES POR QUERYID
 + ---------- + ------------------------- + ------------ -------- + ------------------------------ + ---------- ---------- + -------------------- + ------------------ -
 El |  pid |  tipo de bloqueo |  modo |  comenzó |  queryid |  Blocking_pids |  duración
 + ---------- + ------------------------- + ------------ -------- + ------------------------------ + ---------- ---------- + -------------------- + ------------------ -
 El |  11288 |  relación |  RowExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {11092} |  00:03:34
 El |  11092 |  transaccion |  ExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {} |  00:03:34
 El |  11288 |  relación |  RowExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {} |  00:00:10
 El |  11092 |  relación |  RowExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {} |  00:03:34
 El |  11092 |  virtualxid |  ExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {} |  00:03:34
 El |  11288 |  virtualxid |  ExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {11092} |  00:03:34
 El |  11288 |  transaccion |  ExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {11092} |  00:03:34
 El |  11288 |  tupla |  AccessExclusiveLock |  2019-09-17 10: 00: 00.302936 |  389015618226997618 |  {11092} |  00:03:34

Uso del historial de bloqueo al analizar incidentes de rendimiento.

  1. Una solicitud con queryid = 389015618226997618 ejecutada por un proceso con pid = 11288 bloqueo esperado desde 2019-09-17 10:00:00 durante 3 minutos.
  2. El bloqueo se realizó mediante un proceso con pid = 11092
  3. Un proceso con pid = 11092 ejecutando una consulta con queryid = 389015618226997618 a partir de 2019-09-17 10:00:00 mantuvo el bloqueo durante 3 minutos.

Resumen


Ahora, espero, comienza lo más interesante y útil: recopilar estadísticas y analizar casos sobre el historial de expectativas y bloqueos.

En el futuro, quiero creer, resultará ser un conjunto de algún tipo de nota (similar al metalink de Oracle).

En general, es por esta razón que la técnica utilizada se muestra lo más rápido posible para la familiarización general.

En un futuro muy cercano intentaré poner el proyecto en github.

Source: https://habr.com/ru/post/467719/

More articles:


All Articles