search

jonwagner / EventSourceProxy

EventSourceProxy (ESP) is the easiest way to add scalable Event Tracing for Windows (ETW) logging to your .NET program
Other
97 stars 20 forks source link

Timestamp handling in ETW #60

Closed srudin closed 3 years ago

srudin commented 4 years ago

We have observed a somewhat weird behaviour:

  1. We started a trace collector real-time session using the Microsoft.Diagnostics.Tracing.TraceEvent NuGet package.
  2. We started logging events using the EventSourceProxy NuGet package.
  3. We get the events and the TraceEvent.TimeStamp property contains the current system time.
  4. Now we keep everything running and change the system time, e.g. we add 5 minutes.
  5. We still get the events but THEY CONTAIN THE UNCHANGED TIME which differs from the current system time. This is a problem because in production the trace collector runs over a longer period of time. The system time gets synchronized regularly and is therefore more or less correct but the logged events start to differ from server to server and also to values written to the db using DateTime.Now. This of course makes analyzing the log entries a pain - the difference can be up to several seconds!

We assume that there is some logic involved that handles a "session time" to ensure that events are always in chronological order. However, we think that this causes more problems that an occasional overlapping of events would and we'd like to always have the current system time logged.

It is unclear to us who is actually setting the timestamp value - is it the EventSourceProxy component, the ETW framework or the trace collector component? All we can see is that we don't manually set it using the EventSourceProxy component and we get it in the TraceEvent objects that are delivered to the events in the trace collector component, so it must happen somewhere in between. Any hints as to who is doing this and how we can change the behavior would be appreciated.

srudin commented 4 years ago

bump...

mjeanrichard commented 4 years ago

Hoi Sandro,

From what I know about ETW I would assume that this is not an Issue with EventSourceProxy, but with the underlying infrastructure. I would ask in the Perfview Repository (https://github.com/microsoft/perfview). They were able to help me in the past with timing Issues (it was a bug when converting to/from UTC) and also maintain the Microsoft.Diagnostics.Tracing.TraceEvent NuGet package.

Gruess an alle... Meini

jonwagner commented 3 years ago

Definitely not an issue with ESP - this code just acts as a proxy for the system libraries.

Closing this issue so I can clean things up for a .net46/.netstandard2.0 release.