[libvirt] [PATCH 7/7] Remove global log buffer feature entirely

[Daniel P. Berrange]

On Fri, Mar 07, 2014 at 11:27:53AM -0700, Eric Blake wrote:
> On 03/03/2014 12:18 PM, Daniel P. Berrange wrote:
> > A earlier commit changed the global log buffer so that it only
> > records messages that are explicitly requested via the log
> > filters setting. This removes the performance burden, and
> > improves the signal/noise ratio for messages in the global
> > buffer. At the same time though, it is somewhat pointless, since
> > all the recorded log messages are already going to be sent to an
> > explicit log output like syslog, stderr or the journal. The
> > global log buffer is thus just duplicating this data on stderr
> > upon crash.
> 
> I still wonder if there is value on keeping the ring buffer for when
> logging is not stderr.  That is, if we dump to syslog by default but
> ALSO dump the ring buffer to stderr, it may be easier to find what got
> logged by reading stderr rather than having to hunt for the syslog.  But
> that's a weak argument.

Yep, that is the only real reason I know of for keeping this. eg
syslog may be configured to throw away the libvirt logs...

> If we commit to patch 1, then the logging ring really is duplicated
> overhead, and I'm fine ditching it.  You may want to get DV's opinion,
> but I'm fine with this patch going in on the premise that patch 1 made
> sense.
> 
> On the other hand, if patch 1 meets resistance, should we look at ways
> to minimize printf() overhead?  For example, a LOT of our overhead is
> tied to the fact that we malloc() a lot when constructing the log
> string.  It may be possible to fine-tune things so that most (if not
> all) log messages get computed into a static buffer (gnulib's asnprintf
> is cool in how it avoids malloc in the common case if you provide a
> large enough buffer, while still being robust to larger strings).  It
> won't kill as much overhead as what you killed by completely ditching
> the ring buffer, but may still be enough improvement to merit keeping
> the ring buffer around.
> 
> I'm not tied to the ring buffer - I still think that targetted logging
> is easier to sift through than the signal-to-noise ratio of a ring
> buffer dump.  I'm just raising the question to make sure we think of the
> issues before applying patch 1 and losing what might still be a useful
> last-ditch debug aid for hard-to-reproduce crashes.

If we were to keep the global log buffer pretty much none of this
patch series is worthwhile, because as long as the global log buffer
exists the other performance improvements in this patch are dwarved
by the printf. Just minimizing malloc/printf overhead might let you
cut overhead in 1/2 or even in 1/4, but that still leaves massive
overhead behind. This patch series is reducing the execution time
in the test program from 1 minute 40 secs, to 3 secs.

I don't see any optimization of printf/malloc being able to get us
anywhere near this kind of level of improvement.

> > @@ -431,7 +429,6 @@ daemonConfigLoadOptions(struct daemonConfig *data,
> >      GET_CONF_INT(conf, filename, log_level);
> >      GET_CONF_STR(conf, filename, log_filters);
> >      GET_CONF_STR(conf, filename, log_outputs);
> > -    GET_CONF_INT(conf, filename, log_buffer_size);
> 
> Does augeas gracefully handle an option that is no longer used by
> current libvirtd, but which mattered to older versions?  That is, I
> think you still have to support the option in the .conf file, and
> document that it is now ignored, but guarantee that having it in the
> .conf file doesn't cause a syntax error.

If the user had set this config file, and they now try to parse the
file with augeas, it will raise an error.

> 
> > +++ b/daemon/libvirtd.aug
> > @@ -64,7 +64,6 @@ module Libvirtd =
> >     let logging_entry = int_entry "log_level"
> >                       | str_entry "log_filters"
> >                       | str_entry "log_outputs"
> > -                     | int_entry "log_buffer_size"
> 
> That is, I don't think you can safely delete this line.

I guess so.

> > +++ b/daemon/libvirtd.conf
> > @@ -345,13 +345,6 @@
> >  #log_outputs="3:syslog:libvirtd"
> >  #
> >  
> > -# Log debug buffer size: default 64
> > -# The daemon keeps an internal debug log buffer which will be dumped in case
> > -# of crash or upon receiving a SIGUSR2 signal. This setting allows to override
> > -# the default buffer size in kilobytes.
> > -# If value is 0 or less the debug log buffer is deactivated
> > -#log_buffer_size = 64
> 
> And that you may need to mention that this variable is present but
> ignored for backward compatibility, rather than deleting it altogether.

Ok.

> > -static void
> > -virNetServerFatalSignal(int sig, siginfo_t *siginfo ATTRIBUTE_UNUSED,
> > -                        void *context ATTRIBUTE_UNUSED)
> > -{
> > -    struct sigaction sig_action;
> > -    int origerrno;
> > -
> > -    origerrno = errno;
> > -    virLogEmergencyDumpAll(sig);
> 
> We may not be dumping the ring buffer any more, but I _still_ think it's
> worth keeping this signal handler and dumping a message that we detected
> a fatal crash, as well as pointing the user to go read the contents of
> the logging files (and/or rerun libvirtd with more logging enabled).  In
> other words, delete the ring buffer, but DON'T delete this last-ditch
> message to the user.

But if you don't install any SEGV signal handler, the kernel/glibc default
will already print

  Segmentation fault (core dumped)

So what more would libvirt do ?

I'm open to suggestions of what else libvirt could usefully (& safely)
add to this, but I couldn't think of anything worthwhile.


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 :|