mike-ward / VSColorOutput

Color highlighting to Visual Studio's Build and Debug Output Windows
MIT License
430 stars 93 forks source link

VSColorOutput doesn't show timestamp for all lines #130

Closed talbotsk closed 3 years ago

talbotsk commented 3 years ago

Why? Would it be possible to show timestamps for each line? Thank you very much! Great extension!

mike-ward commented 3 years ago

The resolution of the timers is such that many statements have the same timestamp, which made it almost impossible to spot time changes. Thus the current implementation which eliminates the duplicates.

talbotsk commented 3 years ago

Thank you for the explanation. I looked into your code and I found you use DateTime.Now. Look at Stopwatch class which is mentioned at page: https://docs.microsoft.com/en-us/dotnet/api/system.datetime.now?view=net-5.0 in the Remarks section. It can be used for this high performance purposes.

mike-ward commented 3 years ago

What's the use case that requires more than 15 milliseconds of resolution? Seems like it would be the same problem. Lots of lines with almost identical timestamps.

talbotsk commented 3 years ago

The problem is that VSColorOutput has too big granularity. May be it is not the problem of DateTime then. See this printscreen: image

mike-ward commented 3 years ago

What's the use case? If you're using it for some kind of benchmarking then you'll likely be disappointed. Logging is usually asynchronous and out of band. It's a bit like having an egg timer with nanosecond accuracy.

talbotsk commented 3 years ago

5 seconds is too long time. If I want to have info about duration of SQL select in the output, I need to use another tools. It would be nice to see it in output without 3rd party tools.

mike-ward commented 3 years ago

VSColorOutput does not echo duplicate timestamps. It does this for readability. The statement indicating 5 seconds literally occurred 5 seconds after the log statements above it.

You're also assuming VSColorOutput gets notified when your log event fires. It's likely Visual Studio puts those log events in a queue and processes them asynchronously. VSColorOutput likely received those log events within a single timer tick.

I can only report when I received the event. Not when the event occurred.