Only INFO level logs are delteded when LogCleaner is enabled

[broken-dream]

glog commit: 4f007d9

When I used google::EnableLogCleaner() to clean the outdated log, I found that only INFO level log file is removed while all other logs were remained.

I analyzed the related code and found it was jointly caused by following factors:

1. log cleaner is a singleton and shared by all log level
2. clean is triggered by log print and only log belonging to current level will be remoed
3. the interval between two clean operation is at least FLAGS_logcleansecs seconds

I modified the cleanup_immediately_unittest.cc to give a reproducible example:

#include "base/commandlineflags.h"
#include "glog/logging.h"
#include "glog/raw_logging.h"
#include "googletest.h"

#ifdef GLOG_USE_GFLAGS
#  include <gflags/gflags.h>
using namespace GFLAGS_NAMESPACE;
#endif

#ifdef HAVE_LIB_GMOCK
#  include <gmock/gmock.h>

#  include "mock-log.h"
// Introduce several symbols from gmock.
using google::glog_testing::ScopedMockLog;
using testing::_;
using testing::AllOf;
using testing::AnyNumber;
using testing::HasSubstr;
using testing::InitGoogleMock;
using testing::StrictMock;
using testing::StrNe;
#endif

using namespace google;

TEST(CleanImmediately, logging) {
  using namespace std::chrono_literals;
  google::SetLogFilenameExtension(".foobar");
  google::EnableLogCleaner(0h);

  for (unsigned i = 0; i < 5; ++i) {
    sleep(2);
    LOG(INFO) << "cleanup test";
    LOG(WARNING) << "warning";
    LOG(ERROR) << "error";
  }

  google::DisableLogCleaner();
}

int main(int argc, char** argv) {
  FLAGS_colorlogtostderr = false;
  FLAGS_timestamp_in_logfile_name = true;
  FLAGS_log_dir = "./logs";
  FLAGS_logcleansecs = 1;
#ifdef GLOG_USE_GFLAGS
  ParseCommandLineFlags(&argc, &argv, true);
#endif
  // Make sure stderr is not buffered as stderr seems to be buffered
  // on recent windows.
  setbuf(stderr, nullptr);

  // Test some basics before InitGoogleLogging:
  CaptureTestStderr();
  const string early_stderr = GetCapturedTestStderr();

  EXPECT_FALSE(IsGoogleLoggingInitialized());

  InitGoogleLogging(argv[0]);

  EXPECT_TRUE(IsGoogleLoggingInitialized());

  InitGoogleTest(&argc, argv);
#ifdef HAVE_LIB_GMOCK
  InitGoogleMock(&argc, argv);
#endif

  // so that death tests run before we use threads
  CHECK_EQ(RUN_ALL_TESTS(), 0);
}

after the program finished, only INFO log was removed. The key was that I set FLAGS_logcleansecs to 1 but all logs are printed every two seconds, then clean operation was always triggered by LOG(INFO) according to following code:

glog/src/logging.cc

Lines 1315 to 1323 in 4f007d9

	// avoid scanning logs too frequently
	if (current_time < next_cleanup_time_) {
	return;
	}
	next_cleanup_time_ =
	current_time +
	std::chrono::duration_cast<std::chrono::system_clock::duration>(
	std::chrono::duration<int32>{FLAGS_logcleansecs});

Theoretically, all logs have the opportunity to be cleaned. But in reality, INFO log is much more than WARNING or ERROR, resulting in that they will never be deleted.

I'm not sure whether it is a bug. If it's a bug, I will make a PR to fix it.

[zwass]

I also ran into this issue, though I see now that Google has deprecated this project. Maybe a fix could go into the new fork?

[broken-dream]

I also ran into this issue, though I see now that Google has deprecated this project. Maybe a fix could go into the new fork?

I have made a PR to fix it in the ng-log. I'll let you know once the PR is merged.

[broken-dream]

Hi @zwass , the fix has been merged to the master branch of ng-log. You can try it now.