Short version
If I change this ...
EventSource(Name="BasicLogger")
public class BasicLogger : EventSource { ... }
to this ...
EventSource(Name="HardymanDatabaseLog")
public class BasicLogger : EventSource { ... }
... I still receive log messages, but they are corrupted.
Either the messages don't arrive, or they are formatted by a missing/deleted/removed method that doesn't even exist in my current project!
For some unknown reason there is a problem with the specific string 'HardymanDatabaseLog'
I think it might be down to a corrupted instrumentation manifest that is manifestering somewhere.
Read on to find out more ...! ( thanks :o) )
Long Version (with pictures)
I have a simple console application that references EnterpriseLibrary.SemanticLogging
via a nuget package.
Using the example code from here, I added a BasicLogger
class.
When I run my simple app ...
using System.ComponentModel;
using System.Diagnostics.Tracing;
namespace Etw
{
class Program
{
static void Main(string[] args)
{
BasicLogger.Log.Error("Hello1");
BasicLogger.Log.Critical("Hello2");
}
}
[EventSource(Name = "BasicLogger")]
public class BasicLogger : EventSource
{
public static readonly BasicLogger Log = new BasicLogger();
[Event(1, Message = "{0}", Level = EventLevel.Critical)]
public void Critical(string message)
{ if (IsEnabled()) WriteEvent(1, message); }
[Event(2, Message = "{0}", Level = EventLevel.Error)]
public void Error(string message)
{ if (IsEnabled()) WriteEvent(2, message); }
[Event(3, Message = "{0}", Level = EventLevel.Warning)]
public void Warning(string message)
{ if (IsEnabled()) WriteEvent(3, message); }
[Event(4, Message = "{0}", Level = EventLevel.Informational)]
public void Informational(string message)
{ if (IsEnabled()) WriteEvent(4, message); }
}
}
... I get the following response in the log viewer console (SemanticLogging-svc.exe
)
... which is correct!
BUT, if I now update the EventSource
attribute to [EventSource(Name = "HardymanDatabaseLog")]
, and adjust my SemanticLogging-svc.xml
to also reference HardymanDatabaseLog
...
<?xml version="1.0" encoding="utf-8" ?>
<configuration xmlns="http://schemas.microsoft.com/practices/2013/entlib/semanticlogging/etw" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://schemas.microsoft.com/practices/2013/entlib/semanticlogging/etw SemanticLogging-svc.xsd">
<sinks>
<consoleSink name="ConsoleEventSink">
<sources>
<eventSource name="HardymanDatabaseLog" level="LogAlways" />
</sources>
<eventTextFormatter header="+=========================================+"/>
</consoleSink>
</sinks>
</configuration>
... then I get the following response in the log viewer console ...
... Which has not only lost the first message, but corrupted the second!
If you look closely at the line that starts EventId : 1
then you can see it says Message : Application Started
... How, why and where is that message coming from?! ... even the Level : Informational
bit is wrong ... my code has Level = Critical
!
Before this problem started, I created a (long since deleted) method in the BasicLogger
class that had the attribute [Event(1, Message = "Application Started.", Level = EventLevel.Informational)]
, and now, whenever I set EventSource(Name="HardymanDatabaseLog")
, this phantom method is being called.
To be clear ... the text 'Application Started' no longer exists anywhere in my application (I'm using a completely new project) ... The sole cause of this error is the reuse of the 'HardymanDatabaseLog' EventSource name.
Here's what I've done so far to try and clear whatever corrupted information is making things go awry:
- Restarted my computer (standard!)
- Remove and re-add all references to Enterprise Library (the problem persists between different solutions, so it can't be an application/solution level setting)
- Stop and delete perfmon > Data Collector Sets > Event Trace Sessions > Microsoft-SemanticLogging-Etw-ConsoleEventSink
- Look in
HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog
to see if my app is registered (certainly 'HardymanDatabaseLog` wasn't found anywhere in the registry) - Sleep on it
- System.Diagnostics.EventLog.DeleteEventSource("HardymanDatabaseLog")
- Clean/Rebuild/Clean/Build/Clean/etc/etc solution
- Running my application without the visual studio host application
And this is what i tried but had no success with ...
- Determine if Enterprise Library persists configuration data
- Determine if the .NET EventSource persists configuration data
- Reinstall Enterprise Library (only
install-packages.ps1
is included with the download) - Banging my head on the keyboard
Any and all help/suggestions gratefully appreciated.
Update
Using JustDecompile, I've found a method in the EventSource
code that uses an object called a ManifestBuilder
. That method appears to build an <instrumentationManifest />
document which could certainly contain all the information that seems to be lurking in the phantom method.
Perhaps someone could shed some light on where these magic documents get stored in the context of .NET and Enterprise Library?
Update 2
As @Randy Levy has discovered by investigating the SLAB source, the problem can be fixed by deleting the files in C:\Users\<UserName>\AppData\Local\Temp\7D2611AE-6432-4639-8B91-3E46EB56CADF
. His answer also relates to this question ... SLAB, out-of-process: changing the signature of an event source method causes incorrect event logging.
Thanks @Randy Levy!
It certainly sounds like some sort of manifest caching and/or corruption issue.
For a console app SLAB ETW Service caches the manifests at C:\Users\\AppData\Local\Temp\7D2611AE-6432-4639-8B91-3E46EB56CADF. If there is a manifest caching issue then deleting the manifest .xml files (in this case BasicLogger.manifest.xml and HardymanDatabaseLog.manifest.xml) in that directory should (hopefully) resolve the issue.
The steps would be to stop the service, delete the .xml files and then restart the service.