diff --git a/CMakeLists.txt b/CMakeLists.txt index f27f00d59..4eae6cc3c 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -73,6 +73,7 @@ check_include_file (sys/syscall.h HAVE_SYS_SYSCALL_H) check_include_file (sys/time.h HAVE_SYS_TIME_H) check_include_file (sys/types.h HAVE_SYS_TYPES_H) check_include_file (sys/utsname.h HAVE_SYS_UTSNAME_H) +check_include_file (sys/wait.h HAVE_SYS_WAIT_H) check_include_file (syscall.h HAVE_SYSCALL_H) check_include_file (syslog.h HAVE_SYSLOG_H) check_include_file (ucontext.h HAVE_UCONTEXT_H) diff --git a/Makefile.am b/Makefile.am index d578a4082..93d4db6d5 100644 --- a/Makefile.am +++ b/Makefile.am @@ -209,9 +209,9 @@ libglog_la_SOURCES = $(gloginclude_HEADERS) \ src/base/commandlineflags.h src/googletest.h nodist_libglog_la_SOURCES = $(nodist_gloginclude_HEADERS) -libglog_la_CXXFLAGS = $(PTRHEAD_CFLAGS) $(GFLAGS_CFLAGS) $(MINGW_CFLAGS) \ +libglog_la_CXXFLAGS = $(PTHREAD_CFLAGS) $(GFLAGS_CFLAGS) $(MINGW_CFLAGS) \ $(AM_CXXFLAGS) -DNDEBUG -libglog_la_LDFLAGS = $(PTRHEAD_CFLAGS) $(GFLAGS_LDFLAGS) +libglog_la_LDFLAGS = $(PTHREAD_CFLAGS) $(GFLAGS_LDFLAGS) libglog_la_LIBADD = $(COMMON_LIBS) ## The location of the windows project file for each binary we make diff --git a/src/config.h.cmake.in b/src/config.h.cmake.in index e15c73712..1d325bc58 100644 --- a/src/config.h.cmake.in +++ b/src/config.h.cmake.in @@ -109,6 +109,9 @@ /* Define to 1 if you have the header file. */ #cmakedefine HAVE_SYS_UTSNAME_H +/* Define to 1 if you have the header file. */ +#cmakedefine HAVE_SYS_WAIT_H + /* Define to 1 if you have the header file. */ #cmakedefine HAVE_UCONTEXT_H diff --git a/src/glog/logging.h.in b/src/glog/logging.h.in index ce3700347..321764998 100644 --- a/src/glog/logging.h.in +++ b/src/glog/logging.h.in @@ -330,6 +330,9 @@ typedef unsigned __int64 uint64; using fLS::FLAGS_##name #endif +// Set whether appending a timestamp to the log file name +DECLARE_bool(timestamp_in_logfile_name); + // Set whether log messages go to stderr instead of logfiles DECLARE_bool(logtostderr); diff --git a/src/logging.cc b/src/logging.cc index afb8332b3..f9955b038 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -103,6 +103,9 @@ static bool BoolFromEnv(const char *varname, bool defval) { return memchr("tTyY1\0", valstr[0], 6) != NULL; } +GLOG_DEFINE_bool(timestamp_in_logfile_name, + BoolFromEnv("GOOGLE_TIMESTAMP_IN_LOGFILE_NAME", true), + "put a timestamp at the end of the log file name"); GLOG_DEFINE_bool(logtostderr, BoolFromEnv("GOOGLE_LOGTOSTDERR", false), "log messages go to stderr instead of logfiles"); GLOG_DEFINE_bool(alsologtostderr, BoolFromEnv("GOOGLE_ALSOLOGTOSTDERR", false), @@ -442,7 +445,7 @@ class LogFileObject : public base::Logger { WallTime start_time_; // Actually create a logfile using the value of base_filename_ and the - // supplied argument time_pid_string + // optional argument time_pid_string // REQUIRES: lock_ is held bool CreateLogfile(const string& time_pid_string); }; @@ -921,23 +924,64 @@ void LogFileObject::FlushUnlocked(){ } bool LogFileObject::CreateLogfile(const string& time_pid_string) { - string string_filename = base_filename_+filename_extension_+ - time_pid_string; + string string_filename = base_filename_+filename_extension_; + if (FLAGS_timestamp_in_logfile_name) { + string_filename += time_pid_string; + } const char* filename = string_filename.c_str(); - int fd = open(filename, O_WRONLY | O_CREAT | O_EXCL, FLAGS_logfile_mode); + //only write to files, create if non-existant. + int flags = O_WRONLY | O_CREAT; + if (FLAGS_timestamp_in_logfile_name) { + //demand that the file is unique for our timestamp (fail if it exists). + flags = flags | O_EXCL; + } + int fd = open(filename, flags, FLAGS_logfile_mode); if (fd == -1) return false; #ifdef HAVE_FCNTL // Mark the file close-on-exec. We don't really care if this fails fcntl(fd, F_SETFD, FD_CLOEXEC); + + // Mark the file as exclusive write access to avoid two clients logging to the + // same file. This applies particularly when !FLAGS_timestamp_in_logfile_name + // (otherwise open would fail because the O_EXCL flag on similar filename). + // locks are released on unlock or close() automatically, only after log is + // released. + // This will work after a fork as it is not inherited (not stored in the fd). + // Lock will not be lost because the file is opened with exclusive lock (write) + // and we will never read from it inside the process. + // TODO windows implementation of this (as flock is not available on mingw). + static struct flock w_lock; + + w_lock.l_type = F_WRLCK; + w_lock.l_start = 0; + w_lock.l_whence = SEEK_SET; + w_lock.l_len = 0; + + int wlock_ret = fcntl(fd, F_SETLK, &w_lock); + if (wlock_ret == -1) { + close(fd); //as we are failing already, do not check errors here + return false; + } #endif + //fdopen in append mode so if the file exists it will fseek to the end file_ = fdopen(fd, "a"); // Make a FILE*. if (file_ == NULL) { // Man, we're screwed! close(fd); - unlink(filename); // Erase the half-baked evidence: an unusable log file + if (FLAGS_timestamp_in_logfile_name) { + unlink(filename); // Erase the half-baked evidence: an unusable log file, only if we just created it. + } return false; } - +#ifdef OS_WINDOWS + // https://github.com/golang/go/issues/27638 - make sure we seek to the end to append + // empirically replicated with wine over mingw build + if (!FLAGS_timestamp_in_logfile_name) { + if (fseek(file_, 0, SEEK_END) != 0) { + return false; + } + } +#endif // We try to create a symlink called ., // which is easier to use. (Every time we create a new logfile, // we destroy the old symlink and create a new one, so it always diff --git a/src/logging_unittest.cc b/src/logging_unittest.cc index 6c9445cb2..6b6700439 100644 --- a/src/logging_unittest.cc +++ b/src/logging_unittest.cc @@ -40,9 +40,13 @@ #ifdef HAVE_UNISTD_H # include #endif +#ifdef HAVE_SYS_WAIT_H +# include +#endif #include #include +#include #include #include #include @@ -103,6 +107,8 @@ static void TestCHECK(); static void TestDCHECK(); static void TestSTREQ(); static void TestBasename(); +static void TestBasenameAppendWhenNoTimestamp(); +static void TestTwoProcessesWrite(); static void TestSymlink(); static void TestExtension(); static void TestWrapper(); @@ -176,6 +182,7 @@ BENCHMARK(BM_vlog); int main(int argc, char **argv) { FLAGS_colorlogtostderr = false; + FLAGS_timestamp_in_logfile_name = true; #ifdef HAVE_LIB_GFLAGS ParseCommandLineFlags(&argc, &argv, true); #endif @@ -227,6 +234,8 @@ int main(int argc, char **argv) { FLAGS_logtostderr = false; TestBasename(); + TestBasenameAppendWhenNoTimestamp(); + TestTwoProcessesWrite(); TestSymlink(); TestExtension(); TestWrapper(); @@ -658,7 +667,8 @@ static void DeleteFiles(const string& pattern) { } } -static void CheckFile(const string& name, const string& expected_string) { +//check string is in file (or is *NOT*, depending on optional checkInFileOrNot) +static void CheckFile(const string& name, const string& expected_string, const bool checkInFileOrNot = true) { vector files; GetFiles(name + "*", &files); CHECK_EQ(files.size(), 1UL); @@ -667,13 +677,16 @@ static void CheckFile(const string& name, const string& expected_string) { CHECK(file != NULL) << ": could not open " << files[0]; char buf[1000]; while (fgets(buf, sizeof(buf), file) != NULL) { - if (strstr(buf, expected_string.c_str()) != NULL) { + char* first = strstr(buf, expected_string.c_str()); + //if first == NULL, not found. + //Terser than if (checkInFileOrNot && first != NULL || !check... + if (checkInFileOrNot != (first == NULL)) { fclose(file); return; } } fclose(file); - LOG(FATAL) << "Did not find " << expected_string << " in " << files[0]; + LOG(FATAL) << "Did " << (checkInFileOrNot? "not " : "") << "find " << expected_string << " in " << files[0]; } static void TestBasename() { @@ -692,6 +705,65 @@ static void TestBasename() { DeleteFiles(dest + "*"); } +static void TestBasenameAppendWhenNoTimestamp() { + fprintf(stderr, "==== Test setting log file basename without timestamp and appending properly\n"); + const string dest = FLAGS_test_tmpdir + "/logging_test_basename_append_when_no_timestamp"; + DeleteFiles(dest + "*"); + + ofstream out(dest.c_str()); + out << "test preexisting content" << endl; + out.close(); + + CheckFile(dest, "test preexisting content"); + + FLAGS_timestamp_in_logfile_name=false; + SetLogDestination(GLOG_INFO, dest.c_str()); + LOG(INFO) << "message to new base, appending to preexisting file"; + FlushLogFiles(GLOG_INFO); + FLAGS_timestamp_in_logfile_name=true; + + //if the logging overwrites the file instead of appending it will fail. + CheckFile(dest, "test preexisting content"); + CheckFile(dest, "message to new base, appending to preexisting file"); + + // Release file handle for the destination file to unlock the file in Windows. + LogToStderr(); + DeleteFiles(dest + "*"); +} + +static void TestTwoProcessesWrite() { +// test only implemented for platforms with fork & wait; the actual implementation relies on flock +#if defined(HAVE_SYS_WAIT_H) && defined(HAVE_UNISTD_H) && defined(HAVE_FCNTL) + fprintf(stderr, "==== Test setting log file basename and two processes writing - second should fail\n"); + const string dest = FLAGS_test_tmpdir + "/logging_test_basename_two_processes_writing"; + DeleteFiles(dest + "*"); + + //make both processes write into the same file (easier test) + FLAGS_timestamp_in_logfile_name=false; + SetLogDestination(GLOG_INFO, dest.c_str()); + LOG(INFO) << "message to new base, parent"; + FlushLogFiles(GLOG_INFO); + + pid_t pid = fork(); + CHECK_ERR(pid); + if (pid == 0) { + LOG(INFO) << "message to new base, child - should only appear on STDERR not on the file"; + ShutdownGoogleLogging(); //for children proc + exit(0); + } else if (pid > 0) { + wait(NULL); + } + FLAGS_timestamp_in_logfile_name=true; + + CheckFile(dest, "message to new base, parent"); + CheckFile(dest, "message to new base, child - should only appear on STDERR not on the file", false); + + // Release + LogToStderr(); + DeleteFiles(dest + "*"); +#endif +} + static void TestSymlink() { #ifndef OS_WINDOWS fprintf(stderr, "==== Test setting log file symlink\n");