set custom loglevel for external libraries

In src/libxl/libxl_conf.c:libxlDriverConfigInit, virLogGetDefaultPriority is used to specify the (private) loglevel of an external library. This value could be controlled via "log_level=N" in libvirtd.conf. But doing it that way will affect libvirtd itself, instead of libxenlight.so as intended. There might be ways to suppress everything but libxl output via "log_filters=", but it is not clear what the syntax would be. I wonder what the preferred way is to specify the desired loglevel for the external library. It seems a separate configuration setting is required so that each value of XTL_* from xentoollog.h can be specified. Olaf

On Wed, Jun 16, 2021 at 12:19:16PM +0200, Olaf Hering wrote:
In src/libxl/libxl_conf.c:libxlDriverConfigInit, virLogGetDefaultPriority is used to specify the (private) loglevel of an external library. This value could be controlled via "log_level=N" in libvirtd.conf. But doing it that way will affect libvirtd itself, instead of libxenlight.so as intended. There might be ways to suppress everything but libxl output via "log_filters=", but it is not clear what the syntax would be.
We support wildcards so probably: log_filters="3:*"
I wonder what the preferred way is to specify the desired loglevel for the external library. It seems a separate configuration setting is required so that each value of XTL_* from xentoollog.h can be specified.
In general I think the global log level concept in libvirt is flawed, because libvirt has way too much logging present for it to be viable to control level globally. So the right answer is really to use the fine grained logging filters which control logging per virLogSource object. Usually there is a single virLogSource per file. In the case of libxl, it provides callbacks that can be used to receive the messages and then output them wherever is needed. The libxl driver does this to write logs into the per-domain log file. The problem is that the libvirt_vmessage method is filtering messages based on the 'minLevel' field which is set from virLogGetDefaultPriority I think the better solution is to filter based on a virLogSource object. Two options in this respect. Either we can use the existing VIR_LOG_INIT("libxl.libxl_logger") source from libxl_logger.c Or we can define a second logging source manually static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .priority = VIR_LOG_ERROR, .serial = 0, } The only complication here is that the 'priority' field is not valid until we've called virLogVMessage with this virLogSource instance. If we're reusing the existing virLogSource instance from libxl_logger.c that's ok, as we have a VIR_DEBUG call that will trigger update of the 'priority' field. If we're defining a custom virLogSource instance, then we need to make the virLogSourceUpdate() method public from virlog.c, so that you can call it to update 'priority'. eg libvirt_vmessage needs todo if (source->serial < virLogFiltersSerial) virLogSourceUpdate(source); Anyway if you used a virLogSource object, then turning on debugging exclusively for libxl library messages would be as simple as log_filters="1:libxl.libxl_library" without affecting the global libvirt logging behaviour Regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :|

Thanks for your reply, I had no time to look at this until now. Am Wed, 16 Jun 2021 11:44:10 +0100 schrieb Daniel P. Berrangé <berrange@redhat.com>:
Anyway if you used a virLogSource object, then turning on debugging exclusively for libxl library messages would be as simple as
log_filters="1:libxl.libxl_library"
without affecting the global libvirt logging behaviour
It seems log_filters= does not allow arbitrary numbers. virLogParseFilter would just allow values from 1 to 4. Such extra logfilter needs to handle a xentoollog_level, values from 1 to 9 (>XTL_NONE and <XTL_NUM_LEVELS). How should this be expressed in a config setting? Perhaps just go the easy route and obtain a value from environment? --- a/src/libxl/libxl_conf.c +++ b/src/libxl/libxl_conf.c @@ -1829,7 +1829,7 @@ libxlDriverConfigInit(libxlDriverConfig *cfg) return -1; } - cfg->logger = libxlLoggerNew(cfg->logDir, virLogGetDefaultPriority()); + cfg->logger = libxlLoggerNew(cfg->logDir); if (!cfg->logger) { VIR_ERROR(_("cannot create logger for libxenlight, disabling driver")); return -1; --- a/src/libxl/libxl_logger.c +++ b/src/libxl/libxl_logger.c @@ -129,25 +129,33 @@ libvirt_destroy(xentoollog_logger *logger_in) libxlLogger * -libxlLoggerNew(const char *logDir, virLogPriority minLevel) +libxlLoggerNew(const char *logDir) { xentoollog_logger_libvirt logger; g_autofree char *path = NULL; - - switch (minLevel) { - case VIR_LOG_DEBUG: - logger.minLevel = XTL_DEBUG; - break; - case VIR_LOG_INFO: - logger.minLevel = XTL_INFO; - break; - case VIR_LOG_WARN: - logger.minLevel = XTL_WARN; - break; - case VIR_LOG_ERROR: - logger.minLevel = XTL_ERROR; - break; + char *xenlight_minlevel = getenv("xenlight_minlevel"); + int minlevel; + + if (!(xenlight_minlevel && *xenlight_minlevel && + virStrToLong_i(xenlight_minlevel, NULL, 10, &minlevel) >= 0 && + minlevel > XTL_NONE && minlevel < XTL_NUM_LEVELS)) { + minlevel = virLogGetDefaultPriority(); + switch (minlevel) { + case VIR_LOG_DEBUG: + minlevel = XTL_DEBUG; + break; + case VIR_LOG_INFO: + minlevel = XTL_INFO; + break; + case VIR_LOG_WARN: + minlevel = XTL_WARN; + break; + case VIR_LOG_ERROR: + minlevel = XTL_ERROR; + break; + } } + logger.minLevel = minlevel; logger.logDir = logDir; if ((logger.files = virHashNew(libxlLoggerFileFree)) == NULL) --- a/src/libxl/libxl_logger.h +++ b/src/libxl/libxl_logger.h @@ -24,8 +24,7 @@ typedef struct xentoollog_logger_libvirt libxlLogger; -libxlLogger *libxlLoggerNew(const char *logDir, - virLogPriority minLevel); +libxlLogger *libxlLoggerNew(const char *logDir); void libxlLoggerFree(libxlLogger *logger); void libxlLoggerOpenFile(libxlLogger *logger, int id, const char *name, Olaf

On Thu, Jul 22, 2021 at 04:39:24PM +0200, Olaf Hering wrote:
Thanks for your reply, I had no time to look at this until now.
Am Wed, 16 Jun 2021 11:44:10 +0100 schrieb Daniel P. Berrangé <berrange@redhat.com>:
Anyway if you used a virLogSource object, then turning on debugging exclusively for libxl library messages would be as simple as
log_filters="1:libxl.libxl_library"
without affecting the global libvirt logging behaviour
It seems log_filters= does not allow arbitrary numbers. virLogParseFilter would just allow values from 1 to 4. Such extra logfilter needs to handle a xentoollog_level, values from 1 to 9 (>XTL_NONE and <XTL_NUM_LEVELS).
How should this be expressed in a config setting?
Do we actually need to care about every single level, as opposed to just doing a sparse mapping where we squash several xen levels into one libvirt level, as the code below shows ?
Perhaps just go the easy route and obtain a value from environment?
--- a/src/libxl/libxl_conf.c +++ b/src/libxl/libxl_conf.c @@ -1829,7 +1829,7 @@ libxlDriverConfigInit(libxlDriverConfig *cfg) return -1; }
- cfg->logger = libxlLoggerNew(cfg->logDir, virLogGetDefaultPriority()); + cfg->logger = libxlLoggerNew(cfg->logDir); if (!cfg->logger) { VIR_ERROR(_("cannot create logger for libxenlight, disabling driver")); return -1; --- a/src/libxl/libxl_logger.c +++ b/src/libxl/libxl_logger.c @@ -129,25 +129,33 @@ libvirt_destroy(xentoollog_logger *logger_in)
libxlLogger * -libxlLoggerNew(const char *logDir, virLogPriority minLevel) +libxlLoggerNew(const char *logDir) { xentoollog_logger_libvirt logger; g_autofree char *path = NULL; - - switch (minLevel) { - case VIR_LOG_DEBUG: - logger.minLevel = XTL_DEBUG; - break; - case VIR_LOG_INFO: - logger.minLevel = XTL_INFO; - break; - case VIR_LOG_WARN: - logger.minLevel = XTL_WARN; - break; - case VIR_LOG_ERROR: - logger.minLevel = XTL_ERROR; - break; + char *xenlight_minlevel = getenv("xenlight_minlevel"); + int minlevel; + + if (!(xenlight_minlevel && *xenlight_minlevel && + virStrToLong_i(xenlight_minlevel, NULL, 10, &minlevel) >= 0 && + minlevel > XTL_NONE && minlevel < XTL_NUM_LEVELS)) { + minlevel = virLogGetDefaultPriority(); + switch (minlevel) { + case VIR_LOG_DEBUG: + minlevel = XTL_DEBUG; + break; + case VIR_LOG_INFO: + minlevel = XTL_INFO; + break; + case VIR_LOG_WARN: + minlevel = XTL_WARN; + break; + case VIR_LOG_ERROR: + minlevel = XTL_ERROR; + break; + } } + logger.minLevel = minlevel; logger.logDir = logDir;
if ((logger.files = virHashNew(libxlLoggerFileFree)) == NULL) --- a/src/libxl/libxl_logger.h +++ b/src/libxl/libxl_logger.h @@ -24,8 +24,7 @@
typedef struct xentoollog_logger_libvirt libxlLogger;
-libxlLogger *libxlLoggerNew(const char *logDir, - virLogPriority minLevel); +libxlLogger *libxlLoggerNew(const char *logDir); void libxlLoggerFree(libxlLogger *logger);
void libxlLoggerOpenFile(libxlLogger *logger, int id, const char *name,
Olaf
Regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :|

Am Thu, 22 Jul 2021 16:07:15 +0100 schrieb Daniel P. Berrangé <berrange@redhat.com>:
Do we actually need to care about every single level, as opposed to just doing a sparse mapping where we squash several xen levels into one libvirt level, as the code below shows ?
xc_private.h uses XTL_INFO, XTL_DETAIL, XTL_DEBUG and XTL_ERROR in the wrappers. I think in the end all of the values can be used once execution enters libxenlight.so. The code I changed had to map the few libvirt values somehow to the XTL values. Olaf

On 7/22/21 11:28 AM, Olaf Hering wrote:
Am Thu, 22 Jul 2021 17:17:11 +0200 schrieb Olaf Hering <olaf@aepfle.de>:
xc_private.h uses XTL_INFO, XTL_DETAIL, XTL_DEBUG and XTL_ERROR in the wrappers.
I wonder if the code should map VIR_LOG_INFO to XTL_DETAIL to enable DPRINTF.
Does the output of DPRINTF pass the "info" smell test? :-) Or is it only useful for debugging? INFO vs DEBUG can be a bit gray IMO, but reviewing the use of VIR_INFO vs VIR_DEBUG throughout the code might help decide what side of the fence DPRINTF lies. Jim

Am Fri, 23 Jul 2021 16:26:10 -0600 schrieb Jim Fehlig <jfehlig@suse.com>:
Does the output of DPRINTF pass the "info" smell test? :-) Or is it only useful for debugging? INFO vs DEBUG can be a bit gray IMO, but reviewing the use of VIR_INFO vs VIR_DEBUG throughout the code might help decide what side of the fence DPRINTF lies.
I think it is wrong to use internal libvirt values for internal libxentoollog values. There has to be a separate configuration setting to specify the various xentoollog_level values. It is just the question where to put such setting, and how to name it. I guess no other used library provides similar internal logging, this requirement is unique to libxenlight.so. Olaf

This question is still open: where should the libxl specific setting be specified? Olaf Am Sun, 25 Jul 2021 10:17:49 +0200 schrieb Olaf Hering <olaf@aepfle.de>:
I think it is wrong to use internal libvirt values for internal libxentoollog values.
There has to be a separate configuration setting to specify the various xentoollog_level values. It is just the question where to put such setting, and how to name it.
I guess no other used library provides similar internal logging, this requirement is unique to libxenlight.so.

On 10/11/21 04:30, Olaf Hering wrote:
This question is still open: where should the libxl specific setting be specified?
Sorry for not responding to your earlier mail.
Am Sun, 25 Jul 2021 10:17:49 +0200 schrieb Olaf Hering <olaf@aepfle.de>:
I think it is wrong to use internal libvirt values for internal libxentoollog values.
What is gained over the sparse mapping? Are values not covered actually useful in practice? Also, how are the values specified when using the xl tool? A quick peek at the code seems to imply using more 'v' options. E.g. 'xl -vvvv ...'.
There has to be a separate configuration setting to specify the various xentoollog_level values. It is just the question where to put such setting, and how to name it.
If such a setting is actually needed, then the proper place would be /etc/libvirt/libxl.conf. And IMO we should avoid creating a new name that could potentially confuse users. If 'xentoollog_level' is the common jargon in xen, we should stick with the same name.
I guess no other used library provides similar internal logging, this requirement is unique to libxenlight.so.
Good question, but I think you are right. It is unique to libxenlight. Jim

Am Mon, 11 Oct 2021 13:25:20 -0600 schrieb Jim Fehlig <jfehlig@suse.com>:
I think it is wrong to use internal libvirt values for internal libxentoollog values. What is gained over the sparse mapping? Are values not covered actually useful in practice? Also, how are the values specified when using the xl tool? A quick peek at the code seems to imply using more 'v' options. E.g. 'xl -vvvv ...'.
Since libvirt has no control about what libxentoollog values the authors use, it should provide a simple way to request a specific loglevel. xl decided to use the number of v's for it.
If such a setting is actually needed, then the proper place would be /etc/libvirt/libxl.conf. And IMO we should avoid creating a new name that could potentially confuse users. If 'xentoollog_level' is the common jargon in xen, we should stick with the same name.
If that is an acceptable approach I will try to prepare a patch. Olaf

On 10/11/21 14:38, Olaf Hering wrote:
Am Mon, 11 Oct 2021 13:25:20 -0600 schrieb Jim Fehlig <jfehlig@suse.com>:
I think it is wrong to use internal libvirt values for internal libxentoollog values. What is gained over the sparse mapping? Are values not covered actually useful in practice? Also, how are the values specified when using the xl tool? A quick peek at the code seems to imply using more 'v' options. E.g. 'xl -vvvv ...'.
Since libvirt has no control about what libxentoollog values the authors use, it should provide a simple way to request a specific loglevel. xl decided to use the number of v's for it.
How does one correlate a specific log level to the correct number of 'v'? :-) IMO the sparse mapping we currently have is more intuitive.
If such a setting is actually needed, then the proper place would be /etc/libvirt/libxl.conf. And IMO we should avoid creating a new name that could potentially confuse users. If 'xentoollog_level' is the common jargon in xen, we should stick with the same name.
If that is an acceptable approach I will try to prepare a patch.
I must admit I'm not fond of another log level knob. For many classes of bugs, users would then need to tweak libvirtd.conf and libxl.conf to collect appropriate debug info. That said, there is prior art. Going back to your snipped question
I guess no other used library provides similar internal logging, this requirement is unique to libxenlight.so.
Sorry for not looking closer earlier, but the qemu driver has a similar setting in qemu.conf for the gluster libgfapi log level https://gitlab.com/libvirt/libvirt/-/commit/a944bd925902d9ecce81e08900ad6a1a... Jim
participants (3)
-
Daniel P. Berrangé
-
Jim Fehlig
-
Olaf Hering