Using spdlog to output logs makes my programme stuck and unable to continue.

[Mq-b]

Dump File:

#include "Timer.h"

Timer::Timer() = default;

Timer::~Timer() {
    stop = true;
}

void Timer::start(){
    stop = false;
    run();
}

void Timer::addTask(const std::function<void()>& task, std::chrono::milliseconds interval, TaskType type) {
    tasks[static_cast<std::size_t>(type)] = {task, interval};
}

void Timer::run() {
    
    std::array<std::chrono::time_point<std::chrono::steady_clock>, 2> nextExecutionTimes;
    auto now = std::chrono::steady_clock::now();
    for (std::size_t i = 0; i < tasks.size(); ++i) {
        nextExecutionTimes[i] = now + tasks[i].interval;
    }

    while (!stop) {

        if (stop) break;

        auto now = std::chrono::steady_clock::now();

        auto nextTaskTime = *std::min_element(nextExecutionTimes.begin(), nextExecutionTimes.end());

        spdlog::info("Sleep...... {}", nextTaskTime - now);
        if (nextTaskTime > now) {
            std::this_thread::sleep_for(nextTaskTime - now);
        }
        spdlog::info("run.....");

        now = std::chrono::steady_clock::now();

        for (std::size_t i = 0; i < tasks.size(); ++i) {
            spdlog::info("run2.....");
            if (now >= nextExecutionTimes[i]) {
                spdlog::info("run3.....");
                tasks[i].func();

                nextExecutionTimes[i] = now + tasks[i].interval;
                spdlog::info("Task {} executed, next execution at: {}", i, formatTimePoint(nextExecutionTimes[i]));
            }
        }
    }
}

set spdlog code:

inline void setupLogging() {
    if (std::filesystem::exists("Log")) {
        std::filesystem::create_directory("Log");
    }
    auto file_sink = std::make_shared<spdlog::sinks::daily_file_sink_mt>("Log/daily.log", 0, 0);
    file_sink->set_level(spdlog::level::debug);
    file_sink->set_pattern("[%Y-%m-%d %H:%M:%S] [thread %t] [%oms] [%l] %v");

    auto console_sink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
    console_sink->set_level(spdlog::level::debug);
    console_sink->set_pattern("%^[%Y-%m-%d %H:%M:%S] [thread %t] [%oms] [%l] %v%$");

    auto logger = std::make_shared<spdlog::logger>("multi_sink", spdlog::sinks_init_list{ file_sink, console_sink });
    spdlog::register_logger(logger);

    spdlog::set_default_logger(logger);
    spdlog::flush_on(spdlog::level::debug);
}

[2025-03-25 15:57:11] [thread 7852] [3ms] [info] Sleep...... 59999999600ns
[2025-03-25 15:58:11] [thread 7852] [60002ms] [info] run.....
[2025-03-25 15:59:16] [thread 7852] [64117ms] [info] run2.....
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] run3.....
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] Reporting device status to server.
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] POST request to /report
[2025-03-25 15:59:16] [thread 7852] [591ms] [info] POST for
[2025-03-25 15:59:16] [thread 7852] [1ms] [info] POST Response code: 200
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] POST Response body: Yes
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] POST request successful.
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] Task 0 executed, next execution at: 2025-03-25 16:00:16
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] run2.....
[2025-03-25 15:59:16] [thread 7852] [0ms] [info] Sleep...... 59403475200ns
[2025-03-25 16:00:16] [thread 7852] [59405ms] [info] run.....
[2025-03-25 16:03:16] [thread 7852] [180041ms] [info] run2.....
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] run3.....
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] Reporting device status to server.
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] POST request to /report
[2025-03-25 16:03:16] [thread 7852] [239ms] [info] POST for
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] POST Response code: 200
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] POST Response body: Yes
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] POST request successful.
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] Task 0 executed, next execution at: 2025-03-25 16:04:16
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] run2.....
[2025-03-25 16:03:16] [thread 7852] [0ms] [info] Sleep...... 59756764000ns

[Mq-b]

The amazing thing is that I can't reproduce the encounter with my own developed machine (windows 11), but the windows 10 machine I deployed does.

[gabime]

Try installing latest vc runtime in the stuck machine

[Mq-b]

Thank you very much for your reply, I'll try it tomorrow when I go to work.

Can you give some of your further guesses? Because I've always liked to use spdlog, I've been testing it for a long time, doubting the standard library, doubting myself, but not even sceptical of spdlog.

But when I debugged the dump file, I realised that it was because of it.

[Mq-b]

I tested it again overnight and found that the code it blocks is:

auto ignored = ::WriteConsoleA(static_cast<HANDLE>(out_handle_), formatted.data() + start,
                                      size, nullptr, nullptr);

[Mq-b]

It's the same as before.

[tt4g]

WriteConsoleA() is a Windows API, and if it hangs, there is most likely a problem with that machine.
Does simple stdout such as std::cout << “hello” << std::end; work?

And, are the development machine and the machine with the problem using the same version Windows OS?

Tip

If we believe the comments on StackOverflow (https://stackoverflow.com/questions/55560959/is-there-a-way-to-output-ansi-escape-sequences-using-low-level-output#comment97839031_55560959),
it appears that WriteConsole started using NtDeviceIoControlFile in versions later than Windows 8.
It would not be compatible with any Windows OS before that.

It's documented that VT support is implemented only for the high-level stream functions WriteFile (i.e. NtWriteFile in Windows 8+, but the syscall is an implementation detail; it was different in Windows 7) and WriteConsole (i.e. NtDeviceIoControlFile in Windows 8+, for a screen-buffer file, using an undocumented IOCTL code). The low-level console API is character-cell based instead of stream-like, so it's not compatible with a virtual-terminal interface. The character-cell API performs better, but it comes at the cost of losing high-level processing.

[Mq-b]

I use

#pragma comment(linker, "/SUBSYSTEM:WINDOWS /ENTRY:mainCRTStartup")

Works fine for the time being after closing the console.