From: Darold Gilles <gilles@darold.net>
Date: Thu, 14 Jan 2016 14:12:52 +0000 (+0100)
Subject: Report information about "LOG: sending cancel to blocking autovacuum" into events... 
X-Git-Tag: v7.3~16
X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=fabefdbd8d0b7af6d36efede829f74cbdd325ec7;p=pgbadger

Report information about "LOG: sending cancel to blocking autovacuum" into events reports. Usefull to know which queries generate autovacuum kill do to a lock issue.
---

diff --git a/pgbadger b/pgbadger
index 22ac490..bba30b8 100755
--- a/pgbadger
+++ b/pgbadger
@@ -3887,6 +3887,7 @@ sub show_error_as_text
 			$msg =~ s/ERROR:  (database system was shut down)/LOG:  $1/;
 			$msg =~ s/ERROR:  (recovery has paused)/LOG:  $1/;
 			$msg =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/;
+			$msg =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/;
 			print $fh "$idx) " . &comma_numbers($error_info{$k}{count}) . " - $msg\n";
 			print $fh "--\n";
 			my $j = 1;
@@ -3894,7 +3895,9 @@ sub show_error_as_text
 				if (   ($error_info{$k}{error}[$i] =~ s/ERROR:  (parameter "[^"]+" changed to)/LOG:  $1/)
 					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (database system was shut down)/LOG:  $1/)
 					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/)
-					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (recovery has paused)/LOG:  $1/))
+					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (recovery has paused)/LOG:  $1/)
+					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/)
+					)
 				{
 					$logs_type{ERROR}--;
 					$logs_type{LOG}++;
@@ -3911,7 +3914,9 @@ sub show_error_as_text
 			if (   ($error_info{$k}{error}[0] =~ s/ERROR:  (parameter "[^"]+" changed to)/LOG:  $1/)
 				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (database system was shut down)/LOG:  $1/)
 				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/)
-				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (recovery has paused)/LOG:  $1/))
+				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (recovery has paused)/LOG:  $1/)
+				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/)
+				)
 			{
 				$logs_type{ERROR}--;
 				$logs_type{LOG}++;
@@ -8886,7 +8891,9 @@ sub print_log_level
 				if (   ($error_info{$k}{error}[$i] =~ s/ERROR:  (parameter "[^"]+" changed to)/LOG:  $1/)
 					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (database system was shut down)/LOG:  $1/)
 					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/)
-					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (recovery has paused)/LOG:  $1/))
+					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (recovery has paused)/LOG:  $1/)
+					|| ($error_info{$k}{error}[$i] =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/)
+				)
 				{
 					$logs_type{ERROR}--;
 					$logs_type{LOG}++;
@@ -8896,7 +8903,9 @@ sub print_log_level
 			if (   ($error_info{$k}{error}[0] =~ s/ERROR:  (parameter "[^"]+" changed to)/LOG:  $1/)
 				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (database system was shut down)/LOG:  $1/)
 				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/)
-				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (recovery has paused)/LOG:  $1/))
+				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (recovery has paused)/LOG:  $1/)
+				|| ($error_info{$k}{error}[0] =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/)
+				)
 			{
 				$logs_type{ERROR}--;
 				$logs_type{LOG}++;
@@ -9102,6 +9111,7 @@ sub show_error_as_html
 		$msg =~ s/ERROR:  (database system was shut down)/LOG:  $1/;
 		$msg =~ s/ERROR:  (database system was interrupted while in recovery)/LOG:  $1/;
 		$msg =~ s/ERROR:  (recovery has paused)/LOG:  $1/;
+		$msg =~ s/ERROR:  (sending cancel to blocking autovacuum)/LOG:  $1/;
 		my $error_level_class = 'text-error';
 		if ($msg =~ /^WARNING: /) {
 			$error_level_class = 'text-warning';
@@ -10081,6 +10091,8 @@ sub parse_query
 			$prefix_vars{'t_loglevel'} = 'ERROR';
 		} elsif ($prefix_vars{'t_query'} =~ /recovery has paused/) {
 			$prefix_vars{'t_loglevel'} = 'ERROR';
+		} elsif ($prefix_vars{'t_query'} =~ /ending cancel to blocking autovacuum/) {
+			$prefix_vars{'t_loglevel'} = 'ERROR';
 		}
 
 	} elsif (($prefix_vars{'t_loglevel'} eq 'ERROR') && !$error_only) {
@@ -11196,6 +11208,7 @@ sub normalize_error
 	$orig_query =~ s/(relation) \d+ (deleted while still in use)/$1 ... $2/g;
 	$orig_query =~ s/[0-9A-F]{24}/.../g; # Remove WAL filename
 	$orig_query =~ s/, u_uuid: [^,]+, file_path:.*/. Retrying/g;
+	$orig_query =~ s/ PID \d+//;
 
 	# Need more normalization stuff here
 	return $orig_query;