Bug 1356108 - Garbled output on memory locking failure
Summary: Garbled output on memory locking failure
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux Advanced Virtualization
Classification: Red Hat
Component: libvirt
Version: 8.0
Hardware: ppc64le
OS: Linux
low
low
Target Milestone: rc
: 8.0
Assignee: Andrea Bolognani
QA Contact: Junxiang Li
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-07-13 12:21 UTC by Andrea Bolognani
Modified: 2020-11-14 06:10 UTC (History)
11 users (show)

Fixed In Version: libvirt-5.0.0-1.el8
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1660531 (view as bug list)
Environment:
Last Closed: 2019-05-29 16:04:07 UTC
Type: Bug
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2019:1293 0 None None None 2019-05-29 16:04:47 UTC

Description Andrea Bolognani 2016-07-13 12:21:30 UTC
KVM guests on ppc64 hardware need to lock some memory in the
host to store internal structures. If the memory locking limit
for the user not high enough to allow that, eg.

  $ ulimit -l
  64

attempts to start a guest will result in an error:

  $ virsh start abologna-rhel73
  error: Failed to start domain abologna-rhel73
  error: internal error: Process exited prior to exec: libvirt:  error :
  cannot limit locked memory to 23068672: Operation not permitted

This is expected. However, sometimes the attempt will result
in garbled output instead:

  $ virsh start abologna-rhel73
  error: Failed to start domain abologna-rhel73
  error: internal error: Process exited prior to exec: ontrol -rtc base=utc
  -no-shutdown -boot strict=on -device pci-ohci,id=usb,bus=pci.0,addr=0x3
  -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x2 -device
  virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x4 -drive [...]
  libvirt:  error : cann

The output seems to erroneously contain some information that
are meant for the log file only.

Comment 5 Daniel Berrangé 2018-12-18 14:51:04 UTC
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>

Comment 6 Andrea Bolognani 2018-12-18 16:02:17 UTC
Thanks a lot Dan for addressing the issue! \o/

Moving to POST now.

Comment 11 Junxiang Li 2019-02-18 06:33:17 UTC
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.

Comment 12 Andrea Bolognani 2019-02-18 16:50:20 UTC
(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.

Comment 13 Junxiang Li 2019-02-22 06:18:15 UTC
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.

Comment 15 errata-xmlrpc 2019-05-29 16:04:07 UTC
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


Note You need to log in before you can comment on or make changes to this bug.