[Bug] Data race in log::debug() when debug logging is not enabled

[bthiae2934]

Operating System

Windows

What's the issue you encountered?

I found ImHex crashes when it starts. Here's the stack trace:

0:010> k
 # Child-SP          RetAddr               Call Site
00 0000001d`433fe3e8 00007ffb`93d89676     ntdll!NtWaitForMultipleObjects+0x14
01 0000001d`433fe3f0 00007ffb`93d892df     ntdll!WerpWaitForCrashReporting+0x82
02 0000001d`433fe470 00007ffb`93e0bcd8     ntdll!RtlReportExceptionHelper+0x4d3
03 0000001d`433fe5f0 00007ffb`93e69fe6     ntdll!RtlReportException+0x78
04 0000001d`433fe620 00007ffb`93e1f933     ntdll!RtlReportFatalFailure$filt$0+0x33
05 0000001d`433fe650 00007ffb`93e647af     ntdll!_C_specific_handler+0x93
06 0000001d`433fe6c0 00007ffb`93d221c7     ntdll!RtlpExecuteHandlerForException+0xf
07 0000001d`433fe6f0 00007ffb`93d96ea1     ntdll!RtlDispatchException+0x437
08 0000001d`433fee40 00007ffb`93e12265     ntdll!RtlRaiseException+0x221
09 0000001d`433ff620 00007ffb`93d09d69     ntdll!RtlReportFatalFailure+0x9
0a 0000001d`433ff670 00007ffb`93d75ba2     ntdll!RtlReportCriticalFailure+0xa9
0b 0000001d`433ff760 00007ffb`93e1bb3a     ntdll!RtlpHeapHandleError+0x12
0c 0000001d`433ff790 00007ffb`93d330fb     ntdll!RtlpHpHeapHandleError+0x7a
0d 0000001d`433ff7c0 00007ffb`93d2fdfa     ntdll!RtlpLogHeapFailure+0x4b
0e 0000001d`433ff7f0 00007ffb`92abd60c     ntdll!RtlFreeHeap+0x6da
0f 0000001d`433ff8e0 00007ffa`eb6676bb     msvcrt!free+0x1c
10 0000001d`433ff910 00007ffa`eb54ac6e     libimhex!ZN3hex3log4impl11addLogEntryESt17basic_string_viewIcSt11char_traitsIcEES5_NSt7__cxx1112basic_stringIcS4_SaIcEEE+0x21b
11 0000001d`433ff9b0 00007ffa`eb58aaa8     libimhex!ZN3hex3log5debugIJRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEEEvN3fmt3v127fstringIJDpT_EE1tEDpOSD_+0xae
12 0000001d`433ffa90 00007ffa`ec5da2ff     libimhex!ZN3hex11TaskManager18createBlockingTaskERKNS_17UnlocalizedStringEySt8functionIFvvEE+0x3e8
13 0000001d`433ffba0 00007ffb`7218673c     libstdc___6!atomic_flag_test_and_set_explicit+0x2cf
14 0000001d`433ffbe0 00007ffb`92adf0ad     libwinpthread_1!pthread_create_wrapper+0x9c
15 0000001d`433ffc20 00007ffb`92adf17c     msvcrt!_callthreadstartex+0x1d
16 0000001d`433ffc50 00007ffb`9304e957     msvcrt!_threadstartex+0x7c
17 0000001d`433ffc80 00007ffb`93d87c1c     kernel32!BaseThreadInitThunk+0x17
18 0000001d`433ffcb0 00000000`00000000     ntdll!RtlUserThreadStart+0x2c

The exception is about a heap operation:

0:010> !heap
**************************************************************
*                                                            *
*                  HEAP ERROR DETECTED                       *
*                                                            *
**************************************************************

Details:

Heap address:  000001ed54e70000
Error address: 000001ed5b076040
Error type:    HEAP_FAILURE_BLOCK_NOT_BUSY
Details:       The caller performed an operation (such as a free
               or a size check) that is illegal on a free block.
Follow-up:     Check the error's stack trace to find the culprit.

Stack trace:
Stack trace at 0x00007ffb93ecc138
    00007ffb93d330fb: ntdll!RtlpLogHeapFailure+0x4b
    00007ffb93d2fdfa: ntdll!RtlFreeHeap+0x6da
    00007ffb92abd60c: msvcrt!free+0x1c
    00007ffaeb6676bb: libimhex!ZN3hex3log4impl11addLogEntryESt17basic_string_viewIcSt11char_traitsIcEES5_NSt7__cxx1112basic_stringIcS4_SaIcEEE+0x21b
    00007ffaeb54ac6e: libimhex!ZN3hex3log5debugIJRKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEEEEvN3fmt3v127fstringIJDpT_EE1tEDpOSD_+0xae
    00007ffaeb58aaa8: libimhex!ZN3hex11TaskManager18createBlockingTaskERKNS_17UnlocalizedStringEySt8functionIFvvEE+0x3e8
    00007ffaec5da2ff: libstdc___6!atomic_flag_test_and_set_explicit+0x2cf
    00007ffb7218673c: libwinpthread_1!pthread_create_wrapper+0x9c
    00007ffb92adf0ad: msvcrt!_callthreadstartex+0x1d
    00007ffb92adf17c: msvcrt!_threadstartex+0x7c
    00007ffb9304e957: kernel32!BaseThreadInitThunk+0x17
    00007ffb93d87c1c: ntdll!RtlUserThreadStart+0x2c

I analyzed the crash dump and found that it's about a double free of memory of std::vector.
I checked the code and found addLogEntry is not protected by mutex:

    template<typename ... Args>
    [[maybe_unused]] void debug(fmt::format_string<Args...> fmt, Args && ... args) {
        if (impl::isDebugLoggingEnabled()) [[unlikely]] {
            impl::print(fg(impl::color::debug()) | fmt::emphasis::bold, "[DEBUG]", fmt, std::forward<Args>(args)...);
        } else {
            impl::addLogEntry(IMHEX_PROJECT_NAME, "[DEBUG]", fmt::format(fmt, std::forward<Args>(args)...));
        }
    }

        void addLogEntry(std::string_view project, std::string_view level, std::string message) {
            s_logEntries->emplace_back(
                project,
                level,
                std::move(message)
            );
        }

The print method is protected:

    template<typename ... Args>
    [[maybe_unused]] void print(fmt::format_string<Args...> fmt, Args && ... args) {
        impl::lockLoggerMutex();
        ON_SCOPE_EXIT { impl::unlockLoggerMutex(); };
...

How can the issue be reproduced?

Right click a file and select "open by ImHex".

ImHex Version

1.38.1

ImHex Build Type

• Nightly or built from sources

Installation type

MSI

Additional context?

No response