gabime / spdlog

Fast C++ logging library.
Other
24.37k stars 4.55k forks source link

Daily Logger - daily rotations and confusing target file names #3246

Open onavratil-monetplus opened 5 days ago

onavratil-monetplus commented 5 days ago

I was experimenting with daily filename rotation, like this:


        // Prepare sink
        std::shared_ptr<spdlog::sinks::sink> targetSink;
        if (loggerConfig.daily){
            Logger::info("Creating daily logger sink.");
            targetSink = std::make_shared<spdlog::sinks::daily_file_sink_mt>(loggerConfig.fileName, loggerConfig.hours, loggerConfig.minutes, false, loggerConfig.maxFiles);
        }
        else{
            Logger::info("Creating stdout logger sink.");
            targetSink = std::make_shared<spdlog::sinks::stdout_sink_mt>();
        }

        //Prepare logger
        std::shared_ptr<spdlog::logger> targetLogger; 
        if(loggerConfig.async){
            Logger::info("Creating async logger.");
            spdlog::init_thread_pool(loggerConfig.queueItems, loggerConfig.threadCount);
            targetLogger = std::make_shared<spdlog::async_logger>("async_logger", targetSink, spdlog::thread_pool());
        }
        else {
            Logger::info("Creating sync logger.");
            targetLogger = std::make_shared<spdlog::logger>("sync_logger", targetSink);
        }
        targetLogger->set_pattern(Logger::PATTERN);
        spdlog::set_default_logger(targetLogger);

I wanted to test the rotation, i.e. I set the hour and minute to like ~1-2min ahead, started my app, poked it to produce some logs, and expected to see new file created in the log folder in a few mins.

Which did not happen.

The logger constructor calculates the initial log filename based on current date/time

        auto now = log_clock::now();
        auto filename = FileNameCalc::calc_filename(base_filename_, now_tm(now));

Then, when rotation occurs, this happens

        bool should_rotate = time >= rotation_tp_;
        if (should_rotate)
        {
            auto filename = FileNameCalc::calc_filename(base_filename_, now_tm(time));
            file_helper_.open(filename, truncate_);
            rotation_tp_ = next_rotation_tp_();
        }

Once again, the filename is determined by the log entry count, and the date remains unchanged.

This is kind of tricky to figure out, and even harder to debug. I suggest at least to make a documentation entry.

Moreover, in extreme cases, this may lead to unexpected/undefined behavior:

gabime commented 5 days ago

The daily logger has indeed some issues. The queue stuff for example, which means that after app restart/crash, the queue would be empty. Improvements/suggestions/PR are welcome. Breaking changes are also ok since we could have a new daily sink v2 and deprecate the current. For example I dont think it should support max file count as it complicates greatly the implementation and it is really the job of some cron job.