issue with track_commit_timestamp and server restart

Started by Julien Rouhaudabout 9 years ago8 messages
#1Julien Rouhaud
julien.rouhaud@dalibo.com
1 attachment(s)

I just noticed that if track_commit_timestamp is enabled, the
oldestCommitTsXid and newestCommitTsXid don't persist after a server
restart, so you can't ask for the commit ts of a transaction that
committed before the last server start, although the information is
still available (unless of course if a freeze occured). AFAICT it
always behave this way.

I'm not familiar with that code, but it looks like these counters are
supposed to be restored in StartupXLOG(), with a call to
SetCommitTsLimit(). However, this function doesn't store the new value
if ShmemVariableCache->oldestCommitTsXid is InvalidTransactionId, which
is the initial value.

So the counters are initialized on a subsequent call of
ActivateCommitTs(), which does:

if (ShmemVariableCache->oldestCommitTsXid == InvalidTransactionId)
{
ShmemVariableCache->oldestCommitTsXid =
ShmemVariableCache->newestCommitTsXid = ReadNewTransactionId();
}

(but doesn't try to cleanup the SLRU directory btw)

leaving any previous transaction unreachable. Simple attached patch
seems to fix the issue. I tried on a master and a replica, enabling and
disabling track_commit_timestamp, and everything seemed to work as intended.

--
Julien Rouhaud
http://dalibo.com - http://dalibo.org

Attachments:

fix_committs.difftext/x-diff; name=fix_committs.diffDownload
diff --git a/src/backend/access/transam/commit_ts.c b/src/backend/access/transam/commit_ts.c
index a8d275f..7746578 100644
--- a/src/backend/access/transam/commit_ts.c
+++ b/src/backend/access/transam/commit_ts.c
@@ -844,6 +844,8 @@ SetCommitTsLimit(TransactionId oldestXact, TransactionId newestXact)
 	else
 	{
 		Assert(ShmemVariableCache->newestCommitTsXid == InvalidTransactionId);
+		ShmemVariableCache->oldestCommitTsXid = oldestXact;
+		ShmemVariableCache->newestCommitTsXid = newestXact;
 	}
 	LWLockRelease(CommitTsLock);
 }
#2Craig Ringer
craig@2ndquadrant.com
In reply to: Julien Rouhaud (#1)
1 attachment(s)
Re: issue with track_commit_timestamp and server restart

On 22 October 2016 at 19:51, Julien Rouhaud <julien.rouhaud@dalibo.com> wrote:

I just noticed that if track_commit_timestamp is enabled, the
oldestCommitTsXid and newestCommitTsXid don't persist after a server
restart, so you can't ask for the commit ts of a transaction that
committed before the last server start, although the information is
still available (unless of course if a freeze occured). AFAICT it
always behave this way.

I initially could'n't see this when tested on 8f1fb7d with a
src/test/recovery/t test script. But it turns out it's OK on immediate
shutdown and crash recovery, but not on clean shutdown and restart.

The attached patch adds a TAP test to src/test/recovery to show this.
If you run the TAP test before recompiling with the fix it'll fail.
"make" to apply the fix, then re-run and it'll succeed. Or just
temporarily roll back the fix with:

git checkout HEAD^1 -- src/backend/access/transam/commit_ts.c
git reset src/backend/access/transam/commit_ts.c

and rebuild to see it fail.

To save time running the recovery suite, just

rm src/test/recovery/00[0-8]*.pl

(It'd be nice to have a prove_check target to run just one test file).

This would explain a few issues I've seen reported with BDR from the
community which I've so far been unable to reproduce, so thanks very
much for the report.

Álvaro, would you mind checking this and committing to HEAD and 9.6?
The commits.c change only should also be committed to 9.5, but not the
TAP test.

--
Craig Ringer http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

Attachments:

0001-Preserve-access-to-commit-timestamps-across-restart.patchtext/x-patch; charset=US-ASCII; name=0001-Preserve-access-to-commit-timestamps-across-restart.patchDownload
From 485ecc6c579073cf71ac88746c53668733bc5cac Mon Sep 17 00:00:00 2001
From: Craig Ringer <craig@2ndquadrant.com>
Date: Mon, 24 Oct 2016 12:16:41 +0800
Subject: [PATCH] Preserve access to commit timestamps across restart

An oversight in setting the boundaries of known commit timestamps during
startup caused old commit timestamps to become inaccessible after a server
restart.

Report and bugfix by Julien Rouhaud
Review and commit timestamp tests by Craig Ringer
---
 src/backend/access/transam/commit_ts.c |   2 +
 src/test/recovery/t/009_committs.pl    | 103 +++++++++++++++++++++++++++++++++
 2 files changed, 105 insertions(+)
 create mode 100644 src/test/recovery/t/009_committs.pl

diff --git a/src/backend/access/transam/commit_ts.c b/src/backend/access/transam/commit_ts.c
index a8d275f..7746578 100644
--- a/src/backend/access/transam/commit_ts.c
+++ b/src/backend/access/transam/commit_ts.c
@@ -844,6 +844,8 @@ SetCommitTsLimit(TransactionId oldestXact, TransactionId newestXact)
 	else
 	{
 		Assert(ShmemVariableCache->newestCommitTsXid == InvalidTransactionId);
+		ShmemVariableCache->oldestCommitTsXid = oldestXact;
+		ShmemVariableCache->newestCommitTsXid = newestXact;
 	}
 	LWLockRelease(CommitTsLock);
 }
diff --git a/src/test/recovery/t/009_committs.pl b/src/test/recovery/t/009_committs.pl
new file mode 100644
index 0000000..48f8899
--- /dev/null
+++ b/src/test/recovery/t/009_committs.pl
@@ -0,0 +1,103 @@
+# Testing of logical decoding using SQL interface and/or pg_recvlogical
+use strict;
+use warnings;
+use PostgresNode;
+use TestLib;
+use Test::More tests => 16;
+
+my $node_master = get_new_node('master');
+$node_master->init(allows_streaming => 1);
+$node_master->append_conf(
+		'postgresql.conf', qq(
+track_commit_timestamp = on
+));
+$node_master->start;
+
+my ($ret, $stdout, $stderr);
+
+($ret, $stdout, $stderr) = $node_master->psql('postgres', qq[SELECT pg_xact_commit_timestamp('0');]);
+is($ret, 3, 'getting ts of InvalidTransactionId reports error');
+like($stderr, qr/cannot retrieve commit timestamp for transaction/, 'expected error from InvalidTransactionId');
+
+($ret, $stdout, $stderr) = $node_master->psql('postgres', qq[SELECT pg_xact_commit_timestamp('1');]);
+is($ret, 3, 'getting ts of BootstrapTransactionId reports error');
+like($stderr, qr/cannot retrieve commit timestamp for transaction/, 'expected error from BootstrapTransactionId');
+
+($ret, $stdout, $stderr) = $node_master->psql('postgres', qq[SELECT pg_xact_commit_timestamp('2');]);
+is($ret, 3, 'getting ts of FrozenTransactionId reports error');
+like($stderr, qr/cannot retrieve commit timestamp for transaction/, 'expected error from FrozenTransactionId');
+
+# Since FirstNormalTransactionId will've occurred during initdb, long before we
+# enabled commit timestamps, it'll be null since we have no cts data for it but
+# cts are enabled.
+is($node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('3');]), '',
+	'committs for FirstNormalTransactionId is null');
+
+$node_master->safe_psql('postgres', qq[CREATE TABLE committs_test(x integer, y timestamp with time zone);]);
+
+my $xid = $node_master->safe_psql('postgres', qq[
+	BEGIN;
+	INSERT INTO committs_test(x, y) VALUES (1, current_timestamp);
+	SELECT txid_current();
+	COMMIT;
+]);
+
+my $before_restart_ts = $node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid');]);
+ok($before_restart_ts != '' && $before_restart_ts != 'null', 'commit timestamp recorded');
+
+$node_master->stop('immediate');
+$node_master->start;
+
+my $after_crash_ts = $node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid');]);
+is($after_crash_ts, $before_restart_ts, 'timestamps before and after crash are equal');
+
+$node_master->stop('fast');
+$node_master->start;
+
+my $after_restart_ts = $node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid');]);
+is($after_restart_ts, $before_restart_ts, 'timestamps before and after restart are equal');
+
+# Now disable commit timestamps
+
+$node_master->append_conf(
+		'postgresql.conf', qq(
+track_commit_timestamp = off
+));
+
+$node_master->stop('fast');
+$node_master->start;
+
+($ret, $stdout, $stderr) = $node_master->psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid');]);
+is($ret, 3, 'no commit timestamp from enable tx when cts disabled');
+like($stderr, qr/could not get commit timestamp data/, 'expected error from enabled tx when committs disabled');
+
+# Do a tx while cts disabled
+my $xid_disabled = $node_master->safe_psql('postgres', qq[
+	BEGIN;
+	INSERT INTO committs_test(x, y) VALUES (2, current_timestamp);
+	SELECT txid_current();
+	COMMIT;
+]);
+
+# Should be inaccessible
+($ret, $stdout, $stderr) = $node_master->psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid_disabled');]);
+is($ret, 3, 'no commit timestamp when disabled');
+like($stderr, qr/could not get commit timestamp data/, 'expected error from disabled tx when committs disabled');
+
+# Re-enable, restart and ensure we can still get the old timestamps
+$node_master->append_conf(
+		'postgresql.conf', qq(
+track_commit_timestamp = on
+));
+
+$node_master->stop('fast');
+$node_master->start;
+
+
+my $after_enable_ts = $node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid');]);
+is($after_enable_ts, '', 'timestamp of enabled tx null after re-enable');
+
+my $after_enable_disabled_ts = $node_master->safe_psql('postgres', qq[SELECT pg_xact_commit_timestamp('$xid_disabled');]);
+is($after_enable_disabled_ts, '', 'timestamp of disabled tx null after re-enable');
+
+$node_master->stop;
-- 
2.5.5

#3Michael Paquier
michael.paquier@gmail.com
In reply to: Craig Ringer (#2)
Re: issue with track_commit_timestamp and server restart

(thread hijacking)

On Mon, Oct 24, 2016 at 1:58 PM, Craig Ringer <craig@2ndquadrant.com> wrote:

To save time running the recovery suite, just

rm src/test/recovery/00[0-8]*.pl

(It'd be nice to have a prove_check target to run just one test file).

Agreed! Or multiple chosen files. I usually remove those files
manually from time to time when working on a fix just to run one
dedicated test repeatedly.
--
Michael

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

#4Craig Ringer
craig@2ndquadrant.com
In reply to: Craig Ringer (#2)
Re: issue with track_commit_timestamp and server restart

On 24 October 2016 at 12:58, Craig Ringer <craig@2ndquadrant.com> wrote:

The attached patch adds a TAP test to src/test/recovery to show this.

Added to CF.

https://commitfest.postgresql.org/11/834/

... but IMO this should go in the next bugfix release.

I've also applied nearly the same fix for the same bug in the original
commit timestamp implementation in the BDR Postgres tree.

--
Craig Ringer http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

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

#5Julien Rouhaud
julien.rouhaud@dalibo.com
In reply to: Craig Ringer (#2)
Re: issue with track_commit_timestamp and server restart

On 24/10/2016 06:58, Craig Ringer wrote:

On 22 October 2016 at 19:51, Julien Rouhaud <julien.rouhaud@dalibo.com> wrote:

I just noticed that if track_commit_timestamp is enabled, the
oldestCommitTsXid and newestCommitTsXid don't persist after a server
restart, so you can't ask for the commit ts of a transaction that
committed before the last server start, although the information is
still available (unless of course if a freeze occured). AFAICT it
always behave this way.

I initially could'n't see this when tested on 8f1fb7d with a
src/test/recovery/t test script. But it turns out it's OK on immediate
shutdown and crash recovery, but not on clean shutdown and restart.

The attached patch adds a TAP test to src/test/recovery to show this.
If you run the TAP test before recompiling with the fix it'll fail.
"make" to apply the fix, then re-run and it'll succeed. Or just
temporarily roll back the fix with:

git checkout HEAD^1 -- src/backend/access/transam/commit_ts.c
git reset src/backend/access/transam/commit_ts.c

and rebuild to see it fail.

To save time running the recovery suite, just

rm src/test/recovery/00[0-8]*.pl

(It'd be nice to have a prove_check target to run just one test file).

This would explain a few issues I've seen reported with BDR from the
community which I've so far been unable to reproduce, so thanks very
much for the report.

Álvaro, would you mind checking this and committing to HEAD and 9.6?
The commits.c change only should also be committed to 9.5, but not the
TAP test.

Thanks a lot for the review, and adding the tests!

--
Julien Rouhaud
http://dalibo.com - http://dalibo.org

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

#6Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Craig Ringer (#2)
Re: issue with track_commit_timestamp and server restart

Craig Ringer wrote:

I initially could'n't see this when tested on 8f1fb7d with a
src/test/recovery/t test script. But it turns out it's OK on immediate
shutdown and crash recovery, but not on clean shutdown and restart.

Oh, oops.

The attached patch adds a TAP test to src/test/recovery to show this.

I moved it to src/test/modules/commit_ts and pushed. src/test/recovery
is not currently run by buildfarm, except hamster, unless the bf client
has been patched since I last looked. But that's not the reason I moved
it, but rather because the other location seemed better. I also fixed
the wrongly pasted comment at the top of the file while at it.

If this disrupts the buildfarm in any way I will just revert it
immediately.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

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

#7Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Alvaro Herrera (#6)
Re: issue with track_commit_timestamp and server restart

Now let's discuss a release note entry for 9.5 and 9.6, shall we?

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

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

#8Tom Lane
tgl@sss.pgh.pa.us
In reply to: Alvaro Herrera (#7)
Re: issue with track_commit_timestamp and server restart

Alvaro Herrera <alvherre@2ndquadrant.com> writes:

Now let's discuss a release note entry for 9.5 and 9.6, shall we?

The text in your commit message seems sufficient from here.
On it now (although if somebody doesn't fix anon git PDQ, we're
not releasing today anyway).

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