From 6e836ed5cb5f41391e335b4f508dc6c0e8915ba5 Mon Sep 17 00:00:00 2001 From: Bitflash Date: Wed, 29 Jul 2026 12:46:33 -0300 Subject: util: stop debug.log dropping lines under concurrency (#29) OutputDebugStringF resolved its path lazily with no lock: static string strDebugFile; if (strDebugFile.empty()) { ... strDebugFile = dir + "\\" + "debug.log"; } FILE* fileout = fopen(strDebugFile.c_str(), "a"); if (fileout) { ... } One thread could read that string while another was still assigning to it, and at startup three threads log within milliseconds of each other. When it raced, fopen received a torn path, returned NULL, and the `if (fileout)` dropped the line with no error anywhere. Several threads calling fopen on the same file at once had no protection either. Measured over six runs, counting first-statement printfs that are unconditional and must appear every time: ThreadBtfAccept started 4/6 ThreadNostrSeed started 5/6 btfpeers: (cached peers) 2/6 Over eight runs after the change, all three are 8/8. This matters beyond tidiness. A missing line was read as a thread that never started, and a real investigation was spent on it. Any reasoning of the form "it is not in the log, so it did not happen" was unsound against this build. Path resolution and the write now share one critical section. The rest of the function already had its own for the OutputDebugString accumulation path; only the file half was unguarded. --- src/util.h | 56 ++++++++++++++++++++++++++++++++++++-------------------- 1 file changed, 36 insertions(+), 20 deletions(-) (limited to 'src/util.h') diff --git a/src/util.h b/src/util.h index 641b838..b583248 100644 --- a/src/util.h +++ b/src/util.h @@ -269,29 +269,45 @@ string GetAppDir(); inline int OutputDebugStringF(const char* pszFormat, ...) { #if 1 // debug.log always enabled - // Write to data directory so it's always findable - static string strDebugFile; - if (strDebugFile.empty()) { - string dir = GetAppDir(); - if (!dir.empty()) - strDebugFile = dir + + // Write to data directory so it's always findable. + // + // Path resolution and the write are both under the lock, because neither + // used to be under anything. strDebugFile was filled in lazily inside an + // `if (empty())`, so one thread could read the path while another was + // still assigning to it -- and at startup three threads log within + // milliseconds of each other. When that raced, fopen got a torn path, + // returned NULL, and the `if (fileout)` below dropped the line silently. + // Measured before this change: unconditional first-statement printfs in + // ThreadBtfAccept, ThreadNostrSeed and the cached-peer thread reached the + // file in only 4/6, 5/6 and 2/6 of runs respectively. Concluding a thread + // never ran because its line was absent was not sound, and the lock also + // stops several threads calling fopen on the same file at once. + static CCriticalSection cs_debugFile; + CRITICAL_BLOCK(cs_debugFile) + { + static string strDebugFile; + if (strDebugFile.empty()) { + string dir = GetAppDir(); + if (!dir.empty()) + strDebugFile = dir + #ifdef _WIN32 - "\\" + "\\" #else - "/" + "/" #endif - + "debug.log"; - else - strDebugFile = "debug.log"; - } - FILE* fileout = fopen(strDebugFile.c_str(), "a"); - if (fileout) - { - va_list arg_ptr; - va_start(arg_ptr, pszFormat); - vfprintf(fileout, pszFormat, arg_ptr); - va_end(arg_ptr); - fclose(fileout); + + "debug.log"; + else + strDebugFile = "debug.log"; + } + FILE* fileout = fopen(strDebugFile.c_str(), "a"); + if (fileout) + { + va_list arg_ptr; + va_start(arg_ptr, pszFormat); + vfprintf(fileout, pszFormat, arg_ptr); + va_end(arg_ptr); + fclose(fileout); + } } #ifndef _WIN32 -- cgit v1.2.3