dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.27k stars 4.73k forks source link

Deadlock in the Console.OutputEncoding setter #83723

Open clguiman opened 1 year ago

clguiman commented 1 year ago

Description

The Console.OutputEncoding setter takes a lock on s_syncObject then calls Flush() on the s_out and s_error streams. Those streams are SyncTextWriter objects which have the MethodImpl(MethodImplOptions.Synchronized)attribute set on their methods. If another thread flushes the console output (e.g. ConsoleLoggerProcessor.ProcessLogQueue) the locks will be taken in the reverse order: SyncTextWriter.Flush, that ends up in Console.Out.EnsureInitialized() which takes the s_syncObject lock.

Reproduction Steps

I managed to sometimes repro the issue on Linux (WSL) with .net 6.0.14. Here are the deadlocked threads:

Thread 0x121

[Deadlocked, double-click or press enter to view all thread stacks] [Waiting on lock owned by Thread 0x12F] System.Private.CoreLib.dll!System.IO.TextWriter.SyncTextWriter.Flush() Line 759 C# System.Console.dll!System.Console.OutputEncoding.set(System.Text.Encoding value) Line 147 C#

Thread 0x12F

[Deadlocked, double-click or press enter to view all thread stacks] [Waiting on lock owned by Thread 0x121] System.Private.CoreLib.dll!System.Threading.Monitor.Enter(object obj, ref bool lockTaken) Line 49 C# System.Console.dll!System.Console.get_Out.__EnsureInitialized|26_0() Line 205 C# System.Console.dll!System.Console.Out.get() Line 199 C# System.Console.dll!System.ConsolePal.UpdatedCachedCursorPosition(byte* bufPtr, int count, int cursorVersion) Line 1320 C# System.Console.dll!System.ConsolePal.Write(Microsoft.Win32.SafeHandles.SafeFileHandle fd, System.ReadOnlySpan buffer, bool mayChangeCursorPosition) Line 1308 C# System.Console.dll!System.ConsolePal.UnixConsoleStream.Write(System.ReadOnlySpan buffer) Line 1468 C# System.Private.CoreLib.dll!System.IO.StreamWriter.Flush(bool flushStream, bool flushEncoder) Line 330 C# System.Private.CoreLib.dll!System.IO.StreamWriter.Write(string value) Line 495 C# System.Private.CoreLib.dll!System.IO.TextWriter.SyncTextWriter.Write(string value) Line 798 C# Microsoft.Extensions.Logging.Console.dll!Microsoft.Extensions.Logging.Console.ConsoleLoggerProcessor.WriteMessage(Microsoft.Extensions.Logging.Console.LogMessageEntry entry) Line 58 C# Microsoft.Extensions.Logging.Console.dll!Microsoft.Extensions.Logging.Console.ConsoleLoggerProcessor.ProcessLogQueue() Line 64 C# System.Private.CoreLib.dll!System.Threading.Thread.StartCallback() Line 106 C# [Native to Managed Transition]

Expected behavior

The process shouldn't deadlock when setting the output encoding.

Actual behavior

The process deadlocks.

Regression?

No response

Known Workarounds

No response

Configuration

x64 .NET 6.0.14, Ubuntu WSL

Other information

No response

ghost commented 1 year ago

Tagging subscribers to this area: @dotnet/area-system-console See info in area-owners.md if you want to be subscribed.

Issue Details
### Description The `Console.OutputEncoding` setter takes a lock on `s_syncObject` then calls `Flush()` on the s_out and s_error streams. Those streams are `SyncTextWriter` objects which have the `MethodImpl(MethodImplOptions.Synchronized)`attribute set on their methods. If another thread flushes the console output (e.g. `ConsoleLoggerProcessor.ProcessLogQueue`) the locks will be taken in the reverse order: `SyncTextWriter.Flsuh`, that ends up in `Console.Out.EnsureInitialized()` which takes the `s_syncObject` lock. ### Reproduction Steps I managed to sometimes repro the issue on Linux (WSL) with .net 6.0.14. Here are the deadlocked threads: Thread 0x121 > [Deadlocked, double-click or press enter to view all thread stacks] [Waiting on lock owned by Thread 0x12F] System.Private.CoreLib.dll!System.IO.TextWriter.SyncTextWriter.Flush() Line 759 C# > System.Console.dll!System.Console.OutputEncoding.set(System.Text.Encoding value) Line 147 C# Thread 0x12F > [Deadlocked, double-click or press enter to view all thread stacks] [Waiting on lock owned by Thread 0x121] System.Private.CoreLib.dll!System.Threading.Monitor.Enter(object obj, ref bool lockTaken) Line 49 C# > System.Console.dll!System.Console.get_Out.__EnsureInitialized|26_0() Line 205 C# System.Console.dll!System.Console.Out.get() Line 199 C# System.Console.dll!System.ConsolePal.UpdatedCachedCursorPosition(byte* bufPtr, int count, int cursorVersion) Line 1320 C# System.Console.dll!System.ConsolePal.Write(Microsoft.Win32.SafeHandles.SafeFileHandle fd, System.ReadOnlySpan buffer, bool mayChangeCursorPosition) Line 1308 C# System.Console.dll!System.ConsolePal.UnixConsoleStream.Write(System.ReadOnlySpan buffer) Line 1468 C# System.Private.CoreLib.dll!System.IO.StreamWriter.Flush(bool flushStream, bool flushEncoder) Line 330 C# System.Private.CoreLib.dll!System.IO.StreamWriter.Write(string value) Line 495 C# System.Private.CoreLib.dll!System.IO.TextWriter.SyncTextWriter.Write(string value) Line 798 C# Microsoft.Extensions.Logging.Console.dll!Microsoft.Extensions.Logging.Console.ConsoleLoggerProcessor.WriteMessage(Microsoft.Extensions.Logging.Console.LogMessageEntry entry) Line 58 C# Microsoft.Extensions.Logging.Console.dll!Microsoft.Extensions.Logging.Console.ConsoleLoggerProcessor.ProcessLogQueue() Line 64 C# System.Private.CoreLib.dll!System.Threading.Thread.StartCallback() Line 106 C# [Native to Managed Transition] ### Expected behavior The process shouldn't deadlock when setting the output encoding. ### Actual behavior The process deadlocks. ### Regression? _No response_ ### Known Workarounds _No response_ ### Configuration x64 .NET 6.0.14, Ubuntu WSL ### Other information _No response_
Author: clguiman
Assignees: -
Labels: `area-System.Console`
Milestone: -
danmoseley commented 1 year ago

Is this a regression?

clguiman commented 1 year ago

The issue doesn't reproduce always so I didn't spend time trying it on net5.