[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]

Re: [libvirt] [PATCH] logging: remove concept of default log priority



On 11.05.2016 16:12, Daniel P. Berrange wrote:
> The logging framework has categories which can be selectively
> enabled/disabled by setting a suitable LIBVIRT_LOG_FILTERS
> environment variable or config file setting.
> 
> Along side that we also have the LIBVIRT_DEBUG environment
> variable which unconditionally enables every single category
> at DEBUG level. With the amount of logging produced by libvirt
> these days, the signal/noise ratio in the output from setting
> LIBVIRT_DEBUG is to poor for it to be useful.
> 
> Originally the LIBVIRT_DEBUG env variable had a very specific
> use case - it resulted in logging of anything in our public
> API entrypoints. eg it turned on src/libvirt.c debugging and
> nothing else. Additionally it would always result in log
> messages being sent to stderr.
> 
> When applied to any of the daemons, the log output no longers
> gets sent to stderr, but rather to whatever default log output
> has been configured by the daemon. If no log_outputs setting
> or LIBVIRT_LOG_OUTPUTS env is set, then messages will often
> go to the systemd journal or a /var/log/libvirt/libvirtd.log
> file rather than stderr.
> 
> These factors have conspired to make the LIBVIRT_DEBUG env
> and/or default log priority to be pretty useless in the real
> world.
> 
> This change attempts to take us back towards the original
> semantics of the LIBVIRT_DEBUG env variable as follows.
> 
> If LIBVIRT_DEBUG is set to a plain integer, or log level
> string, then it will turn on logging for the "libvirt" log
> category at that level. Any other string will be parsed in
> the same way as LIBVIRT_LOG_FILTERS would be. In all cases
> use of LIBVIRT_DEBUG will result in an explicit output being
> added for stderr. This ensures that messages always go to
> stderr, even if other outputs are already configured.
> 
> IOW,   LIBVIRT_DEBUG=1 virsh or LIBVIRT_DEBUG=1 libvirtd
> will both result in printing logs of libvirt public API
> calls to stderr. Meanwhile setting LIBVIRT_DEBUG="1:qemu"
> is equivalent to setting LIBVIRT_LOG_FILTERS="1:qemu" and
> LIBVIRT_LOG_OUTPUTS="1:stderr"
> 
> Signed-off-by: Daniel P. Berrange <berrange redhat com>
> ---
>  daemon/libvirtd.c         |  27 ++++++------
>  src/libvirt_private.syms  |   1 +
>  src/libxl/libxl_conf.c    |   3 +-
>  src/locking/lock_daemon.c |  29 ++++++-------
>  src/logging/log_daemon.c  |  29 ++++++-------
>  src/lxc/lxc_process.c     |   7 ----
>  src/util/vircommand.c     |   4 --
>  src/util/virlog.c         | 104 +++++++++++++++++++---------------------------
>  src/util/virlog.h         |  11 ++---
>  tests/eventtest.c         |   6 +--
>  10 files changed, 97 insertions(+), 124 deletions(-)
> 
> diff --git a/daemon/libvirtd.c b/daemon/libvirtd.c
> index cc5190f..e88a982 100644
> --- a/daemon/libvirtd.c
> +++ b/daemon/libvirtd.c
> @@ -668,6 +668,8 @@ daemonSetupLogging(struct daemonConfig *config,
>                     bool verbose,
>                     bool godaemon)
>  {
> +    int level = VIR_LOG_WARN;
> +
>      virLogReset();
>  
>      /*
> @@ -684,9 +686,6 @@ daemonSetupLogging(struct daemonConfig *config,
>       * level has been set, we must process variables in the opposite
>       * order, each one overriding the previous.
>       */
> -    if (config->log_level != 0)
> -        virLogSetDefaultPriority(config->log_level);
> -
>      virLogSetFromEnv();
>  
>      if (virLogGetNbFilters() == 0)
> @@ -695,11 +694,14 @@ daemonSetupLogging(struct daemonConfig *config,
>      if (virLogGetNbOutputs() == 0)
>          virLogParseOutputs(config->log_outputs);
>  
> -    /*
> -     * Command line override for --verbose
> -     */
> -    if ((verbose) && (virLogGetDefaultPriority() > VIR_LOG_INFO))
> -        virLogSetDefaultPriority(VIR_LOG_INFO);
> +    if (config->log_level != 0 || verbose) {
> +        level = config->log_level;
> +        if (verbose && level > VIR_LOG_INFO)
> +            level = VIR_LOG_INFO;
> +        virLogDefineFilter("libvirt", level, 0);
> +        if (virLogGetNbOutputs() == 0)
> +            virLogParseOutputs("1:stderr");
> +    }

I've noticed this code being copied over and over. Is it worth putting
into a function, say virLogSetDefaultLevel(config->log_level, verbose)?

>  
>      /*
>       * If no defined outputs, and either running
> @@ -711,7 +713,7 @@ daemonSetupLogging(struct daemonConfig *config,
>          (godaemon || !isatty(STDIN_FILENO))) {
>          char *tmp;
>          if (access("/run/systemd/journal/socket", W_OK) >= 0) {
> -            virLogPriority priority = virLogGetDefaultPriority();
> +            virLogPriority priority = level;
>  
>              /* By default we don't want to log too much stuff into journald as
>               * it may employ rate limiting and thus block libvirt execution. */
> @@ -735,8 +737,7 @@ daemonSetupLogging(struct daemonConfig *config,
>          if (godaemon) {
>              if (privileged) {
>                  if (virAsprintf(&tmp, "%d:file:%s/log/libvirt/libvirtd.log",
> -                                virLogGetDefaultPriority(),
> -                                LOCALSTATEDIR) == -1)
> +                                level, LOCALSTATEDIR) == -1)
>                      goto error;
>              } else {
>                  char *logdir = virGetUserCacheDirectory();
> @@ -753,14 +754,14 @@ daemonSetupLogging(struct daemonConfig *config,
>                  umask(old_umask);
>  
>                  if (virAsprintf(&tmp, "%d:file:%s/libvirtd.log",
> -                                virLogGetDefaultPriority(), logdir) == -1) {
> +                                level, logdir) == -1) {
>                      VIR_FREE(logdir);
>                      goto error;
>                  }
>                  VIR_FREE(logdir);
>              }
>          } else {
> -            if (virAsprintf(&tmp, "%d:stderr", virLogGetDefaultPriority()) < 0)
> +            if (virAsprintf(&tmp, "%d:stderr", level) < 0)
>                  goto error;
>          }
>          virLogParseOutputs(tmp);
> diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms
> index a980a32..5586d8b 100644
> --- a/src/libvirt_private.syms
> +++ b/src/libvirt_private.syms
> @@ -1801,6 +1801,7 @@ virLogProbablyLogMessage;
>  virLogReset;
>  virLogSetDefaultPriority;
>  virLogSetFromEnv;
> +virLogSourceGetPriority;
>  virLogUnlock;
>  virLogVMessage;
>  


> diff --git a/src/util/virlog.c b/src/util/virlog.c
> index 738eaac..82fb4dc 100644
> --- a/src/util/virlog.c
> +++ b/src/util/virlog.c
> @@ -112,11 +112,6 @@ typedef virLogOutput *virLogOutputPtr;
>  static virLogOutputPtr virLogOutputs;
>  static int virLogNbOutputs;
>  
> -/*
> - * Default priorities
> - */
> -static virLogPriority virLogDefaultPriority = VIR_LOG_DEFAULT;
> -
>  static int virLogResetFilters(void);
>  static int virLogResetOutputs(void);
>  static void virLogOutputToFd(virLogSourcePtr src,
> @@ -175,7 +170,6 @@ virLogOnceInit(void)
>          return -1;
>  
>      virLogLock();
> -    virLogDefaultPriority = VIR_LOG_DEFAULT;
>  
>      if (VIR_ALLOC_QUIET(virLogRegex) >= 0) {
>          if (regcomp(virLogRegex, VIR_LOG_REGEX, REG_EXTENDED) != 0)
> @@ -205,35 +199,10 @@ virLogReset(void)
>      virLogLock();
>      virLogResetFilters();
>      virLogResetOutputs();
> -    virLogDefaultPriority = VIR_LOG_DEFAULT;
>      virLogUnlock();
>      return 0;
>  }
>  
> -/**
> - * virLogSetDefaultPriority:
> - * @priority: the default priority level
> - *
> - * Set the default priority level, i.e. any logged data of a priority
> - * equal or superior to this level will be logged, unless a specific rule
> - * was defined for the log category of the message.
> - *
> - * Returns 0 if successful, -1 in case of error.
> - */
> -int
> -virLogSetDefaultPriority(virLogPriority priority)
> -{
> -    if ((priority < VIR_LOG_DEBUG) || (priority > VIR_LOG_ERROR)) {
> -        VIR_WARN("Ignoring invalid log level setting.");
> -        return -1;
> -    }
> -    if (virLogInitialize() < 0)
> -        return -1;
> -
> -    virLogDefaultPriority = priority;
> -    return 0;
> -}
> -

This should be also removed from libvirt_private.syms.

>  
>  /**
>   * virLogResetFilters:
> @@ -472,7 +441,7 @@ virLogSourceUpdate(virLogSourcePtr source)
>  {
>      virLogLock();
>      if (source->serial < virLogFiltersSerial) {
> -        unsigned int priority = virLogDefaultPriority;
> +        unsigned int priority = VIR_LOG_DEFAULT;
>          unsigned int flags = 0;
>          size_t i;
>  
> @@ -1310,18 +1279,6 @@ virLogParseFilters(const char *filters)
>  
>  
>  /**
> - * virLogGetDefaultPriority:
> - *
> - * Returns the current logging priority level.
> - */
> -virLogPriority
> -virLogGetDefaultPriority(void)
> -{
> -    return virLogDefaultPriority;
> -}
> -
> -

This is still used in src/security/security_apparmor.c and also after
fixing that place should be removed from libvirt_private.syms.

> -/**
>   * virLogGetFilters:
>   *
>   * Returns a string listing the current filters, in the format originally
> @@ -1423,35 +1380,53 @@ virLogGetNbOutputs(void)
>  
>  
>  /**
> - * virLogParseDefaultPriority:
> + * virLogParseDebug:
>   * @priority: string defining the desired logging level
>   *
> - * Parses and sets the default log priority level. It can take a string or
> - * number corresponding to the following levels:
> + * This method is a shortcut for setting a filter
> + * along with output to stderr.
> + *
> + * It can take one of the following strings or numbers:
> + *
>   *    1: DEBUG
>   *    2: INFO
>   *    3: WARNING
>   *    4: ERROR
>   *
> + * in which case it will set the priority level on the
> + * "libvirt" log source filter. If it does not match any
> + * of these standard strings it will be treated as a full
> + * filter string.
> + *
> + * In all cases an output to stderr will be defined.
> + *
>   * Returns 0 if successful, -1 in case of error.
>   */
>  int
> -virLogParseDefaultPriority(const char *priority)
> +virLogParseDebug(const char *debug)

Yet again, this requires changes in libvirt_private.syms. I belive our
'make check' would have caught this.

>  {
> -    int ret = -1;
> +    unsigned int priority = VIR_LOG_DEFAULT;
> +    if (STREQ(debug, "1") || STREQ(debug, "debug"))
> +        priority = VIR_LOG_DEBUG;
> +    else if (STREQ(debug, "2") || STREQ(debug, "info"))
> +        priority = VIR_LOG_INFO;
> +    else if (STREQ(debug, "3") || STREQ(debug, "warning"))
> +        priority = VIR_LOG_WARN;
> +    else if (STREQ(debug, "4") || STREQ(debug, "error"))
> +        priority = VIR_LOG_ERROR;
> +
> +    if (priority == VIR_LOG_DEFAULT) {
> +        if (virLogParseFilters(debug) < 0)
> +            return -1;
> +    } else {
> +        if (virLogDefineFilter("libvirt", priority, 0) < 0)
> +            return -1;
> +    }
>  
> -    if (STREQ(priority, "1") || STREQ(priority, "debug"))
> -        ret = virLogSetDefaultPriority(VIR_LOG_DEBUG);
> -    else if (STREQ(priority, "2") || STREQ(priority, "info"))
> -        ret = virLogSetDefaultPriority(VIR_LOG_INFO);
> -    else if (STREQ(priority, "3") || STREQ(priority, "warning"))
> -        ret = virLogSetDefaultPriority(VIR_LOG_WARN);
> -    else if (STREQ(priority, "4") || STREQ(priority, "error"))
> -        ret = virLogSetDefaultPriority(VIR_LOG_ERROR);
> -    else
> -        VIR_WARN("Ignoring invalid log level setting");
> +    if (virLogParseOutputs("1:stderr") < 0)
> +        return -1;
>  
> -    return ret;
> +    return 0;
>  }
>  
>  


Otherwise looking good. ACK if you fix all the nits I've raised.

Michal


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]