Created attachment 304920 [details] [review]
Log better

There are two ways in Python to log a message with the logging module.
Either you pass a fully formatted message:

    logger.debug("Error: %s" % e)

Or you pass a format string followed by arguments, in the printf style:

    logger.debug("Error: %s", e)

The first one looks more idiomatic to Python, as it's how we generally
output strings with the print() function.

However, there is a difference between the two: with the second method,
the string is formatted inside the logging method, **after** the level
is checked.

That means that if the level for the logger was set to logging.WARNING,
the message as passed to logger.debug() in the first example above would
be formatted anyway, before calling logger.debug(), which would discard
the string anyway.

But in the second example, logger.debug() would first check that the
level is set to logger.WARNING, and just return directly, so that the
string would not get formatted for nothing.

This is a potential performance boost, for objects with a costly
__str__() method, or for repeated calls of logger.debug() when the level
is set to something higher.

And in gnome-music, pretty much every function call will generate a call
to logger.debug() because of the @log decorator. This in itself could
end up being quite costly, but formatting the strings in advance (the
first example above) makes it even worse.

This patch moves all the logging calls from the first style above to the
second one.

Created attachment 304921 [details] [review]
Reduce the overhead of the @log decorator

With this, if the log level is set to anything else than logging.DEBUG,
the decorator does absolutely nothing, it just returns the decorated
function unmodified.

Given how often this decorator is used, this could improve performance
a bit, avoiding to compute the artefacts used in the debug log message
if they are not going to be outputted anyway.

Agreed. We should also add a parameter to save the log directly to file in order to avoid 'gnome-music -d &> log' invocations

Vadim, does your "agreed" mean I can push the patches?

I'm asking because usually maintainers for other GNOME projects will edit the patch status to "accepted-commitnow" when that's the case. :)

(In reply to Mathieu Bridon from comment #4)
> Vadim, does your "agreed" mean I can push the patches?

Agreed on the idea itself, haven't reviewed the patch yet.

> I'm asking because usually maintainers for other GNOME projects will edit
> the patch status to "accepted-commitnow" when that's the case. :)

I'll take a look at this today and will push the patch soon

(In reply to Vadim Rutkovsky from comment #5)
> (In reply to Mathieu Bridon from comment #4)
> > Vadim, does your "agreed" mean I can push the patches?
> 
> Agreed on the idea itself, haven't reviewed the patch yet.

Got it.

Glad I asked then, otherwise I would have pushed unreviewed patches. ^_^

> > I'm asking because usually maintainers for other GNOME projects will edit
> > the patch status to "accepted-commitnow" when that's the case. :)
> 
> I'll take a look at this today and will push the patch soon

Thanks!

Review of attachment 304920 [details] [review]:

Thanks, pushed https://git.gnome.org/browse/gnome-music/commit/?id=eb4b2db to gnome-3-16 and https://git.gnome.org/browse/gnome-music/commit/?id=b738de7

Review of attachment 304921 [details] [review]:

Nice, pushed https://git.gnome.org/browse/gnome-music/commit/?id=1e67be9 to gnome-3-16 and https://git.gnome.org/browse/gnome-music/commit/?id=16c9857 to master

Pushed the patches (thanks, Mathieu!), will keep this open for 'write log to file' functionality

Suggested enhancement has been implemented, keeping this open for a minor enhancement seems counter-productive.

Logging to file would be nice to have, patches can be filed as a new bug.