spdlog icon indicating copy to clipboard operation
spdlog copied to clipboard

Windows: flush_every stops working when adjusting system clock backwards

Open kbridge opened this issue 5 years ago • 13 comments

Tested using VS2017.

To reproduce:

#include <iostream>
#include <spdlog/spdlog.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <windows.h>

int main()
{
	// use Bash from Git for Windows
	//
	// $ touch app.log
	// $ tail -f app.log

	auto file_logger = spdlog::basic_logger_mt("default", "app.log");
	spdlog::set_default_logger(file_logger);
	
	spdlog::flush_every(std::chrono::seconds(1));

	spdlog::info("first");

	// change system time to an earlier point, then press enter
	//
	// C:\>time 10:00

	getchar();

	// then you won't see this line

	spdlog::info("second");

	for (;;) { Sleep(1000); }
	return 0;
}

Similar to issue #609. But caused by MSVC's buggy implementation of std::condition_variable::wait_for. (According to cppreference, this function must use a steady clock.)

File periodic_worker-inl.h:

SPDLOG_INLINE periodic_worker::periodic_worker(const std::function<void()> &callback_fun, std::chrono::seconds interval)
{
    active_ = (interval > std::chrono::seconds::zero());
    if (!active_)
    {
        return;
    }

    worker_thread_ = std::thread([this, callback_fun, interval]() {
        for (;;)
        {
            std::unique_lock<std::mutex> lock(this->mutex_);
            // ↓ THIS LINE
            if (this->cv_.wait_for(lock, interval, [this] { return !this->active_; }))
            {
                return; // active_ == false, so exit this thread
            }
            callback_fun();
        }
    });
}

I try to replace std::mutex & std::condition_variable to CRITICAL_SECTION & CONDITION_VARIABLE, then the problem disappears.

kbridge avatar Aug 30 '19 08:08 kbridge

Possible (quick and dirty) fix:

  • ~~https://github.com/kbridge/spdlog/blob/v1.x/include/spdlog/details/periodic_worker.h~~
  • ~~https://github.com/kbridge/spdlog/blob/v1.x/include/spdlog/details/periodic_worker-inl.h~~

↓ See below

kbridge avatar Aug 30 '19 08:08 kbridge

Thanks. Seems very similar #947 isn't it?

gabime avatar Aug 30 '19 08:08 gabime

Yes. Can't believe g++ has the same issue. These buggy standard libraries... :disappointed:

kbridge avatar Aug 30 '19 09:08 kbridge

@gabime Would you like to add a workaround, or leave this to standard library implementors?

kbridge avatar Aug 30 '19 09:08 kbridge

Lets leave it - it will never end if spdlog try to reimplement buggy standard lib features. I think it out of spdlog’s scope..

gabime avatar Aug 30 '19 09:08 gabime

Of course this is out of spdlog's scope!

To be helpful, let me post my workaround here, for people who suffer. Then we can close this issue.

kbridge avatar Aug 30 '19 09:08 kbridge

Sure. Thanks. if you could make it portable to gcc as well, it would be super!

gabime avatar Aug 30 '19 09:08 gabime

spdlog periodic_worker workaround for MSVC

https://gist.github.com/kbridge/251808f0cb7411782c3a2ce5f4877287

kbridge avatar Aug 30 '19 09:08 kbridge

I think I will try someday, or maybe someone else. I'm a Windows programmer. Haven't been working with pthreads for a long time.

kbridge avatar Aug 30 '19 09:08 kbridge

I will leave this open. Its important for users to be aware of this.

gabime avatar Aug 30 '19 09:08 gabime

Related SO: https://stackoverflow.com/questions/47349751/stdconditional-variablewait-for-stdthreadsleep-for-on-windows-are-affec

gabime avatar Aug 30 '19 09:08 gabime

duplicate of #947

gabime avatar Aug 30 '19 10:08 gabime

duplicate of#947

omnaladkar avatar Dec 11 '20 06:12 omnaladkar