wowserhq / spelunker

Database explorer for World of Warcraft servers.
https://spelunkerdb.com
MIT License
17 stars 4 forks source link

Debug timings are potentially confusing #22

Open timkurvers opened 6 years ago

timkurvers commented 6 years ago

Spelunker uses debug for logging debug messages during operation.

One of its features, millisecond diffing, is potentially confusing:

When actively developing an application it can be useful to see when the time spent between one debug() call and the next. Suppose for example you invoke debug() before requesting a resource, and after as well, the "+NNNms" will show you how much time was spent between calls.

Given that Spelunker uses separate namespaces for timed operations – such as caching, DBC and database queries – these diffs may be interpret as query timers, which couldn't be further from the truth depending on the order of operations.

screen shot 2018-08-13 at 21 43 16

timkurvers commented 6 years ago

The easy solution here would be to log both before and after an operation as suggested by the debug docs. This may cause issues due to the asynchronous nature of GraphQL resolvers.