diff --git a/src/glog/logging.h.in b/src/glog/logging.h.in index b1de2c98e..4c784b37f 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 ec9eef1b8..c778ef867 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), @@ -443,7 +446,7 @@ class LogFileObject : public base::Logger { int64 next_flush_time_; // cycle count at which to flush log // 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); }; @@ -902,20 +905,54 @@ 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. + 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; } diff --git a/src/logging_unittest.cc b/src/logging_unittest.cc index b88622256..d40de7d7a 100644 --- a/src/logging_unittest.cc +++ b/src/logging_unittest.cc @@ -40,9 +40,11 @@ #ifdef HAVE_UNISTD_H # include #endif +#include #include #include +#include #include #include #include @@ -103,6 +105,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 +180,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 +232,8 @@ int main(int argc, char **argv) { FLAGS_logtostderr = false; TestBasename(); + TestBasenameAppendWhenNoTimestamp(); + TestTwoProcessesWrite(); TestSymlink(); TestExtension(); TestWrapper(); @@ -651,7 +658,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); @@ -660,13 +668,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() { @@ -685,6 +696,60 @@ 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(); + + 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() { + 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 + "*"); +} + static void TestSymlink() { #ifndef OS_WINDOWS fprintf(stderr, "==== Test setting log file symlink\n");