I've noticed some problems with the way dbus-python does logging, so I want to open this issue for discussion. Once we agree on something, I'll try to propose a patch/branch/merge. The basic problem I think is that dbus-python expects to log through the root logger, and formats its messages making certain assumptions about how the root logger is configured. Here's an example from proxies.py: def _introspect_error_handler(self, error): logging.basicConfig() _logger.error("Introspect error on %s:%s: %s.%s: %s", self._named_service, self.__dbus_object_path__, error.__class__.__module__, error.__class__.__name__, error) The problem with this is that other libraries or applications may already have initialized the root logger, and in fact may have set style='{' which will essentially break all dbus logging. I noticed this in my system-image application. One minor comment here is that you don't need to call logging.basicConfig(). The logging infrastructure will call that automatically if needed, and if it's not needed, it's a no-op. So you can probably remove all the basicConfig() calls. The other thing is that you probably want to set up your own loggers to have the format and style that the library wants, independent of whatever other settings an application using dbus-python has made. Or in other words: don't rely on the root logger. I wish Python's logging infrastructure was more amenable to composition of distinct libraries, and use by applications. While inconvenient and requiring a bunch of extra code, it *is* possibly to set up library-specific loggers that won't be affected by any other logging system settings elsewhere. Even better, it would be cool if a client of dbus-python could direct log messages anywhere they wanted, e.g. syslog, or a specific debug file. I can provide some examples of the kinds of things I've done on request. I'm not saying I have great solutions, but I think they're better given what we have to work with.
(In reply to comment #0) > The basic problem I think is that dbus-python expects to log through the > root logger It always uses the dbus.* hierarchy, AIUI? If not, that's a bug. > One minor comment here is that you don't need to call logging.basicConfig(). > The logging infrastructure will call that automatically if needed, and if > it's not needed, it's a no-op. So you can probably remove all the > basicConfig() calls. In the version of Python under which I wrote this code, the default default handler (if you see what I mean) was "complain to stderr that logging has not been configured, but don't actually do anything with my message". That isn't very useful to anyone :-) If the default has changed to doing the equivalent of basicConfig() whenever necessary, great, we can remove those calls. What I'm aiming for is this pseudocode: if a module has configured logging send my message wherever that module wanted to send it else oh well, something is better than nothing send >= warning messages to stderr > The problem with this is that other libraries or applications may already > have initialized the root logger, and in fact may have set style='{' which > will essentially break all dbus logging. I noticed this in my system-image > application. "Note that this governs the formatting of logging messages for final output to logs, and is completely orthogonal to how an individual logging message is constructed." -the docs (Python 3.3.4) Doesn't that mean this usage is correct regardless of style settings? As far as I can see from the docs, it always uses %-style formatting to build LogRecord.message from LogRecord.msg and LogRecord.args, and then the Formatter composes various keys (including LogRecord.message) into the final message using %-, {- or $-style formatting. I don't think dbus-python uses any Formatters or Handlers, other than calling basicConfig() on a just-in-time basis if something bad happens. > The other thing is that you probably want to set up your own loggers to have > the format and style that the library wants, independent of whatever other > settings an application using dbus-python has made. I specifically don't want dbus-python to have to set up its own logging. I just want to log some messages - "hey, this thing went wrong" - and let the host application do whatever it wants to do with them (including prepending a timestamp or not, writing to syslog or a file or stderr, etc.), with a default of "spam to stderr for warnings and errors" if the host application has done no configuration whatsoever. > Even better, it would be cool if a client of dbus-python could direct log > messages anywhere they wanted, e.g. syslog, or a specific debug file. I don't want to duplicate logging's rich API for "redirect your messages over there" in dbus-python; I want the API that dbus presents to other modules to be "I log messages to logging.getLogger('dbus') and its children, so if you don't like its default handling, reconfigure it via the logging API". If a host application has configured logging so that >= debug messages go to debug.txt and >= warning messages go to syslog, but has not specifically configured logging for dbus to be different, then I would like dbus debug messages to end up in debug.txt too, and I would like dbus warning messages to end up in debug.txt and syslog; and if the host application has decided that each message should contain a ms-precision timestamp, thread ID and file:line information, then I'd like dbus messages to contain that information too.
(In reply to comment #1) > If the default has changed to doing the equivalent of basicConfig() whenever > necessary, great, we can remove those calls. It appears to have changed in or before Python 3.3, but not in Python 2.7; so dbus-python should still do those calls at least in Python 2, as long as it supports Python 2 (which at this point seems like it probably means "forever").
-- GitLab Migration Automatic Message -- This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/dbus/dbus-python/issues/4.
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.