Repository navigation
Win32 Access Violation in EnterCriticalSection when application exits that has multiple mixed mode managed .dlls in .NET runtime inside trace.cpp trace::flush #75760
Description
Description
The software uses multiple mixed/mode C++ dlls.
The "Access Violation" always happens when the software is shut down i.e. the MainWindow (WPF) is closed.
Exception thrown at 0x00007FFC529FD7D1 (ntdll.dll) in XYZ.exe: 0xC0000005: Access violation writing location 0x0000000000000024.
Unhandled exception at 0x00007FFC529FD7D1 (ntdll.dll) in XYZ.exe: 0xC0000005: Access violation writing location 0x0000000000000024.
Calls stack:
ntdll.dll!RtlpWaitOnCriticalSection() Unknown Symbols loaded.
ntdll.dll!RtlpEnterCriticalSectionContended() Unknown Symbols loaded.
ntdll.dll!RtlEnterCriticalSection�() Unknown Symbols loaded.
[Inline Frame] XYZ.exe!pal::mutex_t::lock() Line 850 C++ Symbols loaded.
[Inline Frame] XYZ.exe!std::lock_guard<pal::mutex_t>::{ctor}(pal::mutex_t &) Line 438 C++ Symbols loaded.
> [Inline Frame] XYZ.exe!trace::flush() Line 187 C++ Symbols loaded.
XYZ.exe!wmain(const int argc, const wchar_t * * argv) Line 304 C++ Symbols loaded.
[Inline Frame] XYZ.exe!invoke_main() Line 90 C++ Symbols loaded.
XYZ.exe!__scrt_common_main_seh() Line 288 C++ Symbols loaded.
kernel32.dll!BaseThreadInitThunk�() Unknown Symbols loaded.
ntdll.dll!RtlUserThreadStart�() Unknown Symbols loaded.
We downloaded and installed the NET runtime source code and debug symbols and the access violation is inside the "runtime\src\native\corehost\hostmisc\trace.cpp"
this is called from "runtime\src\native\corehost\corehost.cpp" after the call exe_start returns i.e. after the execution of the whole software finished where for whatever reason it calls these two lines:
// Flush traces before exit - just to be sure
trace::flush();
And the crash is on the lock_guard here:
void trace::flush()
{
std::lock_guard<pal::mutex_t> lock(g_trace_mutex);
pal::file_flush(g_trace_file);
pal::err_flush();
pal::out_flush();
}
Looking at the code, it doesnt make any sense that it is executed anyways on most systems because trace::setup checks the environment variable "COREHOST_TRACE" and does nothing if it is not set.
Can somone simply add a early return at the beginning of trace::flush when g_trace_verbosity is 0 anyways i.e. the trace is not even used?
Reproduction Steps
I cannot provide a sample to reproduce right now (only in our whole software). It only happens in .NET6 with Release, not in Debug. It also does not happen with .NET48 .
We can see that trace::enable does nothing when g_trace_verbosity == 0 but very strangely trace::flush does something which is probably wrong.
While debugging we noticed that trace::setup() is called for each managed/mixed mode .dll that is loaded on startup, but that might not be related.
But I provided in the Description a fix that should probably avoid this issue without any breaking changes.
Expected behavior
trace::flush should not do anything if g_trace_verbosity==0
Actual behavior
trace::flush tries to lock a mutex in shutdown situations where the mutex might positionally have an issue and was even never used before because trace::enabled bailed out early
Regression?
For us it is a regression from .net48
Known Workarounds
None. Our software crashes on exit all the time with NET6 Release.
Configuration
NET6 x64 Release
Other information
No response
Activity
vitek-karas commentedon Sep 19, 2022
Thanks for the details. I'm not sure if we still need to flush the stderr even if tracing is disabled, mainly in cases where there was an error which has been written (but not flushed).
vitek-karas commentedon Sep 19, 2022
This is basically by design- C++/CLI assemblies use hosting components to load themselves into the process, the hosting component will call
trace::setupto enable its tracing if asked via env. variable. As you mention, it should basically do nothing.mgexo commentedon Oct 24, 2022
Another suggested fix for trace.cpp which works for us:
Change in trace.cpp
static pal::mutex_t g_trace_mutex;To
This avoids that in the shutdown situation the mutex is already destroyed when the crt shuts down e.g. due to abort/terminate or Environment.Exit calls etc.
I am not sure but think its a random effect i.e. the static objects in trace.cpp may already be shut down then when the crt did shut down
This small change lets the crash go away for us, I because I guess no random static destructor of the global mutex is happening then
vitek-karas commentedon Oct 24, 2022
@elinor-fung to take a look...
elinor-fung commentedon Oct 24, 2022
Sorry for the delay @mgexo. Yeah, I believe the issue is - as you found - due to the static object's destructor. If a thread calls exit, static destructors are called on that thread with no synchronization with other threads, so the other threads continue running as if there wasn't an exit happening. I'll work on fixing it.
elinor-fung commentedon Oct 25, 2022
@mgexo I put up a change at #77425. From your last comment, it sounds like you are set up to make changes and validate locally - is this something you would be able to validate against your scenario?
mgexo commentedon Oct 26, 2022
Since some people do not like the memory leak, I made another suggestion here which seems to fix our issue too
#77425 (comment)
mgexo commentedon Oct 27, 2022
We had the same problem now also with other smaller tools, e.g. a separate console program.
I wonder why nobody else is reporting this issue? We have it on multiple computers with different setups.
Do we get crash-telemetry from Microsoft Error reports where we could see, how often it happens?
elinor-fung commentedon Oct 28, 2022
I haven't seen other reports of this. I tried searching for crash reports - I only found one instance that was hit a number of times yesterday.
By my understanding, this should only be hit if some other thread is doing an abort/exit - I expect that is not the common case for most applications. If you are comfortable sharing a dump for the smaller tool/separate console program, I'd certainly double-check that my understanding aligns with the dump.