The EventSource NuGet package and support for the Windows Event Log (Channel Support)
One of the more common questions we get about the System.Diagnostics.Tracing.EventSource class is whether it can be used to log message to the
Windows Event Log (that is can be viewed with eventvwr.exe). This EventLog support is also called 'Channel support' because that is the official name for a 'stream of events' in the Windows event log.
The answer to whether EventSource supports the Windows Event log as a target has been 'no' but now the answer is 'yes'. Moreover, you don't even have to wait for the next version of the .NET Framework to get it.
That is because we have now created a 'Stand alone' version of EventSource and published as the Microsoft EventSource Library NuGet Package (currently in Prerelease form, so you have to set your filtering to include prereleases to see it). Note that the class in this package is in a different namespace Microsoft.Diagnostics.Tracing.EventSource, so it is 'side by side' with System.Diagnostics.Tracing.EventSource that comes with the V4.5 framework. It is however intended to be 100% compatible with code using the framework version. It is also effectively your way of getting at new features of the framework version before they are officially released (or your customers have upgraded their framework). Switching from one to the other should be as easy as changing a 'Using' declaration at the top of the file that uses EvenSource.
Thus Windows Event Log support is just the first installment of new features that we will be bringing to you through NuGet as a way of getting started now without having to wait for the next version of the runtime.
To see more details about the Event Log support see the dotnet Blog entry 'Announcing the EventSource NuGet Package : Write to the Windows Event Log'.
Along with the Microsoft EventSource Library NuGet Package, there is also the Microsoft EventSource Library Samples NuGet Package. This package makes it very easy to download some working EventSource code and see well commented examples of its use. The best way to use this samples package is to
- Create a new Console Application in Visual Studio called 'DemoEventSource'
- Reference the Microsoft EventSource Library Samples NuGet Package from this new project by
- Right clicking on the 'References node in the Project tree
- Selecting 'Manage NuGet Packages
- Searching for 'EventSource Samples'
- Selecting the Microsoft EventSource Library Samples package
- It will download some code to a 'EventSourceSamples directory, which you look at
- You run the code by adding the following line to your main program
- EventSourceSamples.AllSamples.Run();
- Hit F5.
Some of the samples are very similar to samples I have blogged about in the past, but the Window Event Log sample is new. It is also more complex because there is a registration (install time) step with the operating system. This is the price you pay for wanting your messages to get to the Windows EventLog.
Finally, also included in both packages is a EventSource Users Guide. This contains information similar to things I have blogged about, as well as best practices etc. Note that the previous link (as the file in this blog) may not be up to date. The most up to date version is in the Microsoft EventSource Library NuGet Package.
Vance
Comments
Anonymous
September 29, 2013
Hi Vance. Thanks for your amazing work on the ETW support for .NET Framework. There are a few problems that we encounter while using EventSource and TraceEvent libraries in our application. When using theparamsoverload of theWriteEventmethod, passingnullto one of the string parameters causes the call to silently fail. Consider this class: class MyEventSource : EventSource { public static readonly MyEventSource Log = new MyEventSource(); public void Write(string userName, int i, string text) { WriteEvent(1, UserName, i, text); } } This will fall back to theparamsoverload of theWriteEvent. If we do: MyEventSource.Log.Write(null, 1, "this is a text"); the event will not be sent, while if we remove the int parameter (that uses one of the non-params overloads) the call will succeed. I've tested this in the latest version of the EventSource nuget package (1.0.6-beta) and the problem still exists. ThanksAnonymous
September 29, 2013
Strange thing is that calling both MyEventSource.Log.Write(null, 1, "text"); and MyEventSource.Log.Write("user1", 1, null); fails in nuget package version, but in .NET 4.5 version only the first call fails!Anonymous
September 30, 2013
The basic answer to your question is that passing null to an WriteEvent method is illegal. This can be inconvenient for some cases where strings are passed, there are a number of problems with making WriteEvent do something with null strings (most noteably is that ETW does not define a serialization for the null string). Our advice is that if you need to pass null strings to your logging functions that you do the null check in your helper routine using the ?? operator. public void Write(string userName, int i, string text) { WriteEvent(1, UserName??"", i, text); }Anonymous
September 30, 2013
Thanks for your answer Vance. This is what I do now, but it took me some time (almost a day) to debug the EventSource source code (using .NET Reflector VS Add-In) and find the reason for not sending the event when I add anintparameter to my event method! (No relevant, but my situation was a little complicated because we are creating EventSources dynamically using dynamic assembly generation and Emit) The inconsistent behavior is what mostly I'm complaining about. By the way, I'm very thankful for your great job. Another problem we have is that we cannot receive events from an EventSource by two separate sessions at the same time when one of the sessions are started after the creation of the EventSource. The second session receives the events as unhandled events. The event ID and other data are correct, but it does not contain the event name and parsed payload data. What I found so far is that the manifest data is sent only for the first session, so the second session knows nothing about the structure of the events. I'm trying to solve this problem by manually sending the manifest data (calling EventSource.SendManifest method) every time the EventSource is being enabled by a session. What do you recommend?Anonymous
September 30, 2013
Oh! Sorry! I was using the .NET 4.5 version. The problem is fixed in the latest version (Nuget package). I forgot to test my second problem with new version. After 2 days of investigation, and fixing the problem my own way, I found that it is already fixed in the new version! Thanks again!Anonymous
October 24, 2013
I have been having some problems with registering the ETW Manifest files. When I built my sample in My DocumentsVisual Studio 2012Project... I got this error: **** Warning: Publisher Blah-Blah-Blah esources are not accessible. Saw something on the web about paths too long so moved the solution to C:Temp. Now it registers without error but the corresponding logs aren't created. When I check with wevtutil gp Blah-Blah-Blah, I get: name: Blah-Blah-Blah guid: e71f8805-84a4-502f-4fe9-54cc01066a60 Failed to get helpLink property. The specified image file did not contain a resource section. FWIW if I open the manifest DLL I see two resource sections: 11 and "WEVT_TEMPLATE". I am targeting .NET 4.0. And just tried .NET 4.5 - same error. What could I be doing wrong?Anonymous
October 24, 2013
Nevermind. Pilot error on the wevtutil.exe im invocation. I had the .man file as the /mf: parameter. Also you have to apparently stop & restart the computer management console in order to see the new log.Anonymous
October 24, 2013
BTW why do my EventChannel.Admin log entries have Keywords set to: Session0,Session1,Session2,Session3 I did not specify these in the corresponding attribute. Where is this value coming from?Anonymous
October 25, 2013
The short answer, is that these are internal keywords reserved for EventSoruce/Session communication. The longer answer is that EventSource supports passing extra parameters from the session to the EventSource to specify more precisely than Keywords can which events a particular session wants. Sadly ETW's support for this is incomplete and two session using this technique may interfere (sessions might see events that were intended for the other session). EventSource fixes this by reserving some of the keywords (those 4 shown above), to represent up to 4 sessions that an event might be destined for. This allows each session to only receive the events that they actually turned on.Anonymous
October 25, 2013
Thanks for the clarification on the use of Keywords by EventSource. BTW I was somewhat surprised that I could export the event log to file and read it on another machine and have all the custom message formatting strings appear on the other machine where I hadn't registered the ETW manifest. Is this more of the EventSource magic of inline manifests?Anonymous
October 25, 2013
When you say 'log file' I assume you mean ETL file. and the tools you are referring to are either PerfView or WPA then yes, that is by design. EventSources log their manifest to the event stream so that the ETL file is self-describing (they way it always should have been). Note that other Providers besides Evensources can do this (it is a contract between providers and consumers).Anonymous
October 25, 2013
Actually I'm referring to an EVTX file created by the Windows EventViewer. That loaded up on another machine I couldn't tell a diference. All my custom formatted "Messages" appear just fine there. I wasn't expecting that to work since the manifest wasn't installed on the other machine.Anonymous
October 25, 2013
I don't have any insight into EVTX files, but clearly they store the formatted information and not the raw information (which is the right thing to do).Anonymous
November 01, 2013
I'm using this drop in a .NET 4.0 application but I'm having trouble getting PerfView to give me DURATION_MSEC information even though I'm using the attribute values: [Event(..., Task = Tasks.ParseMessages, Opcode = EventOpcode.Start)] and [Event(..., Task = Tasks.ParseMessages, Opcode = EventOpcode.Stop)] What I find is that if I specify no parameters to some of my start/stop methods I get DURATION_MSEC in PerfView. However in some case (like Tasks.ParseHeaders) I don't have the parsed header until I hit the Stop method. So the ParseHeadersStart() event source call takes no parameters and the ParseHeadersStop(string header) takes on parameter. I several Start/Stop pairs like this that only have a parameter in the Stop method. None of the give timing info i.e. DURATION_MSEC. I haven't quite figured out the magic of getting correlation (ActivityID) to work with EventSource. Is there something I'm missing?Anonymous
November 04, 2013
The issue with computing durations is that many starts and stops might be in flight at the same time. Thus you need something 'id' that allows you to 'link up' start and stop events unambiguously. PerfView has some heuristics, but if you make the first field in your Start and Stop event be an ID that uniquely identifies the start-stop pair, then PerfView should produce the DURATION_MSECAnonymous
November 07, 2013
In section 5.6.2.2 of the spec, it would be helpful to give a WriteEventCore example that takes a string argument. When getting a pointer to the string, do we need to marshal the string to HGlobalAnsi string?Anonymous
November 07, 2013
Here is an example of using EventWriteCore to write a string and an integer argument This code is very similar to some of the type specific WriteEvent() classes that are shipped in the library. Basically you use the 'fixed' statement to pin the string, stack allocate the descriptors needed and call the core function with the descriptors of the arguments. You can have several nested fixed statements if you want to pass multiple strings. Notice that the string length includes a null terminator which is part of every .NET string. unsafe void WriteEvent(int eventId, string arg1, int arg2) { fixed (char* string1Bytes = arg1) { EventSource.EventData* descrs = stackalloc EventSource.EventData[2]; descrs[0].DataPointer = (IntPtr)string1Bytes; descrs[0].Size = ((arg1.Length + 1) * 2); descrs[1].DataPointer = (IntPtr)(&arg2); descrs[1].Size = 4; WriteEventCore(eventId, 2, descrs); } }Anonymous
November 11, 2013
>> PerfView has some heuristics, but if you make the first field in your Start and Stop event >> be an ID that uniquely identifies the start-stop pair, I've noticed that Start/Stop WriteEvent() calls with no parameters seem to pair up correctly in PerfView. But I'm thinking I should not rely on that and should pass in a unique ID anyway, right? BTW, one enhancement request is that it would be nice to have a WriteEvent overload that supports a string parameter(s) but with an int parameter (for this start/stop pairing ID) right after the eventId parameter and before the string parameter(s). Hence my question about passing strings into WriteEventCore. :-)Anonymous
November 11, 2013
PerfView uses the ActivityID and if that is not present the thread ID as the coorelationID for start and stop if you dont' provide one. ActtivityID could be 'perfect' and ultimately would probably be enough, but in the short term having an ID is definitely a good idea.Anonymous
November 14, 2013
Just to be clear, there is no way using the current EventSource implementation for clients to specify the ActivityId. That seems to be an internal detail and it kind of looks like it is passing a null Guid*. I guess that is why it is best to use our own ID.Anonymous
November 14, 2013
You can specify an Activity ID with the Nuget version of the EventSource. See the SetCurrentThreadActivityId API. However you can do more harm than good if you set ActivityIds without a clear understanding of how they should be used (you can clobber some other code that WAS using them correctly). If you goal is simply to hook up start and end events, it is better to use an ID (also ActivityIDs are not guaranteed to be enough, since you could start two tasks on one thread, but complete them on two different threads 'caused' by that activity. In that case, activity IDs are not sufficient to disambiguate. Thus it is really not bad to have an ID for a start and stop event EVEN IF you also use activities IDS. Ultimately they are for different purposes.Anonymous
December 02, 2013
Can you implement AppFabric-enabled WCF Data Service as show in Ron Jacobs excellent blog post but with the new .Net 4.5 EventSource infrastructure?Anonymous
December 02, 2013
Sound a bit outside the scope of the EventSource package.Anonymous
April 07, 2014
The comment has been removedAnonymous
April 08, 2014
The comment has been removedAnonymous
April 08, 2014
The comment has been removedAnonymous
April 08, 2014
Indeed you do seem to understood the basics of how activity IDs need to work. As you your question about when Activity ID management will be in place, it is indeed coming, but it will come in phases over time. Already some support is already in place (the TPL events for instance), and some rudimentary support is available in some libraries and tools (e.g. TraceEvent and PerfView), and more is coming. There is work in App Insights and VS tooling in this area. I would like to flip the question around. You were about to add ActivityID code to your library/app. What exactly where you hoping to get from it? What tool or library (or whatever) were you expecting to 'light up'? and in what way (how did you expect your events to be displayed in that tool). What exactly do you mean by 'ActivityID management'? At one level, we do have the most important basic plumbing of an end-to-end activity management system in place (e.g. the TPL events are there and added the SetCurrentThreadActivityId which allow us to instrument the rest of the framework), and we are moving up the stack, making infrastructure that can process this activity information. Thus we are executing on a plan. But realistically a really good end-to-end story is many months off. However it is possible and event likely that you can get 'good enough' solutions that will tide you over much more quickly, depending on exactly what you need most critically. Thus having some idea what you want and what the priorities of each of those desires is would be helpful. Finally one last point. While we can commiserate about the current level of support for activities, what is definitely true is that a certain amount of instrumentation on your part (start and stop event of the time periods that are most critical to you) is part of the long term plan, and YOU CAN GET VALUE from the IMMEDIATELY (you can do light weight, monitoring) Thus getting 'your part' of the plan done is a clear first step.Anonymous
June 05, 2014
The comment has been removedAnonymous
August 11, 2014
I haven't seen any feedback on this. I'm beginning to use tools like Microsoft Message Analyzer and PerfView. The lack of an Activity ID prevents many features from working such as Call Stacks. Any advice is welcomed.Anonymous
August 11, 2014
Are you saying that when you log with your EventSource (and send it to an ETL file) do you see both the ActivityID and RelatedActivityID when you view it with WPA or PerfView, but not when you look in the windows Event viewer (the windows EventLog)? This is surprising. This may be a bug in the OS;s EventWriteTransfer API. It is supposed to get the activity ID from thread local storage if you don't pass an activity ID explicitly (which it seems to do properly for ETL files), but I wonder if it fails to do that when sending the data to the Windows Event Log. Can you work-around this by simply passing the activity ID as some other payload field.Anonymous
November 19, 2015
Hi Vance Morrison, Not sure if this the right place for asking question about ETW on Azure. When I use ETW within the Azure Cloud Service, I recorded event with WriteEventWithRelatedActivityIdCore, the etw result in the Azure Cloud Service Storage do not include the "RelatedActivityId" column. Is this the default behavoir of azure diagnostics logging sink? Is this behavior could be customized? BTW, I can see those columns when I use PerfView.Anonymous
November 20, 2015
If you see the columns in PerfView, it means that the RelatedActivityID is actually being written out properly. To be able to comment more, I would need to know more specifics on what service is listening and copying your events (Is it WADS?). This is more properly a question to that team.Anonymous
November 20, 2015
The comment has been removedAnonymous
February 15, 2016
The comment has been removedAnonymous
February 17, 2016
The comment has been removedAnonymous
February 21, 2016
"If the string that you log contains %n, where n is an integer value (for example, %1), the event viewer treats it as an insertion string. Because an IPv6 address can contain this character sequence, you must provide a format specifier (!S!) to log an event message that contains an IPv6 address. This specifier tells the formatting code to use the string literally and not perform any further expansions (for example, "my IPv6 address is: %1!S!")." In contrast, the same topic in Visual Studio 2008 documentation (Build date: 8/15/2007) said: "Note that there is no way to log a string that contains %n, where n is an integer value. This syntax is used in IPv6 addresses, so it is a problem to log an event message that contains an IPv6 address. For example, if the message text contains %1, the event viewer treats it as an insertion string." I tested it a bit on Windows 7 SP1 by running this command as administrator: EVENTCREATE /ID 1 /L Application /SO RecursiveExpansionTest /T INFORMATION /D "{{%1}}, [[%1!s!]], ((%1!S!))" This command registered "RecursiveExpansionTest" as an event source with EventMessageFile = REG_EXPAND_SZ "%SystemRoot%System32EventCreate.exe", in which each entry of the message table contains only "%1" and a newline. I then opened Event Viewer, in which XML View displayed the EventData as follows: <EventData> <Data>{{%1}}, [[%1!s!]], ((%1!S!))</Data> </EventData> The General tab of Event Viewer expanded the event to: {{{{{{{{%1}}, [[%1!s!]], ((%1!S!))}}, [[{{%1}}, [[%1!s!]], ((%1!S!))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))}}, [[{{{{%1}}, [[%1!s!]], ((%1!S!))}}, [[{{%1}}, [[%1!s!]], ((%1!S!))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))}}, [[{{{{{{%1}}, [[%1!s!]], ((%1!S!))}}, [[{{%1}}, [[%1!s!]], ((%1!S!))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))}}, [[{{{{%1}}, [[%1!s!]], ((%1!S!))}}, [[{{%1}}, [[%1!s!]], ((%1!S!))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!))))!s!]], (({{%1}}, [[%1!s!]], ((%1!S!)))) Clearly, Event Viewer recognized the "%1" in the insertion string and further expanded it. I did not test the %%number syntax and ParameterMessageFile. I did not test "%1!s!" and "%1!S!" in the message table. I did not test using the ETW API instead of ReportEvent.Anonymous
February 21, 2016
The page is "ReportEvent function (Windows)" msdn.microsoft.com/.../aa363679%28v=vs.85%29.aspx As a programmer, I don't think it is useful that Event Viewer scans insertion strings for references to more insertion strings, but that's what it does so I'll have to cope with it. References to ParameterMessageFile are more useful -- or at least would be if there were a public ParameterMessageFile for looking up Win32 error codes. Those are now in kernel32.dll but I don't think Microsoft has ever documented that, so it's subject to change. In Windows 7 and later though, I think I could instead use template/data/@outType="win:Win32Error" in an instrumentation manifest and not have to refer to a specific file. If "%1!S!" indeed prevents expansion of the %number (insertion string) and %%number (parameter message) syntaxes, that's nice, but I'll have to test with a few versions of Windows before I dare use that.Anonymous
February 26, 2016
I tested a similar thing using the EventSource 1.1.28 NuGet packages on Windows 7. The repeated expansion happens there too. I built the following program: namespace TestEventLogRecursiveExpansion { using Microsoft.Diagnostics.Tracing; internal class Program { private static void Main(string[] args) { using (var eventSource = new TestEventSource()) { eventSource.Demo1("one: 2=[%2]", "two"); } } } [EventSource(Name = "Test-EventLog-RecursiveExpansion")] internal sealed class TestEventSource : EventSource { [Event(1, Channel = EventChannel.Admin, Level = EventLevel.Informational, Message = "Demo1: arg1=[{0}], arg2=[{1}]")] public void Demo1(string arg1, string arg2) { this.WriteEvent(1, arg1, arg2); } } } I then registered the manifest using "wevtutil im", and ran the program. Event Viewer displayed "Demo1: arg=[one: 2=[two]], arg2=[two]". I would have preferred "Demo1: arg=[one: 2=[%2]], arg2=[two]". Next, I unregistered the manifest and edited it, changing this part <string id="event_Demo1" value="Demo1: arg1=[%1], arg2=[%2]"/> to the following: <string id="event_Demo1" value="Demo1: arg1=[%1!S!], arg2=[%2!S!]"/> I compiled the manifest to a DLL using "eventRegister.exe -CompileManifest", registered it again using "wevtutil im", and restarted Event Viewer. Now it displayed "Demo1: arg1=[one: 2=[%2]], arg2=[two]". Finally, I unregistered, edited, compiled, and registered the manifest again, but this time with lower-case "%1!s!" and "%2!s!". Event Viewer again displayed "Demo1: arg1=[one: 2=[two]], arg2=[two]". It appears that only an upper-case "!S!" prevents nested expansion. Thus, I think ManifestBuilder.TranslateToManifestConvention should indeed be changed to emit "%1!S!" rather than "%1", so that IPv6 addresses with scope identifiers can be safely logged.Anonymous
February 28, 2016
I have passed this along to the owner of the code. I agree it is a good change.- Anonymous
March 25, 2016
Hi Vance,This was really helpful information to log to windows event log.I have got a use case where I need to have a my own defined channel .For example , I have many plugins trying to use my library to log to windows event log.I need to separate these plugins under my folder MyCompany/MyApp/Plugin1 or MyCompany/MyApp/Plugin2 instead MyCompany/MyApp/Admin(or Operational or Debug or Analytic).Is this possible ?
- Anonymous