[libvirt] [PATCH] libxl: open libxl log stream with libvirtd log_level

Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands. Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/src/libxl/libxl_conf.c b/src/libxl/libxl_conf.c index a76ad5a..40fa4b5 100644 --- a/src/libxl/libxl_conf.c +++ b/src/libxl/libxl_conf.c @@ -1496,6 +1496,7 @@ libxlDriverConfigNew(void) { libxlDriverConfigPtr cfg; char *log_file = NULL; + xentoollog_level log_level; char ebuf[1024]; unsigned int free_mem; @@ -1540,9 +1541,24 @@ libxlDriverConfigNew(void) } VIR_FREE(log_file); + switch (virLogGetDefaultPriority()) { + case VIR_LOG_DEBUG: + log_level = XTL_DEBUG; + break; + case VIR_LOG_INFO: + log_level = XTL_INFO; + break; + case VIR_LOG_WARN: + log_level = XTL_WARN; + break; + case VIR_LOG_ERROR: + log_level = XTL_ERROR; + break; + } + cfg->logger = (xentoollog_logger *)xtl_createlogger_stdiostream(cfg->logger_file, - XTL_DEBUG, XTL_STDIOSTREAM_SHOW_DATE); + log_level, XTL_STDIOSTREAM_SHOW_DATE); if (!cfg->logger) { VIR_ERROR(_("cannot create logger for libxenlight, disabling driver")); goto error; -- 2.5.0

On Tue, 2015-09-15 at 09:26 -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com>
FWIW this seems like a good idea to me: Acked-by: Ian Campbell <ian.campbell@citrix.com>

On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly. Regards, Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|

Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred. Regards, Jim

On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... } LIBVIRT_LOG_FILTERS="1:libxl_library" Regardless we should just merge your current patch right now. Regards, Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|

Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Regardless we should just merge your current patch right now.
Thanks; done now. Regards, Jim

On 09/15/2015 01:21 PM, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Regardless we should just merge your current patch right now.
Thanks; done now.
Regards, Jim
Looks like compilations on Fedora are 'unhappy': libxl/libxl_conf.c: In function 'libxlDriverConfigNew': libxl/libxl_conf.c:1560:30: error: 'log_level' may be used uninitialized in this function [-Werror=maybe-uninitialized] (xentoollog_logger *)xtl_createlogger_stdiostream(cfg->logger_file, ^ libxl/libxl_conf.c:1499:22: note: 'log_level' was declared here xentoollog_level log_level; ^ cc1: all warnings being treated as errors Makefile:8000: recipe for target 'libxl/libvirt_driver_libxl_impl_la-libxl_conf.lo' failed You can also see failures today in libvirt-daemon-build and libvirt-daemon-check from: https://ci.centos.org/view/libvirt-project/ I wasn't sure if initializing log_level to XTL_DEBUG and then changing if virLogGetDefaultPriority returns something else would be better or going the "default:" route in the switch statement would be better. John

On Sep 15, 2015, at 4:06 PM, John Ferlan <jferlan@redhat.com> wrote:
On 09/15/2015 01:21 PM, Jim Fehlig wrote: Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly. I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Regardless we should just merge your current patch right now.
Thanks; done now.
Regards, Jim
Looks like compilations on Fedora are 'unhappy':
Hrm, thanks for bringing it to my attention. I'll send a patch later when I have something in front of me besides a mobile device. Regards, Jim

On 09/15/2015 04:06 PM, John Ferlan wrote:
On 09/15/2015 01:21 PM, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Regardless we should just merge your current patch right now.
Thanks; done now.
Regards, Jim
Looks like compilations on Fedora are 'unhappy':
libxl/libxl_conf.c: In function 'libxlDriverConfigNew': libxl/libxl_conf.c:1560:30: error: 'log_level' may be used uninitialized in this function [-Werror=maybe-uninitialized] (xentoollog_logger *)xtl_createlogger_stdiostream(cfg->logger_file, ^ libxl/libxl_conf.c:1499:22: note: 'log_level' was declared here xentoollog_level log_level; ^ cc1: all warnings being treated as errors Makefile:8000: recipe for target 'libxl/libvirt_driver_libxl_impl_la-libxl_conf.lo' failed
You can also see failures today in libvirt-daemon-build and libvirt-daemon-check from:
https://ci.centos.org/view/libvirt-project/
I wasn't sure if initializing log_level to XTL_DEBUG and then changing if virLogGetDefaultPriority returns something else would be better or going the "default:" route in the switch statement would be better.
I took the bit more explicit route and went with the former, worried that Coverity would be the next thing to complain :-). I considered initializing log_level to XTL_WARN, matching VIR_LOG_DEFAULT, but in the end went with DEBUG. It matches the behavior before this change, and is reasonable default if we're already this confused while loading the driver. Regards, Jim

On Tue, Sep 15, 2015 at 11:21:00AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Is it done anywhere? If not, how can I help? This the above change (setting libxl log level to libvirtd global one), makes almost impossible to get libxl debug, because the rest of libvirtd trashes the logs (hundreds virEvent* and virObject* messages, at "info"(!) level). -- Best Regards, Marek Marczykowski-Górecki Invisible Things Lab A: Because it messes up the order in which people normally read text. Q: Why is top-posting such a bad thing?

On Wed, Nov 11, 2015 at 04:57:59PM +0100, Marek Marczykowski-Górecki wrote:
On Tue, Sep 15, 2015 at 11:21:00AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
Instead of a hardcoded DEBUG log level, use the overall daemon log level specified in libvirtd.conf when opening a log stream with libxl. libxl is very verbose when DEBUG log level is set, resulting in huge log files that can potentially fill a disk. Control of libxl verbosity should be placed in the administrator's hands.
Signed-off-by: Jim Fehlig <jfehlig@suse.com> --- src/libxl/libxl_conf.c | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-)
ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Is it done anywhere? If not, how can I help?
This the above change (setting libxl log level to libvirtd global one), makes almost impossible to get libxl debug, because the rest of libvirtd trashes the logs (hundreds virEvent* and virObject* messages, at "info"(!) level).
Presumably that's because you are using LIBVIRT_DEBUG=1 or setting log_debug=1 in /etc/libvirt/libvirtd.log. That is generally discouraged because it turns on all logging, which is essentially unusably verbose. It is also better to use more specific log settings, eg when I debug the QEMU driver I usually use log_filters="1:qemu 1:security 3:event 3:object 1:util" log_outputs="1:file:/var/log/libvirt/libvirtd.log" This generates log messages from every source file in qemu and security directories, and also log messages from every file in the util/ directory *except* for event & object files. So it is much more managable to read. The log filter strings just do a wildcard match against the VIR_LOG_INIT("...."); lines in each source file, so you can make things more or less specific as you desire. Regards, Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|

On Wed, Nov 11, 2015 at 04:04:22PM +0000, Daniel P. Berrange wrote:
On Wed, Nov 11, 2015 at 04:57:59PM +0100, Marek Marczykowski-Górecki wrote:
On Tue, Sep 15, 2015 at 11:21:00AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 10:57:50AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Tue, Sep 15, 2015 at 09:26:23AM -0600, Jim Fehlig wrote:
> Instead of a hardcoded DEBUG log level, use the overall > daemon log level specified in libvirtd.conf when opening > a log stream with libxl. libxl is very verbose when DEBUG > log level is set, resulting in huge log files that can > potentially fill a disk. Control of libxl verbosity should > be placed in the administrator's hands. > > Signed-off-by: Jim Fehlig <jfehlig@suse.com> > --- > src/libxl/libxl_conf.c | 18 +++++++++++++++++- > 1 file changed, 17 insertions(+), 1 deletion(-) > > ACK, this makes sense as default behaviour. As a future enhancement you might also consider supporting a config setting in /etc/libvirt/libxl.conf to explicitly control the libxl library logging behaviour independantly.
I had actually thought of adding it there first, but then took this approach assuming it would be more receptive upstream :-). Personally, I'm on the fence. I like the idea of a single knob to control log level throughout the daemon, making it a bit easier on admins. On the other hand, individual knobs are more friendly to those pouring through logs. I can add a knob in libxl.conf if preferred.
After thinking about it some more, I could actually see value in create a dedicated virLogSource() instance, solely for libxl library messages. If we then created a virLogSourceGetPriority() method, you could query that to see if to turn on logging for the libxl library. That would ultimately allow you to turn on debug for just the libxl library if desired, eg
static virLogSource virLogLibXL = { .name = "libxl.libxl_library", .... }
LIBVIRT_LOG_FILTERS="1:libxl_library"
Ah, good idea. I'll look into it.
Is it done anywhere? If not, how can I help?
This the above change (setting libxl log level to libvirtd global one), makes almost impossible to get libxl debug, because the rest of libvirtd trashes the logs (hundreds virEvent* and virObject* messages, at "info"(!) level).
Presumably that's because you are using LIBVIRT_DEBUG=1 or setting log_debug=1 in /etc/libvirt/libvirtd.log. That is generally discouraged because it turns on all logging, which is essentially unusably verbose.
It is also better to use more specific log settings, eg when I debug the QEMU driver I usually use
log_filters="1:qemu 1:security 3:event 3:object 1:util" log_outputs="1:file:/var/log/libvirt/libvirtd.log"
This generates log messages from every source file in qemu and security directories, and also log messages from every file in the util/ directory *except* for event & object files. So it is much more managable to read.
Ok, I'll try with "3:event 3:object", thanks!
The log filter strings just do a wildcard match against the VIR_LOG_INIT("...."); lines in each source file, so you can make things more or less specific as you desire.
Regards, Daniel
-- Best Regards, Marek Marczykowski-Górecki Invisible Things Lab A: Because it messes up the order in which people normally read text. Q: Why is top-posting such a bad thing?
participants (5)
-
Daniel P. Berrange
-
Ian Campbell
-
Jim Fehlig
-
John Ferlan
-
Marek Marczykowski-Górecki