Events not received by out-of-process listener when string parameter is null

Topics: Semantic Logging Application Block
Mar 15, 2014 at 7:17 PM

I have a simple problem (I think), but I can't find any information to confirm the valid behaviour.

I have a simple test event:
        public void LoadTest(string testName, int eventsPerSecond, string executionLength, int eventNumber)
            LoadTest(testName, eventsPerSecond, executionLength, eventNumber);

        [Event(4, Keywords = Keywords.MonitoringService, Level = (EventLevel)LogLevel.Error, Message = "Load test event - test name [{0}] events per seconds [{1}] execution length [{2}] event # [{3}]")]
        private void LoadTest(string testName, int eventsPerSecond, string executionLength, int eventNumber)
            if (LoadTestIsEnabled())
                WriteEvent(4, testName, eventsPerSecond, executionLength, eventNumber);

        public bool LoadTestIsEnabled()
            return IsEnabled((EventLevel)LogLevel.Error, (EventKeywords)EventKeywordFlags.MonitoringService);
If one of the string parameters is null (e.g. LoadTest(null, 1, "foo", 1);), I do not get this event on the out-of-process listener (i.e. through ETW). But I do receive the event on an in-process listener.
If I change that string parameter to String.Empty, I do get this event on the out-of-process listener too.

I can change the event to coalesce null to String.Empty, but I don't like to make a change without knowing what is wrong in the first place. Please point out what am I doing wrong?!

Thank you very much.

Regards, Paul.
Mar 16, 2014 at 6:06 PM
Edited Mar 16, 2014 at 6:06 PM
tl;dr In general, don't send null strings to EventSource.WriteEvent. In some scenarios it will work and in some it won't.

I see the same behavior as you do with a slightly modified version of the posted EventSource.

However if you change the method signature to something like this:
        [Event(4, Keywords = Keywords.MonitoringService, Level = (EventLevel)LogLevel.Error, Message = "Load test event - test name [{0}] events per seconds [{1}] event # [{2}]")]
        private void LoadTest(string testName, int eventsPerSecond, int eventNumber)
            if (LoadTestIsEnabled())
                WriteEvent(4, testName, eventsPerSecond, eventNumber);

[The only change I made was removing the executionLength parameter.]

And if you then call it like this:
LoadTest(null, 1, 1);
you will see that the event is written in the above scenario with a null string.

So what is the difference between the two scenarios and why is the message not written? The difference of behavior happens in the System.Diagnostics.Tracing.EventSource.

When the method WriteEvent(string, int, int) is called the specific EventSource.WriteEvent(string, int, int) overload is invoked. If a null is passed in it is converted to an empty string.

However, there is no explicit overload that accepts (string, int, string, int) so when WriteEvent(string, int, string, int) is called the overload is resolved as EventSource.WriteEvent(int eventId, params object[] args). The params implementation checks for null and if one of the parameters is null it (may) throw an exception. This makes sense because when writing to ETW the EventSource needs to marshall the payload so it can be sent out-of-process. To do this the type of the items in the object array are used and if the object is null then there is no type information available.

So, when a null argument is passed to WriteEvent(int eventId, params object[] args) the event is not sent to ETW. You can see this if you change the event source to set the throwOnEventWriteErrors in the EventSource constructor:
        private MyEventSource() 
            : base(true)
            // ...
Now if an out-of-process session is open (e.g. semantic logging service) and a null is passed in an exception will be raised:

Unhandled Exception: System.Diagnostics.Tracing.EventSourceException: Null passed as a event argument.
at System.Diagnostics.Tracing.EventSource.ThrowEventSourceException()
at System.Diagnostics.Tracing.EventSource.WriteEventVarargs(Int32 eventId, Guid* childActivityID, Object[] args)

Currently, string is the only nullable type that can be passed in to an EventSource so it might be safe to assume that any null values are strings and set to empty. Or perhaps the type information could be retrieved from the manifest? Maybe this wasn't done due to existing ETW behavior or to accommodate for future nullable types or to avoid more complicated issues on the receiving end (exceptions) or for performance.

So why does the in-proc scenario work? It succeeds because ETW is probably not also enabled (e.g. semantic logging service is not running) and even if it was the default is not to throw exceptions and instead silently fail on writing to ETW. After sending any ETW messages then all other listeners are notified of the event being written. For the in-process scenario, because there is no marshalling required, the arguments are put in a list and passed in as the payload for the event written event and there are no problems.

Randy Levy
Enterprise Library support engineer
Support How-to
Marked as answer by pvwichen on 3/16/2014 at 1:30 PM
Mar 16, 2014 at 9:29 PM
Thanks Randy for the speedy and detailed reply.

I will good ahead with the planned "value ?? String.Empty" (my event sources are generated by T4 transforms so I can easily apply to all event methods).

Thanks for the info on enabling exceptions too. I had been reviewing that class on the MSDN site, but had been too focused on the WriteEvent method. Had I tested with that enabled, I could have confirmed my suspicions.

Thanks again.