Backup command and functions can cause assertion failure and segmentation fault
Hi, I found that the assertion failure and the segmentation fault could happen by running pg_backup_start(), pg_backup_stop() and BASE_BACKUP replication command, in v15 or before. Here is the procedure to reproduce the assertion failure. 1. Connect to the server as the REPLICATION user who is granted EXECUTE to run pg_backup_start() and pg_backup_stop(). $ psql =# CREATE ROLE foo REPLICATION LOGIN; =# GRANT EXECUTE ON FUNCTION pg_backup_start TO foo; =# GRANT EXECUTE ON FUNCTION pg_backup_stop TO foo; =# \q $ psql "replication=database user=foo dbname=postgres" 2. Run pg_backup_start() and pg_backup_stop(). => SELECT pg_backup_start('test', true); => SELECT pg_backup_stop(); 3. Run BASE_BACKUP replication command with smaller MAX_RATE so that it can take a long time to finish. => BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32); 4. Terminate the replication connection while it's running BASE_BACKUP. $ psql =# SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE backend_type = 'walsender'; This procedure can cause the following assertion failure. TRAP: FailedAssertion("XLogCtl->Insert.runningBackups > 0", File: "xlog.c", Line: 8779, PID: 69434) 0 postgres0x00010ab2ff7f ExceptionalCondition + 223 1 postgres0x00010a455126 do_pg_abort_backup + 102 2 postgres0x00010a8e13aa shmem_exit + 218 3 postgres0x00010a8e11ed proc_exit_prepare + 125 4 postgres0x00010a8e10f3 proc_exit + 19 5 postgres0x00010ab3171c errfinish + 1100 6 postgres0x00010a91fa80 ProcessInterrupts + 1376 7 postgres0x00010a886907 throttle + 359 8 postgres0x00010a88675d bbsink_throttle_archive_contents + 29 9 postgres0x00010a885aca bbsink_archive_contents + 154 10 postgres0x00010a885a2a bbsink_forward_archive_contents + 218 11 postgres0x00010a884a99 bbsink_progress_archive_contents + 89 12 postgres0x00010a881aba bbsink_archive_contents + 154 13 postgres0x00010a881598 sendFile + 1816 14 postgres0x00010a8806c5 sendDir + 3573 15 postgres0x00010a8805d9 sendDir + 3337 16 postgres0x00010a87e262 perform_base_backup + 1250 17 postgres0x00010a87c734 SendBaseBackup + 500 18 postgres0x00010a89a7f8 exec_replication_command + 1144 19 postgres0x00010a92319a PostgresMain + 2154 20 postgres0x00010a82b702 BackendRun + 50 21 postgres0x00010a82acfc BackendStartup + 524 22 postgres0x00010a829b2c ServerLoop + 716 23 postgres0x00010a827416 PostmasterMain + 6470 24 postgres0x00010a703e19 main + 809 25 libdyld.dylib 0x7fff2072ff3d start + 1 Here is the procedure to reproduce the segmentation fault. 1. Connect to the server as the REPLICATION user who is granted EXECUTE to run pg_backup_stop(). $ psql =# CREATE ROLE foo REPLICATION LOGIN; =# GRANT EXECUTE ON FUNCTION pg_backup_stop TO foo; =# \q $ psql "replication=database user=foo dbname=postgres" 2. Run BASE_BACKUP replication command with smaller MAX_RATE so that it can take a long time to finish. => BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32); 3. Press Ctrl-C to cancel BASE_BACKUP while it's running. 4. Run pg_backup_stop(). => SELECT pg_backup_stop(); This procedure can cause the following segmentation fault. LOG: server process (PID 69449) was terminated by signal 11: Segmentation fault: 11 DETAIL: Failed process was running: SELECT pg_backup_stop(); The root cause of these failures seems that sessionBackupState flag is not reset to SESSION_BACKUP_NONE even when BASE_BACKUP is aborted. So attached patch changes do_pg_abort_backup callback so that it resets sessionBackupState. I confirmed that, with the patch, those assertion failure and segmentation fault didn't happen. But this change has one issue that; if BASE_BACKUP is run while a backup is already in progress in the session by pg_backup_start() and that session is terminated, the change causes XLogCtl->Insert.runningBackups to be decremented incorrectly. That is, XLogCtl->Insert.runningBackups is incremented by two by pg_backup_start() and BASE_BACKUP, but it's decremented only by one by the termination of the session. To address this issue, I think that we should disallow BAS
Re: Backup command and functions can cause assertion failure and segmentation fault
At Thu, 30 Jun 2022 12:28:43 +0900, Fujii Masao wrote in > The root cause of these failures seems that sessionBackupState flag > is not reset to SESSION_BACKUP_NONE even when BASE_BACKUP is aborted. > So attached patch changes do_pg_abort_backup callback so that > it resets sessionBackupState. I confirmed that, with the patch, > those assertion failure and segmentation fault didn't happen. > > But this change has one issue that; if BASE_BACKUP is run while > a backup is already in progress in the session by pg_backup_start() > and that session is terminated, the change causes > XLogCtl->Insert.runningBackups > to be decremented incorrectly. That is, XLogCtl->Insert.runningBackups > is incremented by two by pg_backup_start() and BASE_BACKUP, > but it's decremented only by one by the termination of the session. > > To address this issue, I think that we should disallow BASE_BACKUP > to run while a backup is already in progress in the *same* session > as we already do this for pg_backup_start(). Thought? I included > the code to disallow that in the attached patch. It seems like to me that the root cause is the callback is registered twice. The callback does not expect to be called more than once (at least per one increment of runningBackups). register_persistent_abort_backup_hanedler() prevents duplicate regsitration of the callback so I think perform_base_backup should use this function instead of protecting by the PG_*_ERROR_CLEANUP() section. Please find the attached. regards. -- Kyotaro Horiguchi NTT Open Source Software Center >From 76af9ecee495b34b6a1d2abfd0f35bb7aeb64178 Mon Sep 17 00:00:00 2001 From: Kyotaro Horiguchi Date: Fri, 1 Jul 2022 11:38:34 +0900 Subject: [PATCH 1/2] Use permanent backup-abort call back in perform_base_backup --- src/backend/replication/basebackup.c | 13 +++-- 1 file changed, 3 insertions(+), 10 deletions(-) diff --git a/src/backend/replication/basebackup.c b/src/backend/replication/basebackup.c index 95440013c0..e4345dbff2 100644 --- a/src/backend/replication/basebackup.c +++ b/src/backend/replication/basebackup.c @@ -255,19 +255,14 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) total_checksum_failures = 0; basebackup_progress_wait_checkpoint(); + + register_persistent_abort_backup_handler(); + state.startptr = do_pg_backup_start(opt->label, opt->fastcheckpoint, &state.starttli, labelfile, &state.tablespaces, tblspc_map_file); - /* - * Once do_pg_backup_start has been called, ensure that any failure causes - * us to abort the backup so we don't "leak" a backup counter. For this - * reason, *all* functionality between do_pg_backup_start() and the end of - * do_pg_backup_stop() should be inside the error cleanup block! - */ - - PG_ENSURE_ERROR_CLEANUP(do_pg_abort_backup, BoolGetDatum(false)); { ListCell *lc; tablespaceinfo *ti; @@ -375,8 +370,6 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) basebackup_progress_wait_wal_archive(&state); endptr = do_pg_backup_stop(labelfile->data, !opt->nowait, &endtli); } - PG_END_ENSURE_ERROR_CLEANUP(do_pg_abort_backup, BoolGetDatum(false)); - if (opt->includewal) { -- 2.31.1 >From 477c470fe22f3f98f4ca1f990d8150fbc19bd778 Mon Sep 17 00:00:00 2001 From: Kyotaro Horiguchi Date: Fri, 1 Jul 2022 11:40:14 +0900 Subject: [PATCH 2/2] Remove extra code block. --- src/backend/replication/basebackup.c | 185 +-- 1 file changed, 91 insertions(+), 94 deletions(-) diff --git a/src/backend/replication/basebackup.c b/src/backend/replication/basebackup.c index e4345dbff2..ec9bc6f52b 100644 --- a/src/backend/replication/basebackup.c +++ b/src/backend/replication/basebackup.c @@ -233,6 +233,8 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) StringInfo labelfile; StringInfo tblspc_map_file; backup_manifest_info manifest; + ListCell *lc; + tablespaceinfo *ti; /* Initial backup state, insofar as we know it now. */ state.tablespaces = NIL; @@ -263,114 +265,109 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) labelfile, &state.tablespaces, tblspc_map_file); + /* Add a node for the base directory at the end */ + ti = palloc0(sizeof(tablespaceinfo)); + ti->size = -1; + state.tablespaces = lappend(state.tablespaces, ti); + + /* + * Calculate the total backup size by summing up the size of each + * tablespace + */ + if (opt->progress) { - ListCell *lc; - tablespaceinfo *ti; - - /* Add a node for the base directory at the end */ - ti = palloc0(sizeof(tablespaceinfo)); - ti->size = -1; - state.tablespaces = lappend(state.tablespaces, ti); - - /* - * Calculate the total backup size by summing up the size of each - * tablespace - */ - if (opt->progress) - { - basebackup_progress_estimate_backup_size(); - - foreach(lc, state.tablespaces) - { -tablespaceinfo *tmp = (tablespaceinfo *) lfirst(lc); - -if (tmp->path == NULL) -
Re: Backup command and functions can cause assertion failure and segmentation fault
At Fri, 01 Jul 2022 11:46:53 +0900 (JST), Kyotaro Horiguchi wrote in > Please find the attached. Mmm. It forgot the duplicate-call prevention and query-cancel handling... The first one is the same as you posted but the second one is still a problem.. regards. -- Kyotaro Horiguchi NTT Open Source Software Center
Re: Backup command and functions can cause assertion failure and segmentation fault
At Fri, 01 Jul 2022 11:56:14 +0900 (JST), Kyotaro Horiguchi wrote in > At Fri, 01 Jul 2022 11:46:53 +0900 (JST), Kyotaro Horiguchi > wrote in > > Please find the attached. > > Mmm. It forgot the duplicate-call prevention and query-cancel > handling... The first one is the same as you posted but the second one > is still a problem.. So this is the first cut of that. regards. -- Kyotaro Horiguchi NTT Open Source Software Center >From b160b89eda94213c5355174c30655bc447bff8da Mon Sep 17 00:00:00 2001 From: Kyotaro Horiguchi Date: Fri, 1 Jul 2022 11:38:34 +0900 Subject: [PATCH v2] Use permanent backup-abort call back in perform_base_backup --- src/backend/replication/basebackup.c | 23 +-- 1 file changed, 13 insertions(+), 10 deletions(-) diff --git a/src/backend/replication/basebackup.c b/src/backend/replication/basebackup.c index 95440013c0..6f8fb78212 100644 --- a/src/backend/replication/basebackup.c +++ b/src/backend/replication/basebackup.c @@ -234,6 +234,11 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) StringInfo tblspc_map_file; backup_manifest_info manifest; + if (get_backup_status() == SESSION_BACKUP_RUNNING) + ereport(ERROR, +(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE), + errmsg("a backup is already in progress in this session"))); + /* Initial backup state, insofar as we know it now. */ state.tablespaces = NIL; state.tablespace_num = 0; @@ -255,19 +260,15 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) total_checksum_failures = 0; basebackup_progress_wait_checkpoint(); + + register_persistent_abort_backup_handler(); + state.startptr = do_pg_backup_start(opt->label, opt->fastcheckpoint, &state.starttli, labelfile, &state.tablespaces, tblspc_map_file); - /* - * Once do_pg_backup_start has been called, ensure that any failure causes - * us to abort the backup so we don't "leak" a backup counter. For this - * reason, *all* functionality between do_pg_backup_start() and the end of - * do_pg_backup_stop() should be inside the error cleanup block! - */ - - PG_ENSURE_ERROR_CLEANUP(do_pg_abort_backup, BoolGetDatum(false)); + PG_TRY(); { ListCell *lc; tablespaceinfo *ti; @@ -373,10 +374,12 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) } basebackup_progress_wait_wal_archive(&state); + } + PG_FINALLY(); + { endptr = do_pg_backup_stop(labelfile->data, !opt->nowait, &endtli); } - PG_END_ENSURE_ERROR_CLEANUP(do_pg_abort_backup, BoolGetDatum(false)); - + PG_END_TRY(); if (opt->includewal) { -- 2.31.1
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/01 12:05, Kyotaro Horiguchi wrote: At Fri, 01 Jul 2022 11:56:14 +0900 (JST), Kyotaro Horiguchi wrote in At Fri, 01 Jul 2022 11:46:53 +0900 (JST), Kyotaro Horiguchi wrote in Please find the attached. Mmm. It forgot the duplicate-call prevention and query-cancel handling... The first one is the same as you posted but the second one is still a problem.. So this is the first cut of that. Thanks for reviewing the patch! + PG_FINALLY(); + { endptr = do_pg_backup_stop(labelfile->data, !opt->nowait, &endtli); } - PG_END_ENSURE_ERROR_CLEANUP(do_pg_abort_backup, BoolGetDatum(false)); - + PG_END_TRY(); This change makes perform_base_backup() call do_pg_backup_stop() even when an error is reported while taking a backup, i.e., between PG_TRY() and PG_FINALLY(). Why do_pg_backup_stop() needs to be called in such an error case? It not only cleans up the backup state but also writes the backup-end WAL record, waits for WAL archiving. In an error case, I think that only the cleanup of the backup state is necessary. So it seems ok to use do_pg_abort_backup() in that case, as it is for now. So I'm still thinking that the patch I posted is simpler and enough. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION
Re: Backup command and functions can cause assertion failure and segmentation fault
Hi, On Thu, Jun 30, 2022 at 12:29 PM Fujii Masao wrote: > > Hi, > > I found that the assertion failure and the segmentation fault could > happen by running pg_backup_start(), pg_backup_stop() and BASE_BACKUP > replication command, in v15 or before. > > Here is the procedure to reproduce the assertion failure. > > 1. Connect to the server as the REPLICATION user who is granted > EXECUTE to run pg_backup_start() and pg_backup_stop(). > > $ psql > =# CREATE ROLE foo REPLICATION LOGIN; > =# GRANT EXECUTE ON FUNCTION pg_backup_start TO foo; > =# GRANT EXECUTE ON FUNCTION pg_backup_stop TO foo; > =# \q > > $ psql "replication=database user=foo dbname=postgres" > > 2. Run pg_backup_start() and pg_backup_stop(). > > => SELECT pg_backup_start('test', true); > => SELECT pg_backup_stop(); > > 3. Run BASE_BACKUP replication command with smaller MAX_RATE so that > it can take a long time to finish. > > => BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32); > > 4. Terminate the replication connection while it's running BASE_BACKUP. > > $ psql > =# SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE > backend_type = 'walsender'; > > This procedure can cause the following assertion failure. > > TRAP: FailedAssertion("XLogCtl->Insert.runningBackups > 0", File: "xlog.c", > Line: 8779, PID: 69434) > 0 postgres0x00010ab2ff7f > ExceptionalCondition + 223 > 1 postgres0x00010a455126 do_pg_abort_backup > + 102 > 2 postgres0x00010a8e13aa shmem_exit + 218 > 3 postgres0x00010a8e11ed proc_exit_prepare > + 125 > 4 postgres0x00010a8e10f3 proc_exit + 19 > 5 postgres0x00010ab3171c errfinish + 1100 > 6 postgres0x00010a91fa80 ProcessInterrupts > + 1376 > 7 postgres0x00010a886907 throttle + 359 > 8 postgres0x00010a88675d > bbsink_throttle_archive_contents + 29 > 9 postgres0x00010a885aca > bbsink_archive_contents + 154 > 10 postgres0x00010a885a2a > bbsink_forward_archive_contents + 218 > 11 postgres0x00010a884a99 > bbsink_progress_archive_contents + 89 > 12 postgres0x00010a881aba > bbsink_archive_contents + 154 > 13 postgres0x00010a881598 sendFile + 1816 > 14 postgres0x00010a8806c5 sendDir + 3573 > 15 postgres0x00010a8805d9 sendDir + 3337 > 16 postgres0x00010a87e262 > perform_base_backup + 1250 > 17 postgres0x00010a87c734 SendBaseBackup + > 500 > 18 postgres0x00010a89a7f8 > exec_replication_command + 1144 > 19 postgres0x00010a92319a PostgresMain + 2154 > 20 postgres0x00010a82b702 BackendRun + 50 > 21 postgres0x00010a82acfc BackendStartup + > 524 > 22 postgres0x00010a829b2c ServerLoop + 716 > 23 postgres0x00010a827416 PostmasterMain + > 6470 > 24 postgres0x00010a703e19 main + 809 > 25 libdyld.dylib 0x7fff2072ff3d start + 1 > > > Here is the procedure to reproduce the segmentation fault. > > 1. Connect to the server as the REPLICATION user who is granted > EXECUTE to run pg_backup_stop(). > > $ psql > =# CREATE ROLE foo REPLICATION LOGIN; > =# GRANT EXECUTE ON FUNCTION pg_backup_stop TO foo; > =# \q > > $ psql "replication=database user=foo dbname=postgres" > > 2. Run BASE_BACKUP replication command with smaller MAX_RATE so that > it can take a long time to finish. > > => BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32); > > 3. Press Ctrl-C to cancel BASE_BACKUP while it's running. > > 4. Run pg_backup_stop(). > > => SELECT pg_backup_stop(); > > This procedure can cause the following segmentation fault. > > LOG: server process (PID 69449) was terminated by signal 11: > Segmentation fault: 11 > DETAIL: Failed process was running: SELECT pg_backup_stop(); > > > The root cause of these failures seems that sessionBackupState flag > is not reset to SESSION_BACKUP_NONE even when BASE_BACKUP is aborted. > So attached patch changes do_pg_abort_backup callback so that > it resets sessionBackupState. I confirmed that, with the patch, > those assertion failure and segmentation fault didn't happen. The change looks good to me. I've also confirmed the change fixed the issues. > But this change has one issue that; if BASE_BACKUP is run while > a backup is already in progress i
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/01 15:09, Masahiko Sawada wrote: The change looks good to me. I've also confirmed the change fixed the issues. Thanks for the review and test! @@ -233,6 +233,12 @@ perform_base_backup(basebackup_options *opt, bbsink *sink) StringInfo labelfile; StringInfo tblspc_map_file; backup_manifest_info manifest; + SessionBackupState status = get_backup_status(); + + if (status == SESSION_BACKUP_RUNNING) + ereport(ERROR, + (errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE), +errmsg("a backup is already in progress in this session"))); I think we can move it to the beginning of SendBaseBackup() so we can avoid bbsink initialization and cleanup in the error case. Sounds good idea to me. I updated the patch in that way. Attached. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATIONdiff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 8764084e21..c4d956b9c1 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -8783,6 +8783,8 @@ do_pg_abort_backup(int code, Datum arg) { XLogCtl->Insert.forcePageWrites = false; } + + sessionBackupState = SESSION_BACKUP_NONE; WALInsertLockRelease(); if (emit_warning) diff --git a/src/backend/replication/basebackup.c b/src/backend/replication/basebackup.c index 95440013c0..637c0ce459 100644 --- a/src/backend/replication/basebackup.c +++ b/src/backend/replication/basebackup.c @@ -949,6 +949,12 @@ SendBaseBackup(BaseBackupCmd *cmd) { basebackup_options opt; bbsink *sink; + SessionBackupState status = get_backup_status(); + + if (status == SESSION_BACKUP_RUNNING) + ereport(ERROR, + (errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE), +errmsg("a backup is already in progress in this session"))); parse_basebackup_options(cmd->options, &opt);
Re: Backup command and functions can cause assertion failure and segmentation fault
On Fri, Jul 01, 2022 at 03:32:50PM +0900, Fujii Masao wrote: > Sounds good idea to me. I updated the patch in that way. Attached. Skimming quickly through the thread, this failure requires a termination of a backend running BASE_BACKUP. This is basically something done by the TAP test added in 0475a97f with a WAL sender killed, and MAX_RATE being used to make sure that we have enough time to kill the WAL sender even on fast machines. So you could add a regression test, no? -- Michael signature.asc Description: PGP signature
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/01 15:41, Michael Paquier wrote: On Fri, Jul 01, 2022 at 03:32:50PM +0900, Fujii Masao wrote: Sounds good idea to me. I updated the patch in that way. Attached. Skimming quickly through the thread, this failure requires a termination of a backend running BASE_BACKUP. This is basically something done by the TAP test added in 0475a97f with a WAL sender killed, and MAX_RATE being used to make sure that we have enough time to kill the WAL sender even on fast machines. So you could add a regression test, no? For the test, BASE_BACKUP needs to be canceled after it finishes do_pg_backup_start(), i.e., checkpointing, and before it calls do_pg_backup_stop(). So the timing to cancel that seems more severe than the test added in 0475a97f. I'm afraid that some tests can easily cancel the BASE_BACKUP while it's performing a checkpoint in do_pg_backup_start(). So for now I'm thinking to avoid such an unstable test. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION
Re: Backup command and functions can cause assertion failure and segmentation fault
On Wed, Jul 06, 2022 at 11:27:58PM +0900, Fujii Masao wrote: > For the test, BASE_BACKUP needs to be canceled after it finishes > do_pg_backup_start(), i.e., checkpointing, and before it calls > do_pg_backup_stop(). So the timing to cancel that seems more severe > than the test added in 0475a97f. I'm afraid that some tests can > easily cancel the BASE_BACKUP while it's performing a checkpoint in > do_pg_backup_start(). So for now I'm thinking to avoid such an > unstable test. Hmm. In order to make sure that the checkpoint of the base backup is completed, and assuming that the checkpoint is fast while the base backup has a max rate, you could rely on a query that does a poll_query_until() on pg_control_checkpoint(), no? As long as you use IPC::Run::start, pg_basebackup would be async so the polling query and the cancellation can be done in parallel of it. 0475a97 did almost that, except that it waits for the WAL sender to be started. -- Michael signature.asc Description: PGP signature
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/07 9:09, Michael Paquier wrote: On Wed, Jul 06, 2022 at 11:27:58PM +0900, Fujii Masao wrote: For the test, BASE_BACKUP needs to be canceled after it finishes do_pg_backup_start(), i.e., checkpointing, and before it calls do_pg_backup_stop(). So the timing to cancel that seems more severe than the test added in 0475a97f. I'm afraid that some tests can easily cancel the BASE_BACKUP while it's performing a checkpoint in do_pg_backup_start(). So for now I'm thinking to avoid such an unstable test. Hmm. In order to make sure that the checkpoint of the base backup is completed, and assuming that the checkpoint is fast while the base backup has a max rate, you could rely on a query that does a poll_query_until() on pg_control_checkpoint(), no? As long as you use IPC::Run::start, pg_basebackup would be async so the polling query and the cancellation can be done in parallel of it. 0475a97 did almost that, except that it waits for the WAL sender to be started. There seems to be some corner cases where we cannot rely on that. If "spread" checkpoint is already running when BASE_BACKUP is executed, poll_query_until() may report the end of that "spread" checkpoint before BASE_BACKUP internally starts its checkpoint. Which may cause the test to fail. If BASE_BACKUP is accidentally canceled after poll_query_until() reports the end of checkpoint but before do_pg_backup_start() finishes (i.e., before entering the error cleanup block using do_pg_abort_backup callback), the test may fail. Probably we may be able to decrease the risk of those test failures by using some techniques, e.g., adding the fixed wait time before requesting the cancel. But I'm not sure if it's worth adding the test for the corner case issue that I reported at the risk of adding the unstable test. The issue could happen only when both BASE_BACKUP and low level API for backup are eecuted via logical replication walsender mode, and BASE_BACKUP is canceled or terminated. But if many think that it's worth adding the test, I will give a try. But even in that case, I think it's better to commit the proposed patch at first to fix the bug, and then to write the patch adding the test. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION
Re: Backup command and functions can cause assertion failure and segmentation fault
On Thu, Jul 7, 2022 at 10:58 AM Fujii Masao wrote: > But if many think that it's worth adding the test, I will give a try. But > even in that case, I think it's better to commit the proposed patch at first > to fix the bug, and then to write the patch adding the test. I don't think that we necessarily need to have a test for this patch. It's true that we don't really have good test coverage of write-ahead logging and recovery, but this doesn't seem like the most important thing to be testing in that area, either, and developing stable tests for stuff like this can be a lot of work. I do kind of feel like the patch is fixing two separate bugs. The change to SendBaseBackup() is fixing the problem that, because there's SQL access on replication connections, we could try to start a backup in the middle of another backup by mixing and matching the two different methods of doing backups. The change to do_pg_abort_backup() is fixing the fact that, after aborting a base backup, we don't reset the session state properly so that another backup can be tried afterwards. I don't know if it's worth committing them separately - they are very small fixes. But it would probably at least be good to highlight in the commit message that there are two different issues. -- Robert Haas EDB: http://www.enterprisedb.com
Re: Backup command and functions can cause assertion failure and segmentation fault
On Fri, Jul 08, 2022 at 08:56:14AM -0400, Robert Haas wrote: > On Thu, Jul 7, 2022 at 10:58 AM Fujii Masao > wrote: >> But if many think that it's worth adding the test, I will give a >> try. But even in that case, I think it's better to commit the >> proposed patch at first to fix the bug, and then to write the patch >> adding the test. I have looked at that in details, and it is possible to rely on pg_stat_activity.wait_event to be BaseBackupThrottle, which would make sure that the checkpoint triggered at the beginning of the backup finishes and that we are in the middle of the base backup. The command for the test should be a psql command with two -c switches without ON_ERROR_STOP, so as the second pg_backup_stop() starts after BASE_BACKUP is cancelled using the same connection, for something like that: psql -c "BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32);" \ -c "select pg_backup_stop()" "replication=database" The last part of the test should do a pump_until() and capture "backup is not in progress" from the stderr output of the command run. This is leading me to the attached, that crashes quickly without the fix and passes with the fix. > It's true that we don't really have good test coverage of write-ahead > logging and recovery, but this doesn't seem like the most important > thing to be testing in that area, either, and developing stable tests > for stuff like this can be a lot of work. Well, stability does not seem like a problem to me here. > I do kind of feel like the patch is fixing two separate bugs. The > change to SendBaseBackup() is fixing the problem that, because there's > SQL access on replication connections, we could try to start a backup > in the middle of another backup by mixing and matching the two > different methods of doing backups. The change to do_pg_abort_backup() > is fixing the fact that, after aborting a base backup, we don't reset > the session state properly so that another backup can be tried > afterwards. > > I don't know if it's worth committing them separately - they are very > small fixes. But it would probably at least be good to highlight in > the commit message that there are two different issues. Grouping both fixes in the same commit sounds fine by me. No objections from here. -- Michael From 062bf8a06f68b7d543288260dd0cdf50bb5e9a72 Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Thu, 14 Jul 2022 16:56:17 +0900 Subject: [PATCH] Add TAP test for BASE_BACKUP cancellation with pg_stop_backup() --- src/test/recovery/t/033_basebackup_cancel.pl | 60 1 file changed, 60 insertions(+) create mode 100644 src/test/recovery/t/033_basebackup_cancel.pl diff --git a/src/test/recovery/t/033_basebackup_cancel.pl b/src/test/recovery/t/033_basebackup_cancel.pl new file mode 100644 index 00..56cbaf83d0 --- /dev/null +++ b/src/test/recovery/t/033_basebackup_cancel.pl @@ -0,0 +1,60 @@ +# Copyright (c) 2021-2022, PostgreSQL Global Development Group + +# BASE_BACKUP cancellation with replication database connection. +use strict; +use warnings; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +# Initialize primary node +my $node = PostgreSQL::Test::Cluster->new('node'); +$node->init(allows_streaming => 1); +$node->append_conf('postgresql.conf', 'log_replication_commands = on'); +$node->start; + +note "testing BASE_BACKUP cancellation"; + +my $sigchld_bb_timeout = + IPC::Run::timer($PostgreSQL::Test::Utils::timeout_default); + +# This test requires a replication connection with a database, as it mixes +# a replication command and a SQL command. The first BASE_BACKUP is throttled +# to give enough room for the cancellation running below. The second command +# for pg_backup_stop() should fail. +my $connstr = + $node->connstr('postgres') . " replication=database dbname=postgres"; +my ($sigchld_bb_stdin, $sigchld_bb_stdout, $sigchld_bb_stderr) = ('', '', ''); +my $sigchld_bb = IPC::Run::start( + [ + 'psql', '-X', '-c', "BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32);", + '-c', 'SELECT pg_backup_stop()', + '-d', $connstr + ], + '<', + \$sigchld_bb_stdin, + '>', + \$sigchld_bb_stdout, + '2>', + \$sigchld_bb_stderr, + $sigchld_bb_timeout); + +# Waiting on the wait event BaseBackupThrottle ensures that the checkpoint +# issued at backup start completes, making the cancellation happen in the +# middle of the base backup sent. +is( $node->poll_query_until( + 'postgres', + "SELECT pg_cancel_backend(pid) FROM pg_stat_activity WHERE " + . "wait_event = 'BaseBackupThrottle' " + . "AND backend_type = 'walsender' AND query ~ 'BASE_BACKUP'"), + "1", + "WAL sender sending base backup killed"); + +# The psql command should fail on pg_stop_backup(). +ok( pump_until( + $sigchld_bb, $sigchld_bb_timeout, + \$sigchld_bb_stderr, qr/backup is not in progress/), + 'base backup cleanly cancelled'); +$sigchld_bb->finish(); + +done_testing(); -- 2.36.1 signature.asc Description: PGP signature
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/14 17:00, Michael Paquier wrote: On Fri, Jul 08, 2022 at 08:56:14AM -0400, Robert Haas wrote: On Thu, Jul 7, 2022 at 10:58 AM Fujii Masao wrote: But if many think that it's worth adding the test, I will give a try. But even in that case, I think it's better to commit the proposed patch at first to fix the bug, and then to write the patch adding the test. I have looked at that in details, Thanks! and it is possible to rely on pg_stat_activity.wait_event to be BaseBackupThrottle, which would make ISTM that you can also use pg_stat_progress_basebackup.phase. sure that the checkpoint triggered at the beginning of the backup finishes and that we are in the middle of the base backup. The command for the test should be a psql command with two -c switches without ON_ERROR_STOP, so as the second pg_backup_stop() starts after BASE_BACKUP is cancelled using the same connection, for something like that: psql -c "BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32);" \ -c "select pg_backup_stop()" "replication=database" The last part of the test should do a pump_until() and capture "backup is not in progress" from the stderr output of the command run. This is leading me to the attached, that crashes quickly without the fix and passes with the fix. Thanks for the patch! But I'm still not sure if it's worth adding only this test for the corner case while we don't have basic tests for BASE_BACKUP, pg_backup_start and pg_backup_stop. BTW, if we decide to add that test, are you planning to back-patch it? It's true that we don't really have good test coverage of write-ahead logging and recovery, but this doesn't seem like the most important thing to be testing in that area, either, and developing stable tests for stuff like this can be a lot of work. Well, stability does not seem like a problem to me here. I do kind of feel like the patch is fixing two separate bugs. The change to SendBaseBackup() is fixing the problem that, because there's SQL access on replication connections, we could try to start a backup in the middle of another backup by mixing and matching the two different methods of doing backups. The change to do_pg_abort_backup() is fixing the fact that, after aborting a base backup, we don't reset the session state properly so that another backup can be tried afterwards. I don't know if it's worth committing them separately - they are very small fixes. But it would probably at least be good to highlight in the commit message that there are two different issues. Grouping both fixes in the same commit sounds fine by me. No objections from here. This sounds fine to me, too. On the other hand, it's also fine for me to push the changes separately so that we can easily identify each change later. So I separated the patch into two ones. Since one of them failed to be applied to v14 or before cleanly, I also created the patch for those back branches. So I attached three patches. Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATIONFrom 1d110bf0ff3bfb508374930eb8947a2a0d5ffe5e Mon Sep 17 00:00:00 2001 From: Fujii Masao Date: Tue, 12 Jul 2022 09:31:57 +0900 Subject: [PATCH] Prevent BASE_BACKUP in the middle of another backup in the same session. Multiple non-exclusive backups are able to be run conrrently in different sessions. But, in the same session, only one non-exclusive backup can be run at the same moment. If pg_backup_start (pg_start_backup in v14 or before) is called in the middle of another non-exclusive backup in the same session, an error is thrown. However, previously, in logical replication walsender mode, even if that walsender session had already called pg_backup_start and started a non-exclusive backup, it could execute BASE_BACKUP command and start another non-exclusive backup. Which caused subsequent pg_backup_stop to throw an error because BASE_BACKUP unexpectedly reset the session state marked by pg_backup_start. This commit prevents BASE_BACKUP command in the middle of another non-exclusive backup in the same session. Back-patch to all supported branches. Author: Fujii Masao Reviewed-by: Kyotaro Horiguchi, Masahiko Sawada, Michael Paquier, Robert Haas Discussion: https://postgr.es/m/3374718f-9fbf-a950-6d66-d973e027f...@oss.nttdata.com --- src/backend/replication/basebackup.c | 6 ++ 1 file changed, 6 insertions(+) diff --git a/src/backend/replication/basebackup.c b/src/backend/replication/basebackup.c index 95440013c0..637c0ce459 100644 --- a/src/backend/replication/basebackup.c +++ b/src/backend/replication/basebackup.c @@ -949,6 +949,12 @@ SendBaseBackup(BaseBackupCmd *cmd) { basebackup_options opt; bbsink *sink; + SessionBackupState status = get_backup_status(); + + if (status == SESSION_BACKUP_RUNNING) + ereport(ERROR, + (errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE), +
Re: Backup command and functions can cause assertion failure and segmentation fault
On Fri, Jul 15, 2022 at 04:46:32PM +0900, Fujii Masao wrote: > On 2022/07/14 17:00, Michael Paquier wrote: >> and it is possible to rely on >> pg_stat_activity.wait_event to be BaseBackupThrottle, which would make > > ISTM that you can also use pg_stat_progress_basebackup.phase. Indeed, as of "streaming database files". That should work. > Thanks for the patch! But I'm still not sure if it's worth adding > only this test for the corner case while we don't have basic tests > for BASE_BACKUP, pg_backup_start and pg_backup_stop. > > BTW, if we decide to add that test, are you planning to back-patch it? I was thinking about doing that only on HEAD. One thing interesting about this patch is that it can also be used as a point of reference for other future things. > This sounds fine to me, too. On the other hand, it's also fine for > me to push the changes separately so that we can easily identify > each change later. So I separated the patch into two ones. > > Since one of them failed to be applied to v14 or before cleanly, I > also created the patch for those back branches. So I attached three > patches. Fine by me. -- Michael signature.asc Description: PGP signature
Re: Backup command and functions can cause assertion failure and segmentation fault
On 2022/07/16 11:36, Michael Paquier wrote: I was thinking about doing that only on HEAD. One thing interesting about this patch is that it can also be used as a point of reference for other future things. Ok, here are review comments: +my $connstr = + $node->connstr('postgres') . " replication=database dbname=postgres"; Since the result of connstr() includes "dbname=postgres", you don't need to add "dbname=postgres" again. +# The psql command should fail on pg_stop_backup(). Typo: s/pg_stop_backup/pg_stop_backup I reported two trouble cases; they are the cases where BASE_BACKUP is canceled and terminated, respectively. But you added the test only for one of them. Is this intentional? Since one of them failed to be applied to v14 or before cleanly, I also created the patch for those back branches. So I attached three patches. Fine by me. I pushed these bugfix patches at first. Thanks! Regards, -- Fujii Masao Advanced Computing Technology Center Research and Development Headquarters NTT DATA CORPORATION
Re: Backup command and functions can cause assertion failure and segmentation fault
On Wed, Jul 20, 2022 at 02:00:00PM +0900, Fujii Masao wrote: > I reported two trouble cases; they are the cases where BASE_BACKUP > is canceled and terminated, respectively. But you added the test > only for one of them. Is this intentional? Nope. The one I have implemented was the fanciest case among the two, so I just focused on it. Adding an extra test to cover the second scenario is easier. So I have added one as of the attached, addressing your other comments while on it. I have also decided to add the tests at the bottom of 001_stream_rep.pl, as these are quicker than a node initialization. -- Michael From 2aa841a3dfb643a14d28e6d595703f14e98ad919 Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Wed, 20 Jul 2022 15:48:27 +0900 Subject: [PATCH v2] Add more TAP tests with BASE_BACKUP --- src/test/recovery/t/001_stream_rep.pl | 55 +++ 1 file changed, 55 insertions(+) diff --git a/src/test/recovery/t/001_stream_rep.pl b/src/test/recovery/t/001_stream_rep.pl index 86864098f9..b15dd6b29a 100644 --- a/src/test/recovery/t/001_stream_rep.pl +++ b/src/test/recovery/t/001_stream_rep.pl @@ -531,4 +531,59 @@ my $primary_data = $node_primary->data_dir; ok(!-f "$primary_data/pg_wal/$segment_removed", "WAL segment $segment_removed recycled after physical slot advancing"); +note "testing pg_backup_start() followed by BASE_BACKUP"; +my $connstr = $node_primary->connstr('postgres') . " replication=database"; + +# This test requires a replication connection with a database, as it mixes +# a replication command and a SQL command. +$node_primary->command_fails_like( + [ + 'psql', '-c', "SELECT pg_backup_start('backup', true)", + '-c', 'BASE_BACKUP', '-d', $connstr + ], + qr/a backup is already in progress in this session/, + 'BASE_BACKUP cannot run in session already running backup'); + +note "testing BASE_BACKUP cancellation"; + +my $sigchld_bb_timeout = + IPC::Run::timer($PostgreSQL::Test::Utils::timeout_default); + +# This test requires a replication connection with a database, as it mixes +# a replication command and a SQL command. The first BASE_BACKUP is throttled +# to give enough room for the cancellation running below. The second command +# for pg_backup_stop() should fail. +my ($sigchld_bb_stdin, $sigchld_bb_stdout, $sigchld_bb_stderr) = ('', '', ''); +my $sigchld_bb = IPC::Run::start( + [ + 'psql', '-X', '-c', "BASE_BACKUP (CHECKPOINT 'fast', MAX_RATE 32);", + '-c', 'SELECT pg_backup_stop()', + '-d', $connstr + ], + '<', + \$sigchld_bb_stdin, + '>', + \$sigchld_bb_stdout, + '2>', + \$sigchld_bb_stderr, + $sigchld_bb_timeout); + +# The cancellation is issued once the database files are streamed and +# the checkpoint issued at backup start completes. +is( $node_primary->poll_query_until( + 'postgres', + "SELECT pg_cancel_backend(a.pid) FROM " + . "pg_stat_activity a, pg_stat_progress_basebackup b WHERE " + . "a.pid = b.pid AND a.query ~ 'BASE_BACKUP' AND " + . "b.phase = 'streaming database files';"), + "1", + "WAL sender sending base backup killed"); + +# The psql command should fail on pg_backup_stop(). +ok( pump_until( + $sigchld_bb, $sigchld_bb_timeout, + \$sigchld_bb_stderr, qr/backup is not in progress/), + 'base backup cleanly cancelled'); +$sigchld_bb->finish(); + done_testing(); -- 2.36.1 signature.asc Description: PGP signature
Re: Backup command and functions can cause assertion failure and segmentation fault
On Wed, Jul 20, 2022 at 03:49:17PM +0900, Michael Paquier wrote: > Adding an extra test to cover the second scenario is easier. So I > have added one as of the attached, addressing your other comments > while on it. I have also decided to add the tests at the bottom of > 001_stream_rep.pl, as these are quicker than a node initialization. Hearing nothing, I have looked at that again and applied the two tests on HEAD as of ad34146. -- Michael signature.asc Description: PGP signature