TraceListener call does not block, leads to crash when calling twice

Question

My setup: simple implementation of TraceListener that is instantiated once and keeps one instance of a "MessageBox" implementation. It's purpose is to listen for binding errors, as it is added to PresentationTraceSources.DataBindingSource.Listeners

My test case opens a window that has exactly two binding errors, so what I expect is, the tracer kicks in and shows the "MessageBox" window via ShowDialog(). The user clicks ok, the window is NOT closed, but hidden and the second binding error should came up. Instead I get a crash:

An unhandled exception of type 'System.InvalidOperationException' occurred in PresentationFramework.dll

"ShowDialog" can only be called on hidden windows

Why the heck does this happen? Here is the exact implementation of the trace listener:

public class DummyListener : TraceListener
{
    private readonly MessageBoxView _window = new MessageBoxView();

    public DummyListener()
    {
        _window.HideOnClose = true;
        _window.DataContext = _window;
    }

    public override void Write( string message )
    {
    }

    public override void WriteLine( string message )
    {
        lock ( _window )
        {
            if ( _window.IsActive )
            {
                // !!! WHY IS THIS CODE EXECUTED
                System.Diagnostics.Debugger.Break();
            }
            _window.Message = message;
            _window.ShowDialog();

            throw new NotImplementedException("This line is never reached");
        }
    }

}

I've added a lock just for testing. The _window.ShowDialog is called twice, for each binding error and then crashes. The NotImplementedException is also a test, it never gets called. So first binding error calls _window.ShowDialog(), this seems to block but the trace listener source calls WriteLine a second time, on the same thread, it ignores the lock and enters my Break() call, if I continue, it calls _window.ShowDialog() before the first dialog got hidden. If I replace _window.ShowDialog with a MessageBox.Show, it does really block. Why does ShowDialog() behaves this way? It does block, as the NIE exception after it is not thrown but why does the System.Diagnostics.TraceListener.TraceEvent re-enter the locked section?

For clarification: I want to pool the window, I do not want to spawn multiple message box window but show them in order. I've checked the threads, everything happens on the main thread, but nothing blocks the way I would expect.

Here is a Minimal, Complete, and Verifiable example (sorry it is quite verbose as I could not reduce it more):

It opens a window directly, it throws the above exception because of _window.ShowDialog();

App.xaml (remove the startup uri)

<Application x:Class="WpfApplicationTracerIssue2.App"

             xmlns="http://schemas.microsoft.com/winfx/2006/xaml/presentation"
             xmlns:x="http://schemas.microsoft.com/winfx/2006/xaml"
             >
    <Application.Resources>

    </Application.Resources>
</Application>

App.xaml.cs

using System;
using System.Diagnostics;
using System.Windows;

namespace WpfApplicationTracerIssue2
{
    public class DummyListener : TraceListener
    {
        private readonly MessageBoxView _window = new MessageBoxView();

        public DummyListener()
        {
            _window.HideOnClose = true;
            _window.DataContext = _window;
        }

        public override void Write( string message )
        {
        }

        public override void WriteLine( string message )
        {
            lock ( _window )
            {
                if ( _window.IsActive )
                {
                    // !!! WHY IS THIS CODE EXECUTED
                    System.Diagnostics.Debugger.Break();
                }
                _window.Title = "Log entry occurred";
                _window.Message = message;
                _window.ShowDialog();

                throw new NotImplementedException("This line is never reached");
            }
        }

    }

    public partial class App : Application
    {
        private DummyListener dl = new DummyListener();

        protected override void OnStartup( StartupEventArgs e )
        {
            base.OnStartup( e );
            Current.ShutdownMode = ShutdownMode.OnMainWindowClose;

            PresentationTraceSources.DataBindingSource.Listeners.Add( dl );

            var d = new MainWindow();

            d.DataContext = d;
            MainWindow = d;
            d.Show(); 
        }
    }
}

MainWindow.xaml (cs is default)

<Window x:Class="WpfApplicationTracerIssue2.MainWindow"
        xmlns="http://schemas.microsoft.com/winfx/2006/xaml/presentation"
        xmlns:x="http://schemas.microsoft.com/winfx/2006/xaml"
        Title="MainWindow" Height="350" Width="525">
    <StackPanel>
        <Label Content="{Binding A}"></Label>
        <Label Content="{Binding B}"></Label>
    </StackPanel>
</Window>

Finally the dummy messagebox view:

MessageBoxView.xaml

<Window x:Class="WpfApplicationTracerIssue2.MessageBoxView"
        xmlns="http://schemas.microsoft.com/winfx/2006/xaml/presentation"
        xmlns:x="http://schemas.microsoft.com/winfx/2006/xaml"
        Title="MessageBoxView" Height="300" Width="300">
    <StackPanel>
        <Label Content="{Binding Message}" ContentStringFormat="msg: {0}"></Label>
        <Button Click="ButtonBase_OnClick">Ok</Button>
    </StackPanel>
</Window>

MessageBoxView.xaml.cs

using System.Windows;

namespace WpfApplicationTracerIssue2
{

    public partial class MessageBoxView : Window
    {
        public static readonly DependencyProperty MessageProperty = DependencyProperty.Register("Message", typeof ( string ), typeof ( MessageBoxView ), new PropertyMetadata( default( string ) ) );

        public string Message{ get { return ( string ) GetValue( MessageProperty ); } set { SetValue( MessageProperty, value ); }}


        public MessageBoxView(){InitializeComponent();}

        public bool HideOnClose { get; set; }


        private void ButtonBase_OnClick( object sender, RoutedEventArgs e )
        {
            if ( HideOnClose ){ Hide(); }
            else{ Close(); }
        }
    }
}

Answer 1

First, this doesn't appear to have anything to do with multithreading. It's really about re-entrancy in a single thread.

The issue is that the ShowDialog() method necessarily includes a message pump for the thread messages. The thread message queue is used by the listener framework to deliver events to the listener. So while you are displaying the window for the first message, that message pump in the ShowDialog() method goes ahead and delivers the second message, before the window for the first message has been dismissed.

One way to fix this would be to change the listener code so that it queued the messages itself, and displayed them on at a time. That might look something like this:

public class DummyListener : TraceListener
{
    private readonly MessageBoxView _window = new MessageBoxView();
    private readonly BlockingCollection<string> _messages = new BlockingCollection<string>();

    public DummyListener()
    {
        _window.HideOnClose = true;
        _window.DataContext = _window;

        PresentMessages();
    }

    private async void PresentMessages()
    {
        IEnumerator<string> enumerator = _messages.GetConsumingEnumerable().GetEnumerator();

        while (await Task.Factory.StartNew(() => enumerator.MoveNext(), TaskCreationOptions.LongRunning))
        {
            _window.Title = "Log entry occurred";
            _window.Message = enumerator.Current;
            _window.ShowDialog();
        }
    }

    public override void Write(string message)
    {
    }

    public override void WriteLine(string message)
    {
        _messages.Add(message);
    }

    protected override void Dispose(bool disposing)
    {
        _messages.CompleteAdding();
        base.Dispose(disposing);
    }
}

The above uses a BlockingCollection<string> to queue up each message as it comes in. Also, in the constructor it calls an async method that handles the actual presentation of the window.

That PresentMessages() method uses an asynchronous task to wait for a message to be available to present. When that task completes, the method is resumed in the original thread to present the window.

NOTE: for the above to work, you need to ensure that the listener class instance itself is created in the UI thread, so that the continuation in the PresentMessages() method is in fact executed in the UI thread too. To ensure that, I changed your App code so it looks like this instead:

public partial class App : Application
{
    private DummyListener dl;

    protected override void OnStartup(StartupEventArgs e)
    {
        base.OnStartup(e);
        Current.ShutdownMode = ShutdownMode.OnMainWindowClose;

        dl = new DummyListener();
        PresentationTraceSources.DataBindingSource.Listeners.Add(dl);

        var d = new MainWindow();

        d.DataContext = d;
        MainWindow = d;
        d.Show();
    }
}

Also note that I use Task.Factory.StartNew() to create the task, rather than the more concise Task.Run(). This allows me to pass TaskCreationOptions.LongRunning, so that the Task class knows this operation could take a long time. That way it can avoid tying up a thread pool thread on a blocking operation that could potentially take a long time to complete.

An even better approach would be to implement an asynchronously-completing MoveNext() method (i.e. an asynchronous version of IEnumerable<T>). I leave that as an exercise for the reader. :)