Bug 1356108

Should be fixed upstream in

commit cc9e80c59368478d179ee3eb7bf8106664c56870 (HEAD -> master, origin/master, qemu-logging)
Author: Daniel P. Berrangé <berrange>
Date:   Fri Dec 14 12:57:37 2018 +0000

    logging: ensure pending I/O is drained before reading position
    
    The virtualization driver has two connections to the virtlogd daemon,
    one pipe fd for writing to the log file, and one socket fd for making
    RPC calls. The typical sequence is to write some data to the pipe fd and
    then make an RPC call to determine the current log file offset.
    
    Unfortunately these two operations are not guaranteed to be handling in
    order by virtlogd. The event loop for virtlogd may identify an incoming
    event on both the pipe fd and socket fd in the same iteration of the
    event loop. It is then entirely possible that it will process the socket
    fd RPC call before reading the pending log data from the pipe fd.
    
    As a result the virtualization driver will get an outdated log file
    offset reported back.
    
    This can be seen with the QEMU driver where, when a guest fails to
    start, it will randomly include too much data in the error message it
    has fetched from the log file.
    
    The solution is to ensure we have drained all pending data from the pipe
    fd before reporting the log file offset. The pipe fd is always in
    blocking mode, so cares needs to be taken to avoid blocking. When
    draining this is taken care of by using poll(). The extra complication
    is that they might already be an event loop dispatch pending on the pipe
    fd. If we have just drained the pipe this pending event will be invalid
    so must be discarded.
    
    See also https://bugzilla.redhat.com/show_bug.cgi?id=1356108
    
    Signed-off-by: Daniel P. Berrangé <berrange>

Thanks a lot Dan for addressing the issue! \o/

Moving to POST now.

Hi Andrea,

I try to set the memory to 1:
    # ulimit -l
    1
But when I start the domain, it still could be started successfully.
    # virsh start avocado-vt-vm1
    Domain avocado-vt-vm1 started
So, any other steps I need to do?
Thanks.

(In reply to Junxiang Li from comment #11)
> Hi Andrea,
> 
> I try to set the memory to 1:
>     # ulimit -l
>     1
> But when I start the domain, it still could be started successfully.
>     # virsh start avocado-vt-vm1
>     Domain avocado-vt-vm1 started
> So, any other steps I need to do?
> Thanks.

It seems from the prompt that you're trying this as root, which
complicates verification because now you have to take into account
the fact that the system daemon was probably started before you
altered the ulimit and as such is not affected by it...

A simpler way to bump into the error is to create a guest in the
session daemon, as a regular user.

First of all, verify the memory limit with

  $ ulimit -l
  65536

This is the default in RHEL. Then, create an empty disk image

  $ qemu-img create empty.raw 1
  Formatting 'empty.raw', fmt=raw size=1

and finally try to import it into libvirt while specifying a very
large amount of RAM (32 GiB) which requires a higher limit:

  $ virt-install \
    --connect qemu:///session \
    --import \
    --name memlock-test \
    --ram 32768 \
    --disk path=$(pwd)/empty.raw
  WARNING  Unable to connect to graphical console: virt-viewer not installed. Please install the 'virt-viewer' package.
  WARNING  No console to launch for the guest, defaulting to --wait -1

  Starting install...
  ERROR    internal error: Process exited prior to exec: etdev user,id=hostnet0 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:1c:bc:15,bus=pci.0,addr=0x1 -chardev pty,id=charserial0 -device spapr-vty,chardev=charserial0,id=serial0,reg=0x30000000 -chardev socket,id=charchannel0,fd=27,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.qemu.guest_agent.0 -device usb-kbd,id=input0,bus=usb.0,port=1 -device usb-mouse,id=input1,bus=usb.0,port=2 -vnc 127.0.0.1:0 -device VGA,id=video0,vgamem_mb=16,bus=pci.0,addr=0x6 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 -sandbox on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny -msg timestamp=on
  libvirt:  error : cannot limit locked memory to 281018368: Operation not permitted
  Domain installation does not appear to have been successful.
  If it was, you can restart your domain by running:
    virsh --connect qemu:///session start memlock-test
  otherwise, please restart your installation.

Installation will fail.

In the example above, I'm running libvirt 4.5.0 so I can still see
all the garbage in the output; when running a fixed package that
should not be seen.

Verify steps:
0. Login a non-root user
1. qemu-img create empty.raw 1
Reproduce:
$ rpm -q libvirt
libvirt-4.10.0-1.module+el8+2317+367e35b5.ppc64le
2. 
$ virt-install \
    --connect qemu:///session \
    --import \
    --name memlock-test \
    --ram 32768 \
    --disk path=$(pwd)/empty.raw

WARNING  Unable to connect to graphical console: virt-viewer not installed. Please install the 'virt-viewer' package.
WARNING  No console to launch for the guest, defaulting to --wait -1

Starting install...
ERROR    internal error: Process exited prior to exec:  virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:37:9a:94,bus=pci.0,addr=0x1 -chardev pty,id=charserial0 -device spapr-vty,chardev=charserial0,id=serial0,reg=0x30000000 -chardev socket,id=charchannel0,fd=27,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.qemu.guest_agent.0 -device usb-kbd,id=input0,bus=usb.0,port=1 -device usb-mouse,id=input1,bus=usb.0,port=2 -vnc 127.0.0.1:0 -device VGA,id=video0,vgamem_mb=16,bus=pci.0,addr=0x6 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x5 -sandbox on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny -msg timestamp=on
libvirt:  error : cannot limit locked memory to 281018368: Operation not permitted
Domain installation does not appear to have been successful.
If it was, you can restart your domain by running:
  virsh --connect qemu:///session start memlock-test
otherwise, please restart your installation.

verify:
$ rpm -q libvirt
libvirt-5.0.0-3.module+el8+2807+8bbe0a41.ppc64le
2.
$ virt-install \
    --connect qemu:///session \
    --import \
    --name memlock-test \
    --ram 32768 \
    --disk path=$(pwd)/empty.raw

WARNING  Unable to connect to graphical console: virt-viewer not installed. Please install the 'virt-viewer' package.
WARNING  No console to launch for the guest, defaulting to --wait -1

Starting install...
ERROR    internal error: Process exited prior to exec: libvirt:  error : cannot limit locked memory to 281018368: Operation not permitted
Domain installation does not appear to have been successful.
If it was, you can restart your domain by running:
  virsh --connect qemu:///session start memlock-test
otherwise, please restart your installation.

Above all, the bug is verified.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:1293