Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Only INFO level logs are delteded when LogCleaner is enabled #1154

Open
broken-dream opened this issue Feb 21, 2025 · 0 comments
Open

Only INFO level logs are delteded when LogCleaner is enabled #1154

broken-dream opened this issue Feb 21, 2025 · 0 comments

Comments

@broken-dream
Copy link

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant