Remove race conditions between ECPGdebug() and ecpg_log().

tglsfdc · tglsfdc · commit e892e72b3c8c · 2024-05-23T15:52:06.000-04:00
Coverity complains that ECPGdebug is accessing debugstream without
holding debug_mutex, which is a fair complaint: we should take
debug_mutex while changing the settings ecpg_log looks at.

In some branches it also complains about unlocked use of simple_debug.
I think it's intentional and safe to have a quick unlocked check of
simple_debug at the start of ecpg_log, since that early exit will
always be taken in non-debug cases.  But we should recheck
simple_debug after acquiring the mutex.  In the worst case, calling
ECPGdebug concurrently with ecpg_log in another thread could result
in a null-pointer dereference due to debugstream transiently being
NULL while simple_debug isn't 0.

This is largely hypothetical, since it's unlikely anybody uses
ECPGdebug() at all in the field, and our own regression tests
don't seem to be hitting the theoretical race conditions either.
Still, if we're going to the trouble of having mutexes here, we ought
to be using them in a way that's actually safe not just almost safe.
Hence, back-patch to all supported branches.
diff --git a/src/interfaces/ecpg/ecpglib/misc.c b/src/interfaces/ecpg/ecpglib/misc.c
@@ -91,7 +91,7 @@ static struct sqlca_t sqlca =
 static pthread_mutex_t debug_mutex = PTHREAD_MUTEX_INITIALIZER;
 static pthread_mutex_t debug_init_mutex = PTHREAD_MUTEX_INITIALIZER;
 #endif
-static int	simple_debug = 0;
+static volatile int simple_debug = 0;
 static FILE *debugstream = NULL;
 
 void
@@ -241,7 +241,11 @@ void
 ECPGdebug(int n, FILE *dbgs)
 {
 #ifdef ENABLE_THREAD_SAFETY
+	/* Interlock against concurrent executions of ECPGdebug() */
 	pthread_mutex_lock(&debug_init_mutex);
+
+	/* Prevent ecpg_log() from printing while we change settings */
+	pthread_mutex_lock(&debug_mutex);
 #endif
 
 	if (n > 100)
@@ -254,6 +258,12 @@ ECPGdebug(int n, FILE *dbgs)
 
 	debugstream = dbgs;
 
+	/* We must release debug_mutex before invoking ecpg_log() ... */
+#ifdef ENABLE_THREAD_SAFETY
+	pthread_mutex_unlock(&debug_mutex);
+#endif
+
+	/* ... but keep holding debug_init_mutex to avoid racy printout */
 	ecpg_log("ECPGdebug: set to %d\n", simple_debug);
 
 #ifdef ENABLE_THREAD_SAFETY
@@ -270,6 +280,11 @@ ecpg_log(const char *format,...)
 	int			bufsize;
 	char	   *fmt;
 
+	/*
+	 * For performance reasons, inspect simple_debug without taking the mutex.
+	 * This could be problematic if fetching an int isn't atomic, but we
+	 * assume that it is in many other places too.
+	 */
 	if (!simple_debug)
 		return;
 
@@ -294,18 +309,22 @@ ecpg_log(const char *format,...)
 	pthread_mutex_lock(&debug_mutex);
 #endif
 
-	va_start(ap, format);
-	vfprintf(debugstream, fmt, ap);
-	va_end(ap);
-
-	/* dump out internal sqlca variables */
-	if (ecpg_internal_regression_mode && sqlca != NULL)
+	/* Now that we hold the mutex, recheck simple_debug */
+	if (simple_debug)
 	{
-		fprintf(debugstream, "[NO_PID]: sqlca: code: %ld, state: %s\n",
-				sqlca->sqlcode, sqlca->sqlstate);
-	}
+		va_start(ap, format);
+		vfprintf(debugstream, fmt, ap);
+		va_end(ap);
 
-	fflush(debugstream);
+		/* dump out internal sqlca variables */
+		if (ecpg_internal_regression_mode && sqlca != NULL)
+		{
+			fprintf(debugstream, "[NO_PID]: sqlca: code: %ld, state: %s\n",
+					sqlca->sqlcode, sqlca->sqlstate);
+		}
+
+		fflush(debugstream);
+	}
 
 #ifdef ENABLE_THREAD_SAFETY
 	pthread_mutex_unlock(&debug_mutex);
