This project is read-only.

OutputDebugStringTraceListener

Jun 14, 2010 at 9:03 PM

It might be worth noting that if you are using the OutputDebugStringTraceListener (I was using it from C# in VS2010) and are running from the debugger, the output will not go to the Output Window unless Project->Options->Debug->Enable unmanaged code debugging is checked.  This is not a problem (that I can tell anyway) specific to this trace listener.  Rather, it seems to be a problem with OutputDebugString in general (or maybe when calling it via p/invoke).  I wrote a small sample program that simply wrote to OutputDebugString but the output did not show up in the VS Output Window.  As soon as I checked the "Enable unmanaged code debugging" option, the output did go to the VS Output Window.  Similar, when I checked that option in my program that is using the OutputDebugStringTraceListener, the output started showing up in the VS Output Window.

See my question at www.stackoverflow.com:

http://stackoverflow.com/questions/3040004/can-output-from-outputdebugstring-be-viewed-in-visualstudios-output-window

Jun 15, 2010 at 10:19 AM

Yes, I'm aware that ODS doesn't hit VS by default but we just wanted a raw ODS listener. You could easily add your own combination of our Debugger and OutputDebugString listeners that use ODS only if a Debugger isn't attached (look at code in DebuggerTraceListener for a clue as to how this would look).

Thanks

Josh

Jun 15, 2010 at 3:01 PM

My fault.  I didn't realize that there was a DebuggerListener!  I saw the OutputDebugString listener and just assumed that OutputDebugString would go to the output window (obviously I haven't used OutputDebugString very much!).  I can see that I should have been using the DebuggerTraceListener all along.

I am just starting out with this, so I am trying different experiments to see how things work and what I can accomplish with Ukadc.Diagnostics and other logging packages.

Thanks again.

Jun 15, 2010 at 6:40 PM
Edited Jun 15, 2010 at 7:22 PM

Regarding the DebuggerTraceListener...  I find that I if I use the DebuggerTraceListener, all log  messages are written to the same line (i.e. as if they are written with Debug.Write rather than Debug.WriteLine).  I did an experiment in a test program and found that if I call Debugger.Log (which you use in DebuggerTraceListener) with category = null (which is how DebuggerTraceListener is implemented), all output goes on the same line.  If I call Debugger.Log with category = "" (or with any string value), each message goes on its own line.

I suppose that a fix could be to either explicitly add a linefeed to each message or the call site for Debugger.Log could be modified to pass "" (or any other value), rather than null, for the category parameter.  Alternatively (and maybe more trouble than it is worth), maybe the token system could be used to allow the "category" parameter to be configurable.

Jun 16, 2010 at 5:04 PM

OK - thanks again. We've just changed this to pass string.Empty which should be an improvement. However, I think we could be using this much better (i.e. making use of the EventLevel etc). I don't have time to research this but if you have any time to experiment and feedback that would be great.

Jun 16, 2010 at 7:08 PM

Thanks.

I have fooled around with this a little bit and I found that the level parameter (the first parameter) is not logged at all by the Debugger.Log method.  I can't tell from the documentation how or if this is used.  Maybe it is used by other debugging applications that might allow filtering on the level parameter?

As far as the category (the second parameter), based on the existing token/listener architecture it seems like it would be hard to get a specific property value (separate from the combined value) to use for the category.  Alternatively, all of the eventCache properties as well as all of the TraceEventCore/TraceDataCore parameters are available so it would be easy enough to hardcode to log the source or the id or whatever for the "category".  Maybe the DebuggerTraceListener could have an additional configuration parameter (like "category") that could be specified by token.  So, maybe a user of the DebuggerTraceListener could configure it to log the source name (or some other value that is accessible via a property) and the actual message could be composed in the traditional way.

I did do some experimentation, and this is what I came up with.  It is a bit rough, but seems to work ok.  I modified the DebuggerTraceListener to be like the FileTraceListener in the sense that it now takes three custom(?) configuration attributes (level, category, output) to specify the Debugger.Log level (LVL) and category (CAT) parameters and the format (output) of the message.  I removed the initializationData attribute (was having problems that I eventually fixed, so maybe I didn't really have to remove this).  Now you can specify by token the property(ies) to use for LVL and CAT.  Actually, since LVL is an integer, the associated property should be an integer as well.  I don't know that it is particularly useful, but it does give another customization point.  You can now shorten up the message format (possibly not putting the source name in there) and put a removed property (like source) into CAT.  Even though LVL is not displayed in the output window, it might be used by some other applications that could listen to Debugger.Log.

I am pasting the entire source for DebuggerTraceListener here.  I suppose that I could just paste differences, but they are spread out somewhat.  As I said, it is a bit rough because I did not take the time to go back and really clean things up.  Could certainly use more defensive programming in TraceDataCore and TraceEventCore.  Also, I don't know if the locking inside of init is necessary.  I really just copied that part from FileTraceListener. 

I have also pasted a few lines from the app.config file showing how to configure the configuration attributes.

Anyway, maybe you will find this interesting, if not useful.

app.config:

<sharedListeners>

  <add name="ukadc.debugger" type="Ukadc.Diagnostics.Listeners.DebuggerTraceListener,Ukadc.Diagnostics", level="{EventType}", category="{Source}", output="{DebugFormat}" />

 

DebuggerTraceListener:

// THIS CODE AND INFORMATION ARE PROVIDED AS IS WITHOUT WARRANTY OF ANY
// KIND, EITHER EXPRESSED OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE
// IMPLIED WARRANTIES OF MERCHANTABILITY AND/OR FITNESS FOR A
// PARTICULAR PURPOSE.
using System;
using System.Collections.Generic;
using System.Text;
using System.Diagnostics;
using Ukadc.Diagnostics.Utils.PropertyReaders;
using Ukadc.Diagnostics.Utils;

namespace Ukadc.Diagnostics.Listeners
{
    /// <summary>
    /// DebuggerTraceListener writes trace messages to the debugger using System.Diagnostics.Debugger.Log
    /// </summary>
    public class DebuggerTraceListener : CustomTraceListener
    {
      private const string LEVEL_ATTR = "level";
      private const string CATEGORY_ATTR = "category";
      private const string OUTPUT_ATTR = "output";

      private PropertyReader _levelReader;
      private PropertyReader _categoryReader;

      private readonly object _initlock = new object();
      private bool _initialised = false;

      /// <summary>
      /// Get the level
      /// </summary>
      public string Level
      {
        get { return Attributes[LEVEL_ATTR]; }
      }

      /// <summary>
      /// Get the category
      /// </summary>
      public string Category
      {
        get { return Attributes[CATEGORY_ATTR]; }
      }

      /// <summary>
      /// Get the output format
      /// </summary>
      public string Output
      {
        get { return Attributes[OUTPUT_ATTR]; }
      }

      /// <summary>
      /// Return which attributes this trace listener supports
      /// </summary>
      /// <returns></returns>
      protected override string[] GetSupportedAttributes()
      {
        return new string[] { LEVEL_ATTR, CATEGORY_ATTR, OUTPUT_ATTR };
      }

      private PropertyReader _propertyReader;

        /// <summary>
        /// Creates a new instance of the DebuggerTraceListener class
        /// </summary>
        /// <param name="valueToken"></param>
        //public DebuggerTraceListener(string valueToken)
        public DebuggerTraceListener()
            : base("DebuggerTraceListener")
        {
        }

        //Initialize the property readers based on the configuration attributes.
        //"output" - formatted output
        //"level" - property reader to use to specify the error level
        //"category" - property reader to use to specify the category
        private void Init()
        {
          if (!_initialised)
          {
            lock (_initlock)
            {
              if (!_initialised)
              {
                _initialised = true;
                IPropertyReaderFactory readerFactory = DefaultServiceLocator.GetService<IPropertyReaderFactory>();
                _propertyReader = readerFactory.CreateCombinedReader(Output);
                _levelReader = readerFactory.CreateCombinedReader(Level);
                _categoryReader = readerFactory.CreateCombinedReader(Category);
              }
            }
          }
        }

        /// <summary>
        /// This method implements the logging for TraceEvent calls
        /// </summary>
        protected override void TraceEventCore(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string message)
        {
            Init(); //Be sure to call Init to initialize the property readers
            if (!ShouldLog()) // don't build the message if there's no-one listening
            {
                return;
            }
            object value;
            if (_propertyReader.TryGetValue(out value, eventCache, source, eventType, id, message, null))
            {
              object level;
              object category;

              bool gotLevel = _levelReader.TryGetValue(out level, eventCache, source, eventType, id, message, null);
              bool gotCategory = _categoryReader.TryGetValue(out category, eventCache, source, eventType, id, message, null);

              int logLevel;
              if (!Int32.TryParse(level.ToString(), out logLevel)) logLevel = 0;

              //Log the message based on the output of the property readers
              Log(logLevel, StringFormatter.SafeToString(category), StringFormatter.SafeToString(value));
            }
        }

        /// <summary>
        /// This method implements the logging for TraceData calls
        /// </summary>
        protected override void TraceDataCore(TraceEventCache eventCache, string source, TraceEventType eventType, int id, params object[] data)
        {
            Init(); //Be sure to call Init to initialize the property readers
            if (!ShouldLog()) // don't build the message if there's no-one listening
            {
                return;
            }
            object value;
            if (_propertyReader.TryGetValue(out value, eventCache, source, eventType, id, null, data))
            {
                object level;
                object category;

                bool gotLevel = _levelReader.TryGetValue(out level, eventCache, source, eventType, id, null, data);
                bool gotCategory = _categoryReader.TryGetValue(out category, eventCache, source, eventType, id, null, data);

                int logLevel;
                if (!Int32.TryParse(level.ToString(),out logLevel)) logLevel = 0;

                //Log the message based on the output of the property readers
                Log(logLevel, StringFormatter.SafeToString(category), StringFormatter.SafeToString(value));
            }
        }

        private bool ShouldLog()
        {
            return Debugger.IsLogging();
        }

        private void Log(int level, string category, string message)
        {
          Debugger.Log(level, category, message);
        }

        private void Log(string message)
        {
          Debugger.Log(0, "dbg", message);
        }
    }
}

 

Jun 17, 2010 at 2:50 PM

I went back and modified the DebuggerTraceListener again so that it uses the initializeData parameter from the app.config file and the 1-parameter constructor to set up the output format.  I left in the retrieval of the property readers for level and category and everything still works.  Originally, after I had made the changes to add the level and category property tokens, I had a hard time getting the DebuggerTraceListener working again.  That is what prompted me to change from using initializeData (and the 1-parameter constructor) to using an explicit output format token and a default constructor (I was following the example of the FileTraceListener).  Anyway, the code from above is pretty much the same except for adding back the old constructor signature and adding back some code to the constructor to configure the output format property reader.

Jun 23, 2010 at 6:50 PM

Update ...

I have started a new, more elaborate, test project using Ukadc.Diagnostics and the DebuggerTraceListener.  I found that the Debugger.Log results were all going out in one line.  I thought that was weird because I had run into that same problem before, as I mentioned above, and thought that I had fixed it by ensuring that the category parameter of the Debugger.Log statement was NOT null.  I went back to the program that I used to test Debugger.Log and found that it was giving the "right" output (each Debugger.Log statement went to a separate line).  My test code looks like this:

    static void Main(string[] args)
    {
      Console.WriteLine("Main - Enter - Console.WriteLine");
      Debug.WriteLine("Main - Enter - Debug.WriteLine");

      Debugger.Log(0, "abc", "message1");
      Debugger.Log(1, "def", "message2");
      Debugger.Log(2, "ghi", "message3");
      Debugger.Log(-1, "jkl", "message1");
      Debugger.Log(-2, "mno", "message2");
      Debugger.Log(-3, "pqr", "message3");

      Debug.WriteLine("Main - Exit - Debug.WriteLine");
      Console.WriteLine("Main - Exit - Console.WriteLine");
    }

In my test program, each Debugger.Log statement goes to a separate line.

In my new test of the DebuggerTraceListener, the category parameter is NOT null, yet all of the Debugger.Log output lines go to the same line.

So, I went back to my Debugger.Log test program (that has the code pasted above) and found that I had turned on "Enable unmanaged code debugging" (because I was also using this program to test OutputDebugString, which requires that setting in order to see the OutputDebugString output in the Output window).  I turned off the "Enable unmanaged code debugging" setting and now, in my test program, all Debugger.Log statements output to the same line, regardless of the value of the category parameter.

In the end, this is what I found:

If "Enable unmanaged code debugging" is OFF then all Debugger.Log statements go on one line, regardless of the value of the category parameter and the category parameter is not printed.

If "Enable unamanged code debugging" is ON AND the category parameter is not null (i.e. either a string like "abc" or string.Empty) then all Debugger.Log statements go on separate lines and the category parameter is printed.

If "Enable unmanaged code debugging" is ON AND the category parameter is null then all Debugger.Log statements go on the same line and the category parameter is not printed (actually, category is null, so who knows whether it "printed" or not).

Anyway, the bottom line is that the Debugger.Log behavior seems a little odd to me and my proposed solution from earlier (of making sure that category is not null) does not work the way that I thought it did.  Also, the proposal to hardcode the category parameter to string.Empty also does not have the desired effect, unless "Enable unmanaged code debugging" is ON.  Don't take this as a complaint about the DebuggerTraceListener because it seems obvious that it is the Debugger.Log statement has the odd behavior, not the DebuggerTraceListener.  Granted, your suggestion of string.Empty (or any non-null string for that matter) does work better than null, so your proposed fix is better than null.

 

 

Jun 23, 2010 at 8:26 PM
Thanks for the detailed update - god information. Josh