[Question] No logs found in rotating file when used in an async sink (using log crate proxy)

[loggerheads-with-binary]

Describe the bug

When running an async sink using a rotating file sink and a stderr sink, I am able to find all the logs correctly on the stderr, but none of them seem to be redirected to the rotating file sink. Note: I am using the log crate proxy to redirect application logs sent to the log crate.

To Reproduce

Steps to reproduce the behavior:

1. Setup a stderr sink

    let stderr_sink = spdlog::sink::StdStreamSink::builder()
        .std_stream(spdlog::sink::StdStream::Stderr)
        .level_filter(spdlog::LevelFilter::All)
        .build()
        .with_context(|| "Failed to build stderr sink")?;

2. Setup a rotating sink

    let rotating_sink = spdlog::sink::RotatingFileSink::builder()
        .base_path(base_file)
        .rotation_policy(spdlog::sink::RotationPolicy::Daily { hour: 0, minute: 0 })
        .max_files(10)
        .level_filter(spdlog::LevelFilter::All)
        .build()
        .with_context(|| "Failed to build rotating file sink")?;

3. Setup async sink

    let rotating_sink = Arc::new(rotating_sink);
    let stderr_sink = Arc::new(stderr_sink);
    let async_sink = AsyncPoolSink::builder()
        .sink(stderr_sink.clone())
        .sink(rotating_sink.clone())
        .level_filter(spdlog::LevelFilter::All)
        .overflow_policy(spdlog::sink::OverflowPolicy::Block)
        .build()
        .with_context(|| "Failed to build async pool sink")?;

4. Setup logger

    let logger = spdlog::Logger::builder()
        .sink(Arc::new(async_sink))
        .level_filter(spdlog::LevelFilter::All)
        .flush_level_filter(spdlog::LevelFilter::MoreSevereEqual(spdlog::Level::Warn))
        .build()
        .with_context(|| "Failed to build logger")?;

5. Setup log crate proxy

    log::set_max_level(log::LevelFilter::Trace);

    //Connect to log crate
    spdlog::init_log_crate_proxy()
        .expect("users should only call `init_log_crate_proxy` function once");

    spdlog::log_crate_proxy().set_logger(Some(logger.into()));

Expected behavior

File should also have the same logs as the stderr stream

Screenshots

Environments

• OS: Windows 11
• Version: Build 22631

Additional context

I am using the log crate proxy mechanism

[SpriteOvO]

I'm guessing the reason is that you set flush_level_filter(MoreSevereEqual(Warn)) for the logger, so the logs won't be flushed to a file unless there's a critical, error, warn log, or if the internal buffer is full.

You can try setting up an automatic periodic flush via Logger::set_flush_period, which will ensure that the logs are flushed into the file at the regular interval.

However, for AsyncPoolSink + File/RotatingFileSink users, I recommend reading discussion #57 first so you will understand how they work internally, and then can reconsider whether AsyncPoolSink is really needed here. (I might add it to the documentation later)

[loggerheads-with-binary]

Hi, @SpriteOvO; thanks so much for the speedy and detailed answer.

You can try setting up an automatic periodic flush via Logger::set_flush_period, which will ensure that the logs are flushed into the file at the regular interval.

The Logger::set_flush_period worked. Most of my logs were info level or below, so they never got forwarded.

Thanks a lot

I recommend reading discussion #57 first so you will understand how they work internally

I did go through the ASyncPoolSink documentation. Personally, I was concerned about the stderr logger more than the file based one. If I understand correctly, the stderr in rust is unbuffered. So even inside of a buffer, it might block my operations. That is what I am primarily trying to avoid.

My application generates about 1 log/5ms. I am not sure if the stderr stream might be able to handle that in a way that does not impact performance. Which is why I was offloading that to the AsyncSink to forward it to a separate thread altogether.