From 15aa5609c659a5f01db83523f00c3008e51d0ee7 Mon Sep 17 00:00:00 2001 From: Nik Samokhvalov Date: Wed, 15 Jul 2026 10:22:10 -0700 Subject: [PATCH] fix(log_object_drops): correct commit LSN, DROP DATABASE path, TEMP, and PITR docs Rebase of v5 ("Add log_object_drops GUC for DROP TABLE/DATABASE logging", Dmitry Lebedev, rebased by Andrey Borodin) onto current master, plus fixes for the four defects Kirk Wolak raised, and a fifth found while testing. Rebase (v5 does not build on master as posted): * guc_parameters.dat now enforces alphabetical ordering; log_object_drops was appended after zero_damaged_pages, which fails the build outright. * t/050_drop_table_logging.pl collided with the existing 050_redo_segment_missing.pl; renumbered to 055. 1. Format-string bug (real UB, not cosmetic). The errmsg format had four %X conversions ("drop LSN: %X/%X, commit LSN: %X/%X") but passed a single LSN_FORMAT_ARGS(), which expands to two arguments. clang reports -Wformat-insufficient-args; the trailing two %X read past the varargs and print stack garbage. There is no "drop LSN" recorded anywhere, and it would not be useful for PITR if there were, so the message now reports only the commit LSN. Also switched %X/%X to master's %X/%08X convention, which makes the logged value directly comparable to pg_lsn output. 2. DROP DATABASE used GetXLogInsertRecPtr() (Kirill Reshke's report). That is read before the commit record is written, and dropdb() still forces an immediate checkpoint afterwards, so the value could be far behind the actual commit LSN and was not a valid recovery target. DROP DATABASE now goes through the same deferred XactCallback path as tables. As a side effect, a DROP DATABASE that errors out after the catalog delete is no longer logged. 3. Temporary tables are no longer logged. Their contents are not recoverable by PITR, and they are dropped at every session exit, so the entries were noise. 4. Documented the PITR recipe, including the recovery_target_inclusive trap: the default of on stops recovery *after* the target, so setting only recovery_target_lsn replays the drop and loses the object again. 5. (Found while writing the PITR test.) The logged LSN was the *end* of the commit record, since XactLogCommitRecord() returns XLogInsert()'s EndRecPtr. recovery_target_lsn is compared against each record's *start* (recoveryStopsBefore() tests record->ReadRecPtr), so the end LSN is the start of the following record: recovery with recovery_target_inclusive=off would still replay the drop. RecordTransactionCommit() now reports ProcLastRecPtr, the start of the commit record, which is what a DBA can feed back to recovery_target_lsn. Without this the documented recipe in (4) does not work, and the TAP test in this commit fails. Testing (src/test/recovery/t/055_drop_table_logging.pl, 54 assertions): * the logged LSN is the actual commit LSN, verified against pg_current_wal_insert_lsn() and by writing ~7MB of WAL between the DROP and the COMMIT so that the drop LSN and commit LSN cannot be confused; * nothing is logged when the GUC is off, on ROLLBACK, on ROLLBACK TO SAVEPOINT, for TEMP tables (explicit, ON COMMIT DROP, and session-exit), or when DROP DATABASE fails; * an end-to-end PITR test restores a backup to the logged LSN and asserts the dropped table and its rows come back with recovery_target_inclusive=off, and that the default of on loses them. Co-Authored-By: Claude Opus 4.8 (1M context) --- contrib/postgres_fdw/connection.c | 4 +- contrib/sepgsql/label.c | 2 +- doc/src/sgml/config.sgml | 69 ++ src/backend/access/transam/xact.c | 54 +- src/backend/catalog/dependency.c | 214 ++++++ src/backend/commands/dbcommands.c | 11 + src/backend/utils/misc/guc_parameters.dat | 7 + src/backend/utils/misc/guc_tables.c | 1 + src/include/access/xact.h | 2 +- src/include/catalog/dependency.h | 2 + src/include/utils/guc.h | 1 + src/pl/plpgsql/src/pl_exec.c | 2 +- src/pl/plpgsql/src/plpgsql.h | 2 +- src/test/recovery/meson.build | 1 + src/test/recovery/t/055_drop_table_logging.pl | 659 ++++++++++++++++++ 15 files changed, 1007 insertions(+), 24 deletions(-) create mode 100644 src/test/recovery/t/055_drop_table_logging.pl diff --git a/contrib/postgres_fdw/connection.c b/contrib/postgres_fdw/connection.c index aab216959793f..cec919f3a4b8b 100644 --- a/contrib/postgres_fdw/connection.c +++ b/contrib/postgres_fdw/connection.c @@ -154,7 +154,7 @@ static void do_sql_command_end(PGconn *conn, const char *sql, static void begin_remote_xact(ConnCacheEntry *entry); static void pgfdw_report_internal(int elevel, PGresult *res, PGconn *conn, const char *sql); -static void pgfdw_xact_callback(XactEvent event, void *arg); +static void pgfdw_xact_callback(XactEvent event, void *arg, XLogRecPtr lsn); static void pgfdw_subxact_callback(SubXactEvent event, SubTransactionId mySubid, SubTransactionId parentSubid, @@ -1170,7 +1170,7 @@ pgfdw_report_internal(int elevel, PGresult *res, PGconn *conn, * COMMIT TRANSACTION may run deferred triggers.) */ static void -pgfdw_xact_callback(XactEvent event, void *arg) +pgfdw_xact_callback(XactEvent event, void *arg, XLogRecPtr lsn) { HASH_SEQ_STATUS scan; ConnCacheEntry *entry; diff --git a/contrib/sepgsql/label.c b/contrib/sepgsql/label.c index 01c2074a0edfa..02aa213ee1593 100644 --- a/contrib/sepgsql/label.c +++ b/contrib/sepgsql/label.c @@ -161,7 +161,7 @@ sepgsql_set_client_label(const char *new_label) * changes in the client_label_pending list. */ static void -sepgsql_xact_callback(XactEvent event, void *arg) +sepgsql_xact_callback(XactEvent event, void *arg, XLogRecPtr lsn) { if (event == XACT_EVENT_COMMIT) { diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 0848c18d329e3..6be3dd3cfcafe 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -8055,6 +8055,75 @@ local0.* /var/log/postgresql + + log_object_drops (boolean) + + log_object_drops configuration parameter + + + + + Causes DROP TABLE and DROP DATABASE + operations to be logged with their commit LSN (Log Sequence Number). + The commit LSN represents the point in the write-ahead log where the + drop operation becomes durable and visible to other transactions. + + + + Each logged entry includes the schema name, table name, OID, and the + commit LSN. For example: + + LOG: DROP TABLE: relation "public.employees" (OID 16384), commit LSN: 0/015D4A48 + LOG: DROP DATABASE: database "testdb" (OID 16385), commit LSN: 0/015D4B20 + + + + + Logged operations include: direct DROP TABLE statements, + tables dropped via DROP SCHEMA CASCADE, + partitioned tables and their partitions, tables in inheritance hierarchies, + and DROP DATABASE commands. + Operations that are rolled back (via ROLLBACK or + ROLLBACK TO SAVEPOINT) are not logged. + Temporary tables are not logged, since their contents cannot be + recovered by point-in-time recovery. + + + + This parameter is useful for tracking and auditing destructive operations, + and for coordinating with external systems that monitor the write-ahead log. + Note that enabling this option may generate substantial log volume + when dropping schemas or databases containing many tables. + + + + The default is off. Only superusers and users with + the appropriate SET privilege can change this setting. + + + + Using the logged LSN for point-in-time recovery. + The logged value is the LSN at which the commit + record of the transaction that performed the drop begins, which is the + value compares against. To + recover the dropped object, recovery must stop + before that record is replayed. + Because defaults to + on, which stops recovery after + the target LSN, setting recovery_target_lsn to the + logged LSN alone would replay the drop and lose the object again. + You must also set recovery_target_inclusive to + off: + +recovery_target_lsn = '0/015D4A48' # the commit LSN from the log message +recovery_target_inclusive = off # required: stop BEFORE the drop commits + + With these settings, recovery stops just short of the drop, and the + object is present in the recovered cluster. Note that any transaction + that committed after this LSN is also not recovered. + + + log_duration (boolean) diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c index 3a89149016fe6..6562a188f8078 100644 --- a/src/backend/access/transam/xact.c +++ b/src/backend/access/transam/xact.c @@ -340,7 +340,7 @@ static void AtCommit_Memory(void); static void AtStart_Cache(void); static void AtStart_Memory(void); static void AtStart_ResourceOwner(void); -static void CallXactCallbacks(XactEvent event); +static void CallXactCallbacks(XactEvent event, XLogRecPtr lsn); static void CallSubXactCallbacks(SubXactEvent event, SubTransactionId mySubid, SubTransactionId parentSubid); @@ -1342,9 +1342,10 @@ AtSubStart_ResourceOwner(void) * If you change this function, see RecordTransactionCommitPrepared also. */ static TransactionId -RecordTransactionCommit(void) +RecordTransactionCommit(XLogRecPtr *commit_lsn_out) { TransactionId xid = GetTopTransactionIdIfAny(); + XLogRecPtr commit_lsn = InvalidXLogRecPtr; bool markXidCommitted = TransactionIdIsValid(xid); TransactionId latestXid = InvalidTransactionId; int nrels; @@ -1481,13 +1482,24 @@ RecordTransactionCommit(void) /* * Insert the commit XLOG record. */ - XactLogCommitRecord(GetCurrentTransactionStopTimestamp(), - nchildren, children, nrels, rels, - ndroppedstats, droppedstats, - nmsgs, invalMessages, - RelcacheInitFileInval, - MyXactFlags, - InvalidTransactionId, NULL /* plain commit */ ); + (void) XactLogCommitRecord(GetCurrentTransactionStopTimestamp(), + nchildren, children, nrels, rels, + ndroppedstats, droppedstats, + nmsgs, invalMessages, + RelcacheInitFileInval, + MyXactFlags, + InvalidTransactionId, NULL /* plain commit */ ); + + /* + * Report the *start* of the commit record to XactCallbacks, not its + * end. Recovery compares recovery_target_lsn against the start LSN of + * each record (see recoveryStopsBefore()), so the start LSN is the + * value a DBA can feed back to recovery_target_lsn, together with + * recovery_target_inclusive = off, to stop just before this + * transaction commits. The end LSN would be the start of the *next* + * record and would therefore replay this commit. + */ + commit_lsn = ProcLastRecPtr; if (replorigin) /* Move LSNs forward for this replication origin */ @@ -1610,6 +1622,9 @@ RecordTransactionCommit(void) if (ndroppedstats) pfree(droppedstats); + if (commit_lsn_out) + *commit_lsn_out = commit_lsn; + return latestXid; } @@ -2272,6 +2287,7 @@ CommitTransaction(void) TransactionState s = CurrentTransactionState; TransactionId latestXid; bool is_parallel_worker; + XLogRecPtr commit_lsn = InvalidXLogRecPtr; is_parallel_worker = (s->blockState == TBLOCK_PARALLEL_INPROGRESS); @@ -2320,7 +2336,8 @@ CommitTransaction(void) */ CallXactCallbacks(is_parallel_worker ? XACT_EVENT_PARALLEL_PRE_COMMIT - : XACT_EVENT_PRE_COMMIT); + : XACT_EVENT_PRE_COMMIT, + InvalidXLogRecPtr); /* * If this xact has started any unfinished parallel operation, clean up @@ -2404,7 +2421,7 @@ CommitTransaction(void) * We need to mark our XIDs as committed in pg_xact. This is where we * durably commit. */ - latestXid = RecordTransactionCommit(); + latestXid = RecordTransactionCommit(&commit_lsn); } else { @@ -2447,7 +2464,8 @@ CommitTransaction(void) */ CallXactCallbacks(is_parallel_worker ? XACT_EVENT_PARALLEL_COMMIT - : XACT_EVENT_COMMIT); + : XACT_EVENT_COMMIT, + commit_lsn); CurrentResourceOwner = NULL; ResourceOwnerRelease(TopTransactionResourceOwner, @@ -2597,7 +2615,7 @@ PrepareTransaction(void) break; } - CallXactCallbacks(XACT_EVENT_PRE_PREPARE); + CallXactCallbacks(XACT_EVENT_PRE_PREPARE, InvalidXLogRecPtr); /* * The remaining actions cannot call any user-defined code, so it's safe @@ -2757,7 +2775,7 @@ PrepareTransaction(void) * that cure could be worse than the disease. */ - CallXactCallbacks(XACT_EVENT_PREPARE); + CallXactCallbacks(XACT_EVENT_PREPARE, InvalidXLogRecPtr); ResourceOwnerRelease(TopTransactionResourceOwner, RESOURCE_RELEASE_BEFORE_LOCKS, @@ -3011,9 +3029,9 @@ AbortTransaction(void) if (TopTransactionResourceOwner != NULL) { if (is_parallel_worker) - CallXactCallbacks(XACT_EVENT_PARALLEL_ABORT); + CallXactCallbacks(XACT_EVENT_PARALLEL_ABORT, InvalidXLogRecPtr); else - CallXactCallbacks(XACT_EVENT_ABORT); + CallXactCallbacks(XACT_EVENT_ABORT, InvalidXLogRecPtr); ResourceOwnerRelease(TopTransactionResourceOwner, RESOURCE_RELEASE_BEFORE_LOCKS, @@ -3889,7 +3907,7 @@ UnregisterXactCallback(XactCallback callback, void *arg) } static void -CallXactCallbacks(XactEvent event) +CallXactCallbacks(XactEvent event, XLogRecPtr lsn) { XactCallbackItem *item; XactCallbackItem *next; @@ -3898,7 +3916,7 @@ CallXactCallbacks(XactEvent event) { /* allow callbacks to unregister themselves when called */ next = item->next; - item->callback(event, item->arg); + item->callback(event, item->arg, lsn); } } diff --git a/src/backend/catalog/dependency.c b/src/backend/catalog/dependency.c index c54774b327590..2ce9ee9f2a25a 100644 --- a/src/backend/catalog/dependency.c +++ b/src/backend/catalog/dependency.c @@ -18,6 +18,7 @@ #include "access/htup_details.h" #include "access/table.h" #include "access/xact.h" +#include "access/xlog.h" #include "catalog/catalog.h" #include "catalog/dependency.h" #include "catalog/heap.h" @@ -71,6 +72,7 @@ #include "catalog/pg_ts_template.h" #include "catalog/pg_type.h" #include "catalog/pg_user_mapping.h" +#include "utils/guc.h" #include "commands/comment.h" #include "commands/defrem.h" #include "commands/event_trigger.h" @@ -182,6 +184,185 @@ static bool stack_address_present_add_flags(const ObjectAddress *object, ObjectAddressStack *stack); static void DeleteInitPrivs(const ObjectAddress *object); +/* Kind of object recorded for drop logging */ +typedef enum DropLogKind +{ + DROP_LOG_TABLE, + DROP_LOG_DATABASE, +} DropLogKind; + +/* Structure to hold information about a dropped object */ +typedef struct DropObjectInfo +{ + DropLogKind kind; + Oid objoid; + char objname[NAMEDATALEN]; + char schemaname[NAMEDATALEN]; /* only used for DROP_LOG_TABLE */ + SubTransactionId subxid; + bool valid; +} DropObjectInfo; + +/* Per-transaction list of dropped objects */ +static List *pending_object_drops = NIL; +static bool drop_object_callback_registered = false; + +static void DropObjectXactCallback(XactEvent event, void *arg, XLogRecPtr lsn); +static void DropObjectSubXactCallback(SubXactEvent event, SubTransactionId mySubid, + SubTransactionId parentSubid, void *arg); + +/* + * Record a dropped object so that its commit LSN can be logged once the + * transaction commits. Logging is deferred to the commit callback because + * only the commit LSN is meaningful for point-in-time recovery: the LSN of + * the catalog change itself is useless to a DBA, as the drop does not become + * durable (and other backends cannot observe it) until the commit record is + * written. Deferring also means a drop that is later rolled back is never + * logged at all. + */ +static void +RegisterDropObject(DropLogKind kind, Oid objoid, const char *objname, + const char *schemaname) +{ + DropObjectInfo *info; + MemoryContext oldcontext; + + if (!drop_object_callback_registered) + { + RegisterXactCallback(DropObjectXactCallback, NULL); + RegisterSubXactCallback(DropObjectSubXactCallback, NULL); + drop_object_callback_registered = true; + } + + oldcontext = MemoryContextSwitchTo(TopTransactionContext); + + info = (DropObjectInfo *) palloc(sizeof(DropObjectInfo)); + info->kind = kind; + info->objoid = objoid; + strlcpy(info->objname, objname, NAMEDATALEN); + strlcpy(info->schemaname, schemaname ? schemaname : "", NAMEDATALEN); + info->subxid = GetCurrentSubTransactionId(); + info->valid = true; + + pending_object_drops = lappend(pending_object_drops, info); + + MemoryContextSwitchTo(oldcontext); +} + +/* + * RegisterDropDatabaseForLogging + * Record a DROP DATABASE for commit-LSN logging. + * + * Exposed for dbcommands.c, which does not go through performDeletion(). + */ +void +RegisterDropDatabaseForLogging(Oid dboid, const char *dbname) +{ + RegisterDropObject(DROP_LOG_DATABASE, dboid, dbname, NULL); +} + +/* + * SubXactCallback - handle ROLLBACK TO SAVEPOINT + */ +static void +DropObjectSubXactCallback(SubXactEvent event, SubTransactionId mySubid, + SubTransactionId parentSubid, void *arg) +{ + ListCell *lc; + + if (pending_object_drops == NIL) + return; + + /* + * On subtransaction abort, invalidate all entries belonging to the + * aborted subtransaction and its children. + */ + if (event == SUBXACT_EVENT_ABORT_SUB) + { + foreach(lc, pending_object_drops) + { + DropObjectInfo *info = (DropObjectInfo *) lfirst(lc); + + /* + * Mark entries that belong to our subtransactions. + * SubTransactionIds are assigned incrementally, so we can compare + * them. + */ + if (info->subxid >= mySubid) + info->valid = false; + } + } +} + +/* + * DropObjectXactCallback + * Transaction callback to log the commit LSN for dropped objects. + */ +static void +DropObjectXactCallback(XactEvent event, void *arg, XLogRecPtr commit_lsn) +{ + ListCell *lc; + + if (pending_object_drops == NIL) + return; + + if (event == XACT_EVENT_COMMIT) + { + /* + * Any transaction that dropped a table or a database necessarily + * modified the catalogs, so it must have been assigned an XID and + * written a commit record. + * + * commit_lsn is the start LSN of that commit record, which is + * precisely the value to hand to recovery_target_lsn (with + * recovery_target_inclusive = off) to recover the dropped object. + */ + Assert(!XLogRecPtrIsInvalid(commit_lsn)); + + foreach(lc, pending_object_drops) + { + DropObjectInfo *info = (DropObjectInfo *) lfirst(lc); + + if (!info->valid) + continue; + + switch (info->kind) + { + case DROP_LOG_TABLE: + ereport(LOG, + (errmsg("DROP TABLE: relation \"%s.%s\" (OID %u), commit LSN: %X/%08X", + info->schemaname, + info->objname, + info->objoid, + LSN_FORMAT_ARGS(commit_lsn)))); + break; + case DROP_LOG_DATABASE: + ereport(LOG, + (errmsg("DROP DATABASE: database \"%s\" (OID %u), commit LSN: %X/%08X", + info->objname, + info->objoid, + LSN_FORMAT_ARGS(commit_lsn)))); + break; + } + } + } + + /* Clean up after commit or abort */ + if (event == XACT_EVENT_COMMIT || + event == XACT_EVENT_ABORT || + event == XACT_EVENT_PARALLEL_ABORT) + { + /* Free the DropObjectInfo structures */ + foreach(lc, pending_object_drops) + { + DropObjectInfo *info = (DropObjectInfo *) lfirst(lc); + + pfree(info); + } + + list_free(pending_object_drops); + pending_object_drops = NIL; + } +} /* * Go through the objects given running the final actions on them, and execute @@ -1423,6 +1604,39 @@ doDeletion(const ObjectAddress *object, int flags) { char relKind = get_rel_relkind(object->objectId); + /* + * Log all table drops that go through this function. + * + * Temporary tables are deliberately excluded: their contents + * are not recoverable by point-in-time recovery in the first + * place, and they are routinely dropped at session end, which + * would swamp the log with entries no DBA can act on. + */ + if ((relKind == RELKIND_RELATION || + relKind == RELKIND_PARTITIONED_TABLE) && + log_object_drops && + get_rel_persistence(object->objectId) != RELPERSISTENCE_TEMP) + { + char *relname = get_rel_name(object->objectId); + + if (relname != NULL) + { + char *schemaname = NULL; + Oid schemaoid = get_rel_namespace(object->objectId); + + if (OidIsValid(schemaoid)) + schemaname = get_namespace_name(schemaoid); + + RegisterDropObject(DROP_LOG_TABLE, object->objectId, + relname, + schemaname ? schemaname : "unknown"); + + pfree(relname); + if (schemaname) + pfree(schemaname); + } + } + if (relKind == RELKIND_INDEX || relKind == RELKIND_PARTITIONED_INDEX) { diff --git a/src/backend/commands/dbcommands.c b/src/backend/commands/dbcommands.c index 51dcbd9cace4f..578e261cfad73 100644 --- a/src/backend/commands/dbcommands.c +++ b/src/backend/commands/dbcommands.c @@ -1862,6 +1862,17 @@ dropdb(const char *dbname, bool missing_ok, bool force) CatalogTupleDelete(pgdbrel, &tup->t_self); heap_freetuple(tup); + /* + * Record the drop so that the commit LSN can be logged once this + * transaction commits. We must not log GetXLogInsertRecPtr() here: at + * this point the commit record has not been written yet, and dropdb() + * still has substantial work to do (including forcing a checkpoint), so + * the current insert pointer can be far behind the commit LSN. Only the + * commit LSN is a valid point-in-time recovery target. + */ + if (log_object_drops) + RegisterDropDatabaseForLogging(db_id, dbname); + /* * Drop db-specific replication slots. */ diff --git a/src/backend/utils/misc/guc_parameters.dat b/src/backend/utils/misc/guc_parameters.dat index d421cdbde76da..6c842387c2077 100644 --- a/src/backend/utils/misc/guc_parameters.dat +++ b/src/backend/utils/misc/guc_parameters.dat @@ -1792,6 +1792,13 @@ assign_hook => 'assign_log_min_messages', }, +{ name => 'log_object_drops', type => 'bool', context => 'PGC_SUSET', group => 'LOGGING_WHAT', + short_desc => 'Logs LSN for DROP TABLE and DROP DATABASE operations.', + long_desc => 'When enabled, the system will log the LSN (Log Sequence Number) whenever a DROP TABLE or DROP DATABASE command is executed.', + variable => 'log_object_drops', + boot_val => 'false', +}, + { name => 'log_parameter_max_length', type => 'int', context => 'PGC_SUSET', group => 'LOGGING_WHAT', short_desc => 'Sets the maximum length in bytes of data logged for bind parameter values when logging statements.', long_desc => '-1 means log values in full.', diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 90aa374b3ec70..2b1ddf78cdded 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -545,6 +545,7 @@ bool Debug_write_read_parse_plan_trees; bool Debug_raw_expression_coverage_test; #endif +bool log_object_drops = false; bool log_parser_stats = false; bool log_planner_stats = false; bool log_executor_stats = false; diff --git a/src/include/access/xact.h b/src/include/access/xact.h index a8cbdf247c866..b1195a0311b81 100644 --- a/src/include/access/xact.h +++ b/src/include/access/xact.h @@ -136,7 +136,7 @@ typedef enum XACT_EVENT_PRE_PREPARE, } XactEvent; -typedef void (*XactCallback) (XactEvent event, void *arg); +typedef void (*XactCallback) (XactEvent event, void *arg, XLogRecPtr lsn); typedef enum { diff --git a/src/include/catalog/dependency.h b/src/include/catalog/dependency.h index 2f3c1eae3c71d..fbc6c9f7cb850 100644 --- a/src/include/catalog/dependency.h +++ b/src/include/catalog/dependency.h @@ -238,4 +238,6 @@ extern void shdepDropOwned(List *roleids, DropBehavior behavior); extern void shdepReassignOwned(List *roleids, Oid newrole); +extern void RegisterDropDatabaseForLogging(Oid dboid, const char *dbname); + #endif /* DEPENDENCY_H */ diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index 8057d7870adb4..e2275121964a6 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -304,6 +304,7 @@ extern PGDLLIMPORT int log_statement_max_length; extern PGDLLIMPORT double log_statement_sample_rate; extern PGDLLIMPORT double log_xact_sample_rate; extern PGDLLIMPORT char *backtrace_functions; +extern PGDLLIMPORT bool log_object_drops; extern PGDLLIMPORT int temp_file_limit; diff --git a/src/pl/plpgsql/src/pl_exec.c b/src/pl/plpgsql/src/pl_exec.c index 65b0fd0790f2e..4e127ccfb4ca2 100644 --- a/src/pl/plpgsql/src/pl_exec.c +++ b/src/pl/plpgsql/src/pl_exec.c @@ -8808,7 +8808,7 @@ plpgsql_destroy_econtext(PLpgSQL_execstate *estate) * it has to be cleaned up. The same for the simple-expression resowner. */ void -plpgsql_xact_cb(XactEvent event, void *arg) +plpgsql_xact_cb(XactEvent event, void *arg, XLogRecPtr lsn) { /* * If we are doing a clean transaction shutdown, free the EState and tell diff --git a/src/pl/plpgsql/src/plpgsql.h b/src/pl/plpgsql/src/plpgsql.h index addb14a9959c7..b89cff18c2ffa 100644 --- a/src/pl/plpgsql/src/plpgsql.h +++ b/src/pl/plpgsql/src/plpgsql.h @@ -1266,7 +1266,7 @@ extern HeapTuple plpgsql_exec_trigger(PLpgSQL_function *func, TriggerData *trigdata); extern void plpgsql_exec_event_trigger(PLpgSQL_function *func, EventTriggerData *trigdata); -extern void plpgsql_xact_cb(XactEvent event, void *arg); +extern void plpgsql_xact_cb(XactEvent event, void *arg, XLogRecPtr lsn); extern void plpgsql_subxact_cb(SubXactEvent event, SubTransactionId mySubid, SubTransactionId parentSubid, void *arg); extern PGDLLEXPORT Oid plpgsql_exec_get_datum_type(PLpgSQL_execstate *estate, diff --git a/src/test/recovery/meson.build b/src/test/recovery/meson.build index ad0d85f41897e..bd0f2c04e7d7c 100644 --- a/src/test/recovery/meson.build +++ b/src/test/recovery/meson.build @@ -63,6 +63,7 @@ tests += { 't/052_checkpoint_segment_missing.pl', 't/053_standby_login_event_trigger.pl', 't/054_unlogged_sequence_promotion.pl', + 't/055_drop_table_logging.pl', ], }, } diff --git a/src/test/recovery/t/055_drop_table_logging.pl b/src/test/recovery/t/055_drop_table_logging.pl new file mode 100644 index 0000000000000..2a06a0d127450 --- /dev/null +++ b/src/test/recovery/t/055_drop_table_logging.pl @@ -0,0 +1,659 @@ +# Copyright (c) 2025-2026, PostgreSQL Global Development Group + +# Test log_object_drops. +# +# Beyond checking that a log entry appears at all, this verifies that the +# logged LSN is the *actual commit LSN* of the dropping transaction, that +# nothing is logged when the feature is off / the drop is rolled back / the +# object is temporary, and that the LSN is usable as a point-in-time recovery +# target in the way the documentation prescribes. + +use strict; +use warnings FATAL => 'all'; +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +my $node = PostgreSQL::Test::Cluster->new('primary'); +$node->init(has_archiving => 1, allows_streaming => 1); +$node->append_conf( + 'postgresql.conf', qq{ +log_min_messages = log +logging_collector = off +log_destination = 'stderr' +log_object_drops = on + +# Keep the WAL stream quiet so that the "logged LSN == current insert LSN" +# assertions below are not perturbed by unrelated background WAL. +autovacuum = off +checkpoint_timeout = 1h +max_wal_size = 1GB +}); +$node->start; + +# ============================================================================== +# Log-reading helpers +# ============================================================================== + +my $log_offset = 0; +my $current_test_log_cache = undef; + +# Reset to start a new test - clears cache and updates offset +sub start_new_test +{ + my ($test_name) = @_; + note($test_name) if defined $test_name; + + $current_test_log_cache = undef; + $log_offset = -s $node->logfile; +} + +# Get log content produced since the current test started (cached). +sub get_test_log_content +{ + return $current_test_log_cache if defined $current_test_log_cache; + + my $logfile = $node->logfile; + my $current_size = -s $logfile; + + $log_offset = 0 if $log_offset > $current_size; + $current_test_log_cache = slurp_file($logfile, $log_offset); + + return $current_test_log_cache; +} + +sub count_drop_logs +{ + my ($pattern) = @_; + my $log = get_test_log_content(); + my @matches = $log =~ /$pattern/g; + return scalar @matches; +} + +sub get_log_lines +{ + my ($pattern) = @_; + my @lines = split /\n/, get_test_log_content(); + return grep { /$pattern/ } @lines; +} + +sub drop_table_pattern +{ + my ($schema, $table) = @_; + return qr/DROP TABLE: relation "$schema\.$table"/; +} + +sub drop_database_pattern +{ + my ($dbname) = @_; + return qr/DROP DATABASE: database "$dbname"/; +} + +# ============================================================================== +# LSN helpers +# ============================================================================== + +# Extract the commit LSN from a log line, as a "hi/lo" string. +sub extract_commit_lsn +{ + my ($line) = @_; + return $1 if $line =~ m{commit LSN: ([0-9A-F]+/[0-9A-F]+)}; + return undef; +} + +# Compare two LSN strings numerically. Returns -1, 0 or 1. +# Done by hand rather than by string equality so that the test does not depend +# on the zero-padding of either the log message or pg_lsn's output. +sub lsn_cmp +{ + my ($a, $b) = @_; + my ($ahi, $alo) = map { hex($_) } split m{/}, $a; + my ($bhi, $blo) = map { hex($_) } split m{/}, $b; + return $ahi <=> $bhi || $alo <=> $blo; +} + +sub current_insert_lsn +{ + my $lsn = $node->safe_psql('postgres', 'SELECT pg_current_wal_insert_lsn()'); + chomp $lsn; + return $lsn; +} + +# ============================================================================== +# Test helpers +# ============================================================================== + +sub test_drop_count +{ + my ($test_name, $sql, $pattern, $expected_count) = @_; + + start_new_test($test_name); + $node->safe_psql('postgres', $sql); + is(count_drop_logs($pattern), $expected_count, "$test_name: count check"); + return; +} + +sub test_drop_not_logged +{ + my ($test_name, $sql, $pattern) = @_; + + start_new_test($test_name); + $node->safe_psql('postgres', $sql); + is(count_drop_logs($pattern), 0, "$test_name: not logged"); + return; +} + +sub test_multiple_drops +{ + my ($test_name, $sql, @table_specs) = @_; + + start_new_test($test_name); + $node->safe_psql('postgres', $sql); + + foreach my $spec (@table_specs) + { + my ($schema, $table, $expected) = @$spec; + is(count_drop_logs(drop_table_pattern($schema, $table)), + $expected, "$test_name: $schema.$table"); + } + return; +} + +# ============================================================================== +# Test 1: the logged LSN is the ACTUAL commit LSN +# +# This is the core assertion. The transaction writes a large amount of WAL +# *between* the DROP and the COMMIT, so the LSN of the catalog change is far +# behind the commit LSN. A patch that logs GetXLogInsertRecPtr() at drop time +# (as the DROP DATABASE path used to) fails the "strictly greater" check; a +# patch that logs anything else fails the exact-match check. +# ============================================================================== + +start_new_test('Test 1: logged LSN is the actual commit LSN'); +$node->safe_psql('postgres', + 'CREATE TABLE filler (id int, pad text); CREATE TABLE test_commit_lsn (id int)'); + +my $out = $node->safe_psql( + 'postgres', q{ + BEGIN; + DROP TABLE test_commit_lsn; + SELECT pg_current_wal_insert_lsn(); + INSERT INTO filler SELECT i, repeat('x', 100) FROM generate_series(1, 50000) i; + SELECT pg_current_wal_insert_lsn(); + COMMIT; + SELECT pg_current_wal_insert_lsn(); +}); +my ($lsn_after_drop, $lsn_before_commit, $lsn_after_commit) = split /\n/, $out; + +my @lines = get_log_lines(drop_table_pattern('public', 'test_commit_lsn')); +is(scalar @lines, 1, 'Test 1: exactly one entry logged'); +my $logged = extract_commit_lsn($lines[0]); +ok(defined $logged, 'Test 1: commit LSN present in log message'); + +note("logged=$logged after_drop=$lsn_after_drop " + . "before_commit=$lsn_before_commit after_commit=$lsn_after_commit"); + +# The whole point of the feature: not the drop LSN. +ok(lsn_cmp($logged, $lsn_after_drop) > 0, + 'Test 1: logged LSN is past the drop LSN (not GetXLogInsertRecPtr at drop time)'); + +# The logged value must be the START of the commit record, because that is what +# recovery_target_lsn is compared against (recoveryStopsBefore() tests +# record->ReadRecPtr). lsn_before_commit is the insert pointer immediately +# before COMMIT, i.e. where the commit record begins; lsn_after_commit is where +# it ends. So: before_commit <= logged < after_commit. +# +# The lower bound is not asserted as exact equality because the commit record's +# start can be nudged forward past a WAL page header. +ok(lsn_cmp($logged, $lsn_before_commit) >= 0, + 'Test 1: logged LSN is at or after the start of the commit record'); +ok(lsn_cmp($logged, $lsn_after_commit) < 0, + 'Test 1: logged LSN is the START of the commit record, not its end'); + +# ============================================================================== +# Test 2: nothing is logged when the GUC is off +# ============================================================================== + +start_new_test('Test 2: nothing logged when log_object_drops = off'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE test_guc_off (id int); + SET log_object_drops = off; + DROP TABLE test_guc_off; +}); +is(count_drop_logs(drop_table_pattern('public', 'test_guc_off')), + 0, 'Test 2: GUC off - table drop not logged'); + +start_new_test('Test 2b: nothing logged for DROP DATABASE when GUC is off'); +$node->safe_psql( + 'postgres', q{ + SET log_object_drops = off; + CREATE DATABASE test_guc_off_db; + DROP DATABASE test_guc_off_db; +}); +is(count_drop_logs(drop_database_pattern('test_guc_off_db')), + 0, 'Test 2b: GUC off - database drop not logged'); + +# Confirm the GUC-off result above is meaningful: the same drop IS logged when on. +start_new_test('Test 2c: control - same drop logged when GUC is on'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE test_guc_on (id int); + DROP TABLE test_guc_on; +}); +is(count_drop_logs(drop_table_pattern('public', 'test_guc_on')), + 1, 'Test 2c: GUC on - table drop logged'); + +# ============================================================================== +# Test 3: nothing is logged on ROLLBACK +# ============================================================================== + +test_drop_not_logged( + 'Test 3: DROP TABLE with ROLLBACK', + q{ + CREATE TABLE test_rollback (id int); + BEGIN; + DROP TABLE test_rollback; + ROLLBACK; + }, + drop_table_pattern('public', 'test_rollback')); + +# The table must still be there, and dropping it for real must log. +test_drop_count( + 'Test 3b: committed DROP after rollback is logged', + q{ + SELECT * FROM test_rollback; + DROP TABLE test_rollback; + }, + drop_table_pattern('public', 'test_rollback'), + 1); + +# ============================================================================== +# Test 4: temporary tables are never logged +# ============================================================================== + +test_drop_not_logged( + 'Test 4: explicit DROP of a TEMP table', + q{ + CREATE TEMP TABLE test_temp (id int); + INSERT INTO test_temp VALUES (1); + BEGIN; + DROP TABLE test_temp; + COMMIT; + }, + qr/DROP TABLE: relation "pg_temp[^"]*\.test_temp"/); + +# ON COMMIT DROP and session-end cleanup are the noisy cases the exclusion +# exists for; neither must produce a log entry. +test_drop_not_logged( + 'Test 5: TEMP table with ON COMMIT DROP', + q{ + BEGIN; + CREATE TEMP TABLE test_temp_oncommit (id int) ON COMMIT DROP; + INSERT INTO test_temp_oncommit VALUES (1); + COMMIT; + }, + qr/DROP TABLE: relation "pg_temp[^"]*\.test_temp_oncommit"/); + +test_drop_not_logged( + 'Test 6: TEMP table dropped implicitly at session end', + q{ + CREATE TEMP TABLE test_temp_session (id int); + }, + qr/DROP TABLE: relation "pg_temp[^"]*\.test_temp_session"/); + +# A permanent table dropped in the same transaction as a temp one is still +# logged - the temp exclusion must not swallow its sibling. +start_new_test('Test 7: TEMP exclusion does not suppress permanent tables'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE test_perm_sibling (id int); + BEGIN; + CREATE TEMP TABLE test_temp_sibling (id int); + DROP TABLE test_temp_sibling; + DROP TABLE test_perm_sibling; + COMMIT; +}); +is(count_drop_logs(qr/DROP TABLE: relation "pg_temp[^"]*\.test_temp_sibling"/), + 0, 'Test 7: temp sibling not logged'); +is(count_drop_logs(drop_table_pattern('public', 'test_perm_sibling')), + 1, 'Test 7: permanent sibling logged'); + +# ============================================================================== +# Test 8: DROP DATABASE logs the commit LSN +# +# dropdb() forces an immediate checkpoint between the catalog delete and the +# commit, so the old GetXLogInsertRecPtr()-at-delete-time value is necessarily +# well before the commit record. Exact equality with the post-commit insert +# pointer pins this down. +# ============================================================================== + +start_new_test('Test 8: DROP DATABASE logs the commit LSN'); +$node->safe_psql('postgres', 'CREATE DATABASE test_drop_db'); +my $db_lsn_before = current_insert_lsn(); +$node->safe_psql('postgres', 'DROP DATABASE test_drop_db'); +my $db_lsn_after = current_insert_lsn(); + +my @db_lines = get_log_lines(drop_database_pattern('test_drop_db')); +is(scalar @db_lines, 1, 'Test 8: exactly one DROP DATABASE entry logged'); +my $db_logged = extract_commit_lsn($db_lines[0]); +ok(defined $db_logged, 'Test 8: DROP DATABASE reports a commit LSN'); +note("db logged=$db_logged before=$db_lsn_before after=$db_lsn_after"); +ok(lsn_cmp($db_logged, $db_lsn_before) > 0, + 'Test 8: DROP DATABASE LSN is past the pre-drop LSN'); +ok(lsn_cmp($db_logged, $db_lsn_after) < 0, + 'Test 8: DROP DATABASE LSN is the start of the commit record, not its end'); + +# A DROP DATABASE that fails must not log anything (the old code logged before +# the drop was durable, so a later failure still produced a log line). +start_new_test('Test 9: failed DROP DATABASE is not logged'); +$node->psql('postgres', 'DROP DATABASE test_nonexistent_db'); +is(count_drop_logs(drop_database_pattern('test_nonexistent_db')), + 0, 'Test 9: failed DROP DATABASE not logged'); + +# ============================================================================== +# Structural coverage carried over from v5 +# ============================================================================== + +test_drop_count( + 'Test 10: simple DROP TABLE in autocommit', + q{ + CREATE TABLE test_simple (id int); + DROP TABLE test_simple; + }, + drop_table_pattern('public', 'test_simple'), + 1); + +test_multiple_drops( + 'Test 11: DROP SCHEMA CASCADE', + q{ + CREATE SCHEMA test_schema; + CREATE TABLE test_schema.table1 (id int); + CREATE TABLE test_schema.table2 (name text); + BEGIN; + DROP SCHEMA test_schema CASCADE; + COMMIT; + }, + [ 'test_schema', 'table1', 1 ], + [ 'test_schema', 'table2', 1 ]); + +test_drop_count( + 'Test 12: DROP TABLE CASCADE with foreign keys', + q{ + CREATE TABLE test_parent (id int PRIMARY KEY); + CREATE TABLE test_child (id int, parent_id int REFERENCES test_parent(id)); + BEGIN; + DROP TABLE test_parent CASCADE; + COMMIT; + }, + drop_table_pattern('public', 'test_parent'), + 1); + +test_multiple_drops( + 'Test 13: multiple tables in a single DROP statement', + q{ + CREATE TABLE test_multi1 (id int); + CREATE TABLE test_multi2 (id int); + CREATE TABLE test_multi3 (id int); + BEGIN; + DROP TABLE test_multi1, test_multi2, test_multi3; + COMMIT; + }, + [ 'public', 'test_multi1', 1 ], + [ 'public', 'test_multi2', 1 ], + [ 'public', 'test_multi3', 1 ]); + +test_multiple_drops( + 'Test 14: partitioned table and partitions', + q{ + CREATE TABLE test_partitioned (id int, created_at date) PARTITION BY RANGE (created_at); + CREATE TABLE test_part_2024 PARTITION OF test_partitioned + FOR VALUES FROM ('2024-01-01') TO ('2025-01-01'); + CREATE TABLE test_part_2025 PARTITION OF test_partitioned + FOR VALUES FROM ('2025-01-01') TO ('2026-01-01'); + BEGIN; + DROP TABLE test_partitioned CASCADE; + COMMIT; + }, + [ 'public', 'test_partitioned', 1 ], + [ 'public', 'test_part_2024', 1 ], + [ 'public', 'test_part_2025', 1 ]); + +test_multiple_drops( + 'Test 15: inheritance hierarchy', + q{ + CREATE TABLE parent_inherit (id int); + CREATE TABLE child_inherit1 () INHERITS (parent_inherit); + CREATE TABLE child_inherit2 () INHERITS (parent_inherit); + BEGIN; + DROP TABLE parent_inherit CASCADE; + COMMIT; + }, + [ 'public', 'parent_inherit', 1 ], + [ 'public', 'child_inherit1', 1 ], + [ 'public', 'child_inherit2', 1 ]); + +# Views and indexes are not tables and must not be logged. +start_new_test('Test 16: views and indexes are not logged'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE test_view_base (id int); + CREATE VIEW test_view AS SELECT * FROM test_view_base; + CREATE INDEX test_idx ON test_view_base(id); + DROP VIEW test_view; + DROP INDEX test_idx; + DROP TABLE test_view_base; +}); +is(count_drop_logs(qr/DROP TABLE: relation "public\.test_view"/), + 0, 'Test 16: VIEW drop not logged'); +is(count_drop_logs(qr/DROP TABLE: relation "public\.test_idx"/), + 0, 'Test 16: INDEX drop not logged'); +is(count_drop_logs(drop_table_pattern('public', 'test_view_base')), + 1, 'Test 16: base table drop logged'); + +# ============================================================================== +# Subtransaction handling +# ============================================================================== + +start_new_test('Test 17: SAVEPOINT and ROLLBACK TO'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE test_savepoint1 (id int); + CREATE TABLE test_savepoint2 (id int); + CREATE TABLE test_savepoint3 (id int); + BEGIN; + DROP TABLE test_savepoint1; + SAVEPOINT sp1; + DROP TABLE test_savepoint2; + ROLLBACK TO sp1; + DROP TABLE test_savepoint3; + COMMIT; +}); +is(count_drop_logs(drop_table_pattern('public', 'test_savepoint1')), + 1, 'Test 17: savepoint1 logged'); +is(count_drop_logs(drop_table_pattern('public', 'test_savepoint2')), + 0, 'Test 17: savepoint2 NOT logged (rolled back to savepoint)'); +is(count_drop_logs(drop_table_pattern('public', 'test_savepoint3')), + 1, 'Test 17: savepoint3 logged'); + +start_new_test('Test 18: COMMIT AND CHAIN'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE chain_test1 (id int); + CREATE TABLE chain_test2 (id int); + CREATE TABLE chain_test3 (id int); + CREATE TABLE chain_test4 (id int); + BEGIN; + DROP TABLE chain_test1; + DROP TABLE chain_test2; + COMMIT AND CHAIN; + DROP TABLE chain_test3; + COMMIT AND CHAIN; + DROP TABLE chain_test4; + COMMIT; +}); +is(scalar(get_log_lines(qr/DROP TABLE: relation "public\.chain_test[1-4]"/)), + 4, 'Test 18: four COMMIT AND CHAIN drops logged'); + +start_new_test('Test 19: ROLLBACK AND CHAIN'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE rollback_chain1 (id int); + CREATE TABLE rollback_chain2 (id int); + CREATE TABLE rollback_chain3 (id int); + BEGIN; + DROP TABLE rollback_chain1; + ROLLBACK AND CHAIN; + DROP TABLE rollback_chain2; + COMMIT AND CHAIN; + DROP TABLE rollback_chain3; + COMMIT; +}); +is(count_drop_logs(drop_table_pattern('public', 'rollback_chain1')), + 0, 'Test 19: rollback_chain1 NOT logged (rolled back)'); +is(count_drop_logs(drop_table_pattern('public', 'rollback_chain2')), + 1, 'Test 19: rollback_chain2 logged'); +is(count_drop_logs(drop_table_pattern('public', 'rollback_chain3')), + 1, 'Test 19: rollback_chain3 logged'); + +start_new_test('Test 20: COMMIT AND CHAIN combined with SAVEPOINTs'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE chain_sp1 (id int); + CREATE TABLE chain_sp2 (id int); + CREATE TABLE chain_sp3 (id int); + CREATE TABLE chain_sp4 (id int); + BEGIN; + DROP TABLE chain_sp1; + SAVEPOINT sp1; + DROP TABLE chain_sp2; + ROLLBACK TO sp1; + DROP TABLE chain_sp3; + COMMIT AND CHAIN; + DROP TABLE chain_sp4; + COMMIT; +}); +is(count_drop_logs(drop_table_pattern('public', 'chain_sp1')), + 1, 'Test 20: chain_sp1 logged'); +is(count_drop_logs(drop_table_pattern('public', 'chain_sp2')), + 0, 'Test 20: chain_sp2 NOT logged (rolled back to savepoint)'); +is(count_drop_logs(drop_table_pattern('public', 'chain_sp3')), + 1, 'Test 20: chain_sp3 logged'); +is(count_drop_logs(drop_table_pattern('public', 'chain_sp4')), + 1, 'Test 20: chain_sp4 logged'); + +# PL/pgSQL EXCEPTION blocks are implicit subtransactions that commit. +test_drop_count( + 'Test 21: DROP in PL/pgSQL with EXCEPTION handler', + q{ + CREATE TABLE plpgsql_test (id int); + CREATE FUNCTION test_drop_with_exception() RETURNS void AS $$ + BEGIN + DROP TABLE plpgsql_test; + EXCEPTION + WHEN OTHERS THEN + RAISE NOTICE 'Exception caught'; + END; + $$ LANGUAGE plpgsql; + SELECT test_drop_with_exception(); + }, + drop_table_pattern('public', 'plpgsql_test'), + 1); + +# A drop inside a PL/pgSQL subtransaction that then raises must not be logged. +test_drop_not_logged( + 'Test 22: DROP undone by PL/pgSQL EXCEPTION rollback', + q{ + CREATE TABLE plpgsql_undone (id int); + CREATE FUNCTION test_drop_undone() RETURNS void AS $$ + BEGIN + BEGIN + DROP TABLE plpgsql_undone; + RAISE EXCEPTION 'boom'; + EXCEPTION + WHEN OTHERS THEN + RAISE NOTICE 'rolled back'; + END; + END; + $$ LANGUAGE plpgsql; + SELECT test_drop_undone(); + }, + drop_table_pattern('public', 'plpgsql_undone')); + +# ============================================================================== +# Test 23: end-to-end PITR using the logged LSN +# +# This is the feature's reason for existing, and it exercises the exact recipe +# the documentation gives, including the recovery_target_inclusive trap. +# ============================================================================== + +start_new_test('Test 23: PITR using the logged commit LSN'); + +$node->backup('pitr_backup'); +$node->safe_psql( + 'postgres', q{ + CREATE TABLE precious (id int); + INSERT INTO precious SELECT generate_series(1, 100); +}); +$node->safe_psql('postgres', 'DROP TABLE precious'); +$node->safe_psql('postgres', 'SELECT pg_switch_wal()'); + +my @pitr_lines = get_log_lines(drop_table_pattern('public', 'precious')); +is(scalar @pitr_lines, 1, 'Test 23: drop of precious logged'); +my $pitr_lsn = extract_commit_lsn($pitr_lines[0]); +ok(defined $pitr_lsn, 'Test 23: got a commit LSN to recover to'); +note("PITR target LSN = $pitr_lsn"); + +# 23a: the documented incantation - recovery_target_inclusive = off - must +# stop BEFORE the drop commits and bring the table back. +my $good = PostgreSQL::Test::Cluster->new('pitr_exclusive'); +$good->init_from_backup($node, 'pitr_backup', has_restoring => 1); +$good->append_conf( + 'postgresql.conf', qq{ +recovery_target_lsn = '$pitr_lsn' +recovery_target_inclusive = off +recovery_target_action = 'promote' +recovery_target_timeline = 1 +# The backup carries the primary's archive settings; leaving them on would +# publish this node's promoted timeline into the primary's archive and let the +# other recovery node below follow it. +archive_mode = off +}); +$good->start; +$good->poll_query_until('postgres', 'SELECT NOT pg_is_in_recovery()') + or die "timed out waiting for pitr_exclusive to promote"; + +is( $good->safe_psql( + 'postgres', + "SELECT count(*) FROM pg_class WHERE relname = 'precious'"), + '1', + 'Test 23a: recovery_target_inclusive=off recovers the dropped table'); +is($good->safe_psql('postgres', 'SELECT count(*) FROM precious'), + '100', 'Test 23a: recovered table has its rows'); +$good->stop; + +# 23b: the trap. Setting only recovery_target_lsn leaves +# recovery_target_inclusive at its default of on, which replays the drop and +# loses the table again. This test documents that failure mode so that any +# future change to the default is caught here. +my $trap = PostgreSQL::Test::Cluster->new('pitr_inclusive'); +$trap->init_from_backup($node, 'pitr_backup', has_restoring => 1); +$trap->append_conf( + 'postgresql.conf', qq{ +recovery_target_lsn = '$pitr_lsn' +recovery_target_action = 'promote' +recovery_target_timeline = 1 +archive_mode = off +}); +$trap->start; +$trap->poll_query_until('postgres', 'SELECT NOT pg_is_in_recovery()') + or die "timed out waiting for pitr_inclusive to promote"; + +is( $trap->safe_psql( + 'postgres', + "SELECT count(*) FROM pg_class WHERE relname = 'precious'"), + '0', + 'Test 23b: default recovery_target_inclusive=on replays the drop (documented trap)'); +$trap->stop; + +done_testing();