🥇En af metoderne til at opnå låsehistorik i PostgreSQL

Fortsættelse af artiklen "Et forsøg på at skabe en ASH-analog til PostgreSQL ".

Artiklen vil undersøge og vise, ved hjælp af specifikke forespørgsler og eksempler, hvilken nyttig information der kan opnås ved at bruge historikken for pg_locks-visningen.

Advarsel.
På grund af emnets nyhed og den uafsluttede testperiode, kan artiklen indeholde fejl. Kritik og kommentarer modtages meget gerne og forventes.

Indtast data

Historien om pg_locks repræsentation

arkiv_låsning

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

I det væsentlige ligner bordet bordet archive_pg_stat_activity, beskrevet mere detaljeret her - pg_stat_statements + pg_stat_activity + loq_query = pg_ash? og her - Et forsøg på at skabe en analog af ASH til PostgreSQL.

At udfylde en kolonne queryid funktion bruges

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;

forklaring: værdien af queryid-kolonnen opdateres i history_locking-tabellen, og når der derefter oprettes en ny partition til archive_locking-tabellen, vil værdien blive gemt i de historiske værdier.

Produktion

Generel information om processer generelt.

VENTER PÅ LÅSE EFTER LÅSETYPER

Forespørgsel

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

Eksempel

| VENTER PÅ LÅSE EFTER LÅSETYPER +------+------------------------------------------+ ------------------ | låsetype| tilstand| varighed +--------------------+-------------------------------- - --+--------------------------- | transaktions-id| ShareLock| 19:39:26 | tuple| AccessExclusiveLock| 00:03:35 +--------------------+----------------------------- - -------+----------

OPTAGELSE AF LÅSE EFTER LÅSETYPER

Forespørgsel

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

Eksempel

| OPTAGELSE AF LÅSE EFTER LÅSETYPER +-------------------+------------------------------ ----+------------------------- | låsetype| tilstand| varighed +--------------------+-------------------------------- - --+--------------------------- | forhold| RowExclusiveLock| 51:11:10 | virtualxid| EksklusivLås| 48:10:43 | transaktions-id| EksklusivLås| 44:24:53 | forhold| AccessShareLock| 20:06:13 | tuple| AccessExclusiveLock| 17:58:47 | tuple| EksklusivLås| 01:40:41 | forhold| ShareUpdateExclusiveLock| 00:26:41 | objekt| RowExclusiveLock| 00:00:01 | transaktions-id| ShareLock| 00:00:01 | forlænge| EksklusivLås| 00:00:01 +--------------------+----------------------------- - -------+----------

Detaljerede oplysninger om specifikke queryid-anmodninger

VENTER PÅ LÅSE EFTER LÅSETYPER EFTER QUERYID

Forespørgsel

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

Eksempel

| VENTER PÅ LÅSE EFTER LÅSETYPER VED QUERYID +---------------------------------- +----------------------------+--- ------------------ --+---------------------------+---------------- ---------- | pid| låsetype| tilstand| startede| queryid| blocking_pids| varighed +----------+--------------------------------+---------------- ----------+------------------------------------+---------- -- ----------+---------------------+------------------------ - | 11288| transaktions-id| ShareLock| 2019-09-17 10:00:00.302936| 389015618226997618| {11092}| 00:03:34 | 11626| transaktions-id| ShareLock| 2019-09-17 10:00:21.380921| 389015618226997618| {12380}| 00:00:29 | 11626| transaktions-id| ShareLock| 2019-09-17 10:00:21.380921| 389015618226997618| {11092}| 00:03:25 | 11626| transaktions-id| ShareLock| 2019-09-17 10:00:21.380921| 389015618226997618| {12213}| 00:01:55 | 11626| transaktions-id| ShareLock| 2019-09-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:22 | 11629| transaktions-id| ShareLock| 2019-09-17 10:00:24.331935| 389015618226997618| {12007}| 00:00:01 | 12007| transaktions-id| ShareLock| 2019-09-17 10:05:03.327933| 389015618226997618| {11629}| 00:00:13 | 12007| transaktions-id| ShareLock| 2019-09-17 10:05:03.327933| 389015618226997618| {11092}| 00:01:10 | 12007| transaktions-id| ShareLock| 2019-09-17 10:05:03.327933| 389015618226997618| {11288}| 00:00:05 | 12213| transaktions-id| ShareLock| 2019-09-17 10:06:07.328019| 389015618226997618| {12007}| 00:00:10

AT TAGE LÅS EFTER LÅSETYPER VED QUERYID

Forespørgsel

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

Eksempel

| TAGE LÅS VED LÅSETYPER VED QUERYID +-------------------------------+ ----------------------------+--------------------+ --------------------+---------------------------- | pid| låsetype| tilstand| startede| queryid| blocking_pids| varighed +----------+--------------------------------+---------------- ----------+-------------------------------------+--------- --------------------------------------- --- | 11288| forhold| RowExclusiveLock| 2019-09-17 10:00:00.302936| 389015618226997618| {11092}| 00:03:34 | 11092| transaktions-id| EksklusivLås| 2019-09-17 10:00:00.302936| 389015618226997618| {}| 00:03:34 | 11288| forhold| RowExclusiveLock| 2019-09-17 10:00:00.302936| 389015618226997618| {}| 00:00:10 | 11092| forhold| RowExclusiveLock| 2019-09-17 10:00:00.302936| 389015618226997618| {}| 00:03:34 | 11092| virtualxid| EksklusivLås| 2019-09-17 10:00:00.302936| 389015618226997618| {}| 00:03:34 | 11288| virtualxid| EksklusivLås| 2019-09-17 10:00:00.302936| 389015618226997618| {11092}| 00:03:34 | 11288| transaktions-id| EksklusivLås| 2019-09-17 10:00:00.302936| 389015618226997618| {11092}| 00:03:34 | 11288| tuple| AccessExclusiveLock| 2019-09-17 10:00:00.302936| 389015618226997618| {11092}| 00:03:34

Brug af låsehistorik til at analysere ydeevnehændelser.

En anmodning med queryid=389015618226997618 udført af en proces med pid=11288 ventede på blokering fra 2019-09-17 10:00:00 i 3 minutter.
Låsen blev holdt af en proces med pid=11092
En proces med pid=11092, der udfører en anmodning med queryid=389015618226997618 startende fra 2019-09-17 10:00:00 holdt låsen i 3 minutter.

Total

Nu håber jeg, at den mest interessante og nyttige del begynder - at indsamle statistik og analysere sager om historien om ventetider og blokeringer.

I fremtiden, vil jeg tro, vil vi få et sæt med nogle noter (svarende til Oracles metalink).

Generelt er det derfor, at den anvendte metode bliver gjort tilgængelig for alle så hurtigt som muligt.

Jeg vil forsøge at poste projektet på github i den nærmeste fremtid.

Kilde: www.habr.com

En af metoderne til at få låsehistorik i PostgreSQL

Indtast data

Historien om pg_locks repræsentation

Produktion

VENTER PÅ LÅSE EFTER LÅSETYPER

OPTAGELSE AF LÅSE EFTER LÅSETYPER

VENTER PÅ LÅSE EFTER LÅSETYPER EFTER QUERYID

AT TAGE LÅS EFTER LÅSETYPER VED QUERYID

Total

Tilføj en kommentar Annuller svar