Bug 99585 - Add dbus verbose channels to verbose output.
Summary: Add dbus verbose channels to verbose output.
Status: RESOLVED MOVED
Alias: None
Product: dbus
Classification: Unclassified
Component: core (show other bugs)
Version: unspecified
Hardware: All All
: medium normal
Assignee: D-Bus Maintainers
QA Contact: D-Bus Maintainers
URL:
Whiteboard: review-
Keywords: patch
Depends on:
Blocks:
 
Reported: 2017-01-29 09:17 UTC by Ralf Habacker
Modified: 2018-10-12 21:29 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments
Add dbus verbose channels. (23.28 KB, patch)
2017-01-29 09:17 UTC, Ralf Habacker
Details | Splinter Review
Add dbus verbose channels. (514.99 KB, patch)
2017-02-01 21:34 UTC, Ralf Habacker
Details | Splinter Review
Add dbus verbose channels to verbose output. (514.99 KB, patch)
2017-02-01 21:35 UTC, Ralf Habacker
Details | Splinter Review
- removed unrelated files from patch (23.32 KB, patch)
2017-02-01 21:37 UTC, Ralf Habacker
Details | Splinter Review

Description Ralf Habacker 2017-01-29 09:17:02 UTC
Dbus verbose messages are spread all over the dbus code and prints out
internal informations helping to find issues. Caused by the amount of
generated messages it is partially hard to follow messages from special
categories which is provided by this patch.

DBus verbose channels are special keywords which are defined on file level
and are print out on each _dbus_verbose() call which makes it possible
to filter out unrelated messages.

DBus verbose channels are enabled by adding the following code fragment

...
DBUS_VERBOSE_CHANNEL(<category>)

in a file before using any dbus_verbose () calls.

In case someone do not want to have the keyword in each verbose message,
it would be possible to extend DBUS_VERBOSE environment variable parsing
to support filtering verbose categories by specifing DBUS_VERBOSE=<category>.
Comment 1 Ralf Habacker 2017-01-29 09:17:05 UTC
Created attachment 129210 [details] [review]
Add dbus verbose channels.

Bug:
Comment 2 Simon McVittie 2017-01-30 11:51:36 UTC
Comment on attachment 129210 [details] [review]
Add dbus verbose channels.

Review of attachment 129210 [details] [review]:
-----------------------------------------------------------------

So now we can add G_LOG_DOMAIN to the list of GLib features that we have reinvented under a worse license? :-)

::: dbus/dbus-internals.c
@@ +417,4 @@
>    else
>      need_pid = FALSE;
>  
> +  fprintf (stderr, "%s ", channel);

Some sort of marker like "[%s]" or "(%s)" or even "%s: " would probably make the output clearer.

::: dbus/dbus-internals.h
@@ +96,5 @@
> +#define DBUS_UNUSED
> +#endif
> +
> +#define DBUS_VERBOSE_CHANNEL(a) static DBUS_UNUSED const char *_DBUS_DEFAULT_VERBOSE_CHANNEL = #a;
> +#define DBUS_DEFAULT_VERBOSE_CHANNEL(a) DBUS_UNUSED const char *_DBUS_DEFAULT_VERBOSE_CHANNEL = #a;

Isn't this going to produce -Wshadow warnings for the extern version shadowing the non-extern?

This is also adding a bit of code size for non-verbose builds.

I think it would be a lot simpler like this:

==== dbus-internals.h ====

/* Override this per source file before including this header, if required. */
#ifndef DBUS_VERBOSE_CHANNEL
#   define DBUS_VERBOSE_CHANNEL "default"
#endif

#define _dbus_verbose(fmt, ...) _dbus_verbose_real (DBUS_VERBOSE_CHANNEL, [... etc.])

==== activation.c, for example ====

#include "config.h"
#define DBUS_VERBOSE_CHANNEL "activation"

/* include other headers here */
#include <dbus/dbus-internals.h>
Comment 3 Ralf Habacker 2017-02-01 21:32:07 UTC
(In reply to Simon McVittie from comment #2)
> 
> So now we can add G_LOG_DOMAIN to the list of GLib features that we have
> reinvented under a worse license? :-)
Does not apply because glib is only used in test code, not in production code :-)

> 
> ::: dbus/dbus-internals.c
> @@ +417,4 @@
> >    else
> >      need_pid = FALSE;
> >  
> > +  fprintf (stderr, "%s ", channel);
> 
> Some sort of marker like "[%s]" or "(%s)" or even "%s: " would probably make
> the output clearer.
I  will take a look

> ::: dbus/dbus-internals.h
> @@ +96,5 @@
> > +#define DBUS_UNUSED
> > +#endif
> > +
> > +#define DBUS_VERBOSE_CHANNEL(a) static DBUS_UNUSED const char *_DBUS_DEFAULT_VERBOSE_CHANNEL = #a;
> > +#define DBUS_DEFAULT_VERBOSE_CHANNEL(a) DBUS_UNUSED const char *_DBUS_DEFAULT_VERBOSE_CHANNEL = #a;
 
> Isn't this going to produce -Wshadow warnings for the extern version
> shadowing the non-extern?
So it looks better to skip the extern version DBUS_DEFAULT_VERBOSE_CHANNEL

> This is also adding a bit of code size for non-verbose builds.
.. because the strings are added in the const data section ? 

In case dbus verbose mode is disabled this variable could be skipped

> I think it would be a lot simpler like this:
> 
> ==== dbus-internals.h ====
> 
> /* Override this per source file before including this header, if required.
> */
> #ifndef DBUS_VERBOSE_CHANNEL
> #   define DBUS_VERBOSE_CHANNEL "default"
> #endif
> 
> #define _dbus_verbose(fmt, ...) _dbus_verbose_real (DBUS_VERBOSE_CHANNEL,
> [... etc.])
> 
> ==== activation.c, for example ====
> 
> #include "config.h"
> #define DBUS_VERBOSE_CHANNEL "activation"
> 
> /* include other headers here */
> #include <dbus/dbus-internals.h>

Using a macro would also allow to setup glib debug  domain (G_LOG_DOMAIN) with the same call e.g. 

See updated patch for an example which is coming soon.
Comment 4 Ralf Habacker 2017-02-01 21:34:23 UTC
Created attachment 129281 [details] [review]
Add dbus verbose channels.

Bug:
Comment 5 Ralf Habacker 2017-02-01 21:35:05 UTC
Created attachment 129282 [details] [review]
Add dbus verbose channels to verbose output.

Add dbus verbose channels (update)
Comment 6 Ralf Habacker 2017-02-01 21:37:37 UTC
Created attachment 129283 [details] [review]
- removed unrelated files from patch
Comment 7 Philip Withnall 2017-02-01 22:59:55 UTC
(In reply to Simon McVittie from comment #2)
> So now we can add G_LOG_DOMAIN to the list of GLib features that we have
> reinvented under a worse license? :-)

Someone sounds bitter. I suggest a long walk listening to Fields of the Nephilim.
Comment 8 Simon McVittie 2017-02-02 11:42:52 UTC
Comment on attachment 129283 [details] [review]
- removed unrelated files from patch

Review of attachment 129283 [details] [review]:
-----------------------------------------------------------------

::: bus/activation-helper.c
@@ +44,4 @@
>  #include <dbus/dbus-shell.h>
>  #include <dbus/dbus-marshal-validate.h>
>  
> +DBUS_VERBOSE_CHANNEL(default)

Might as well be "activation"?

::: dbus/dbus-internals.h
@@ +97,5 @@
> +#ifdef __GNUC__
> +#define DBUS_UNUSED __attribute__ ((unused))
> +#else
> +#define DBUS_UNUSED
> +#endif

We already have _DBUS_GNUC_UNUSED in dbus-macros.h, and that version is better because it also enables on clang (LLVM). It should be fine for dbus-internals.h to include dbus-macros.h if it doesn't already.

Think of _DBUS_GNUC_UNUSED as "expands to something compatible with gcc's __attribute__((__unused__)), or to nothing if the compiler doesn't support it" rather than being *specifically* about gcc.

The use of GNUC as shorthand for that is yet another piece of libdbus' design that was inspired by GLib.

@@ +100,5 @@
> +#define DBUS_UNUSED
> +#endif
> +
> +#if DBUS_ENABLE_VERBOSE_MODE
> +#define DBUS_VERBOSE_CHANNEL(a) static DBUS_UNUSED const char *_DBUS_VERBOSE_CHANNEL = #a; static DBUS_UNUSED const char *_G_LOG_DOMAIN = #a;

I still prefer an approach more similar to the one GLib takes with its log domain, where what you'd put in each source file (e.g. bus/bus.c) is:

#define _DBUS_VERBOSE_CHANNEL "bus"

(but you'd move it higher up the file than the DBUS_VERBOSE_CHANNEL(whatever) you're using now, before any headers are included). That seems a *lot* simpler than what you've got here, and then dbus-internals can use

#ifndef _DBUS_VERBOSE_CHANNEL
#define _DBUS_VERBOSE_CHANNEL "dbus"
#endif

to have a sensible fallback for any source file that didn't define something different.

Yes, that introduces a bunch of identical string constants instead of one global variable, but AIUI any decent compiler should be merging identical string constants into one anyway, so the practical result in terms of code size is basically the same.

(Also, code size doesn't really matter when verbose mode is enabled, because the library is full of verbose-mode stuff anyway. Production versions of dbus disable it.)

@@ +104,5 @@
> +#define DBUS_VERBOSE_CHANNEL(a) static DBUS_UNUSED const char *_DBUS_VERBOSE_CHANNEL = #a; static DBUS_UNUSED const char *_G_LOG_DOMAIN = #a;
> +#ifdef G_LOG_DOMAIN
> +#undef G_LOG_DOMAIN
> +#endif
> +#define G_LOG_DOMAIN _G_LOG_DOMAIN

Please don't define G_LOG_DOMAIN here. The core D-Bus code shouldn't be using GLib at all, and the tests that do use GLib should use g_test_message() or g_debug() if they want to emit debug-spam. If they want to use g_debug() then they can define G_LOG_DOMAIN themselves.

@@ +113,5 @@
>  #ifdef DBUS_CPP_SUPPORTS_VARIABLE_MACRO_ARGUMENTS
>  DBUS_PRIVATE_EXPORT
> +void _dbus_verbose_real       (const char *channel, const char *file, const int line, const char *function,
> +                               const char *format,...) _DBUS_GNUC_PRINTF (5, 6);
> +#  define _dbus_verbose(fmt,...) _dbus_verbose_real(_DBUS_VERBOSE_CHANNEL, __FILE__,__LINE__,__FUNCTION__,fmt, ## __VA_ARGS__)

Since the verbose-channel is essentially duplicating the filename, can we perhaps stop using __FILE__ here? It can be a problem for reproducible builds (binaries built in different filesystem locations by the same compiler and toolchain end up different).

I think the combination of _DBUS_VERBOSE_CHANNEL and __FUNCTION__ is probably enough to uniquely identify a _dbus_verbose() call - and if it isn't, improving the fmt would fix that.
Comment 9 GitLab Migration User 2018-10-12 21:29:44 UTC
-- 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/issues/163.


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.