Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crash on Windows x64 in spdlog_ex constructor #2902

Closed
ezemskov opened this issue Oct 11, 2023 · 18 comments
Closed

Crash on Windows x64 in spdlog_ex constructor #2902

ezemskov opened this issue Oct 11, 2023 · 18 comments

Comments

@ezemskov
Copy link

ezemskov commented Oct 11, 2023

Hi Gabi,

We're using spdlog 1.11.0 with external libfmt 1.9.0, on Windows with VS2019 (v142 toolchain, x64 build)
If the file configured for a filesink is no write-accessible, spdlog release build would crash (on access violation ?), inside fmt::v9::format_system_error(...) call
debug build would throw a spdlog::spdlog_ex exception successfully (although, spdlog_ex::what() would return garbage)
Replacing lines 62-63 from spdlog\common-inl.h (that is, format_system_error(...) call) with following workarounds the issue.
msg_ = msg;

Stack trace and caller code are below

 	[Inline Frame] Land_ViDAR_GUI.exe!std::exception::{dtor}() Line 90	C++
 	Land_ViDAR_GUI.exe!fmt::v9::format_system_error(fmt::v9::detail::buffer<char> & out={...}, int error_code=13, const char * message=0x0000021cd7fd87b0) Line 1456	C++
 	Land_ViDAR_GUI.exe!spdlog::spdlog_ex::spdlog_ex(const std::string & msg, int last_errno) Line 63	C++
 	Land_ViDAR_GUI.exe!spdlog::throw_spdlog_ex(const std::string & msg, int last_errno) Line 74	C++
 	Land_ViDAR_GUI.exe!spdlog::details::file_helper::open(const std::string & fname={...}, bool truncate=false) Line 73	C++
>	Land_ViDAR_GUI.exe!spdlog::sinks::basic_file_sink<std::mutex>::basic_file_sink<std::mutex>(const std::string & filename={...}, bool truncate, const spdlog::file_event_handlers & event_handlers={...}) Line 20	C++
 	[Inline Frame] Land_ViDAR_GUI.exe!std::_Construct_in_place(spdlog::sinks::basic_file_sink<std::mutex> &) Line 151	C++
 	[Inline Frame] Land_ViDAR_GUI.exe!std::_Ref_count_obj2<spdlog::sinks::basic_file_sink<std::mutex>>::{ctor}(const std::string &&) Line 2029	C++
 	[Inline Frame] Land_ViDAR_GUI.exe!std::make_shared(const std::string &&) Line 2748	C++
 	Land_ViDAR_GUI.exe!SVS::SpdlogConfig::AddFileSinkToLogger(const std::string & filename={...}, spdlog::level::level_enum fileLevel=trace, spdlog::logger & logger={...}, std::unordered_map<std::string,std::shared_ptr<spdlog::sinks::basic_file_sink<std::mutex>>,std::hash<std::string>,std::equal_to<std::string>,std::allocator<std::pair<std::string const ,std::shared_ptr<spdlog::sinks::basic_file_sink<std::mutex>>>>> & filenameToSinkLookup={...}) Line 448	C++
		try {
			fileSink = std::make_shared<spdlog::sinks::basic_file_sink_mt>((m_logDirectory / filename).string(), false); 
                }
		catch (spdlog::spdlog_ex const& ex) {
                       //exception handler code
		}
@tt4g
Copy link
Contributor

tt4g commented Oct 12, 2023

C++ will not work properly if debug and release builds are mixed.
During debug builds, additional debugging information is stored in each object, but release builds do not have it, so the memory layout is different.
This causes an access violation.

Please unify only debug and release builds.

@ezemskov
Copy link
Author

Thanks for the response.
To clarify - it crashes when I run RelWithDebInfo builds of my application, spdlog.lib and libfmt.lib

Can't link a Release (that is - Release w/o debug info) build of my application (because of some unrelated issue), but don't think I'm mixing Debug and any kind of Release binaries

@tt4g
Copy link
Contributor

tt4g commented Oct 12, 2023

Since the error is occurring in the following code, the build mode (Relase/Debug) of spdlog.lib and libfmt.lib is considered to be different.

SPDLOG_INLINE spdlog_ex::spdlog_ex(const std::string &msg, int last_errno) {
#ifdef SPDLOG_USE_STD_FORMAT
msg_ = std::system_error(std::error_code(last_errno, std::generic_category()), msg).what();
#else
memory_buf_t outbuf;
fmt::format_system_error(outbuf, last_errno, msg.c_str());
msg_ = fmt::to_string(outbuf);
#endif
}

I don't know what you think, but if C++ debugging information is enabled, additional variables are allocated in STL.
The added debug variables allow for investigation by the debugger.
Even if the same object is built with debug information (debug build) and without debug information (release build), the memory layouts do not match, resulting in an access violation at runtime.

Furthermore, Visual Studio has different C++ runtime libraries that are linked depending on the build mode, so libraries built with incompatible build modes cannot even be linked together (I assume this is the reason you cannot link in your release builds).

Where did you get spdlog.lib and libfmt.lib from? Did you make sure they were built with the same build mode?

See also: https://stackoverflow.com/questions/11658915/mixing-debug-and-release-library-binary-bad-practice

@ezemskov
Copy link
Author

Yes, both spdlog.lib and libfmt.lib built myself in the same environment.
Will try to reproduce it in a trivial demo application.
My linking errors in Release are related to CEF library (which is likely built with some debug symbols, indeed).
Thanks for pointing me at stackoverflow discussion, anyway.

@gabime gabime closed this as completed Oct 15, 2023
@zchrissirhcz
Copy link

zchrissirhcz commented Jun 29, 2024

Hi, @ezemskov, @tt4g and @gabime

I get a similar crash on Windows x64 with latest VS2022 (17.10.3), and I searched in existing issues, and this issue is perhaps the most relevant one.

Minimal Reproduce Steps

Visual Studio Version

image

Get code

Get latest code of spdlog:

git clone ssh://git@github.com/gabime/spdlog

which is the latest commit of branch v1.x:

commit c3aed4b68373955e1cc94307683d44dca1515d2b (HEAD -> v1.x, origin/v1.x, origin/HEAD)
Author: Dominik Grabiec <dominik@dominikgrabiec.com>
Date:   Tue May 21 23:20:17 2024 +0200

    Add wide character formatting and output support to wincolor_sink. (#3092)

    Fixes printing of unicode characters to the windows console such as microsecond suffix for std::chrono types.

build

Then build it with commands:

cd spdlog
cmake -S . -B build -G "Visual Studio 17 2022" -A x64

then open build/spdlog.sln, select example project as startup project, and replace content of example.cpp with

#include <spdlog/spdlog.h>

int main()
{
    SPDLOG_INFO("x");
    return 0;
}
image

Ensure the configuration type is RelWithDebInfo, then click the green triangle button (Local Windows Debugger):

image

Then it just run and crash:

image

Configuration types

I can reproduce only in Release and RelWithDebInfo configurations. However, I'm not sure if I have correct understanding of what Release and RelWithDebInfo configurations are.

The previous message by @tt4g, mentions additional variables allocated in STL:

I don't know what you think, but if C++ debugging information is enabled, additional variables are allocated in STL.
The added debug variables allow for investigation by the debugger.
Could you please give some example reproducible code to illustrate this "additional variables allocated in STL" ? @tt4g

I know there is RelWithDebInfo configuration in Visual Studio's configurations:

image

And in my understanding, the Debug configuration is a combination of compiler options, and one of them is /RTC1, which is equivalent to /RTCsu ( /RTC (Run-time error checks) ), which is combination of /RTCs and /RTCu. And /RTCs enables stack frame run-time error checking, which includes:

Detection of overruns and underruns of local variables such as arrays. /RTCs doesn't detect overruns when accessing memory that results from compiler padding within a structure. Padding could occur by using align, /Zp (Struct Member Alignment), or pack, or if you order structure elements in such a way as to require the compiler to add padding.

I'm not sure if the aforementioned "additional allocated variables in STL" is the same as /RTCs's stack frame run-time error checking?

@tt4g
Copy link
Contributor

tt4g commented Jun 29, 2024

cd spdlog
cmake -S . -B build -G "Visual Studio 17 2022" -A x64

@zchrissirhcz This command builds spdlog with Debug configuration and should not be used in combination with Release or RelWithDebInfo.

If you are going to release build an application, you must also release build spdlog.

cd spdlog
cmake -S . -B build -G "Visual Studio 17 2022" -A x64 -DCMAKE_BUILD_TYPE=Release

@zchrissirhcz
Copy link

@tt4g -G "Visual Studio 17 2022" means using MSBuild, which is a Multi-Config generator. Multi-Config generator will have multiple configurations, it defaults to {Debug, Release, RelWithDebInfo, MinSizeRel}, and can be specified with CMAKE_CONFIGURATIONS_TYPES variable.

That it to say, -G "Visual Studio 17 2022" -A x64 does not restrict the spdlog.sln to only build Debug configuration. The configuration is determined via:

  • command line argument, e.g.
    • cmake --build build --config Debug: this builds Debug
    • cmake --build build --config Release: this builds Release
    • cmake --build build: this does not specify configrations, which will usually use Debug
  • Visual Studio solution interface, i.e.
    • image
    • it is usually default to Debug

    • But user can switch to other configuration

In the CMake document, https://cmake.org/cmake/help/latest/prop_gbl/GENERATOR_IS_MULTI_CONFIG.html , Visual Studio generators are marked as Multi-Config generators.

For my reproduce case, I built it in Visual Studio, there is no other dependencies. the bug reproduce when I choose Release or RelWithDebInfo configuration types.

Could you please give an example that "additional variables are allocated in STL" ? @tt4g

@tt4g
Copy link
Contributor

tt4g commented Jun 30, 2024

@zchrissirhcz I don't remember the comment "additional variables are allocated in STL", it is well known that in debug builds additional symbols are added to allow debugging.
The link in this issue explains that in https://stackoverflow.com/a/31810986 the iterator access range check is enabled by the _ITERATOR_DEBUG_LEVEL macro.

However, it is Microsoft that maintains the STL for MSVC. We do not know the exact specifications of the STL.
Please ask in the STL repository (https://github.com/microsoft/STL) what additional variables the STL has on debug builds.

A search for _ITERATOR_DEBUG_LEVEL in code search turns up a lot of codes, but I have never looked into them to see what they do.

@tt4g
Copy link
Contributor

tt4g commented Jun 30, 2024

@zchrissirhcz I just noticed that std::mutex::lock() seems to be crashing in your first comment.
This indicates that std::mutex is not working on your machine, not spdlog.
Have you checked that std::mutex::lock() works without spdlog?

@zchrissirhcz
Copy link

zchrissirhcz commented Jun 30, 2024

@tt4g Thanks for the link https://stackoverflow.com/a/31810986 . Now I know what that means.

I did not check std::mutex::lock(). I just uninstalled the latest (17.10.3) VS2022, re-installed an old version (17.9.7), and cannot reproduce it now.

(I follow the steps in https://learn.microsoft.com/en-us/visualstudio/releases/2022/release-history#uninstalling-visual-studio-to-go-back-to-an-earlier-release to uninstall-reinstall)

@zchrissirhcz
Copy link

I'm not familiar with std::mutex::lock(), could you suggest some use case of that? I think I can re-install the latest version of VS2022(17.10.3) while keep the 17.9.7. @tt4g

@tt4g
Copy link
Contributor

tt4g commented Jun 30, 2024

@zchrissirhcz Probably the same problem as this issue: microsoft/STL#4730
If you build the same code as in the issue and the "End!" is not printed, then the STL and runtime are incompatible.

#include <iostream>
#include <mutex>
std::mutex mtx;

void testmethod() {
        std::scoped_lock lock{ mtx };
        std::cout << "lock worked!\n";
}
int main()
{
    std::cout << "Start!\n";
    testmethod();
    std::cout << "End!\n";
    return 0;
}

@zchrissirhcz
Copy link

zchrissirhcz commented Jun 30, 2024

@tt4g Thanks for the reference link microsoft/STL#4730 and code.

C++17

To be precise, C++17 is required, i.e. in CMakeLists.txt:

set(CMAKE_CXX_STANDARD 17)

This solves the compile errors:

C:\work\dbg\x>cmake --build build --config Debug
MSBuild version 17.9.8+b34f75857 for .NET Framework

  main2.cpp
C:\work\dbg\x\main2.cpp(6,14): error C2039: 'scoped_lock': is not a member of 'std' [C:\work\dbg\x\build\testbed.vcxproj]
  C:\Program Files\Microsoft Visual Studio\2022\Enterprise\VC\Tools\MSVC\14.39.33519\include\mutex(29,1):
  see declaration of 'std'

C:\work\dbg\x\main2.cpp(6,14): error C2065: 'scoped_lock': undeclared identifier [C:\work\dbg\x\build\testbed.vcxproj]
C:\work\dbg\x\main2.cpp(6,26): error C2146: syntax error: missing ';' before identifier 'lock' [C:\work\dbg\x\build\testbed.vcxproj]
C:\work\dbg\x\main2.cpp(6,26): error C2065: 'lock': undeclared identifier [C:\work\dbg\x\build\testbed.vcxproj]

VS2022 17.9.7 Result

Release

C:\work\dbg\x\build>.\Release\testbed.exe
Start!
lock worked!
End!

Debug

C:\work\dbg\x\build>.\Debug\testbed.exe
Start!
lock worked!
End!

VS2022 17.10.3 Result

Still in the progress of re-installing...

VS2022 17.10.3, the "End!" is not printed.

Steps:

C:\work\dbg\y>cl

Microsoft (R) C/C++ Optimizing Compiler Version 19.40.33811 for x64
Copyright (C) Microsoft Corporation.  All rights reserved.

usage: cl [ option... ] filename... [ /link linkoption... ]


cd C:\work\dbg\y
C:\work\dbg\vim ConsoleApplication5.cpp
C:\work\dbg\y>mkdir x64
C:\work\dbg\y>cd x64
C:\work\dbg\y\x64>mkdir Release
C:\work\dbg\y\x64>cd ..

cl /c /Zi /W3 /WX- /diagnostics:column /sdl /O2 /Oi /GL /D NDEBUG /D _CONSOLE /D _UNICODE /D UNICODE /Gm- /EHsc /MD /GS /Gy /fp:precise /Zc:wchar_t /Zc:forScope /Zc:inline /std:c++17 /permissive- /Fo"x64\Release\\" /Fd"x64\Release\vc143.pdb" /external:W3 /Gd /TP /FC /errorReport:prompt ConsoleApplication5.cpp

link x64\Release\ConsoleApplication5.obj

Output:

C:\work\dbg\y>.\ConsoleApplication5.exe
Start!

C:\work\dbg\y>

@zchrissirhcz
Copy link

So, let me do a short conclusion:

  • My minimal reproduce crash code, only occurs on Windows x64 with VS2022 >= 17.10.0 version, only in Release or RelWithDebInfo configuration
  • To resolve that crash, user just have to define the macro _DISABLE_CONSTEXPR_MUTEX_CONSTRUCTOR for spdlog library and user code, e.g. in CMakeLists.txt:
add_compile_definitions(_DISABLE_CONSTEXPR_MUTEX_CONSTRUCTOR)
Fixed bugs:
Fixed mutex's constructor to be constexpr. [#3824](https://github.com/microsoft/STL/pull/3824) [#4000](https://github.com/microsoft/STL/pull/4000) [#4339](https://github.com/microsoft/STL/pull/4339)
Note: Programs that aren't following the documented [restrictions on binary compatibility](https://learn.microsoft.com/en-us/cpp/porting/binary-compat-2015-2017?view=msvc-170) may encounter null dereferences in mutex machinery. You must follow this rule:
When you mix binaries built by different supported versions of the toolset, the Redistributable version must be at least as new as the latest toolset used by any app component.

You can define _DISABLE_CONSTEXPR_MUTEX_CONSTRUCTOR as an escape hatch.

@zchrissirhcz
Copy link

From the side of STL implementation and spdlog implementation:

  • The std::mutex::mutex should be constexpr as of C++11, but before VS2022 17.10.0, the MSVC STL's implementation does not support it, and it seems to be a bug.
  • The VS2022 17.10.0 fixed that.
  • Should spdlog determine VS2022 before 17.10.0 and after that version? And write different code for thme? @tt4g @gabime

@tt4g
Copy link
Contributor

tt4g commented Jun 30, 2024

This problem does not seem to occur if the Microsoft Visual C++ 2015-2022 Redistributable package and toolset is up-to-date, even if it is Visual Studio version 17.10.0 or later.

@zchrissirhcz
Copy link

I check my installation of Microsoft Visual C++ 2015-2022 Redistributable package in control panel, they are 14.40.33810.0 version:

image

In a PowerShell, I check the vcruntime140.dll path and version:

PS C:\work\dbg\x> echo ((Get-Command vcruntime140.dll).Path)
C:\Windows\system32\vcruntime140.dll
PS C:\work\dbg\x> echo ((Get-Command vcruntime140.dll).Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     27     29112  0

I also tried first get all paths of vcruntime140.dll files with the software "everything search", then pick 4 of them and get versions:

PS C:\work\dbg\x> echo ((Get-Command "C:\Program Files\Microsoft Visual Studio\2022\Enterprise\VC\Tools\MSVC\14.39.33519\bin\Hostx64\x64\vcruntime140.dll").Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     39     33523  0


PS C:\work\dbg\x> echo ((Get-Command "C:\Program Files\Microsoft Visual Studio\2022\Community\VC\Tools\MSVC\14.40.33807\bin\Hostx64\x64\vcruntime140.dll").Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     40     33811  0


PS C:\work\dbg\x> echo ((Get-Command "C:\Program Files\Microsoft Visual Studio\2022\Community\VC\Redist\MSVC\14.40.33807\x64\Microsoft.VC143.CRT\vcruntime140.dll").Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     40     33810  0


PS C:\work\dbg\x> echo ((Get-Command "C:\Program Files\Microsoft Visual Studio\2022\Enterprise\VC\Redist\MSVC\14.38.33135\x64\Microsoft.VC143.CRT\vcruntime140.dll").Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     38     33135  0

@zchrissirhcz
Copy link

zchrissirhcz commented Jun 30, 2024

@tt4g Thanks for the link https://stackoverflow.com/questions/78598141/first-stdmutexlock-crashes-in-application-built-with-latest-visual-studio/78599923#78599923 . After a repair of the vc redist package and a Windows reboot, it solved.

Let me do a short conclusion again:

  1. The crash occurs only in:

    • vcruntime140.dll version < 14.40, say, 14.27.29112
    • Visual Studio 2022 >= 17.10.0
    • In Release or RelWithDebInfo mode
    • No ASAN (/fsanitize=address) options required
  2. If users meet similar crash, and would not like to update/reinstall environment, users can define _DISABLE_CONSTEXPR_MUTEX_CONSTRUCTOR macro for quick fix.

  3. If users would like to keep code and build scripts clean, i.e. not add a definition of _DISABLE_CONSTEXPR_MUTEX_CONSTRUCTOR macro, users should update their environment by:

  • Update VS2022 to >= 17.10.0
  • Ensure "vcruntime140.dll" version >= 14.40.0
    • In control panel, ensure "Microsoft Visual C++ 2015-2022 Redistributable" package is >= 14.40.0
    • If the "Microsoft Visual C++ 2015-2022 Redistributable" package was installed by previous Visual Studio Installer, consider repair it even if it shows >= 14.40.0 ( a Windows reboot is also required):
      image
    • Determine vcruntime140.dll's version in PowerShell, e.g.
PS C:\work\dbg\x\build2> echo ((Get-Command vcruntime140.dll).Path)
C:\Windows\system32\vcruntime140.dll
PS C:\work\dbg\x\build2> echo ((Get-Command vcruntime140.dll).Version)

Major  Minor  Build  Revision
-----  -----  -----  --------
14     40     33810  0
  • Then do a fresh build with aforementioned std::mutex related code, it will run OK.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants