From: Michael Paquier <michael@paquier.xyz>
To: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
Cc: Kyotaro Horiguchi <horikyota.ntt@gmail.com>
Cc: masao.fujii@oss.nttdata.com
Cc: pgsql-bugs@lists.postgresql.org
Subject: Re: [BUG] non archived WAL removed during production crash recovery
Date: Thu, 16 Apr 2020 17:11:00 +0900
Message-ID: <20200416081100.GD81957@paquier.xyz> (raw)
In-Reply-To: <20200414180319.731f9593@firost>
References: <20200408022345.GC1606@paquier.xyz>
<20200408135830.25a8e2ef@firost>
<20200409184622.390f9b7f@firost>
<20200410.111454.269125561493324950.horikyota.ntt@gmail.com>
<20200413071414.GF2169@paquier.xyz>
<20200414180319.731f9593@firost>
On Tue, Apr 14, 2020 at 06:03:19PM +0200, Jehan-Guillaume de Rorthais wrote:
Thanks for the new version.
> On Mon, 13 Apr 2020 16:14:14 +0900 Michael Paquier <michael@paquier.xyz> wrote:
>> It seems to me that the initial value of SharedRecoveryState should be
>> CRASH_RECOVERING all the time no? StartupXLOG() is a code path taken
>> even if starting cleanly, and the flag would be reset correctly at the
>> end to NOT_IN_RECOVERY.
>
> Previous version of the patch was setting CRASH_RECOVERING. Fujii-san reported
> (the 4 Apr 2020 02:49:50 +0900) that it could be useful to expose a better value
> until relevant code is reached in StartupXLOG() so GetRecoveryState() returns
> a safer value for futur use.
>
> As I answered upthread, I'm not sure who would need this information before the
> WAL machinery is up though. Note that ARCHIVE_RECOVERING and CRASH_RECOVERING
> are compatible with the previous behavior.
I am not sure either if we need this information until the startup
process is up, but even if we need it I'd rather keep the code
consistent with the past practice, which was that
SharedRecoveryInProgress got set to true, the equivalent of crash
recovery as that's more generic than the archive recovery switch.
> Maybe the solution would be to init with CRASH_RECOVERING and add some comment
> in GetRecoveryState() to warn the state is "enforced" after the XLOG machinery
> is started and is init'ed to RECOVERING in the meantime?
>
> I initialized it to CRASH_RECOVERING in the new v5 patch and added a comment
> to GetRecoveryState().
Not sure that the comment is worth it. Your description of the state
looks enough, and the code is clear that we have just an initial
shared memory state in this case.
>> + /* The file is always deletable if archive_mode is "off". */
>> + if ( ! XLogArchivingActive() )
>> + return true;
>> [...]
>> + if ( recoveryState == ARCHIVE_RECOVERING && !XLogArchivingAlways() )
>> return true;
>> Incorrect indentation.
>
> Is it the spaces as reported by Horiguchi-san? I removed them in latest patch.
Yes.
>> It would be good to mention that while in crash recovery, files are
>> not considered as deletable.
>
> Well, in fact, I am still wondering about this. I was hesitant to add a
> shortcut like:
>
> /* no WAL segment cleanup during crash recovery */
> if (recoveryState == RECOVERT_STATE_CRASH)
> return false;
>
> But, what if for example we crashed for lack of disk space during intensive
> writes? During crash recovery, any WAL marked as .done could be removed and
> allow the system to start again and maybe make even further WAL cleanup by
> archiving some more WAL without competing with previous high write ratio.
>
> When we recover a primary, this behavior seems conform with any value of
> archive_mode, even if it has been changed after crash and before starting it.
> On a standby, we might create .ready files, but they will be removed during the
> first restartpoint if needed.
I guess that you mean .ready and not .done here? Removing .done files
does not matter as the segments related to them are already gone.
Even with that, why should we need to make the backend smarter about
the removal of .ready files during crash recovery. It seems to me
that we should keep them, and an operator could always come by himself
and do some manual cleanup to free some space in the pg_wal partition.
> I needed a failure so I can test pg_stat_archiver reports it as well. In my
> mind, using "false" would either trigger a failure because false returns 1 or...
> a failure because the command is not found. In either way, the result is the
> same.
>
> Using poll_query_until+pg_stat_file, is a good idea, but not enough as
> archiver reports a failure some moment after the .ready signal file appears.
Using an empty string makes the test more portable, but while I looked
at it I have found out that it leads to delays in the archiver except
if you force the generation of more segments in the test, causing the
logic to get more complicated with the manipulation of the .ready and
.done files. And I was then finding myself to add an
archive_timeout.. Anyway, this reduced the readability of the test so
I am pretty much giving up on this idea.
>> The end of the tests actually relies on the
>> fact that archive_command is set to "false" when the cold backup is
>> taken, before resetting it. I think that it would be cleaner to
>> enforce the configuration you want to test before starting each
>> standby. It becomes easier to understand the flow of the test for the
>> reader.
>
> done as well.
I have put my hands on the code, and attached is a cleaned up
version for the backend part. Below are some notes.
+ * RECOVERT_STATE_ARCHIVE is set for archive recovery or for a
standby.
Typo here that actually comes from my previous email, and that you
blindly copy-pasted, repeated five times in the tree actually.
+ RecoveryState recoveryState = GetRecoveryState();
+
+ /* The file is always deletable if archive_mode is "off". */
+ if (!XLogArchivingActive())
+ return true;
There is no point to call GetRecoveryState() is archive_mode = off.
+ * There's two different reasons to recover WAL: when standby mode is
requested
+ * or after a crash to catchup with consistency.
Nit: s/There's/There are/. Anyway, I don't see much point in keeping
this comment as the description of each state value should be enough,
so I have removed it.
I am currently in the middle of reviewing the test and there are a
couple of things that can be improved but I lack of time today, so
I'll continue tomorrow on it. There is no need to send two separate
patches by the way as the code paths touched are different.
--
Michael
Attachments:
[text/x-diff] recovery-archives-v6.patch (12.8K, ../20200416081100.GD81957@paquier.xyz/2-recovery-archives-v6.patch)
download | inline diff:diff --git a/src/include/access/xlog.h b/src/include/access/xlog.hindex f60ed2d36c..2cce871dc9 100644--- a/src/include/access/xlog.h+++ b/src/include/access/xlog.h@@ -166,6 +166,14 @@ typedef enum WalLevel
WAL_LEVEL_LOGICAL
} WalLevel;
+/* Recovery states */+typedef enum RecoveryState+{+ RECOVERY_STATE_CRASH = 0, /* crash recovery */+ RECOVERY_STATE_ARCHIVE, /* archive recovery */+ RECOVERY_STATE_NONE /* currently in production */+} RecoveryState;+
extern PGDLLIMPORT int wal_level;
/* Is WAL archiving enabled (always or only while server is running normally)? */
@@ -291,6 +299,7 @@ extern const char *xlog_identify(uint8 info);
extern void issue_xlog_fsync(int fd, XLogSegNo segno);
extern bool RecoveryInProgress(void);
+extern RecoveryState GetRecoveryState(void);
extern bool HotStandbyActive(void);
extern bool HotStandbyActiveInReplay(void);
extern bool XLogInsertAllowed(void);
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.cindex 11e32733c4..a1372b08f6 100644--- a/src/backend/access/transam/xlog.c+++ b/src/backend/access/transam/xlog.c@@ -221,8 +221,9 @@ static TimeLineID receiveTLI = 0;
static bool lastFullPageWrites;
/*
- * Local copy of SharedRecoveryInProgress variable. True actually means "not- * known, need to check the shared state".+ * Local copy of the state tracked by SharedRecoveryState in shared memory,+ * It is false if SharedRecoveryState is RECOVERY_STATE_NONE. True actually+ * means "not known, need to check the shared state".
*/
static bool LocalRecoveryInProgress = true;
@@ -653,10 +654,10 @@ typedef struct XLogCtlData
TimeLineID PrevTimeLineID;
/*
- * SharedRecoveryInProgress indicates if we're still in crash or archive+ * SharedRecoveryState indicates if we're either in crash or archive
* recovery. Protected by info_lck.
*/
- bool SharedRecoveryInProgress;+ RecoveryState SharedRecoveryState;
/*
* SharedHotStandbyActive indicates if we allow hot standby queries to be
@@ -4434,6 +4435,16 @@ ReadRecord(XLogReaderState *xlogreader, int emode,
updateMinRecoveryPoint = true;
UpdateControlFile();
++ /*+ * We update SharedRecoveryState while holding the lock on+ * ControlFileLock so both states are consistent in shared+ * memory.+ */+ SpinLockAcquire(&XLogCtl->info_lck);+ XLogCtl->SharedRecoveryState = RECOVERY_STATE_ARCHIVE;+ SpinLockRelease(&XLogCtl->info_lck);+
LWLockRelease(ControlFileLock);
CheckRecoveryConsistency();
@@ -5166,10 +5177,10 @@ XLOGShmemInit(void)
* in additional info.)
*/
XLogCtl->XLogCacheBlck = XLOGbuffers - 1;
- XLogCtl->SharedRecoveryInProgress = true;
XLogCtl->SharedHotStandbyActive = false;
XLogCtl->SharedPromoteIsTriggered = false;
XLogCtl->WalWriterSleeping = false;
+ XLogCtl->SharedRecoveryState = RECOVERY_STATE_CRASH;
SpinLockInit(&XLogCtl->Insert.insertpos_lck);
SpinLockInit(&XLogCtl->info_lck);
@@ -7911,7 +7922,7 @@ StartupXLOG(void)
ControlFile->time = (pg_time_t) time(NULL);
SpinLockAcquire(&XLogCtl->info_lck);
- XLogCtl->SharedRecoveryInProgress = false;+ XLogCtl->SharedRecoveryState = RECOVERY_STATE_NONE;
SpinLockRelease(&XLogCtl->info_lck);
UpdateControlFile();
@@ -8057,7 +8068,7 @@ RecoveryInProgress(void)
*/
volatile XLogCtlData *xlogctl = XLogCtl;
- LocalRecoveryInProgress = xlogctl->SharedRecoveryInProgress;+ LocalRecoveryInProgress = (xlogctl->SharedRecoveryState != RECOVERY_STATE_NONE);
/*
* Initialize TimeLineID and RedoRecPtr when we discover that recovery
@@ -8069,8 +8080,8 @@ RecoveryInProgress(void)
{
/*
* If we just exited recovery, make sure we read TimeLineID and
- * RedoRecPtr after SharedRecoveryInProgress (for machines with- * weak memory ordering).+ * RedoRecPtr after SharedRecoveryState (for machines with weak+ * memory ordering).
*/
pg_memory_barrier();
InitXLOGAccess();
@@ -8086,6 +8097,24 @@ RecoveryInProgress(void)
}
}
+/*+ * Returns current recovery state from shared memory.+ *+ * This returned state is accurate after StartupXLOG() finished. See+ * details about the possible values of RecoveryState in xlog.h.+ */+RecoveryState+GetRecoveryState(void)+{+ RecoveryState retval;++ SpinLockAcquire(&XLogCtl->info_lck);+ retval = XLogCtl->SharedRecoveryState;+ SpinLockRelease(&XLogCtl->info_lck);++ return retval;+}+
/*
* Is HotStandby active yet? This is only important in special backends
* since normal backends won't ever be able to connect until this returns
diff --git a/src/backend/access/transam/xlogarchive.c b/src/backend/access/transam/xlogarchive.cindex d62c12310a..ce0127c3d0 100644--- a/src/backend/access/transam/xlogarchive.c+++ b/src/backend/access/transam/xlogarchive.c@@ -572,17 +572,21 @@ XLogArchiveCheckDone(const char *xlog)
{
char archiveStatusPath[MAXPGPATH];
struct stat stat_buf;
- bool inRecovery = RecoveryInProgress();++ /* The file is always deletable if archive_mode is "off". */+ if (!XLogArchivingActive())+ return true;++ /* On standbys, the file is deletable if archive_mode is not "always". */+ if (!XLogArchivingAlways() &&+ GetRecoveryState() == RECOVERY_STATE_ARCHIVE)+ return true;
/*
- * The file is always deletable if archive_mode is "off". On standbys- * archiving is disabled if archive_mode is "on", and enabled with- * "always". On a primary, archiving is enabled if archive_mode is "on"- * or "always".+ * At this point of the logic, note that we are either a primary with+ * with archive_mode set to "on" or "always", or a standby with+ * archive_mode set to "always".
*/
- if (!((XLogArchivingActive() && !inRecovery) ||- (XLogArchivingAlways() && inRecovery)))- return true;
/* First check for .done --- this means archiver is done with it */
StatusFilePath(archiveStatusPath, xlog, ".done");
diff --git a/src/test/recovery/t/020_archive_status.pl b/src/test/recovery/t/020_archive_status.plnew file mode 100644index 0000000000..a5f4fd821a--- /dev/null+++ b/src/test/recovery/t/020_archive_status.pl@@ -0,0 +1,193 @@+#+# 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 => 16;+}++$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 segment still ready to archive after crash recovery on primary");++# 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 succeed";++# tests standby with archive_mode=on+$standby1 = get_new_node('standby');+$standby1->init_from_backup($node, 'backup', has_restoring => 1);+$standby1->append_conf('postgresql.conf', "archive_mode = on");+$standby1_data = $standby1->data_dir;+$standby1->start;+$standby1->safe_psql('postgres', q{CHECKPOINT});++# recovery with archive_mode=on does not keep .ready signal files inherited from backup.+# 000000010000000000000001.ready existed in the backup.+ok( ! -f "$standby1_data/pg_wal/archive_status/000000010000000000000001.ready",+ ".ready signal file existing in backup removed with archive_mode=on on standby" );++# recovery with archive_mode=on should not create .ready signal files+# 000000010000000000000002.ready did not exist in the backup+ok( ! -f "$standby1_data/pg_wal/archive_status/000000010000000000000002.ready",+ "standby doesn't create .ready signal file when archive_mode=on" );++# recovery with archive_mode=on creates .done signal files+ok( -f "$standby1_data/pg_wal/archive_status/000000010000000000000002.done",+ "standby creates .done signal file when archive_mode=on" );++# 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');+$standby1->append_conf('postgresql.auto.conf', "archive_command = false");+$standby2_data = $standby2->data_dir;+$standby2->start;++$standby2->safe_psql('postgres', q{CHECKPOINT});++ok( -f "$standby2_data/pg_wal/archive_status/000000010000000000000001.ready",+ ".ready signal file existing in backup are kept with archive_mode=always on standby" );++ok( -f "$standby2_data/pg_wal/archive_status/000000010000000000000002.ready",+ ".ready signal file are created with archive_mode=always on standby" );++# Allow WAL archiving again+$standby2->safe_psql('postgres', q{SELECT pg_stat_reset_shared('archiver')});++is($standby2->safe_psql('postgres',+ q{ SELECT failed_count, archived_count FROM pg_stat_archiver }),+ '0|0',+ 'statistics reset from pg_stat_archiver succeed');++# We need to crash the cluster because next test checks the crash+# recovery step do not removes non-archived WAL on a standby.+$standby2->stop('immediate');+$standby2->start;++ok( -f "$standby2_data/pg_wal/archive_status/000000010000000000000001.ready",+ "WAL segment still ready to archive after crash recovery on standby with archive_mode=always");++# Allow WAL archiving again+$standby2->safe_psql('postgres', q{+ ALTER SYSTEM RESET archive_command;+ SELECT pg_reload_conf();+});++# wait for archive success+$standby2->poll_query_until('postgres',+ q{SELECT last_archived_wal FROM pg_stat_archiver},+ '000000010000000000000002') or die "Timed out while waiting for archiver to success";++is($standby2->safe_psql('postgres',+ q{SELECT archived_count FROM pg_stat_archiver}),+ '2', 'WAL segment archived from standby');++ok( ! -f "$standby2_data/pg_wal/archive_status/000000010000000000000001.ready"+ && ! -f "$standby2_data/pg_wal/archive_status/000000010000000000000002.ready",+ ".ready signal file removed after archiving with archive_mode=always on standby" );++ok( -f "$standby2_data/pg_wal/archive_status/000000010000000000000001.done"+ and -f "$standby2_data/pg_wal/archive_status/000000010000000000000002.done",+ ".done signal file created after archiving with archive_mode=always on standby" );++#ok(0);+#+## wait for archive success+#$standby2->poll_query_until('postgres',+# q{SELECT 1},+# '0') or die "Timed out while waiting for archiver to success";+
[application/pgp-signature] signature.asc (832B, ../20200416081100.GD81957@paquier.xyz/3-signature.asc)
download
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-bugs@postgresql.org
Cc: michael@paquier.xyz, jgdr@dalibo.com, horikyota.ntt@gmail.com, masao.fujii@oss.nttdata.com, pgsql-bugs@lists.postgresql.org
Subject: Re: [BUG] non archived WAL removed during production crash recovery
In-Reply-To: <20200416081100.GD81957@paquier.xyz>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox