runtime: EventSource is not emitting events to the Windows Event Log

Any progress on this one?

Any updates on this issue?

We have used the event log for a very long time and our customers expects to find their logging information from our products in there.

It is not an option to log directly to the Application Log since we need to provide our own manifest (and make the log appear under “Application and services logs”).

I tried to debug this on .NET 5.0.1. eventRegister.exe from Microsoft.Diagnostics.Tracing.EventRegister/1.1.28 could not load EventSourceTest.Logging.dll, so I added code to write the manifest out:

            string manifest = SampleEventSource.GenerateManifest(
                typeof(SampleEventSource),
                "dummy.dll");
            Console.WriteLine(manifest);

and then built a DLL for it:

bin\Debug\net5.0\EventSourceTest.exe > EventSourceTest.man
mc EventSourceTest.man
rc EventSourceTest.rc
csc  /target:lib /win32res:EventSourceTest.res /out:mani.dll
wevtutil install-manifest EventSourceTest.man /resourceFilePath:%CD%\mani.dll /messageFilePath:%CD%\mani.dll

<instrumentationManifest xmlns="http://schemas.microsoft.com/win/2004/08/events">
 <instrumentation xmlns:xs="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:win="http://manifests.microsoft.com/win/2004/08/windows/events">
  <events xmlns="http://schemas.microsoft.com/win/2004/08/events">
<provider name="SampleEventSource" guid="{b10d9bdd-6939-484f-93a9-be419202e3ac}" resourceFileName="dummy.dll" messageFileName="dummy.dll" symbol="SampleEventSource">
 <channels>
  <channel chid="Admin" name="SampleEventSource/Admin" value="16" type="Admin" enabled="true"/>
 </channels>
 <tasks>
  <task name="MyEvt1" message="$(string.task_MyEvt1)" value="65533"/>
  <task name="EventSourceMessage" message="$(string.task_EventSourceMessage)" value="65534"/>
 </tasks>
 <opcodes>
 </opcodes>
 <keywords>
  <keyword name="Session3" message="$(string.keyword_Session3)" mask="0x100000000000"/>
  <keyword name="Session2" message="$(string.keyword_Session2)" mask="0x200000000000"/>
  <keyword name="Session1" message="$(string.keyword_Session1)" mask="0x400000000000"/>
  <keyword name="Session0" message="$(string.keyword_Session0)" mask="0x800000000000"/>
 </keywords>
 <events>
  <event value="0" version="0" level="win:LogAlways" symbol="EventSourceMessage" task="EventSourceMessage" template="EventSourceMessageArgs"/>
  <event value="1" version="0" level="win:Critical" symbol="MyEvt1" message="$(string.event_MyEvt1)" task="MyEvt1" channel="Admin" template="MyEvt1Args"/>
 </events>
 <templates>
  <template tid="EventSourceMessageArgs">
   <data name="message" inType="win:UnicodeString"/>
  </template>
  <template tid="MyEvt1Args">
   <data name="arg1" inType="win:UnicodeString"/>
  </template>
 </templates>
</provider>
</events>
</instrumentation>
<localization>
 <resources culture="en-US">
  <stringTable>
   <string id="event_MyEvt1" value="MyEvt1"/>
   <string id="keyword_Session0" value="Session0"/>
   <string id="keyword_Session1" value="Session1"/>
   <string id="keyword_Session2" value="Session2"/>
   <string id="keyword_Session3" value="Session3"/>
   <string id="task_EventSourceMessage" value="EventSourceMessage"/>
   <string id="task_MyEvt1" value="MyEvt1"/>
  </stringTable>
 </resources>
</localization>
</instrumentationManifest>

Then ran that in WinDbg with dotnet-sos, with breakpoints at ntdll!EtwEventWriteTransfer and ntdll!EtwEventRegister.

After many ntdll!EtwEventRegister calls from other components, I got the one from SampleEventSource:

• LPCGUID ProviderId = rcx = {b10d9bdd-6939-484f-93a9-be419202e3ac}, matching EventSourceAttribute.Guid
• PENABLECALLBACK EnableCallback = rdx = 0x00007ff9`3c743144; set a breakpoint there
• PVOID CallbackContext = r8 = 0
• PREGHANDLE RegHandle = r9 = 0x000001e9`0c45f5b8

The EnableCallback was called with arguments:

• LPCGUID SourceId = rcx = {00000000-0000-0000-0000-000000000000}
• ULONG IsEnabled = rdx = 1
• UCHAR Level = r8 = 0xff
• ULONGLONG MatchAnyKeyword = r9 = 0x80000000`00000000
• ULONGLONG MatchAllKeyword = 0
• PEVENT_FILTER_DESCRIPTOR FilterData = 0
• PVOID CallbackContext = 0

Soon after, ntdll!EtwEventWriteTransfer was called from within EventSource.SendManifest, with arguments:

• REGHANDLE RegHandle = rcx = 0x002d01e9`0c3e3820
• PCEVENT_DESCRIPTOR EventDescriptor = rdx = { Id = 0xfffe, Version = 0x01, Channel = 0x00, Level = 0x00, Opcode = 0xfe, Task = 0xfffe, Keyword = 0x00ffffff`ffffffff }
• LPCGUID ActivityId = r8 = 0
• LPCGUID RelatedActivityId = r9 = 0
• ULONG UserDataCount = dwo(rsp+0x28) = 2
• PEVENT_DATA_DESCRIPTOR UserData = poi(rsp+0x30) = { { Ptr = 0x00000045`cd57d2a8, Size = 8, Type = 0 }, { Ptr = 0x000001e9`0c464d00, Size = 0x0000093a, Type = 0 } }. That’s the manifest, all right.

Another ntdll!EtwEventWriteTransfer call, now from within SampleEventSource.MyEvt1:

• REGHANDLE RegHandle = rcx = 0x002d01e9`0c3e3820
• PCEVENT_DESCRIPTOR EventDescriptor = rdx = { Id = 0x0001, Version = 0x00, Channel = 0x10 (Admin), Level = 0x01, Opcode = 0x00, Task = 0xfffd, Keyword = 0x0000f000`00000000}
• LPCGUID ActivityId = r8 = 0
• LPCGUID RelatedActivityId = r9 = 0
• ULONG UserDataCount = dwo(rsp+0x28) = 1
• PEVENT_DATA_DESCRIPTOR UserData = poi(rsp+0x30) = { { Ptr = 0x000001e9`0c44b644 = L"test\0", Size = 0xa, Type = 0 } }.

Keyword = 0x0000f000`00000000 is nonzero (see EVENT_ENABLE_PROPERTY_IGNORE_KEYWORD_0 in ENABLE_TRACE_PARAMETERS) but does not match MatchAnyKeyword = 0x80000000`00000000, so ETW discards the event, I think.

Indeed, if I force EVENT_DESCRIPTOR::Keyword to zero in the debugger, then the event appears in Event Viewer.

I wonder whether older versions of EventSource have implicitly set the 0x80000000`00000000 keyword.

Can verify this as well. Events are captured in event viewer if the target is .NET framework 4.6.2 but is not showing up when target is netcoreapp2.2. This prevents us from logging to event viewer in any of our .net core apps.

I suspect this part of ManifestBuilder.GetChannelKeyword should compare channelKeyword == 0 rather than channelKeyword != 0: https://github.com/dotnet/runtime/blob/d4d50db6768f729857b27ced3b68067bf30d18de/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/EventSource.cs#L5332-L5344

As noted years ago in https://github.com/dotnet/coreclr/pull/6628#commitcomment-20938351.

Well, it seems like there is a channel support in .NET Core. If you add an EventAttribute to your EventSource method and specify the Keywords parameter with the value -9223108154064109568 everything is working, EventViewer starts to see all events.

[Event(5, Channel = EventChannel.Admin, Level = EventLevel.Critical, Keywords = ((EventKeywords)(-9223108154064109568)),
            Message = "Instance: {0}\nSource: {1}\nMessage: {2}")]
public override void Critical(string instanceId, string loggerName, string message)
{
    this.WriteEvent(5, instanceId, loggerName, message);
}

Don’t ask how I found this constant -9223108154064109568.