Fixed bug #7896 : replication.log remains empty (and without any error in firebird.log)

Author: hvlad

src/jrd/replication/Utils.cpp

@@ -49,6 +49,7 @@
 
 #include <stdlib.h>
 #include <time.h>
+#include <atomic>
 
 using namespace Firebird;
 using namespace Replication;
@@ -80,15 +81,17 @@ namespace
 			char host[BUFFER_LARGE];
 			ISC_get_host(host, sizeof(host));
 			m_hostname = host;
+			m_error = false;
 #ifdef WIN_NT
-			m_mutex = CreateMutex(NULL, FALSE, "firebird_repl_mutex");
+			m_mutex = CreateMutex(ISC_get_security_desc(), FALSE, "firebird_repl_mutex");
 #endif
 		}
 
 		~LogWriter()
 		{
 #ifdef WIN_NT
-			CloseHandle(m_mutex);
+			if (m_mutex != INVALID_HANDLE_VALUE)
+				CloseHandle(m_mutex);
 #endif
 		}
 
@@ -107,6 +110,9 @@ namespace
 					return;
 				}
 
+				if (m_error)
+					m_error = false;
+
 				string dbname, text;
 
 				if (database.hasData())
@@ -121,25 +127,34 @@ namespace
 				fclose(file);
 				unlock();
 			}
+			else if (!m_error && !m_error.exchange(true))
+			{
+				gds__log("Failed to open log file \'%s\', errno %d",
+					m_filename.c_str(), errno);
+			}
 		}
 
 	private:
 		bool lock(FILE* file)
 		{
+			const bool ret =
 #ifdef WIN_NT
-			return (WaitForSingleObject(m_mutex, INFINITE) == WAIT_OBJECT_0);
+				(WaitForSingleObject(m_mutex, INFINITE) == WAIT_OBJECT_0);
 #else
 #ifdef HAVE_FLOCK
-			if (flock(fileno(file), LOCK_EX))
+				flock(fileno(file), LOCK_EX) == 0;
 #else
-			if (os_utils::lockf(fileno(file), F_LOCK, 0))
+				os_utils::lockf(fileno(file), F_LOCK, 0) == 0;
 #endif
+#endif
+
+			if (!ret && !m_error && !m_error.exchange(true))
 			{
-				return false;
+				gds__log("Failed to lock log file \'%s\', error %d",
+					m_filename.c_str(), ERRNO);
 			}
 
-			return true;
-#endif
+			return ret;
 		}
 
 		void unlock()
@@ -154,6 +169,8 @@ namespace
 #ifdef WIN_NT
 		HANDLE m_mutex;
 #endif
+		// used to not pollute firebird.log with too many messages
+		std::atomic_bool m_error;
 	};
 
 	void logMessage(LogMsgSide side, LogMsgType type,

src/remote/server/ReplServer.cpp

@@ -162,7 +162,7 @@ namespace
 #ifdef WIN_NT
 			string name;
 			name.printf("firebird_replctl_%s", guidStr);
-			m_mutex = CreateMutex(NULL, FALSE, name.c_str());
+			m_mutex = CreateMutex(ISC_get_security_desc(), FALSE, name.c_str());
 			if (WaitForSingleObject(m_mutex, INFINITE) != WAIT_OBJECT_0)
 #else // POSIX
 #ifdef HAVE_FLOCK

src/yvalve/gds.cpp

@@ -969,7 +969,7 @@ static SLONG safe_interpret(char* const s, const FB_SIZE_T bufsize,
 				}
 
 				if (!found) {
-					sprintf(s, "unknown ISC error %ld", code);	// TXNN
+					sprintf(s, "unknown ISC error %ld", (SLONG) code);	// TXNN
 				}
 			}
 		}
@@ -994,11 +994,11 @@ static SLONG safe_interpret(char* const s, const FB_SIZE_T bufsize,
 		break;
 
 	case isc_arg_dos:
-		sprintf(s, "unknown dos error %ld", code);	// TXNN
+		sprintf(s, "unknown dos error %ld", (SLONG) code);	// TXNN
 		break;
 
 	case isc_arg_next_mach:
-		sprintf(s, "next/mach error %ld", code);	// AP
+		sprintf(s, "next/mach error %ld", (SLONG) code);	// AP
 		break;
 
 	case isc_arg_win32:
@@ -1010,7 +1010,7 @@ static SLONG safe_interpret(char* const s, const FB_SIZE_T bufsize,
 						   s, bufsize, NULL))
 #endif
 		{
-			sprintf(s, "unknown Win32 error %ld", code);	// TXNN
+			sprintf(s, "unknown Win32 error %ld", (SLONG) code);	// TXNN
 		}
 		break;
 
@@ -1078,80 +1078,122 @@ const int SECS_PER_HOUR	= 60 * 60;
 const int SECS_PER_DAY	= SECS_PER_HOUR * 24;
 
 #ifdef WIN_NT
-class CleanupTraceHandles
+
+namespace {
+
+class LogFileHandles
 {
 public:
-	~CleanupTraceHandles()
+	LogFileHandles(Firebird::MemoryPool&)
+	{
+		mutex_handle = CreateMutex(ISC_get_security_desc(), FALSE, "firebird_trace_mutex");
+	}
+
+	~LogFileHandles()
 	{
-		CloseHandle(trace_mutex_handle);
-		trace_mutex_handle = INVALID_HANDLE_VALUE;
+		if (mutex_handle != INVALID_HANDLE_VALUE)
+			CloseHandle(mutex_handle);
 
-		if (trace_file_handle != INVALID_HANDLE_VALUE)
-			CloseHandle(trace_file_handle);
+		mutex_handle = INVALID_HANDLE_VALUE;
 
-		trace_file_handle = INVALID_HANDLE_VALUE;
+		if (file_handle != INVALID_HANDLE_VALUE)
+			CloseHandle(file_handle);
+
+		file_handle = INVALID_HANDLE_VALUE;
 	}
 
+	void trace_raw(const char* text, unsigned int length);
+
+private:
 	// This is machine-global. Can be made instance-global.
 	// For as long you don't trace two instances in parallel this shouldn't matter.
-	static HANDLE trace_mutex_handle;
-	static HANDLE trace_file_handle;
-};
-
-HANDLE CleanupTraceHandles::trace_mutex_handle = CreateMutex(NULL, FALSE, "firebird_trace_mutex");
-HANDLE CleanupTraceHandles::trace_file_handle = INVALID_HANDLE_VALUE;
+	static HANDLE mutex_handle;
+	static HANDLE file_handle;
 
-CleanupTraceHandles cleanupHandles;
-
-#endif
+	friend class LogGuard;
+};
 
-void API_ROUTINE gds__trace_raw(const char* text, unsigned int length)
+void LogFileHandles::trace_raw(const char* text, unsigned int length)
 {
-/**************************************
- *
- *	g d s _ t r a c e _ r a w
- *
- **************************************
- *
- * Functional description
- *	Write trace event to a log file
- *
- **************************************/
-	if (!length)
-		length = static_cast<unsigned>(strlen(text));
-#ifdef WIN_NT
-	// Note: thread-safe code
-
 	// Nickolay Samofatov, 12 Sept 2003. Windows opens files extremely slowly.
 	// Slowly enough to make such trace useless. Thus we cache file handle !
-	WaitForSingleObject(CleanupTraceHandles::trace_mutex_handle, INFINITE);
+
 	while (true)
 	{
-		if (CleanupTraceHandles::trace_file_handle == INVALID_HANDLE_VALUE)
+		if (file_handle == INVALID_HANDLE_VALUE)
 		{
 			Firebird::PathName name = fb_utils::getPrefix(Firebird::IConfigManager::DIR_LOG, LOGFILE);
+
 			// We do not care to close this file.
 			// It will be closed automatically when our process terminates.
-			CleanupTraceHandles::trace_file_handle = CreateFile(name.c_str(), GENERIC_WRITE,
+			file_handle = CreateFile(name.c_str(), GENERIC_WRITE,
 				FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE,
 				NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
-			if (CleanupTraceHandles::trace_file_handle == INVALID_HANDLE_VALUE)
+
+			if (file_handle == INVALID_HANDLE_VALUE)
 				break;
 		}
+
+		SetFilePointer(file_handle, 0, NULL, FILE_END);
+
 		DWORD bytesWritten;
-		SetFilePointer(CleanupTraceHandles::trace_file_handle, 0, NULL, FILE_END);
-		WriteFile(CleanupTraceHandles::trace_file_handle, text, length, &bytesWritten, NULL);
+		WriteFile(file_handle, text, length, &bytesWritten, NULL);
+
 		if (bytesWritten != length)
 		{
 			// Handle the case when file was deleted by another process on Win9x
 			// On WinNT we are not going to notice that fact :(
-			CloseHandle(CleanupTraceHandles::trace_file_handle);
-			CleanupTraceHandles::trace_file_handle = INVALID_HANDLE_VALUE;
+			CloseHandle(file_handle);
+			file_handle = INVALID_HANDLE_VALUE;
 			continue;
 		}
 		break;
 	}
-	ReleaseMutex(CleanupTraceHandles::trace_mutex_handle);
+}
+
+Firebird::InitInstance<LogFileHandles> logFileHandles;
+
+HANDLE LogFileHandles::mutex_handle = INVALID_HANDLE_VALUE;
+HANDLE LogFileHandles::file_handle = INVALID_HANDLE_VALUE;
+
+
+class LogGuard
+{
+public:
+	LogGuard()
+	{
+		WaitForSingleObject(logFileHandles().mutex_handle, INFINITE);
+	}
+
+	~LogGuard()
+	{
+		ReleaseMutex(logFileHandles().mutex_handle);
+	}
+};
+
+} // namespace
+
+#endif
+
+void API_ROUTINE gds__trace_raw(const char* text, unsigned int length)
+{
+/**************************************
+ *
+ *	g d s _ t r a c e _ r a w
+ *
+ **************************************
+ *
+ * Functional description
+ *	Write trace event to a log file
+ *
+ **************************************/
+	if (!length)
+		length = static_cast<unsigned>(strlen(text));
+#ifdef WIN_NT
+	// Note: thread-safe code
+
+	LogGuard guard;
+	logFileHandles().trace_raw(text, length);
 #else
 	Firebird::PathName name = fb_utils::getPrefix(Firebird::IConfigManager::DIR_LOG, LOGFILE);
 	int file = os_utils::open(name.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0660);
@@ -1285,7 +1327,7 @@ void API_ROUTINE gds__log(const TEXT* text, ...)
 	Firebird::PathName name = fb_utils::getPrefix(Firebird::IConfigManager::DIR_LOG, LOGFILE);
 
 #ifdef WIN_NT
-	WaitForSingleObject(CleanupTraceHandles::trace_mutex_handle, INFINITE);
+	LogGuard guard;
 #endif
 
 	FILE* file = os_utils::fopen(name.c_str(), "a");
@@ -1323,8 +1365,6 @@ void API_ROUTINE gds__log(const TEXT* text, ...)
 	va_start(ptr, text);
 	__android_log_vprint(ANDROID_LOG_INFO, "FIREBIRD", text, ptr);
 	va_end(ptr);
-#elif defined(WIN_NT)
-	ReleaseMutex(CleanupTraceHandles::trace_mutex_handle);
 #endif
 }
 
@@ -1357,7 +1397,7 @@ void gds__print_pool(MemoryPool* pool, const TEXT* text, ...)
 
 	const int oldmask = umask(0111);
 #ifdef WIN_NT
-	WaitForSingleObject(CleanupTraceHandles::trace_mutex_handle, INFINITE);
+	LogGuard guard;
 #endif
 	FILE* file = os_utils::fopen(name.c_str(), "a");
 	if (file != NULL)
@@ -1372,9 +1412,6 @@ void gds__print_pool(MemoryPool* pool, const TEXT* text, ...)
 		fprintf(file, "\n");
 		fclose(file);
 	}
-#ifdef WIN_NT
-	ReleaseMutex(CleanupTraceHandles::trace_mutex_handle);
-#endif
 
 	umask(oldmask);