Re: A GNUNET_log oddity

[Christian Grothoff]

Dear Alessio,

The idea behind DEBUG-level logging was to allow developers to put tons
of verbose log messages into the code _without_ having to worry about
increasing the code size on production systems. GNUnet should run on
embedded-ish systems, and binary size does matter. The idea behind the
configure flag is that by default, DEBUG messages are never included,
and only developers can (and likely will) explicitly enable them to aid
their diagnosis.

So if you want a message to be possibly visible to ordinary users,
formulate it nicely and log at INFO level. DEBUG messages are, as the
name says, for debugging, and that's not something normal users should
have to do ;-).

As for applications using libgnunetutil, well, they again need to copy
that mechanism into their configure-scripts, or they won't get
DEBUG-level logging. I think that's OK.  That said, we _may_ be able to
improve the (developer) handbook documentation on logging on this point.

My 2 cents

Christian

On 8/29/21 8:31 PM, Alessio Vanni wrote:
> Hello,
> 
> I was recently puzzled by a behaviour which apparently has been going on
> for a while, but I noticed it only now.
> 
> It seems that `GNUNET_log' (and `GNUNET_log_from') is unable to print
> messages when the error level is GNUNET_ERROR_TYPE_DEBUG under certain
> circumstances.
> 
> Consider this small testcase:
> 
> #include <netinet/in.h>
> #include <stdbool.h>
> #include <gnunet/gettext.h>
> #include <gnunet/gnunet_util_lib.h>
> 
> static void
> run(void *cls, char *const *args, const char *cf, const struct 
> GNUNET_CONFIGURATION_Handle *cfg) {
>      GNUNET_log(GNUNET_ERROR_TYPE_ERROR, "error\n");
>      GNUNET_log(GNUNET_ERROR_TYPE_WARNING, "warning\n");
>      GNUNET_log(GNUNET_ERROR_TYPE_INFO, "info\n");
>      GNUNET_log(GNUNET_ERROR_TYPE_DEBUG, "debug\n");
>      GNUNET_SCHEDULER_shutdown();
> }
> 
> int main(int argc, char *argv[]) {
>      const struct GNUNET_GETOPT_CommandLineOption opts[] = {
>         GNUNET_GETOPT_OPTION_END,
>      };
>      return GNUNET_PROGRAM_run(argc, argv, "test-client", "",
>                              opts, &run, NULL);
> }
> 
> (To compile it just run
> 
> gcc -o <out file name> <source file name> -lgnunetutil
> 
> nothing else is required.)
> 
> If you run it with different values for the `-L' flag, you will see that
> `-L DEBUG' will print only up to INFO.
> 
> Apparently, this is because of this condition check:
> 
> (GNUNET_EXTRA_LOGGING > 0) || ((GNUNET_ERROR_TYPE_DEBUG & (kind)) == 0)
> 
> Trying to understand why a message is logged only when this condition is
> true, I discovered that it was introduced in a commit that simply says:
> 
> "Let the compiler not include debug strings in binary when make is not
> configured with verbose"
> 
> (The commit's full hash is: 51ded2191d94c707434cc5e082c7053f9469f149)
> 
> This is somewhat in line with a section of the GNUnet Developer
> Handbook, specifically about building GNUnet from source:
> 
> "If you want to be able to enable DEBUG-level log messages, add
> ‘--enable-logging=verbose’ to the end of the ‘./configure’ command.
> ‘DEBUG’-level log messages are in English only and should only be useful
> for developers (or for filing really detailed bug reports)."
> 
> Because the above doesn't apply to applications not part of the GNUnet
> core, there is currently no way to log DEBUG-level messages unless the
> application developer knows that GNUNET_EXTRA_LOGGING has to be defined
> to a value bigger than 0; it is normally set to 0 if the symbol is not
> defined in "gnunet_common.h".
> 
> It's true that there is a comment briefly explaining
> GNUNET_EXTRA_LOGGING and that it could be possible to change its value
> to a different number when it's not defined (never happens in GNUnet
> core, as configure.ac always define a value for it) in a way that
> applications have DEBUG-level logging enabled by default, but should the
> current behaviour be kept at all in the first place?
> 
> DEBUG-level messages, even when enabled, still require the `-L' flag to
> be set to "DEBUG", so no matter how GNUnet is built users will never see
> those messages unless they explicitly ask for them. Similarly, people
> interested in DEBUG-level messages first will have to build GNUnet with
> the appropriate "configure" flags, which might not be possible in
> certain situations, and then use `-L' accordingly.
> 
> I think that at least the calls to `GNUNET_log' (and `GNUNET_log_from',
> and other similar "generic" function/macros) should always try to print
> something, letting the `-L' flag decide whether the user should see the
> message or not, leaving the whole GNUNET_EXTRA_LOGGING stuff as
> something used internally by GNUnet and nothing else (since it is used
> in a few places to include or exclude some code paths.)
> 
> Thanks,
> A.V.
>

signature.asc
Description: OpenPGP digital signature