Eine der Methoden zum Abrufen des Sperrverlaufs in PostgreSQL

Fortsetzung des Artikels „Ein Versuch, ein Analogon von ASH für PostgreSQL zu erstellen «.

In dem Artikel werden konkrete Abfragen und Beispiele betrachtet und gezeigt, welche nützlichen Informationen mithilfe des pg_locks-Ansichtsverlaufs erhalten werden können.

Warnung.
Aufgrund der Neuartigkeit des Themas und der Unvollständigkeit des Testzeitraums kann der Artikel Fehler enthalten. Kritik und Kommentare sind willkommen und werden erwartet.

Eingabedaten

pg_locks-Darstellungsverlauf

archive_locking

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 
);

Grundsätzlich ähnelt die Tabelle der Tabelle archive_pg_stat_activityhier genauer beschrieben - pg_stat_statements + pg_stat_activity + loq_query = pg_ash? und hier - Ein Versuch, ein Analogon von ASH für PostgreSQL zu erstellen.

Um eine Spalte zu füllen Abfrage-ID Funktion verwendet wird

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;

Erklärung: Der Wert der Spalte „QueryID“ wird in der Tabelle „history_locking“ aktualisiert. Wenn dann eine neue Partition für die Tabelle „archive_locking“ erstellt wird, wird der Wert in historischen Werten gespeichert.

Ausgabe

Allgemeine Informationen zu Prozessen im Allgemeinen.

WARTEN AUF SCHLÖSSER NACH SCHLOSSTYPEN

Wunsch

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 

Beispiel

| WARTEN AUF SCHLÖSSER NACH SCHLOSSTYPEN +----------------------------------+----------------------- -------+-------------------- | Sperrtyp| Modus| Dauer +-------------------+-------------------- ---+-- ------------------- | Transaktions-ID| Sharelock| 19:39:26 | Tupel| AccessExclusiveLock| 00:03:35 +--------------------+---------------------- -------+--------------------

EINNAHMEN VON SCHLÖSERN NACH SCHLOSSTYPEN

Wunsch

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 

Beispiel

| SCHLÖSSERNAHMEN NACH SCHLOSSTYPEN +----------------------------------+----------------------- -------+-------------------- | Sperrtyp| Modus| Dauer +-------------------+-------------------- ---+-- ------------------- | Beziehung| RowExclusiveLock| 51:11:10 | virtualxid| ExclusiveLock| 48:10:43 | Transaktions-ID| ExclusiveLock| 44:24:53 | Beziehung| AccessShareLock| 20:06:13 | Tupel| AccessExclusiveLock| 17:58:47 | Tupel| ExclusiveLock| 01:40:41 | Beziehung| ShareUpdateExclusiveLock| 00:26:41 | Objekt| RowExclusiveLock| 00:00:01 | Transaktions-ID| Sharelock| 00:00:01 | verlängern| ExclusiveLock| 00:00:01 +--------------------+---------------------- -------+--------------------

Detaillierte Informationen für bestimmte Abfrage-ID-Abfragen

WARTEN AUF SPERREN NACH LOCKTYPES NACH QUERYID

Wunsch

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

Beispiel

| WARTEN AUF SPERREN NACH SCHLOSSTYPEN NACH QUERYID +----------+-------------------------+----- ---------------+---------------+--- ----+--------------------+---------- - --------- | pid| Sperrtyp| Modus| gestartet| queryid| blocking_pids| Dauer +----------+-----------+----------- ---------+---------------+--------- ---+--------------------+----------------- --- | 11288| Transaktions-ID| Sharelock| 2019 09:17:10| 00| {00.302936}| 389015618226997618:11092:00 | 03| Transaktions-ID| Sharelock| 34 11626:2019:09| 17| {10}| 00:21.380921:389015618226997618 | 12380| Transaktions-ID| Sharelock| 00 00:29:11626| 2019| {09}| 17:10:00 | 21.380921| Transaktions-ID| Sharelock| 389015618226997618 11092:00:03| 25| {11626}| 2019:09:17 | 10| Transaktions-ID| Sharelock| 00 21.380921:389015618226997618:12213| 00| {01}| 55:11626:2019 | 09| Transaktions-ID| Sharelock| 17 10:00:21.380921| 389015618226997618| {12751}| 00:00:01 | 11629| Transaktions-ID| Sharelock| 2019 09:17:10| 00| {24.331935}| 389015618226997618:11092:00 | 03| Transaktions-ID| Sharelock| 22 11629:2019:09| 17| {10}| 00:24.331935:389015618226997618 | 12007| Transaktions-ID| Sharelock| 00 00:01:12007| 2019| {09}| 17:10:05 | 03.327933| Transaktions-ID| Sharelock| 389015618226997618 11629:00:00| 13| {12007}| 2019:09:17 | 10| Transaktions-ID| Sharelock| 05 03.327933:389015618226997618:11092| 00| {01}| 10:12007:2019

SPERREN NACH SCHLOSSTYPEN NACH QUERYID NEHMEN

Wunsch

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

Beispiel

| SPERREN NACH SCHLOSSTYPEN NACH QUERYID NEHMEN +----------+-------------------------+------ --------------+---------------+---- -+--------------------+------------ -------- | pid| Sperrtyp| Modus| gestartet| queryid| blocking_pids| Dauer +----------+-----------+----------- ---------+---------------+--------- ---+--------------------+----------------- --- | 11288| Beziehung| RowExclusiveLock| 2019 09:17:10| 00| {00.302936}| 389015618226997618:11092:00 | 03| Transaktions-ID| ExclusiveLock| 34 11092:2019:09| 17| {}| 10:00:00.302936 | 389015618226997618| Beziehung| RowExclusiveLock| 00 03:34:11288| 2019| {}| 09:17:10 | 00| Beziehung| RowExclusiveLock| 00.302936 389015618226997618:00:00| 10| {}| 11092:2019:09 | 17| virtualxid| ExclusiveLock| 10 00:00.302936:389015618226997618| 00| {}| 03:34:11092 | 2019| virtualxid| ExclusiveLock| 09 17:10:00| 00.302936| {389015618226997618}| 00:03:34 | 11288| Transaktions-ID| ExclusiveLock| 2019 09:17:10| 00| {00.302936}| 389015618226997618:11092:00 | 03| Tupel| AccessExclusiveLock| 34 11288:2019:09| 17| {10}| 00:00.302936:389015618226997618

Verwendung des Blockierungsverlaufs bei der Analyse von Leistungsvorfällen.

  1. Eine Abfrage mit queryid=389015618226997618, die von einem Prozess mit pid=11288 ausgeführt wurde, wartet seit dem 2019 um 09:17:10 Uhr 00 Minuten lang auf eine Sperre.
  2. Die Sperre wurde von einem Prozess mit pid=11092 gehalten
  3. Ein Prozess mit pid=11092, der seit dem 389015618226997618 um 2019:09:17 Uhr eine Abfrage mit queryid=10 ausführte, hielt die Sperre 00 Minuten lang aufrecht.

Ergebnis

Ich hoffe, dass jetzt das Interessanteste und Nützlichste beginnt – das Sammeln von Statistiken und das Analysieren von Fällen zur Geschichte der Erwartungen und Blockierungen.

Ich würde gerne glauben, dass Sie in Zukunft eine Art Notiz erhalten (ähnlich dem Metalink von Oracle).

Aus diesem Grund wird die verwendete Methodik im Allgemeinen so schnell wie möglich zur öffentlichen Bekanntmachung angezeigt.

In naher Zukunft werde ich versuchen, das Projekt auf Github zu veröffentlichen.

Source: habr.com

Kommentar hinzufügen