Why does EntLib logging emit several messages at the same timestamp?

Question

Using the logging block in Enterprise Library, I am seeing multiple log messages being emitted with the same time stamp, despite knowing that the calls to LogWriter.Write() are separated by several milliesconds (as measured System.Diagnostics.Stopwatch).

Any suggestions on what could be causing this?

Answer 1

This is likely due to the limited precision of the method that Enterprise Library uses to get the current time, probably System.DateTime.Now. If you need higher precision, you might have to look at using a different library for logging.

http://msdn.microsoft.com/en-us/library/system.datetime.now.aspx

Answer 2

If you need to have precision in the log Using the System.Diagnostics.Stopwatch to get a precise time.. see Example here http://msdn.microsoft.com/en-us/library/system.diagnostics.stopwatch.gettimestamp.aspx The resolution is based on your hardware. Can be as good as nanosecs.

contruct the logentry by hand,

//Microsoft.Practices.EnterpriseLibrary.Logging
var logEntry = new LogEntry() ;
/// code re stop watch add here...
FancyTime = StartTime + Elapsedticks // see StopWatch.getTimeStamp
logEntry.TimeStamp = FancyTimeFromStopWatchClass;

LogWriterImpl.Write(logEntry);

In Other words, Build the logentry and call Write, rather than calling overloaded write with params.