Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-21 Thread Marti Raudsepp
Hi, here's version 4 of the patch.

On Wed, Oct 19, 2011 at 19:34, Robert Haas robertmh...@gmail.com wrote:
 I think it would be safer to write this so that
 pgstat_get_crashed_backend_activity writes its answer into a
 statically allocated buffer and returns a pointer to that buffer,
 rather than using palloc. I think the current coding might lead to a
 memory leak in the postmaster

Good catch about the memory leak; I always assumed that the caller
takes care of cleaning the memory context. But looking at the code,
that doesn't seem to happen in postmaster.

Using a global buffer would waste memory in every backend, but this is
needed rarely only in postmaster. So instead I'm allocating the buffer
on stack in LogChildExit(), and pass that to
pgstat_get_crashed_backend_activity() in arguments.

I use a character array of 1024 bytes in LogChildExit() since
'track_activity_query_size' is unknown at compile time (1024 is the
default). I could have used alloca(), but doesn't seem portable or
robust with arbitrary inputs coming from GUC.

 Also, how about having CreateSharedBackendStatus store the length of
 the backend activity buffer in a global somewhere, instead of
 repeating the calculation here?

Sure, I added a BackendActivityBufferSize global to pgstat.c

                                return command string not enabled;
 I'd suggest that we instead return command string not found, and
 avoid making judgements about how things got that way.

Originally I wanted to use exact same messages as
pg_stat_get_backend_activity; but you're right, we should be as
accurate as possible. I think command string empty is better,
since it means the PID was found, but it had a zero-length activity
string.

 It's almost making me cry
 thinking about how much time this would have saved me

Thanks for your review and the generous words. :)

Regards,
Marti
From bce8e81ea4811a823ec7c3a0ad15ff63b5cd1be4 Mon Sep 17 00:00:00 2001
From: Marti Raudsepp ma...@juffo.org
Date: Fri, 21 Oct 2011 18:36:50 +0300
Subject: [PATCH] Log crashed backend's query (activity string)

The crashing query is often a good starting point in debugging the
cause, and much more easily accessible than core dumps.

We're extra-paranoid in reading the activity buffer since it might be
corrupt. All non-ASCII characters are replaced with '?'

Example output:
LOG:  server process (PID 31451) was terminated by signal 9: Killed
DETAIL:  Running query: DO LANGUAGE plpythonu 'import os;os.kill(os.getpid(),9)'
---
 src/backend/postmaster/pgstat.c |   73 ++-
 src/backend/postmaster/postmaster.c |   22 --
 src/backend/utils/adt/ascii.c   |   34 
 src/include/pgstat.h|2 +
 src/include/utils/ascii.h   |1 +
 5 files changed, 125 insertions(+), 7 deletions(-)

diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 44956c1..ba64f23 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -58,6 +58,7 @@
 #include storage/pg_shmem.h
 #include storage/pmsignal.h
 #include storage/procsignal.h
+#include utils/ascii.h
 #include utils/guc.h
 #include utils/memutils.h
 #include utils/ps_status.h
@@ -2228,6 +2229,7 @@ static PgBackendStatus *MyBEEntry = NULL;
 static char *BackendClientHostnameBuffer = NULL;
 static char *BackendAppnameBuffer = NULL;
 static char *BackendActivityBuffer = NULL;
+static Size BackendActivityBufferSize = 0;
 
 
 /*
@@ -2310,9 +2312,12 @@ CreateSharedBackendStatus(void)
 	}
 
 	/* Create or attach to the shared activity buffer */
-	size = mul_size(pgstat_track_activity_query_size, MaxBackends);
+	BackendActivityBufferSize = mul_size(pgstat_track_activity_query_size,
+		 MaxBackends);
 	BackendActivityBuffer = (char *)
-		ShmemInitStruct(Backend Activity Buffer, size, found);
+		ShmemInitStruct(Backend Activity Buffer,
+		BackendActivityBufferSize,
+		found);
 
 	if (!found)
 	{
@@ -2751,6 +2756,70 @@ pgstat_get_backend_current_activity(int pid, bool checkUser)
 	return backend information not available;
 }
 
+/* --
+ * pgstat_get_crashed_backend_activity() -
+ *
+ *	Return a string representing the current activity of the backend with
+ *	the specified PID. Like the function above, but reads shared memory with
+ *	the expectation that it may be corrupt. Returns either a pointer to a
+ *	constant string, or writes into the 'buffer' argument and returns it.
+ *
+ *	This function is only intended to be used by postmaster to report the
+ *	query that crashed the backend. In particular, no attempt is made to
+ *	follow the correct concurrency protocol when accessing the
+ *	BackendStatusArray. But that's OK, in the worst case we'll return a
+ *	corrupted message. We also must take care not to trip on ereport(ERROR).
+ *
+ *	Note: return strings for special cases match pg_stat_get_backend_activity.
+ * --
+ */
+const char *
+pgstat_get_crashed_backend_activity(int pid, 

Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-21 Thread Robert Haas
On Fri, Oct 21, 2011 at 11:45 AM, Marti Raudsepp ma...@juffo.org wrote:
 It's almost making me cry
 thinking about how much time this would have saved me

 Thanks for your review and the generous words. :)

I have committed this version.  I'm expecting Tom to try to find a
scenario in which it's unfixably broken, so we'll see how that turns
out; but there seems to be significant support for this feature and
I'm hopeful that this will pass (or can be made to pass) muster.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-21 Thread Tom Lane
Robert Haas robertmh...@gmail.com writes:
 I have committed this version.  I'm expecting Tom to try to find a
 scenario in which it's unfixably broken, so we'll see how that turns
 out; but there seems to be significant support for this feature and
 I'm hopeful that this will pass (or can be made to pass) muster.

I found some problems with it, but with the changes I just committed
it seems like it should be fairly bulletproof.

regards, tom lane

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-21 Thread Robert Haas
On Fri, Oct 21, 2011 at 4:37 PM, Tom Lane t...@sss.pgh.pa.us wrote:
 Robert Haas robertmh...@gmail.com writes:
 I have committed this version.  I'm expecting Tom to try to find a
 scenario in which it's unfixably broken, so we'll see how that turns
 out; but there seems to be significant support for this feature and
 I'm hopeful that this will pass (or can be made to pass) muster.

 I found some problems with it, but with the changes I just committed
 it seems like it should be fairly bulletproof.

Cool.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-19 Thread Robert Haas
On Thu, Oct 6, 2011 at 10:15 PM, gabrielle gor...@gmail.com wrote:
 On Wed, Oct 5, 2011 at 5:14 PM, Marti Raudsepp ma...@juffo.org wrote:
 I think you intended to use the Waiting on Author status -- that
 leaves the commitfest entry open. I will re-open the commitfest entry
 myself, I hope that's OK.

 No worries, and yeah, I picked the wrong checkbox. :)

 Here is version 3 of the patch.

 Looks good, and performs as advertised.  Thanks!

I think it would be safer to write this so that
pgstat_get_crashed_backend_activity writes its answer into a
statically allocated buffer and returns a pointer to that buffer,
rather than using palloc.  I think the current coding might lead to a
memory leak in the postmaster, but even if it doesn't, it seems better
to make this as simple as possible.

Also, how about having CreateSharedBackendStatus store the length of
the backend activity buffer in a global somewhere, instead of
repeating the calculation here?

For this:

if (*(activity) == '\0')
return command string not enabled;

I'd suggest that we instead return command string not found, and
avoid making judgements about how things got that way.

Other than that, it looks good to me.  It's almost making me cry
thinking about how much time this would have saved me debugging server
crashes.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


Re: [HACKERS] [PATCH] Log crashed backend's query v3

2011-10-06 Thread gabrielle
On Wed, Oct 5, 2011 at 5:14 PM, Marti Raudsepp ma...@juffo.org wrote:
 I think you intended to use the Waiting on Author status -- that
 leaves the commitfest entry open. I will re-open the commitfest entry
 myself, I hope that's OK.

No worries, and yeah, I picked the wrong checkbox. :)

 Here is version 3 of the patch.

Looks good, and performs as advertised.  Thanks!

gabrielle

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers


[HACKERS] [PATCH] Log crashed backend's query v3

2011-10-05 Thread Marti Raudsepp
Hi,

My apologies for the last grumpy message I wrote; I sent it out of
surprise that my patch was marked closed on the current commitfest.
I hope I haven't discouraged you from reviewing this updated version.

I think you intended to use the Waiting on Author status -- that
leaves the commitfest entry open. I will re-open the commitfest entry
myself, I hope that's OK.

Here is version 3 of the patch.

On Wed, Oct 5, 2011 at 02:36, gabrielle gor...@gmail.com wrote:
 - The doc comment 'pgstat_get_backend_current_activity' doesn't match
 the function name 'pgstat_get_crashed_backend_activity'.

This is now fixed in the patch.

 Project coding guidelines:
 - There are some formatting problems, such as all newlines at the same
 indent level need to line up.
 - Wayward tabs, line 2725 in pgstat.c specifically

I wasn't entirely sure which line you're referring to (what's on line
2725 in the current git master wasn't touched by me)
But I presume it's this statement:
if (activity  BackendActivityBuffer || ...

I have rearranged this if statement using a temporary variable so that
there's no need to right-align long expressions anymore.

I also tweaked the wording of comments here and there.

For the points not addressed in this version, see my response here:
http://archives.postgresql.org/pgsql-hackers/2011-10/msg00202.php

Regards,
Marti
From 748c5fcaf1dc7518a06da276574a565098cde628 Mon Sep 17 00:00:00 2001
From: Marti Raudsepp ma...@juffo.org
Date: Wed, 28 Sep 2011 00:46:48 +0300
Subject: [PATCH] Log crashed backend's query (activity string)

The crashing query is often a good starting point in debugging the
cause, and much more easily accessible than core dumps.

We're extra-paranoid in reading the activity buffer since it might be
corrupt. All non-ASCII characters are replaced with '?'

Example output:
LOG:  server process (PID 31451) was terminated by signal 9: Killed
DETAIL:  Running query: DO LANGUAGE plpythonu 'import os;os.kill(os.getpid(),9)'
---
 src/backend/postmaster/pgstat.c |   66 +++
 src/backend/postmaster/postmaster.c |   17 ++---
 src/backend/utils/adt/ascii.c   |   31 
 src/include/pgstat.h|1 +
 src/include/utils/ascii.h   |1 +
 5 files changed, 111 insertions(+), 5 deletions(-)

diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 9132db7..220507f 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -58,6 +58,7 @@
 #include storage/pg_shmem.h
 #include storage/pmsignal.h
 #include storage/procsignal.h
+#include utils/ascii.h
 #include utils/guc.h
 #include utils/memutils.h
 #include utils/ps_status.h
@@ -2751,6 +2752,71 @@ pgstat_get_backend_current_activity(int pid, bool checkUser)
 	return backend information not available;
 }
 
+/* --
+ * pgstat_get_crashed_backend_activity() -
+ *
+ *	Return a string representing the current activity of the backend with
+ *	the specified PID.	Like the function above, but reads shared memory with
+ *	the expectation that it may be corrupt.
+ *
+ *	This function is only intended to be used by postmaster to report the
+ *	query that crashed the backend. In particular, no attempt is made to
+ *	follow the correct concurrency protocol when accessing the
+ *	BackendStatusArray. But that's OK, in the worst case we get a corrupted
+ *	message. We also must take care not to trip on ereport(ERROR).
+ *
+ *	Note: return strings for special cases match pg_stat_get_backend_activity.
+ * --
+ */
+const char *
+pgstat_get_crashed_backend_activity(int pid)
+{
+	volatile PgBackendStatus *beentry;
+	int			i;
+
+	beentry = BackendStatusArray;
+	for (i = 1; i = MaxBackends; i++)
+	{
+		if (beentry-st_procpid == pid)
+		{
+			/* Read pointer just once, so it can't change after validation */
+			const char *activity = beentry-st_activity;
+			char	   *buffer;
+			const char *activity_last;
+
+			/*
+			 * We can't access activity pointer before we verify that it
+			 * falls into BackendActivityBuffer. To make sure that the entire
+			 * string including its ending is contained within the buffer,
+			 * the pointer can start at offset (MaxBackends - 1) at most.
+			 */
+			activity_last = BackendActivityBuffer +
+((MaxBackends - 1) * pgstat_track_activity_query_size);
+
+			if (activity  BackendActivityBuffer ||
+activity  activity_last)
+return command string corrupt;
+
+			if (*(activity) == '\0')
+return command string not enabled;
+
+			buffer = (char *) palloc(pgstat_track_activity_query_size);
+			/*
+			 * Copy only ASCII-safe characters so we don't run into encoding
+			 * problems when reporting the message.
+			 */
+			ascii_safe_strncpy(buffer, activity,
+			   pgstat_track_activity_query_size);
+
+			return buffer;
+		}
+
+		beentry++;
+	}
+
+	/* PID not found */
+	return backend information not available;
+}
 
 /*