agora inbox for [email protected]  
help / color / mirror / Atom feed
[PATCH v2 1/2] wip: Log VACUUM information as DEBUG1 when VERBOSE is not used
2+ messages / 2 participants
[nested] [flat]

* [PATCH v2 1/2] wip: Log VACUUM information as DEBUG1 when VERBOSE is not used
@ 2023-02-08 02:12 Andres Freund <[email protected]>
  0 siblings, 0 replies; 2+ messages in thread

From: Andres Freund @ 2023-02-08 02:12 UTC (permalink / raw)

Otherwise it's very hard to debug some kinds of issues, as one cannot use
VACUUM VERBOSE in regression tests.

Author:
Reviewed-by:
Discussion: https://postgr.es/m/
Backpatch:
---
 src/backend/access/heap/vacuumlazy.c | 57 ++++++++++++++++++++++------
 1 file changed, 45 insertions(+), 12 deletions(-)

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 8f14cf85f38..f6f3bb4c021 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -180,6 +180,7 @@ typedef struct LVRelState
 	OffsetNumber offnum;		/* used only for heap operations */
 	VacErrPhase phase;
 	bool		verbose;		/* VACUUM VERBOSE? */
+	int			elevel;
 
 	/*
 	 * dead_items stores TIDs whose index tuples are deleted by index
@@ -324,10 +325,33 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 				StartPageDirty = VacuumPageDirty;
 	ErrorContextCallback errcallback;
 	char	  **indnames = NULL;
+	int			elevel;
+
+	if (params->options & VACOPT_VERBOSE)
+	{
+		verbose = true;
+		elevel = INFO;
+		instrument = true;
+	}
+	else if (IsAutoVacuumWorkerProcess() && params->log_min_duration >= 0)
+	{
+		verbose = true;
+		elevel = LOG;
+		instrument = true;
+	}
+	else if (message_level_is_interesting(DEBUG1))
+	{
+		verbose = true;
+		elevel = DEBUG1;
+		instrument = true;
+	}
+	else
+	{
+		verbose = false;
+		elevel = DEBUG5; /* avoid compiler warning, not reached */
+		instrument = false;
+	}
 
-	verbose = (params->options & VACOPT_VERBOSE) != 0;
-	instrument = (verbose || (IsAutoVacuumWorkerProcess() &&
-							  params->log_min_duration >= 0));
 	if (instrument)
 	{
 		pg_rusage_init(&ru0);
@@ -361,6 +385,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 	vacrel->indname = NULL;
 	vacrel->phase = VACUUM_ERRCB_PHASE_UNKNOWN;
 	vacrel->verbose = verbose;
+	vacrel->elevel = elevel;
 	errcallback.callback = vacuum_error_callback;
 	errcallback.arg = vacrel;
 	errcallback.previous = error_context_stack;
@@ -475,12 +500,12 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 	if (verbose)
 	{
 		if (vacrel->aggressive)
-			ereport(INFO,
+			ereport(elevel,
 					(errmsg("aggressively vacuuming \"%s.%s.%s\"",
 							vacrel->dbname, vacrel->relnamespace,
 							vacrel->relname)));
 		else
-			ereport(INFO,
+			ereport(elevel,
 					(errmsg("vacuuming \"%s.%s.%s\"",
 							vacrel->dbname, vacrel->relnamespace,
 							vacrel->relname)));
@@ -765,7 +790,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 							 (unsigned long long) walusage.wal_bytes);
 			appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
-			ereport(verbose ? INFO : LOG,
+			ereport(elevel,
 					(errmsg_internal("%s", buf.data)));
 			pfree(buf.data);
 		}
@@ -2707,7 +2732,11 @@ lazy_vacuum_one_index(Relation indrel, IndexBulkDeleteResult *istat,
 	ivinfo.analyze_only = false;
 	ivinfo.report_progress = false;
 	ivinfo.estimated_count = true;
-	ivinfo.message_level = DEBUG2;
+	/*
+	 * FIXME: This shows more information for VACUUM VERBOSE, uses DEBUG1
+	 * instead of DEBUG2.
+	 */
+	ivinfo.message_level = vacrel->elevel;
 	ivinfo.num_heap_tuples = reltuples;
 	ivinfo.strategy = vacrel->bstrategy;
 
@@ -2755,7 +2784,11 @@ lazy_cleanup_one_index(Relation indrel, IndexBulkDeleteResult *istat,
 	ivinfo.analyze_only = false;
 	ivinfo.report_progress = false;
 	ivinfo.estimated_count = estimated_count;
-	ivinfo.message_level = DEBUG2;
+	/*
+	 * FIXME: This shows more information for VACUUM VERBOSE, uses DEBUG1
+	 * instead of DEBUG2.
+	 */
+	ivinfo.message_level = vacrel->elevel;
 
 	ivinfo.num_heap_tuples = reltuples;
 	ivinfo.strategy = vacrel->bstrategy;
@@ -2875,7 +2908,7 @@ lazy_truncate_heap(LVRelState *vacrel)
 				 * We failed to establish the lock in the specified number of
 				 * retries. This means we give up truncating.
 				 */
-				ereport(vacrel->verbose ? INFO : DEBUG2,
+				ereport(vacrel->elevel,
 						(errmsg("\"%s\": stopping truncate due to conflicting lock request",
 								vacrel->relname)));
 				return;
@@ -2945,7 +2978,7 @@ lazy_truncate_heap(LVRelState *vacrel)
 		vacrel->removed_pages += orig_rel_pages - new_rel_pages;
 		vacrel->rel_pages = new_rel_pages;
 
-		ereport(vacrel->verbose ? INFO : DEBUG2,
+		ereport(vacrel->elevel,
 				(errmsg("table \"%s\": truncated %u to %u pages",
 						vacrel->relname,
 						orig_rel_pages, new_rel_pages)));
@@ -3007,7 +3040,7 @@ count_nondeletable_pages(LVRelState *vacrel, bool *lock_waiter_detected)
 			{
 				if (LockHasWaitersRelation(vacrel->rel, AccessExclusiveLock))
 				{
-					ereport(vacrel->verbose ? INFO : DEBUG2,
+					ereport(vacrel->elevel,
 							(errmsg("table \"%s\": suspending truncate due to conflicting lock request",
 									vacrel->relname)));
 
@@ -3175,7 +3208,7 @@ dead_items_alloc(LVRelState *vacrel, int nworkers)
 			vacrel->pvs = parallel_vacuum_init(vacrel->rel, vacrel->indrels,
 											   vacrel->nindexes, nworkers,
 											   max_items,
-											   vacrel->verbose ? INFO : DEBUG2,
+											   vacrel->elevel,
 											   vacrel->bstrategy);
 
 		/* If parallel mode started, dead_items space is allocated in DSM */
-- 
2.38.0


--2olgvfw3dklisbsr--





^ permalink  raw  reply  [nested|flat] 2+ messages in thread

* Re: POC: enable logical decoding when wal_level = 'replica' without a server restart
@ 2025-08-01 23:25 Masahiko Sawada <[email protected]>
  0 siblings, 0 replies; 2+ messages in thread

From: Masahiko Sawada @ 2025-08-01 23:25 UTC (permalink / raw)
  To: shveta malik <[email protected]>; +Cc: Amit Kapila <[email protected]>; Bertrand Drouvot <[email protected]>; Ashutosh Bapat <[email protected]>; pgsql-hackers

On Mon, Jul 28, 2025 at 10:02 PM shveta malik <[email protected]> wrote:
>
> On Fri, Jul 25, 2025 at 11:45 AM Masahiko Sawada <[email protected]> wrote:
> >
> > Thank you for testing the patch!
> >
> > I've reworked the locking part in the patch. The attached v4 patch
> > should address all review comments including your previous
> > comments[1].
> >
>
> Thank You for the patch. I have not reviewed fully, but please find
> few comments:
>
> 1)
> CreateReplicationSlot():
>
>   Assert(cmd->kind == REPLICATION_KIND_LOGICAL);
>  + EnsureLogicalDecodingEnabled();
>   CheckLogicalDecodingRequirements();
>   ReplicationSlotCreate(...);
>
> We may have another race-condition here. We have
> EnsureLogicalDecodingEnabled() before ReplicationSlotCreate(). It
> means we are enabling logical-decoding before incrementing
> LogicalDecodingCtl->n_logical_slots. So before we increment
> LogicalDecodingCtl->n_logical_slots through ReplicationSlotCreate(),
> another session may try to meanwhile drop the logical slot (another
> one and last one), and thus it may end up disabling logical-decoding
> as it will find n_logical_slots as 0.
>
> Steps:
> a) Create logical slot logical_slot1 on primary.
> b) Create  publication pub1.
> c) During Create-sub on subscriber, stop walsender after
> EnsureLogicalDecodingEnabled() by attaching debugger.
> d) Drop logical_slot1 on primary.
> e) Release the walsender debugger.

True. EnsureLogicalDecodingEnabled() has to be called after creating a
logical replication slot in order to reliably enable logical decoding.

>
>
> 2)
> create_logical_replication_slot:
>
> ReplicationSlotCreate(name, true
> ....
> + EnsureLogicalDecodingEnabled();
> + CheckLogicalDecodingRequirements();
>
> Earlier we had CheckLogicalDecodingRequirements() before we actually
> created the slot. Now we had it after slot-creation. It makes sense to
> do Logical-Decoding related checks post EnsureLogicalDecodingEnabled,
> but 'CheckSlotRequirements' should be done prior to slot-creation.
> Otherwise we will end up creating the slot and later dropping it when
> it should not have been created in the first place (for say wal_level
> < replica).
>
>
> 3)
> + EnsureLogicalDecodingEnabled();
> +
>
> We can get rid of this from slotsync as this is no-op on standby
>
>
> 4)
> pg_sync_replication_slots()
>         if (!RecoveryInProgress())
>                 ereport(ERROR,
>
> errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
>                                 errmsg("replication slots can only be
> synchronized to a standby server"));
>
> + EnsureLogicalDecodingEnabled();
>
> This API is called on standby alone, so EnsureLogicalDecodingEnabled
> is not needed here either.

Thank you for reviewing the patch! Agree with these comments. They
have been addressed in the latest patch I've just submitted[1].

Regards,

[1] https://www.postgresql.org/message-id/CAD21AoB%3DRf-SASOJR2WqvWcrA5Q3S2oUBACVLdJPaA8x6EchBA%40mail.g...
--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com





^ permalink  raw  reply  [nested|flat] 2+ messages in thread


end of thread, other threads:[~2025-08-01 23:25 UTC | newest]

Thread overview: 2+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-02-08 02:12 [PATCH v2 1/2] wip: Log VACUUM information as DEBUG1 when VERBOSE is not used Andres Freund <[email protected]>
2025-08-01 23:25 Re: POC: enable logical decoding when wal_level = 'replica' without a server restart Masahiko Sawada <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox