I have spent a few days now finding a bug that freezes my companies application. The dreaded UserPreferenceChanged UI freeze. It's not a complicated bug, but hard to find in a rather big application. There are quite a few articles about how this bug unfolds but not on how to put ones finger on the faulty code. I have put together a solution, in form of a logging mechanism from multiple older tickets and (i hope) improved a bit upon them. May it save some time for the next programmer with this problem.
How to recognize the bug?
The application freezes completely. Nothing more to be done than create a memory dump and then close it via TaskManager. If you open the dmp file in VisualStudio or WinDbg you might see a stack trace like this one
WaitHandle.InternalWaitOne
WaitHandle.WaitOne
Control.WaitForWaitHandle
Control.MarshaledInvoke
Control.Invoke
WindowsFormsSynchronizationContext.Send
System.EventInvokeInfo.Invoke
SystemEvents.RaiseEvent
SystemEvents.OnUserPreferenceChanged
SystemEvents.WindowProc
:
The important two lines here are "OnUserPreferenceChanged" and "WindowsFormsSynchronizationContext.Send"
What's the cause?
SynchronizationContext was introduced with .NET2 to generalize thread synchronization. It gives us methods like "BeginInvoke" and such.
The UserPreferenceChanged event is rather self explanatory. It will be triggered by the user changing his background, logging in or out, changing the Windows accent colors and lots of other actions.
If one creates a GUI control on a background thread a WindowsFormsSynchronizationContext is installed on said thread. Some GUI controls subscribe to the UserPreferenceChanged event when created or when using certain methods. If this event is triggered by the user the main thread sends a message to all subscribers and waits. In the described scenarion: a worker thread without a message loop! The application is frozen.
To find the cause of the freeze can be especially hard because the cause of the bug (creation of GUI element on a background thread) and the error state (application frozen) can be minutes apart. See this really good article for more details and a slightly different scenario. https://www.ikriv.com/dev/dotnet/MysteriousHang
Examples
How can one provoke this error for testing purposes?
Example 1
private void button_Click(object sender, EventArgs e)
{
new Thread(DoStuff).Start();
}
private void DoStuff()
{
using (var r = new RichTextBox())
{
IntPtr p = r.Handle; //do something with the control
}
Thread.Sleep(5000); //simulate some work
}
Not bad but not good either. If the UserPreferenceChanged event gets triggered in the few milliseconds you use the RichTextBox your application will freeze. Could happen, not very likely though.
Example 2
private void button_Click(object sender, EventArgs e)
{
new Thread(DoStuff).Start();
}
private void DoStuff()
{
var r = new RichTextBox();
IntPtr p = r.Handle; //do something with the control
Thread.Sleep(5000); //simulate some work
}
This is bad. The WindowsFormsSynchronizationContext gets not cleaned up because the RichTextBox does not get disposed. If the UserPreferenceChangedEvent occures while the thread lives your application will freeze.
Example 3
private void button_Click(object sender, EventArgs e)
{
Task.Run(() => DoStuff());
}
private void DoStuff()
{
var r = new RichTextBox();
IntPtr p = r.Handle; //do something with the control
}
This is a nightmare. Task.Run(..) will execute the work on a background thread on the threadpool. The WindowsFormsSynchronizationContext gets not cleaned up because the RichTextBox is not disposed. Threadpool threads are not cleaned up. This background thread now lurks in your threadpool just waiting for the UserPreferenceChanged event to freeze your application even long after your task has returned!
Conclusion: Risk is manageable when you know what you do. But whenever possible: avoid GUI Elements in a background thread!
How to deal with this bug?
CodePudding user response：
I put together a solution from older tickets. Thanks very much to those guys!
WinForms application hang due to SystemEvents.OnUserPreferenceChanged event
This solution starts a new thread that continuously tries to detect any threads which are subscribed to the OnUserPreferenceChanged Event and then provide a call stack that should tell you why that is.
public MainForm()
{
InitializeComponent();
new Thread(Observe).Start();
}
private void Observe()
{
new PreferenceChangedObserver().Run();
}
internal sealed class PreferenceChangedObserver
{
private readonly string _logFilePath = $"filePath\\FreezeLog.txt"; //put a better file path here
private BindingFlags _flagsStatic = BindingFlags.NonPublic | BindingFlags.Static;
private BindingFlags _flagsInstance = BindingFlags.NonPublic | BindingFlags.Instance;
public void Run() => CheckSystemEventsHandlersForFreeze();
private void CheckSystemEventsHandlersForFreeze()
{
while (true)
{
try
{
foreach (var info in GetPossiblyBlockingEventHandlers())
{
var msg = $"SystemEvents handler '{info.EventHandlerDelegate.Method.DeclaringType}.{info.EventHandlerDelegate.Method.Name}' could freeze app due to wrong thread. ThreadId: {info.Thread.ManagedThreadId}, IsThreadPoolThread:{info.Thread.IsThreadPoolThread}, IsAlive:{info.Thread.IsAlive}, ThreadName:{info.Thread.Name}{Environment.NewLine}{info.StackTrace}{Environment.NewLine}";
File.AppendAllText(_logFilePath, DateTime.Now.ToString("dd.MM.yyyy HH:mm:ss") $": {msg}{Environment.NewLine}");
}
}
catch { }
}
}
private IEnumerable<EventHandlerInfo> GetPossiblyBlockingEventHandlers()
{
var handlers = typeof(SystemEvents).GetField("_handlers", _flagsStatic).GetValue(null);
if (!(handlers?.GetType().GetProperty("Values").GetValue(handlers) is IEnumerable handlersValues))
yield break;
foreach(var systemInvokeInfo in handlersValues.Cast<IEnumerable>().SelectMany(x => x.OfType<object>()).ToList())
{
var syncContext = systemInvokeInfo.GetType().GetField("_syncContext", _flagsInstance).GetValue(systemInvokeInfo);
//Make sure its the problematic type
if (!(syncContext is WindowsFormsSynchronizationContext wfsc))
continue;
//Get the thread
var threadRef = (WeakReference)syncContext.GetType().GetField("destinationThreadRef", _flagsInstance).GetValue(syncContext);
if (!threadRef.IsAlive)
continue;
var thread = (Thread)threadRef.Target;
if (thread.ManagedThreadId == 1) //UI thread
continue;
if (thread.ManagedThreadId == Thread.CurrentThread.ManagedThreadId)
continue;
//Get the event delegate
var eventHandlerDelegate = (Delegate)systemInvokeInfo.GetType().GetField("_delegate", _flagsInstance).GetValue(systemInvokeInfo);
//Get the threads call stack
string callStack = string.Empty;
try
{
if (thread.IsAlive)
callStack = GetStackTrace(thread)?.ToString().Trim();
}
catch { }
yield return new EventHandlerInfo
{
Thread = thread,
EventHandlerDelegate = eventHandlerDelegate,
StackTrace = callStack,
};
}
}
private static StackTrace GetStackTrace(Thread targetThread)
{
using (ManualResetEvent fallbackThreadReady = new ManualResetEvent(false), exitedSafely = new ManualResetEvent(false))
{
Thread fallbackThread = new Thread(delegate () {
fallbackThreadReady.Set();
while (!exitedSafely.WaitOne(200))
{
try
{
targetThread.Resume();
}
catch (Exception) {/*Whatever happens, do never stop to resume the target-thread regularly until the main-thread has exited safely.*/}
}
});
fallbackThread.Name = "GetStackFallbackThread";
try
{
fallbackThread.Start();
fallbackThreadReady.WaitOne();
//From here, you have about 200ms to get the stack-trace.
targetThread.Suspend();
StackTrace trace = null;
try
{
trace = new StackTrace(targetThread, true);
}
catch (ThreadStateException) { }
try
{
targetThread.Resume();
}
catch (ThreadStateException) {/*Thread is running again already*/}
return trace;
}
finally
{
//Just signal the backup-thread to stop.
exitedSafely.Set();
//Join the thread to avoid disposing "exited safely" too early. And also make sure that no leftover threads are cluttering iis by accident.
fallbackThread.Join();
}
}
}
private class EventHandlerInfo
{
public Delegate EventHandlerDelegate { get; set; }
public Thread Thread { get; set; }
public string StackTrace { get; set; }
}
}
Attention
1)This is a very ugly hack. It deals with threads in a very invasive way. It should never see a live customer system. I was already nervous deploying it to the customers test system.
2)If you get a logfile it might be very big. Any thread might cause hundreds of entries. Start at the oldest entries, fix it and repeat.(Because of the "tainted thread" scenario from Example 3 it might also contain false positives)
3)I am not sure about the performance impact of this hack. I assumed it would be very big. to my surprise it was almost not noteable. Might be different on other systems though