Date: Thu, 9 Apr 2020 18:46:22 +0200
From: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
To: Michael Paquier <michael@paquier.xyz>
Cc: Fujii Masao <masao.fujii@oss.nttdata.com>, Kyotaro Horiguchi
 <horikyota.ntt@gmail.com>, pgsql-bugs@lists.postgresql.org
Subject: Re: [BUG] non archived WAL removed during production crash recovery
Message-ID: <20200409184622.390f9b7f@firost>
In-Reply-To: <20200408135830.25a8e2ef@firost>
References: <20200402.130443.1791362864704140391.horikyota.ntt@gmail.com>
	<20200402.130734.613319908534820379.horikyota.ntt@gmail.com>
	<03900fc5-fff4-109a-fe69-83de2c167929@oss.nttdata.com>
	<20200402.162323.770257425358491539.horikyota.ntt@gmail.com>
	<ca964b3a-61a0-902e-c7b3-3abbc01a921f@oss.nttdata.com>
	<20200402154915.4984cff2@firost>
	<3d543ef2-ae02-5e59-3bfe-b79d00dab360@oss.nttdata.com>
	<20200403182625.0fccc6fd@firost>
	<4d48dbdb-e1db-a2d6-2fb2-c2a66efa7818@oss.nttdata.com>
	<20200407171736.61906608@firost>
	<20200408022345.GC1606@paquier.xyz>
	<20200408135830.25a8e2ef@firost>
Organization: Dalibo
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="MP_/qQk8YZ8DQFVeW91zVoeDWR1"
Precedence: bulk

--MP_/qQk8YZ8DQFVeW91zVoeDWR1
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

On Wed, 8 Apr 2020 13:58:30 +0200
Jehan-Guillaume de Rorthais <jgdr@dalibo.com> wrote:
[...]
> > May I ask why this new test is added to 011_crash_recovery.pl which is
> > aimed at testing crash and redo, while we have 002_archiving.pl that
> > is dedicated to archiving in a more general manner?  
> 
> I thought it was a better place because the test happen during crash recovery.
> 
> In the meantime, while working on other tests related to $SUBJECT and the
> current consensus, I was wondering if a new file would be a better place
> anyway.

So, 002_archiving.pl deals more with testing recovering on hot standby side
than archiving. Maybe it could be renamed?

While discussing this, I created a new file to add some more tests about WAL
archiving and how recovery deal with them. Please, find the patch in
attachment. I'll be able to move them elsewhere later, depending on the
conclusions of this discussion.

Regards,

--MP_/qQk8YZ8DQFVeW91zVoeDWR1
Content-Type: text/x-patch
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename=0002-v3-Add-tests-relative-to-WAL-archiving.patch

From 8a5422c451d91fb9e2bf3d5d826b9625118d3f24 Mon Sep 17 00:00:00 2001
From: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
Date: Thu, 9 Apr 2020 18:38:50 +0200
Subject: [PATCH 2/2] Add tests relative to WAL archiving

---
 src/test/recovery/t/020_archive_status.pl | 130 ++++++++++++++++++++++
 1 file changed, 130 insertions(+)
 create mode 100644 src/test/recovery/t/020_archive_status.pl

diff --git a/src/test/recovery/t/020_archive_status.pl b/src/test/recovery/t/020_archive_status.pl
new file mode 100644
index 0000000000..5423e86978
--- /dev/null
+++ b/src/test/recovery/t/020_archive_status.pl
@@ -0,0 +1,130 @@
+#
+# Tests relating to WAL archiving and cleanup
+#
+use strict;
+use warnings;
+use PostgresNode;
+use TestLib;
+use Test::More;
+use Config;
+
+my ($node, $standby1, $standby2);
+my ($node_data, $standby1_data, $standby2_data);
+
+if ($Config{osname} eq 'MSWin32')
+{
+
+	# some Windows Perls at least don't like IPC::Run's start/kill_kill regime.
+	plan skip_all => "Test fails on Windows perl";
+}
+else
+{
+	plan tests => 8;
+}
+
+$node = get_new_node('master');
+$node->init(
+	has_archiving => 1,
+	allows_streaming => 1
+);
+$node->start;
+$node_data = $node->data_dir;
+
+# temporary fail archive_command for futur tests
+$node->safe_psql('postgres', q{
+	ALTER SYSTEM SET archive_command TO 'false';
+	SELECT pg_reload_conf();
+});
+
+$node->safe_psql('postgres', q{
+	CREATE TABLE mine AS SELECT generate_series(1,10) AS x;
+	SELECT pg_switch_wal();
+	CHECKPOINT;
+});
+
+# wait for archive failure
+$node->poll_query_until('postgres',
+	q{SELECT failed_count > 0 FROM pg_stat_archiver},
+	't') or die "Timed out while waiting for archiver to fail";
+
+ok( -f "$node_data/pg_wal/archive_status/000000010000000000000001.ready",
+  "ready file exists for WAL waiting to be archived");
+
+is($node->safe_psql('postgres', q{
+		SELECT archived_count, last_failed_wal
+		FROM pg_stat_archiver
+	}),
+	'0|000000010000000000000001', 'pg_stat_archiver reports archive failure');
+
+
+# We need to crash the cluster because next test checks the crash
+# recovery step do not removes non-archived WAL. 
+$node->stop('immediate');
+
+# Standby recovery tests checks the recovery behavior when restoring a
+# backup taken using eg. a snapshot with no pg_start/stop_backup.
+# In this situation, the recovered standby should enter first crash
+# recovery then switch to regular archive recovery.
+$node->backup_fs_cold('backup');
+
+$node->start;
+
+ok( -f "$node_data/pg_wal/archive_status/000000010000000000000001.ready",
+  "WAL still ready to archive in archive_status");
+
+# Allow WAL archiving again
+$node->safe_psql('postgres', q{
+	ALTER SYSTEM RESET archive_command;
+	SELECT pg_reload_conf();
+});
+
+# wait for archive success
+$node->poll_query_until('postgres',
+	q{SELECT archived_count FROM pg_stat_archiver},
+	'1')  or die "Timed out while waiting for archiver to success";
+
+ok( ! -f "$node_data/pg_wal/archive_status/000000010000000000000001.ready",
+  "ready file for archived WAL removed");
+
+ok( -f "$node_data/pg_wal/archive_status/000000010000000000000001.done",
+  "done file for archived WAL exists");
+
+is($node->safe_psql('postgres',
+		q{ SELECT last_archived_wal FROM pg_stat_archiver }),
+	'000000010000000000000001',
+	'Archive success reported in pg_stat_archiver');
+
+# create some wal activity and a new checkpoint so futur standby can create
+# a restartpoint.
+# As standby start in crash recovery because of the backup method, they need
+# a clean restartpoint to deal with existing status files.
+$node->safe_psql('postgres', q{
+	INSERT INTO mine SELECT generate_series(10,20) AS x;
+	SELECT pg_switch_wal();
+	CHECKPOINT;
+});
+
+$node->poll_query_until('postgres',
+	q{ SELECT last_archived_wal FROM pg_stat_archiver },
+	'000000010000000000000002')  or die "Timed out while waiting for archiver to success";
+
+# test recovery without archive_mode=always does not keep .ready WALs
+$standby1 = get_new_node('standby');
+$standby1->init_from_backup($node, 'backup', has_restoring => 1);
+$standby1_data = $standby1->data_dir;
+$standby1->start;
+$standby1->safe_psql('postgres', q{CHECKPOINT});
+
+ok( ! -f "$standby1_data/pg_wal/archive_status/000000010000000000000001.ready",
+  "WAL waiting to be archived in backup removed with archive_mode=on on standby" );
+
+# test recovery with archive_mode=always keeps .ready WALs
+$standby2 = get_new_node('standby2');
+$standby2->init_from_backup($node, 'backup', has_restoring => 1);
+$standby2->append_conf('postgresql.conf', "archive_mode = always");
+$standby2_data = $standby2->data_dir;
+$standby2->start;
+$standby2->safe_psql('postgres', q{CHECKPOINT});
+
+ok( -f "$standby2_data/pg_wal/archive_status/000000010000000000000001.ready",
+  "WAL waiting to be archived in backup kept with archive_mode=always on standby" );
-- 
2.20.1


--MP_/qQk8YZ8DQFVeW91zVoeDWR1--