Fwd: Emit namespace in post-copy output

Started by Mikeover 4 years ago8 messages

miketheman@gmail.com

over 4 years ago

1 attachment(s)

When running a VACUUM or CLUSTER command, the namespace name is not part of
the emitted message.

Using `vacuumdb` CLI tool recently with multiple jobs, I found that
reading the output messages harder to match the relations with their
namespaces.

Example:

INFO: vacuuming "sendgrid.open"
INFO: vacuuming "mailgun.open"
...
INFO: "open": found 0 removable, 31460776 nonremovable row versions in
1358656 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU 31.35s/261.26u sec elapsed 1620.68 sec.
...

In this example. the user can't readily tell which `open` relation was
completed.

Attached is a patch using existing functions to include the namespace in
the output string.

Looking forward to feedback!
-Mike Fiedler

Attachments:

0001-emit-namespace-in-post-copy-output.patchapplication/x-patch; name=0001-emit-namespace-in-post-copy-output.patchDownload

From c66506ad7440a1b501cca858b5120cc568f7a00b Mon Sep 17 00:00:00 2001
From: Mike Fiedler <miketheman@gmail.com>
Date: Tue, 22 Jun 2021 12:05:48 -0400
Subject: [PATCH] Emit namespace in post-copy output

During a VACUUM or CLUSTER command, the initial output emits the
relation namespace along with the relation name.

Add the namespace to the post-action to match the initial `errmsg`
using the same functions to build the string.

Signed-off-by: Mike Fiedler <miketheman@gmail.com>
---
 src/backend/access/heap/vacuumlazy.c | 3 ++-
 src/backend/commands/cluster.c       | 3 ++-
 2 files changed, 4 insertions(+), 2 deletions(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 44f198398c..bd30461dec 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -1673,7 +1673,8 @@ lazy_scan_heap(LVRelState *vacrel, VacuumParams *params, bool aggressive)
 	appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0));
 
 	ereport(elevel,
-			(errmsg("\"%s\": found %lld removable, %lld nonremovable row versions in %u out of %u pages",
+			(errmsg("\"%s.%s\": found %lld removable, %lld nonremovable row versions in %u out of %u pages",
+					vacrel->relnamespace,
 					vacrel->relname,
 					(long long) vacrel->tuples_deleted,
 					(long long) vacrel->num_tuples, vacrel->scanned_pages,
diff --git a/src/backend/commands/cluster.c b/src/backend/commands/cluster.c
index 6487a9e3fc..e4c577cfff 100644
--- a/src/backend/commands/cluster.c
+++ b/src/backend/commands/cluster.c
@@ -921,7 +921,8 @@ copy_table_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex, bool verbose,
 
 	/* Log what we did */
 	ereport(elevel,
-			(errmsg("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u pages",
+			(errmsg("\"%s.%s\": found %.0f removable, %.0f nonremovable row versions in %u pages",
+					get_namespace_name(RelationGetNamespace(OldHeap)),
 					RelationGetRelationName(OldHeap),
 					tups_vacuumed, num_tuples,
 					RelationGetNumberOfBlocks(OldHeap)),
-- 
2.30.1 (Apple Git-130)

Import Notes

Reply to msg id not found: CAMerE0pMeqjSmQDzvVEK5mJ7wnn4pkoyVt7gNpu2teaFY35KFA@mail.gmail.comReference msg id not found: CAMerE0pMeqjSmQDzvVEK5mJ7wnn4pkoyVt7gNpu2teaFY35KFA@mail.gmail.com

Corey Huinker

corey.huinker@gmail.com

over 4 years ago

In reply to: Mike (#1)

Re: Emit namespace in post-copy output

On Tue, Jun 22, 2021 at 6:08 PM Mike <miketheman@gmail.com> wrote:

When running a VACUUM or CLUSTER command, the namespace name is not part
of the emitted message.

Using `vacuumdb` CLI tool recently with multiple jobs, I found that
reading the output messages harder to match the relations with their
namespaces.

Example:

INFO: vacuuming "sendgrid.open"
INFO: vacuuming "mailgun.open"
...
INFO: "open": found 0 removable, 31460776 nonremovable row versions in
1358656 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU 31.35s/261.26u sec elapsed 1620.68 sec.
...

In this example. the user can't readily tell which `open` relation was
completed.

Attached is a patch using existing functions to include the namespace in
the output string.

Looking forward to feedback!
-Mike Fiedler

I've added this to the open commitfest:
https://commitfest.postgresql.org/33/3200/

The change is quite simple, just 3 lines, adding the schema name to two
different lines of output.

As such, there is no obvious documentation to change, though I can imagine
that we have sample output from vacuum, vacuumdb or cluster somewhere that
would need to be updated.

I cobbled together a very simple test:

~/pgdata$ /usr/local/pgsql/bin/psql postgres
psql (14beta2)
Type "help" for help.
postgres=# create database mike_test;
CREATE DATABASE
postgres=# \c mike_test
You are now connected to database "mike_test" as user "corey".
mike_test=# create schema foo;
CREATE SCHEMA
mike_test=# create table foo.bar(x integer);
CREATE TABLE
mike_test=# \q
mike_test=# VACUUM FULL VERBOSE foo.bar;
INFO: vacuuming "foo.bar"
INFO: "foo.bar": found 0 removable, 0 nonremovable row versions in 0 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
VACUUM

And of course vacuumdb

~/pgdata$ /usr/local/pgsql/bin/vacuumdb --full --verbose mike_test
--table=foo.bar
vacuumdb: vacuuming database "mike_test"
INFO: vacuuming "foo.bar"
INFO: "foo.bar": found 0 removable, 0 nonremovable row versions in 0 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.

So far, so good.

Mike

miketheman@gmail.com

over 4 years ago

In reply to: Corey Huinker (#2)

Re: Emit namespace in post-copy output

Awesome, thanks! Are there any other steps I should take?

On Wed, Jun 23, 2021 at 5:46 PM Corey Huinker <corey.huinker@gmail.com>
wrote:

Show quoted text

On Tue, Jun 22, 2021 at 6:08 PM Mike <miketheman@gmail.com> wrote:

When running a VACUUM or CLUSTER command, the namespace name is not part
of the emitted message.

Using `vacuumdb` CLI tool recently with multiple jobs, I found that
reading the output messages harder to match the relations with their
namespaces.

Example:

INFO: vacuuming "sendgrid.open"
INFO: vacuuming "mailgun.open"
...
INFO: "open": found 0 removable, 31460776 nonremovable row versions in
1358656 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU 31.35s/261.26u sec elapsed 1620.68 sec.
...

In this example. the user can't readily tell which `open` relation was
completed.

Attached is a patch using existing functions to include the namespace in
the output string.

Looking forward to feedback!
-Mike Fiedler

I've added this to the open commitfest:
https://commitfest.postgresql.org/33/3200/

The change is quite simple, just 3 lines, adding the schema name to two
different lines of output.

As such, there is no obvious documentation to change, though I can imagine
that we have sample output from vacuum, vacuumdb or cluster somewhere that
would need to be updated.

I cobbled together a very simple test:

~/pgdata$ /usr/local/pgsql/bin/psql postgres
psql (14beta2)
Type "help" for help.
postgres=# create database mike_test;
CREATE DATABASE
postgres=# \c mike_test
You are now connected to database "mike_test" as user "corey".
mike_test=# create schema foo;
CREATE SCHEMA
mike_test=# create table foo.bar(x integer);
CREATE TABLE
mike_test=# \q
mike_test=# VACUUM FULL VERBOSE foo.bar;
INFO: vacuuming "foo.bar"
INFO: "foo.bar": found 0 removable, 0 nonremovable row versions in 0 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
VACUUM

And of course vacuumdb

~/pgdata$ /usr/local/pgsql/bin/vacuumdb --full --verbose mike_test
--table=foo.bar
vacuumdb: vacuuming database "mike_test"
INFO: vacuuming "foo.bar"
INFO: "foo.bar": found 0 removable, 0 nonremovable row versions in 0 pages
DETAIL: 0 dead row versions cannot be removed yet.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.

So far, so good.

Euler Taveira

euler@eulerto.com

over 4 years ago

In reply to: Mike (#3)

Re: Emit namespace in post-copy output

On Fri, Jun 25, 2021, at 12:10 PM, Mike wrote:

Awesome, thanks! Are there any other steps I should take?

No. Keep an eye on this thread. If you modify this patch, check if PostgreSQL
Patch Tester [1]http://cfbot.cputube.org/index.html reports failure. Since your patch does not modify a
considerable amount of code, it probably won't conflict with another patch. If
so, a reviewer will say so. If your patch doesn't have objections, it will
eventually be committed. BTW, your patch looks good to me.

[1]: http://cfbot.cputube.org/index.html

--
Euler Taveira
EDB https://www.enterprisedb.com/

Corey Huinker

corey.huinker@gmail.com

over 4 years ago

In reply to: Euler Taveira (#4)

Re: Fwd: Emit namespace in post-copy output

The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: not tested
Documentation: not tested

Passed make check-world. Running make installcheck-world had 2 errors out of 209, but I got those same 2 errors on a clean branch.

Feature is as-described, and very simple.

As far as I can tell, there is no external specification for vacuum or any related utility.

I searched the documentation, and found several examples of the invocation of the VACUUM FULL command and vacuuumdb utility, but at no point was sample output shown, so this change will not require updating documentation.

The new status of this patch is: Ready for Committer

Daniel Gustafsson

daniel@yesql.se

over 4 years ago

In reply to: Corey Huinker (#5)

1 attachment(s)

Re: Emit namespace in post-copy output

I took a look at this I agree with the reviewer that it's a good change. The
output from multiple jobs in vacuumdb is clearly easier to parse with this
since the initial LOG and later DETAIL can be interleaved with other relations
of the same name in other namespaces.

+ get_namespace_name(RelationGetNamespace(OldHeap)),

Since get_namespace_name() returns a palloced string, this will lead to a 2x
leak of the namespace length as opposed to the 1x of today. While hardly a big
deal, it seems prudent to cap this by storing the returned string locally now
that we need it twice.

I've updated the patch with this, see the attached v2. Barring objections I
will go ahead with this.

--
Daniel Gustafsson https://vmware.com/

Attachments:

v2-0001-Emit-namespace-in-the-post-copy-errmsg.patchapplication/octet-stream; name=v2-0001-Emit-namespace-in-the-post-copy-errmsg.patch; x-unix-mode=0644Download

From b09426fe4d1e049410ccba92157a9cca917b05ce Mon Sep 17 00:00:00 2001
From: Daniel Gustafsson <daniel@yesql.se>
Date: Wed, 28 Jul 2021 15:44:14 +0200
Subject: [PATCH v2] Emit namespace in the post-copy errmsg

During a VACUUM or CLUSTER command, the initial output emits the
fully qualified relation path with namespace.  The post-action
errmsg only emitted the relation name however, which could lead
to hard to parse output when using multiple jobs with vacuumdb
for example.  Output the post-action errmsg to include the full
path to be consistent with the initial errmsg.

Author: Mike Fiedler <miketheman@gmail.com>
Reviewed-by: Corey Huinker <corey.huinker@gmail.com>
Discussion: https://postgr.es/m/CAMerE0oz+8G-aORZL_BJcPxnBqewZAvND4bSUysjz+r-oT1BxQ@mail.gmail.com
---
 src/backend/access/heap/vacuumlazy.c |  3 ++-
 src/backend/commands/cluster.c       | 13 +++++++++----
 2 files changed, 11 insertions(+), 5 deletions(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 2c04b69221..e8a27362f6 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -1673,7 +1673,8 @@ lazy_scan_heap(LVRelState *vacrel, VacuumParams *params, bool aggressive)
 	appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0));
 
 	ereport(elevel,
-			(errmsg("\"%s\": found %lld removable, %lld nonremovable row versions in %u out of %u pages",
+			(errmsg("\"%s.%s\": found %lld removable, %lld nonremovable row versions in %u out of %u pages",
+					vacrel->relnamespace,
 					vacrel->relname,
 					(long long) vacrel->tuples_deleted,
 					(long long) vacrel->num_tuples, vacrel->scanned_pages,
diff --git a/src/backend/commands/cluster.c b/src/backend/commands/cluster.c
index b3d8b6deb0..39185cc5b9 100644
--- a/src/backend/commands/cluster.c
+++ b/src/backend/commands/cluster.c
@@ -776,6 +776,7 @@ copy_table_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex, bool verbose,
 	BlockNumber num_pages;
 	int			elevel = verbose ? INFO : DEBUG2;
 	PGRUsage	ru0;
+	char	   *nspname;
 
 	pg_rusage_init(&ru0);
 
@@ -789,6 +790,9 @@ copy_table_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex, bool verbose,
 	else
 		OldIndex = NULL;
 
+	/* Store a copy of the namespace name for logging purposes */
+	nspname = get_namespace_name(RelationGetNamespace(OldHeap));
+
 	/*
 	 * Their tuple descriptors should be exactly alike, but here we only need
 	 * assume that they have the same number of columns.
@@ -887,18 +891,18 @@ copy_table_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex, bool verbose,
 	if (OldIndex != NULL && !use_sort)
 		ereport(elevel,
 				(errmsg("clustering \"%s.%s\" using index scan on \"%s\"",
-						get_namespace_name(RelationGetNamespace(OldHeap)),
+						nspname,
 						RelationGetRelationName(OldHeap),
 						RelationGetRelationName(OldIndex))));
 	else if (use_sort)
 		ereport(elevel,
 				(errmsg("clustering \"%s.%s\" using sequential scan and sort",
-						get_namespace_name(RelationGetNamespace(OldHeap)),
+						nspname,
 						RelationGetRelationName(OldHeap))));
 	else
 		ereport(elevel,
 				(errmsg("vacuuming \"%s.%s\"",
-						get_namespace_name(RelationGetNamespace(OldHeap)),
+						nspname,
 						RelationGetRelationName(OldHeap))));
 
 	/*
@@ -923,7 +927,8 @@ copy_table_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex, bool verbose,
 
 	/* Log what we did */
 	ereport(elevel,
-			(errmsg("\"%s\": found %.0f removable, %.0f nonremovable row versions in %u pages",
+			(errmsg("\"%s.%s\": found %.0f removable, %.0f nonremovable row versions in %u pages",
+					nspname,
 					RelationGetRelationName(OldHeap),
 					tups_vacuumed, num_tuples,
 					RelationGetNumberOfBlocks(OldHeap)),
-- 
2.30.1 (Apple Git-130)

Michael Paquier

michael@paquier.xyz

over 4 years ago

In reply to: Daniel Gustafsson (#6)

Re: Emit namespace in post-copy output

On Wed, Jul 28, 2021 at 04:15:19PM +0200, Daniel Gustafsson wrote:

Since get_namespace_name() returns a palloced string, this will lead to a 2x
leak of the namespace length as opposed to the 1x of today. While hardly a big
deal, it seems prudent to cap this by storing the returned string locally now
that we need it twice.

I don't think this matters much. A quick read of the code shows that
this memory should be allocated within the transaction context running
CLUSTER/VACUUM FULL, and that gets free'd in the internal calls of
CommitTransactionCommand().
--
Michael

Daniel Gustafsson

daniel@yesql.se

over 4 years ago

In reply to: Daniel Gustafsson (#6)

Re: Emit namespace in post-copy output

On 28 Jul 2021, at 16:15, Daniel Gustafsson <daniel@yesql.se> wrote:

I took a look at this I agree with the reviewer that it's a good change.

Pushed to master, thanks!

--
Daniel Gustafsson https://vmware.com/