On Thu, Apr 30, 2020 at 2:51 PM Daniel P. Berrangé <berrange@xxxxxxxxxx> wrote: > > On Thu, Apr 30, 2020 at 02:42:21PM +0200, Christian Ehrhardt wrote: > > On Thu, Apr 30, 2020 at 2:10 PM Michal Privoznik <mprivozn@xxxxxxxxxx> wrote: > > > > > > On 4/30/20 11:59 AM, Christian Ehrhardt wrote: > > > > Newer systemd is too smart, it detects the PIDs of the gettext calls > > > > and due to that a log lists libvirt-guests.sh with many different PIDs. > > > > > > > > Furthermore it struggles to collect the output in time, so it can be > > > > truncated and overall looks like: > > > > libvirt-guests.sh[37986]: Running guests on default URI: > > > > libvirt-guests.sh[37995]: Running guests on > > > > libvirt-guests.sh[37977]: R > > > > > > > > Gather the gettext result into a local variable and printing > > > > the value from libvirt-guests.sh itself fixes both issues. > > > > > > > > Fixes: https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1875708 > > > > > > > > Signed-off-by: Christian Ehrhardt <christian.ehrhardt@xxxxxxxxxxxxx> > > > > --- > > > > tools/libvirt-guests.sh.in | 74 +++++++++++++++++++++----------------- > > > > 1 file changed, 42 insertions(+), 32 deletions(-) > > > > > > > > diff --git a/tools/libvirt-guests.sh.in b/tools/libvirt-guests.sh.in > > > > index 7af24dab3b..324abe3623 100644 > > > > --- a/tools/libvirt-guests.sh.in > > > > +++ b/tools/libvirt-guests.sh.in > > > > @@ -28,6 +28,16 @@ test ! -r "$sysconfdir"/rc.d/init.d/functions || > > > > # Make sure this file is recognized as having translations: _("dummy") > > > > . "@bindir@"/gettext.sh > > > > > > > > +# Avoid output being listed under gettext PID and being truncated > > > > +unbuffered_gettext () { > > > > + msg="$(gettext "$1")" > > > > + echo "$msg" > > > > +} > > > > +unbuffered_eval_gettext () { > > > > + msg="$(eval_gettext "$1")" > > > > + echo "$msg" > > > > +} > > > > + > > > > > > Ah, is this the case where gettext prints the text in many sequences > > > whereas echo does it all at once? Or what do you think is happening > > > here? I don't quite understand how buffering steps into this. > > > > You have two effects: > > - systemd tries to detect and report which PID the output is from when > > something it printed. Therefore it appears to a user as if the script > > itself would have been invoked multiple times while actually is will be > > the PIDs of the different gettext calls > > - I assume that to get this content it is hitchhiking the output streams > > somehow - the gettext processes are very very short lived and it seems > > when they are exiting some output of them might be lost. > > This doesn't pass a sniff test to me. > > systemd is reading stdout/stderr of the libvirt-guests script. How > would it ever tell that certain lines from stdout/err are coming from > different PIDs. Systemd isn't involved in spawning the gettext processes. > It can see they come & go via cgroups pids, but that's about it. Well it seems I have a reproducible symptom and a fix, but not the explanation why the latter fixes the former. I'll need to dive into some debug & analysis myself to explain it better. I'll be back here once I got time to do that in depth check. Until then whoever is affected (should be everyone) can give it a thought as well. Repro is as easy as One console: $ journalctl -f -u libvirt-guests Other console: $ systemctl stop libvirt-guests $ systemctl start libvirt-guests I see it with 245.4-4ubuntu3 (18.04) I'm not seeing it on 237-3ubuntu10.39 (20.04). Maybe it is a systemd bug after all? I'd be interested to hear if that is/isn't clobbering output for anyone else and what your systemd versions are? > 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 :| > -- Christian Ehrhardt Staff Engineer, Ubuntu Server Canonical Ltd
