0

I've run into a situation and I don't know if it can be resolved.

I've started adding a TraceSource and trace statements to my multithreaded service, and I'm running into locks in the threads that process the trace methods in my code. This is causing the entire app to hang.

My service is configured to run within a console window for debugging purposes. I know this is related to the issue as I am also writing to a ConsoleTraceListener.

This locking seems to occur between external code and an internal call to Console.ReadKey(). As an example of the code and configuration, my application may make calls such as these within async methods:

class MyService : ServiceBase
{
    static TraceSource trace = new TraceSource("mysource");

    void asyncMethod1()
    {
        trace.TraceInformation("Some useful information.");
    }

    void asyncMethod2()
    {
        trace.TraceInformation("Some other useful information.");
    }

    /// other members and methods ...
}

The TraceSource is defined in the app.config file as

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <startup>
    <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.0"/>
  </startup>
  <system.diagnostics>
    <trace autoflush="true" indentsize="4" useGlobalLock="true" />
    <sources>
      <source name="mysource" switchName="TraceSwitch" switchType="System.Diagnostics.SourceSwitch">
        <listeners>
          <add name="console" />
          <add name="eventlog" />
          <add name="logfile" />
        </listeners>
      </source>
    </sources>
    <sharedListeners>
      <add name="console" type="System.Diagnostics.ConsoleTraceListener" initializeData="false" />
      <add name="eventlog" type="System.Diagnostics.EventLogTraceListener" initializeData="EventSource">
        <filter type="System.Diagnostics.EventTypeFilter" initializeData="Error"/>
      </add>
      <add name="logfile" type="System.Diagnostics.TextWriterTraceListener" initializeData="logfiles\errors.log">
        <filter type="System.Diagnostics.EventTypeFilter" initializeData="Error"/>
      </add>
    </sharedListeners>
    <switches>
      <add name="TraceSwitch" value="Information" />
    </switches>
  </system.diagnostics>
</configuration>

REPRODUCING the issue

Once the app is started, the code in Program.Main(args[]) waits for a Console.ReadKey() to stop the app.

static int Main(string[] args)
{
    /// ...

    MyService service = new MyService();
    service.StartService();

    Console.WriteLine("Press any key to exit application.");
    Console.ReadKey(true);

    ///...
}

When I run the service in console, and using quickedit mode click or select with the mouse anywhere in the console window, the TraceSource method calls lock up the rest of the application, until I hit a key which also stops the application.

Is there a way that I can prevent this console thread from locking the other threads? Or do I misinterpret what is happening here?


After I click in the console window to reproduce the issue, the call stack may look something like this:

THREAD 1

[Managed to Native Transition]  
System.IO.__ConsoleStream.WriteFileNative
System.IO.__ConsoleStream.Write
System.IO.StreamWriter.Flush
System.IO.StreamWriter.Write
System.IO.TextWriter.SyncTextWriter.Write
System.Diagnostics.TextWriterTraceListener.Write
System.Diagnostics.TraceListener.WriteHeader
System.Diagnostics.TraceListener.TraceEvent
System.Diagnostics.TraceSource.TraceEvent
System.Diagnostics.TraceSource.TraceInformation
myservice.MyService.asyncMethod1 Line 202   C#

THREAD 2

System.Threading.Monitor.Enter
System.Diagnostics.TraceSource.TraceEvent
System.Diagnostics.TraceSource.TraceInformation
myservice.MyService.asyncMethod2 Line 134   C#
khargoosh
  • 1,450
  • 15
  • 40
  • When deployed, the only time the application will run in console is when the trace identifies an error that needs to be investigated. Otherwise it runs as a service and as of yet I haven't seen this locking issue in that mode of operation. But I would really like to resolve this if possible to give our field engineers one less roadblock. – khargoosh Feb 08 '16 at 03:23
  • Several methods are asynchronous and running in parallel. – khargoosh Feb 08 '16 at 04:07
  • @MickyD they are async callbacks such as those used with the TcpListener or UdpClient asynchronous methods. Anyways, I promise they are asynchronous, as evidenced by the parallel stacks I have posted in the question. Do you have any thoughts as to the resolution of the issue I'm experiencing? – khargoosh Feb 08 '16 at 04:15
  • @MickyD I can't post the thousands of lines of code in the app, but I felt the above contained the relevant information. Is there something specific that you are looking for? – khargoosh Feb 08 '16 at 04:28
  • @MickyD as you can see from the parallel stacks, the code that is locked up is in External Code, I can't post it. – khargoosh Feb 08 '16 at 04:32
  • What happens if your comment out the "console" listener in your config file? –  Feb 08 '16 at 05:04
  • Two things; 1) I stop getting trace messages in the console, and 2) the application no longer hangs when I click in the console. I continue to see trace messages in the debug Output window to verify the app is still running. – khargoosh Feb 08 '16 at 05:10
  • Would you try turning on quickedit in your console, and use the mouse to highlight some characters? – khargoosh Feb 08 '16 at 05:39

1 Answers1

3

OP:

When I run the service in console, and click with the mouse anywhere in the console window, the TraceSource method calls lock up the rest of the application, until I hit a key which also stops the application.

Would you try turning on quickedit in your console, and use the mouse to highlight some characters?

Based on our conversation below your question above, the reason it appears to hang is that during QuickEdit mode/highlighting text, console output is suspended for all threads. This was confirmed in the Visual Studio debugger.

To resume execution, press Esc or click your right mouse button.

OP:

I was wondering do you know if there was a way to prevent this behaviour

Yes, Jim Mishel writes:

If you want to disable quick edit mode, you need to call GetConsoleMode to get the current mode. Then clear the bit that enables quick edit

You can find more about Jim's answer here.

Community
  • 1
  • 1
  • I suspected it was something like this, thank you... but I was wondering do you know if there was a way to prevent this behaviour. If the app hangs long enough, it will crash, and that's undesirable in this case. – khargoosh Feb 08 '16 at 05:58
  • @khargoosh ya didn't know you were using QuickEdit till the last comment. Glad we got there in the end :) –  Feb 08 '16 at 06:27
  • 1
    I didn't realise it was relevant until you tried to reproduce it! Thank you :-) – khargoosh Feb 08 '16 at 06:35