From b94d13b8381df976e4294120ff42d84311cacb5b Mon Sep 17 00:00:00 2001 From: baldurk Date: Wed, 17 May 2017 19:41:39 +0100 Subject: [PATCH] Make sure linux log files don't get deleted while still logging to them * We need to use file locks to ensure the last process knows it can delete the log, as well as delete any inherited file descriptors when forking to launch a new executable. * To accomplish this, tracking the single logfile handle is now part of the OS-specific code instead of common logging code. It makes little difference either way as we don't support multiple log files. --- renderdoc/common/common.cpp | 22 ++++---- renderdoc/common/common.h | 4 +- renderdoc/core/core.cpp | 6 +- renderdoc/os/os_specific.h | 6 +- renderdoc/os/posix/posix_process.cpp | 6 ++ renderdoc/os/posix/posix_stringio.cpp | 79 ++++++++++++++++++++++----- renderdoc/os/win32/win32_stringio.cpp | 30 +++++++--- 7 files changed, 111 insertions(+), 42 deletions(-) diff --git a/renderdoc/common/common.cpp b/renderdoc/common/common.cpp index 39ce496e5..9c406f026 100644 --- a/renderdoc/common/common.cpp +++ b/renderdoc/common/common.cpp @@ -253,7 +253,7 @@ uint64_t Log2Floor(uint64_t value) #endif static string logfile; -static void *logfileHandle = NULL; +static bool logfileOpened = false; const char *rdclog_getfilename() { @@ -268,20 +268,21 @@ void rdclog_filename(const char *filename) if(filename && filename[0]) logfile = filename; - FileIO::logfile_close(logfileHandle); + FileIO::logfile_close(NULL); + + logfileOpened = false; if(!logfile.empty()) { - logfileHandle = FileIO::logfile_open(filename); + logfileOpened = FileIO::logfile_open(filename); - if(logfileHandle && previous.c_str()) + if(logfileOpened && previous.c_str()) { vector previousContents; FileIO::slurp(previous.c_str(), previousContents); if(!previousContents.empty()) - FileIO::logfile_append(logfileHandle, (const char *)&previousContents[0], - previousContents.size()); + FileIO::logfile_append((const char *)&previousContents[0], previousContents.size()); FileIO::Delete(previous.c_str()); } @@ -295,11 +296,10 @@ void rdclog_enableoutput() log_output_enabled = true; } -void rdclog_closelog() +void rdclog_closelog(const char *filename) { log_output_enabled = false; - if(logfileHandle) - FileIO::logfile_close(logfileHandle); + FileIO::logfile_close(filename); } void rdclog_flush() @@ -326,10 +326,10 @@ void rdclogprint_int(LogType type, const char *fullMsg, const char *msg) OSUtility::WriteOutput(OSUtility::Output_StdErr, msg); #endif #if ENABLED(OUTPUT_LOG_TO_DISK) - if(logfileHandle) + if(logfileOpened) { // strlen used as byte length - str is UTF-8 so this is NOT number of characters - FileIO::logfile_append(logfileHandle, fullMsg, strlen(fullMsg)); + FileIO::logfile_append(fullMsg, strlen(fullMsg)); } #endif } diff --git a/renderdoc/common/common.h b/renderdoc/common/common.h index 8f60f0537..205698fab 100644 --- a/renderdoc/common/common.h +++ b/renderdoc/common/common.h @@ -301,13 +301,13 @@ void rdclog_int(LogType type, const char *project, const char *file, unsigned in const char *rdclog_getfilename(); void rdclog_filename(const char *filename); void rdclog_enableoutput(); -void rdclog_closelog(); +void rdclog_closelog(const char *filename); #define RDCLOGFILE(fn) rdclog_filename(fn) #define RDCGETLOGFILE() rdclog_getfilename() #define RDCLOGOUTPUT() rdclog_enableoutput() -#define RDCSTOPLOGGING() rdclog_closelog() +#define RDCSTOPLOGGING(filename) rdclog_closelog(filename) #if(ENABLED(RDOC_DEVEL) || ENABLED(FORCE_DEBUG_LOGS)) && DISABLED(STRIP_DEBUG_LOGS) #define RDCDEBUG(...) rdclog(LogType::Debug, __VA_ARGS__) diff --git a/renderdoc/core/core.cpp b/renderdoc/core/core.cpp index 5c4ef414e..48f7b5b1a 100644 --- a/renderdoc/core/core.cpp +++ b/renderdoc/core/core.cpp @@ -364,9 +364,7 @@ RenderDoc::~RenderDoc() } } - RDCSTOPLOGGING(); - - FileIO::Delete(m_LoggingFilename.c_str()); + RDCSTOPLOGGING(m_LoggingFilename.c_str()); if(m_RemoteThread) { @@ -383,8 +381,6 @@ RenderDoc::~RenderDoc() Network::Shutdown(); Threading::Shutdown(); - - FileIO::Delete(m_LoggingFilename.c_str()); } void RenderDoc::Shutdown() diff --git a/renderdoc/os/os_specific.h b/renderdoc/os/os_specific.h index ddc1713d4..ac175e966 100644 --- a/renderdoc/os/os_specific.h +++ b/renderdoc/os/os_specific.h @@ -265,9 +265,9 @@ int fclose(FILE *f); // functions for atomically appending to a log that may be in use in multiple // processes -void *logfile_open(const char *filename); -void logfile_append(void *handle, const char *msg, size_t length); -void logfile_close(void *handle); +bool logfile_open(const char *filename); +void logfile_append(const char *msg, size_t length); +void logfile_close(const char *filename); // utility functions inline bool dump(const char *filename, const void *buffer, size_t size) diff --git a/renderdoc/os/posix/posix_process.cpp b/renderdoc/os/posix/posix_process.cpp index a2fb75bb3..089c1c98f 100644 --- a/renderdoc/os/posix/posix_process.cpp +++ b/renderdoc/os/posix/posix_process.cpp @@ -219,6 +219,11 @@ void Process::ApplyEnvironmentModification() modifications.clear(); } +namespace FileIO +{ +void ReleaseFDAfterFork(); +}; + static pid_t RunProcess(const char *app, const char *workingDir, const char *cmdLine, char **envp, int stdoutPipe[2] = NULL, int stderrPipe[2] = NULL) { @@ -355,6 +360,7 @@ static pid_t RunProcess(const char *app, const char *workingDir, const char *cmd pid_t childPid = fork(); if(childPid == 0) { + FileIO::ReleaseFDAfterFork(); if(stdoutPipe) { // Redirect stdout & stderr write ends. diff --git a/renderdoc/os/posix/posix_stringio.cpp b/renderdoc/os/posix/posix_stringio.cpp index 65f5ddfb0..d742f1f79 100644 --- a/renderdoc/os/posix/posix_stringio.cpp +++ b/renderdoc/os/posix/posix_stringio.cpp @@ -31,6 +31,7 @@ #include #include #include +#include #include #include #include @@ -381,27 +382,79 @@ bool exists(const char *filename) return (res == 0); } -void *logfile_open(const char *filename) +static int logfileFD = -1; + +// this is used in posix_process.cpp, so that we can close the handle any time that we fork() +void ReleaseFDAfterFork() { - int fd = open(filename, O_APPEND | O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); - return (void *)(intptr_t)fd; + // we do NOT release the shared lock here, since the file descriptor is shared so we'd be + // releasing the parent process's lock. Just close our file descriptor + close(logfileFD); } -void logfile_append(void *handle, const char *msg, size_t length) +bool logfile_open(const char *filename) { - if(handle) - { - int fd = ((intptr_t)handle & 0xffffffff); - write(fd, msg, (unsigned int)length); - } + logfileFD = open(filename, O_APPEND | O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); + + // acquire a shared lock. Every process acquires a shared lock to the common logfile. Each time a + // process shuts down and wants to close the logfile, it releases its shared lock and tries to + // acquire an exclusive lock, to see if it can delete the file. See logfile_close. + int err = flock(logfileFD, LOCK_SH | LOCK_NB); + + if(err < 0) + RDCWARN("Couldn't acquire shared lock to %s: %d", filename, (int)errno); + + return logfileFD >= 0; } -void logfile_close(void *handle) +void logfile_append(const char *msg, size_t length) { - if(handle) + if(logfileFD) + write(logfileFD, msg, (unsigned int)length); +} + +void logfile_close(const char *filename) +{ + if(logfileFD) { - int fd = ((intptr_t)handle & 0xffffffff); - close(fd); + // release our shared lock + int err = flock(logfileFD, LOCK_UN | LOCK_NB); + + if(err == 0 && filename) + { + // now try to acquire an exclusive lock. If this succeeds, no other processes are using the + // file (since no other shared locks exist), so we can delete it. If it fails, some other + // shared lock still exists so we can just close our fd and exit. + // NOTE: there is a race here between acquiring the exclusive lock and unlinking, but we + // aren't interested in this kind of race - we're interested in whether an application is + // still running when the UI closes, or vice versa, or similar cases. + err = flock(logfileFD, LOCK_EX | LOCK_NB); + + if(err == 0) + { + // we got the exclusive lock. Now release it, close fd, and unlink the file + err = flock(logfileFD, LOCK_UN | LOCK_NB); + + // can't really error handle here apart from retrying + if(err != 0) + RDCWARN("Couldn't release exclusive lock to %s: %d", filename, (int)errno); + + close(logfileFD); + + unlink(filename); + + // return immediately so we don't close again below. + return; + } + } + else + { + RDCWARN("Couldn't release shared lock to %s: %d", filename, (int)errno); + // nothing to do, we won't try again, just exit. The log might lie around, but that's + // relatively harmless. + } + + close(logfileFD); } } }; diff --git a/renderdoc/os/win32/win32_stringio.cpp b/renderdoc/os/win32/win32_stringio.cpp index 729151d27..3cfeca16d 100644 --- a/renderdoc/os/win32/win32_stringio.cpp +++ b/renderdoc/os/win32/win32_stringio.cpp @@ -524,25 +524,39 @@ int fclose(FILE *f) return ::fclose(f); } -void *logfile_open(const char *filename) +static HANDLE logHandle = NULL; + +bool logfile_open(const char *filename) { wstring wfn = StringFormat::UTF82Wide(string(filename)); - return (void *)CreateFileW(wfn.c_str(), FILE_APPEND_DATA, FILE_SHARE_READ | FILE_SHARE_WRITE, - NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL); + logHandle = CreateFileW(wfn.c_str(), FILE_APPEND_DATA, FILE_SHARE_READ | FILE_SHARE_WRITE, NULL, + OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL); + + return logHandle != NULL; } -void logfile_append(void *handle, const char *msg, size_t length) +void logfile_append(const char *msg, size_t length) { - if(handle) + if(logHandle) { DWORD bytesWritten = 0; - WriteFile((HANDLE)handle, msg, (DWORD)length, &bytesWritten, NULL); + WriteFile(logHandle, msg, (DWORD)length, &bytesWritten, NULL); } } -void logfile_close(void *handle) +void logfile_close(const char *filename) { - CloseHandle((HANDLE)handle); + CloseHandle(logHandle); + logHandle = NULL; + + if(filename) + { + // we can just try to delete the file. If it's open elsewhere in another process, the delete + // will + // fail. + wstring wpath = StringFormat::UTF82Wide(string(filename)); + ::DeleteFileW(wpath.c_str()); + } } };