Bug 2213385

Summary: Failed to call openGraphics()
Product: Red Hat Enterprise Linux 9 Reporter: lcheng
Component: selinux-policyAssignee: Nikola Knazekova <nknazeko>
Status: NEW --- QA Contact: BaseOS QE Security Team <qe-baseos-security>
Severity: medium Docs Contact:
Priority: medium    
Version: 9.3CC: jsuchane, lmen, lvrabec, mmalik, virt-maint, zpytela
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description lcheng 2023-06-08 02:44:42 UTC
Description of problem:
Failed to call openGraphics().


Version-Release number of selected component (if applicable):
libvirt-9.3.0-2.el9.x86_64
python3-libvirt-9.3.0-1.el9.x86_64
qemu-kvm-8.0.0-3.el9.x86_64

How reproducible:
100%

Steps to Reproduce:
# python
Python 3.9.16 (main, Dec  8 2022, 00:00:00)
[GCC 11.3.1 20221121 (Red Hat 11.3.1-4)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import libvirt
>>> import socket
>>> server, client = socket.socketpair(socket.AF_UNIX, socket.SOCK_STREAM)
>>> conn = libvirt.open()
>>> domobj = conn.lookupByName("test")
>>> domobj.openGraphics(0, server.fileno(), 0)
libvirt: QEMU Driver error : internal error: unable to execute QEMU command 'add_client': parameter @fdname must name a socket
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib64/python3.9/site-packages/libvirt.py", line 2264, in openGraphics
    raise libvirtError('virDomainOpenGraphics() failed')
libvirt.libvirtError: internal error: unable to execute QEMU command 'add_client': parameter @fdname must name a socket


Actual results:
Failed to call openGraphics()


Expected results:
openGraphics() works fine.


Additional info:
virtqemud.log
2023-06-07 02:37:31.663+0000: 692516: info : qemuMonitorSend:861 : QEMU_MONITOR_SEND_MSG: mon=0x7f5e080cb460 msg={"execute":"add_client","arguments":{"protocol":"vnc","fdname":"graphicsfd","skipauth":false},"id":"libvirt-25"}^M
 fd=-1
2023-06-07 02:37:31.663+0000: 692572: info : qemuMonitorIOWrite:366 : QEMU_MONITOR_IO_WRITE: mon=0x7f5e080cb460 buf={"execute":"add_client","arguments":{"protocol":"vnc","fdname":"graphicsfd","skipauth":false},"id":"libvirt-25"}^M
 len=114 ret=114 errno=0
2023-06-07 02:37:31.667+0000: 692572: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-25", "error": {"class": "GenericError", "desc": "parameter @fdname must name a socket"}}]
2023-06-07 02:37:31.667+0000: 692572: debug : virJSONValueFromString:1666 : string={"id": "libvirt-25", "error": {"class": "GenericError", "desc": "parameter @fdname must name a socket"}}
...
2023-06-07 02:37:31.668+0000: 692516: debug : qemuMonitorJSONCheckErrorFull:356 : unable to execute QEMU command {"execute":"add_client","arguments":{"protocol":"vnc","fdname":"graphicsfd","skipauth":false},"id":"libvirt-25"}: {"id":"libvirt-25","error":{"class":"GenericError","desc":"parameter @fdname must name a socket"}}
2023-06-07 02:37:31.668+0000: 692516: error : qemuMonitorJSONCheckErrorFull:368 : internal error: unable to execute QEMU command 'add_client': parameter @fdname must name a socket
2023-06-07 02:37:31.668+0000: 692516: debug : qemuMonitorCloseFileHandle:2492 : fdname=graphicsfd
2023-06-07 02:37:31.668+0000: 692516: debug : qemuMonitorCloseFileHandle:2496 : mon:0x7f5e080cb460 vm:0x7f5e0808d850 fd:19
2023-06-07 02:37:31.668+0000: 692516: debug : virJSONValueToBuffer:1791 : object=0x7f5e4c001470
...
2023-06-07 02:37:31.668+0000: 692516: info : qemuMonitorSend:861 : QEMU_MONITOR_SEND_MSG: mon=0x7f5e080cb460 msg={"execute":"closefd","arguments":{"fdname":"graphicsfd"},"id":"libvirt-26"}^M
 fd=-1
2023-06-07 02:37:31.668+0000: 692572: info : qemuMonitorIOWrite:366 : QEMU_MONITOR_IO_WRITE: mon=0x7f5e080cb460 buf={"execute":"closefd","arguments":{"fdname":"graphicsfd"},"id":"libvirt-26"}^M
 len=77 ret=77 errno=0
2023-06-07 02:37:31.671+0000: 692572: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-26", "error": {"class": "GenericError", "desc": "File descriptor named 'graphicsfd' not found"}}]
2023-06-07 02:37:31.671+0000: 692572: debug : virJSONValueFromString:1666 : string={"id": "libvirt-26", "error": {"class": "GenericError", "desc": "File descriptor named 'graphicsfd' not found"}}




openGraphics() works fine with libvirt-9.0.0-10.2.el9_2.x86_64, python3-libvirt-9.0.0-1.el9.x86_64 and qemu-kvm-7.2.0-14.el9_2.1.x86_64.

# python
Python 3.9.16 (main, Dec  8 2022, 00:00:00)
[GCC 11.3.1 20221121 (Red Hat 11.3.1-4)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import libvirt
>>> import socket
>>> server, client = socket.socketpair(socket.AF_UNIX, socket.SOCK_STREAM)
>>> conn = libvirt.open()
>>> domobj = conn.lookupByName("vm2")
>>> domobj.openGraphics(0, server.fileno(), 0)
0
>>> conn = libvirt.open()
>>> domobj = conn.lookupByName("vm2")
>>> domobj.openGraphics(0, server.fileno(), 0)
0

Comment 1 Peter Krempa 2023-06-22 14:19:41 UTC
I was not able to reproduce this on my setup.

Please attach the full debug log of virtqemud as well as the full VM xml used.

Comment 4 Peter Krempa 2023-08-08 14:42:50 UTC
There is nothing that changed in libvirt between the releases where it supposedly works and where it doesn't, but the error message in qemu was added recently [1].

Note that the FD is passed down from python via libvirt to qemu.

Libvirt invokes the following commands:
2023-06-26 01:46:37.056+0000: 1846131: info : qemuMonitorSend:864 : QEMU_MONITOR_SEND_MSG: mon=0x7fd41c0d6460 msg={"execute":"getfd","arguments":{"fdname":"graphicsfd"},"id":"libvirt-12"} fd=24
2023-06-26 01:46:37.058+0000: 1846153: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"return": {}, "id": "libvirt-12"}]
2023-06-26 01:46:37.058+0000: 1846131: info : qemuMonitorSend:864 : QEMU_MONITOR_SEND_MSG: mon=0x7fd41c0d6460 msg={"execute":"add_client","arguments":{"protocol":"vnc","fdname":"graphicsfd","skipauth":false},"id":"libvirt-13"} fd=-1
2023-06-26 01:46:37.060+0000: 1846153: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-13", "error": {"class": "GenericError", "desc": "parameter @fdname must name a socket"}}]

and then attempts to clean up:

2023-06-26 01:46:37.061+0000: 1846131: info : qemuMonitorSend:864 : QEMU_MONITOR_SEND_MSG: mon=0x7fd41c0d6460 msg={"execute":"closefd","arguments":{"fdname":"graphicsfd"},"id":"libvirt-14"} fd=-1
2023-06-26 01:46:37.062+0000: 1846153: info : qemuMonitorJSONIOProcessLine:210 : QEMU_MONITOR_RECV_REPLY: mon=0x7fd41c0d6460 reply={"id": "libvirt-14", "error": {"class": "GenericError", "desc": "File descriptor named 'graphicsfd' not found"}


[1]:
commit bf5de8c5d66552721fefe08de849c115ca366b56
Author: Marc-André Lureau <marcandre.lureau>
Date:   Mon Mar 6 16:27:45 2023 +0400

    qmp: 'add_client' actually expects sockets
    
    Whether it is SPICE, VNC, D-Bus, or the socket chardev, they all
    actually expect a socket kind or will fail in different ways at runtime.
    
    Throw an error early if the given 'add_client' fd is not a socket, and
    close it to avoid leaks.
    
    This allows to replace the close() call with a more correct & portable
    closesocket() version.
    
    (this will allow importing sockets on Windows with a specialized command
    in the following patch, while keeping the remaining monitor associated
    sockets/add_client code & usage untouched)
    
    Signed-off-by: Marc-André Lureau <marcandre.lureau>
    Reviewed-by: Philippe Mathieu-Daudé <philmd>
    Acked-by: Markus Armbruster <armbru>
    Message-Id: <20230306122751.2355515-6-marcandre.lureau>


As noted I can't reproduce this with upstream qemu with the above python code.

Moving to qemu for further analysis.

Comment 5 Marc-Andre Lureau 2023-08-08 19:47:13 UTC
That looks like `getsockopt(fd, SOL_SOCKET, SO_TYPE)` failed. The code treat any error (including ENOTSOCK) as indicating fd is not a socket.

Maybe SELinux is preventing calling getsockopt?

@lcheng
Could you check and attach the audit log, and  with selinux disabled? 

thanks

Comment 6 lcheng 2023-08-09 06:17:35 UTC
Thanks very much. Test with 'setenforce 0', no error to call openGraphics().


# setenforce 0
# getenforce 
Permissive

# python
Python 3.9.17 (main, Jun 26 2023, 00:00:00) 
[GCC 11.4.1 20230605 (Red Hat 11.4.1-2)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import libvirt
>>> import socket
>>> server, client = socket.socketpair(socket.AF_UNIX, socket.SOCK_STREAM)
>>> conn = libvirt.open()
>>> domobj = conn.lookupByName("vm1")
>>> domobj.openGraphics(0, server.fileno(), 0)
0

Comment 8 Marc-Andre Lureau 2023-08-09 07:33:19 UTC
thanks, moving to selinux-policy for further analysis.

Could you update the policy to allow qemu `getsockopt(fd, SOL_SOCKET, SO_TYPE)` ?

Comment 9 Nikola Knazekova 2023-08-10 07:30:16 UTC
Hi, 

Can you please reproduce the issue in permissive mode with full auditing enabled?


1) Open the /etc/audit/rules.d/audit.rules file in an editor.
2) Remove the following line if it exists:
-a task,never
3) Add the following line to the end of the file:
-w /etc/shadow -p w
4) Restart the audit daemon:
  # service auditd restart
5) Re-run your scenario.
6) Collect AVC denials:
  # ausearch -i -m avc,user_avc,selinux_err,user_selinux_err -ts today

Thank you,
Nikola

Comment 10 lcheng 2023-08-11 07:17:19 UTC
Hi Nikola,

I followed the steps in comment 9 to reproduce the issue. AVC denials as follows:

# ausearch -i -m avc,user_avc,selinux_err,user_selinux_err -ts today
----
type=PROCTITLE msg=audit(08/11/2023 02:58:15.735:37112) : proctitle=/usr/libexec/qemu-kvm -name guest=vm1,debug-threads=on -S -object {"qom-type":"secret","id":"masterKey0","format":"raw","file":" 
type=SYSCALL msg=audit(08/11/2023 02:58:15.735:37112) : arch=x86_64 syscall=getsockopt success=no exit=EACCES(Permission denied) a0=0x72 a1=SOL_SOCKET a2=SO_TYPE a3=0x7f4f73528f44 items=0 ppid=1 pid=489494 auid=unset uid=qemu gid=qemu euid=qemu suid=qemu fsuid=qemu egid=qemu sgid=qemu fsgid=qemu tty=(none) ses=unset comm=qemu-kvm exe=/usr/libexec/qemu-kvm subj=system_u:system_r:svirt_t:s0:c94,c660 key=(null) 
type=AVC msg=audit(08/11/2023 02:58:15.735:37112) : avc:  denied  { getopt } for  pid=489494 comm=qemu-kvm scontext=system_u:system_r:svirt_t:s0:c94,c660 tcontext=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 tclass=unix_stream_socket permissive=0


# rpm -q qemu-kvm selinux-policy
qemu-kvm-8.0.0-10.el9.x86_64
selinux-policy-38.1.17-1.el9.noarch


Thank you,
lcheng