When VACUUM or ANALYZE skips a concurrently dropped table, log it.

Hopefully, the additional logging will help avoid confusion that
could otherwise result.

Nathan Bossart, reviewed by Michael Paquier, Fabrízio Mello, and me

Author: robertmhaas

doc/src/sgml/config.sgml

@@ -5926,8 +5926,8 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
         <literal>250ms</literal> then all automatic vacuums and analyzes that run
         250ms or longer will be logged.  In addition, when this parameter is
         set to any value other than <literal>-1</literal>, a message will be
-        logged if an autovacuum action is skipped due to the existence of a
-        conflicting lock.  Enabling this parameter can be helpful
+        logged if an autovacuum action is skipped due to a conflicting lock or a
+        concurrently dropped relation.  Enabling this parameter can be helpful
         in tracking autovacuum activity.  This parameter can only be set in
         the <filename>postgresql.conf</filename> file or on the server command line;
         but the setting can be overridden for individual tables by

src/backend/commands/analyze.c

@@ -120,6 +120,7 @@ analyze_rel(Oid relid, RangeVar *relation, int options,
 	int			elevel;
 	AcquireSampleRowsFunc acquirefunc = NULL;
 	BlockNumber relpages = 0;
+	bool		rel_lock = true;
 
 	/* Select logging level */
 	if (options & VACOPT_VERBOSE)
@@ -149,15 +150,50 @@ analyze_rel(Oid relid, RangeVar *relation, int options,
 	else
 	{
 		onerel = NULL;
-		if (relation &&
-			IsAutoVacuumWorkerProcess() && params->log_min_duration >= 0)
-			ereport(LOG,
+		rel_lock = false;
+	}
+
+	/*
+	 * If we failed to open or lock the relation, emit a log message before
+	 * exiting.
+	 */
+	if (!onerel)
+	{
+		/*
+		 * If the RangeVar is not defined, we do not have enough information
+		 * to provide a meaningful log statement.  Chances are that
+		 * analyze_rel's caller has intentionally not provided this
+		 * information so that this logging is skipped, anyway.
+		 */
+		if (relation == NULL)
+			return;
+
+		/*
+		 * Determine the log level.  For autovacuum logs, we emit a LOG if
+		 * log_autovacuum_min_duration is not disabled.  For manual ANALYZE,
+		 * we emit a WARNING to match the log statements in the permissions
+		 * checks.
+		 */
+		if (!IsAutoVacuumWorkerProcess())
+			elevel = WARNING;
+		else if (params->log_min_duration >= 0)
+			elevel = LOG;
+		else
+			return;
+
+		if (!rel_lock)
+			ereport(elevel,
 					(errcode(ERRCODE_LOCK_NOT_AVAILABLE),
 					 errmsg("skipping analyze of \"%s\" --- lock not available",
 							relation->relname)));
-	}
-	if (!onerel)
+		else
+			ereport(elevel,
+					(errcode(ERRCODE_UNDEFINED_TABLE),
+					 errmsg("skipping analyze of \"%s\" --- relation no longer exists",
+							relation->relname)));
+
 		return;
+	}
 
 	/*
 	 * Check permissions --- this should match vacuum's check!

src/backend/commands/vacuum.c

@@ -1330,6 +1330,7 @@ vacuum_rel(Oid relid, RangeVar *relation, int options, VacuumParams *params)
 	Oid			save_userid;
 	int			save_sec_context;
 	int			save_nestlevel;
+	bool		rel_lock = true;
 
 	Assert(params != NULL);
 
@@ -1400,16 +1401,52 @@ vacuum_rel(Oid relid, RangeVar *relation, int options, VacuumParams *params)
 	else
 	{
 		onerel = NULL;
-		if (relation &&
-			IsAutoVacuumWorkerProcess() && params->log_min_duration >= 0)
-			ereport(LOG,
-					(errcode(ERRCODE_LOCK_NOT_AVAILABLE),
-					 errmsg("skipping vacuum of \"%s\" --- lock not available",
-							relation->relname)));
+		rel_lock = false;
 	}
 
+	/*
+	 * If we failed to open or lock the relation, emit a log message before
+	 * exiting.
+	 */
 	if (!onerel)
 	{
+		int			elevel = 0;
+
+		/*
+		 * Determine the log level.
+		 *
+		 * If the RangeVar is not defined, we do not have enough information
+		 * to provide a meaningful log statement.  Chances are that
+		 * vacuum_rel's caller has intentionally not provided this information
+		 * so that this logging is skipped, anyway.
+		 *
+		 * Otherwise, for autovacuum logs, we emit a LOG if
+		 * log_autovacuum_min_duration is not disabled.  For manual VACUUM, we
+		 * emit a WARNING to match the log statements in the permission
+		 * checks.
+		 */
+		if (relation != NULL)
+		{
+			if (!IsAutoVacuumWorkerProcess())
+				elevel = WARNING;
+			else if (params->log_min_duration >= 0)
+				elevel = LOG;
+		}
+
+		if (elevel != 0)
+		{
+			if (!rel_lock)
+				ereport(elevel,
+						(errcode(ERRCODE_LOCK_NOT_AVAILABLE),
+						 errmsg("skipping vacuum of \"%s\" --- lock not available",
+								relation->relname)));
+			else
+				ereport(elevel,
+						(errcode(ERRCODE_UNDEFINED_TABLE),
+						 errmsg("skipping vacuum of \"%s\" --- relation no longer exists",
+								relation->relname)));
+		}
+
 		PopActiveSnapshot();
 		CommitTransactionCommand();
 		return false;

src/test/isolation/expected/vacuum-concurrent-drop.out

@@ -0,0 +1,76 @@
+Parsed test spec with 2 sessions
+
+starting permutation: lock vac_specified drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step vac_specified: VACUUM test1, test2; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+WARNING:  skipping vacuum of "test2" --- relation no longer exists
+step vac_specified: <... completed>
+
+starting permutation: lock vac_all drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step vac_all: VACUUM; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+step vac_all: <... completed>
+
+starting permutation: lock analyze_specified drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step analyze_specified: ANALYZE test1, test2; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+WARNING:  skipping analyze of "test2" --- relation no longer exists
+step analyze_specified: <... completed>
+
+starting permutation: lock analyze_all drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step analyze_all: ANALYZE; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+step analyze_all: <... completed>
+
+starting permutation: lock vac_analyze_specified drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step vac_analyze_specified: VACUUM ANALYZE test1, test2; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+WARNING:  skipping vacuum of "test2" --- relation no longer exists
+step vac_analyze_specified: <... completed>
+
+starting permutation: lock vac_analyze_all drop_and_commit
+step lock: 
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+
+step vac_analyze_all: VACUUM ANALYZE; <waiting ...>
+step drop_and_commit: 
+	DROP TABLE test2;
+	COMMIT;
+
+step vac_analyze_all: <... completed>

src/test/isolation/isolation_schedule

@@ -62,3 +62,4 @@ test: sequence-ddl
 test: async-notify
 test: vacuum-reltuples
 test: timeouts
+test: vacuum-concurrent-drop

src/test/isolation/specs/vacuum-concurrent-drop.spec

@@ -0,0 +1,45 @@
+# Test for log messages emitted by VACUUM and ANALYZE when a specified
+# relation is concurrently dropped.
+#
+# This also verifies that log messages are not emitted for concurrently
+# dropped relations that were not specified in the VACUUM or ANALYZE
+# command.
+
+setup
+{
+	CREATE TABLE test1 (a INT);
+	CREATE TABLE test2 (a INT);
+}
+
+teardown
+{
+	DROP TABLE IF EXISTS test1;
+	DROP TABLE IF EXISTS test2;
+}
+
+session "s1"
+step "lock"
+{
+	BEGIN;
+	LOCK test1 IN SHARE MODE;
+}
+step "drop_and_commit"
+{
+	DROP TABLE test2;
+	COMMIT;
+}
+
+session "s2"
+step "vac_specified"		{ VACUUM test1, test2; }
+step "vac_all"			{ VACUUM; }
+step "analyze_specified"	{ ANALYZE test1, test2; }
+step "analyze_all"		{ ANALYZE; }
+step "vac_analyze_specified"	{ VACUUM ANALYZE test1, test2; }
+step "vac_analyze_all"		{ VACUUM ANALYZE; }
+
+permutation "lock" "vac_specified" "drop_and_commit"
+permutation "lock" "vac_all" "drop_and_commit"
+permutation "lock" "analyze_specified" "drop_and_commit"
+permutation "lock" "analyze_all" "drop_and_commit"
+permutation "lock" "vac_analyze_specified" "drop_and_commit"
+permutation "lock" "vac_analyze_all" "drop_and_commit"