Bug 856634

Summary: selinux policy discards writes to libvirt / qemu log file
Product: [Fedora] Fedora Reporter: Richard W.M. Jones <rjones>
Component: selinux-policyAssignee: Miroslav Grepl <mgrepl>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: berrange, clalancette, dominick.grift, dwalsh, itamar, jforbes, jyang, laine, libvirt-maint, mgrepl, veillard, virt-maint
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-12-15 19:16:42 UTC 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:
Attachments:
Description Flags
strace.log (xz-compressed) none

Description Richard W.M. Jones 2012-09-12 13:39:00 UTC
Created attachment 612118 [details]
strace.log (xz-compressed)

Description of problem:

When testing libguestfs using libvirt, I was running into a problem
where qemu was "just exiting".  The only thing reported by libvirt
was:

libguestfs: error: could not create appliance through libvirt: internal error process exited while connecting to monitor:  [code=1 domain=10]

Furthermore no extra information appeared in the ~/.cache/
libvirt/qemu/log/*.log file.

However when I straced the entire process, I found that qemu was
emitting a meaningful error message to stderr, but libvirt appears
to completely discard it.  The error was:

19401 connect(4, {sa_family=AF_FILE, sun_path="/home/rjones/d/libguestfs/libguestfsbtLEfB/console.sock"}, 110) = -1 EACCES (Permission denied)
19401 write(2, "connect(unix:/home/rjones/d/libguestfs/libguestfsbtLEfB/console.sock): Permission denied\n", 89) = 89
19401 close(4)                          = 0
19401 write(2, "chardev: opening backend \"socket\" failed\n", 41) = 41
19401 exit_group(1)                     = ?
19401 +++ exited with 1 +++

(Complete strace attached)

Version-Release number of selected component (if applicable):

libvirt-0.10.0-1.fc19.x86_64

How reproducible:

?

Steps to Reproduce:
1. Run libguestfs with libvirt attach method, eg
  LIBGUESTFS_ATTACH_METHOD=libvirt libguestfs-test-tool

Actual results:

As above.

Expected results:

Need to see any and every message output by qemu.

Additional info:

Comment 1 Daniel Berrangé 2012-09-12 13:52:59 UTC
Sadly I don't believe it is as simple as libvirt discarding the log messages.  First, libvirtd itself opens the log file and dup()s the file descriptor onto the QEMU process' stdout & stderr file descriptors. Thus any writes QEMU does to stderr should go directly to the logfile with no interference from libvirtd.

There is, however, interference from SELinux. If the labelling on the logfile is not write, then even though QEMU has the open file descriptor, it may well be forbidden to write to it. For reasons I don't understand, when SELinux blocks writes, it does not cause write() to return EPERM, instead they appear to be just discarded. I expect you should hoever see an AVC record akin to

 type=AVC msg=audit(1347457706.768:34): avc:  denied  { write } for  pid=407 comm="qemu-kvm" path="/home/berrange/.cache/libvirt/qemu/log/vm1.log" dev="dm-1" ino=708497 scontext=unconfined_u:unconfined_r:svirt_t:s0:c521,c647 tcontext=unconfined_u:object_r:cache_home_t:s0 tclass=file

The fix is thus to address the policy issues that both prevent the creation of the monitor socket (the first failure) and that prevent QEMU from writing to its log (the second failure). I don't think there is libvirt itself can do to handle QEMU logs which could avoid this problem.

Comment 2 Richard W.M. Jones 2012-09-12 14:01:52 UTC
Yup, Dan's analysis is correct:

type=AVC msg=audit(1347456629.344:493): avc:  denied  { write } for  pid=19401 c
omm="qemu-kvm" path="/home/rjones/.cache/libvirt/qemu/log/guestfs-s0g1o2g0srkjjv
be.log" dev="dm-5" ino=1864772 scontext=unconfined_u:unconfined_r:svirt_t:s0:c11
8,c968 tcontext=unconfined_u:object_r:cache_home_t:s0 tclass=file
type=AVC msg=audit(1347456629.345:494): avc:  denied  { write } for  pid=19401 c
omm="qemu-kvm" path="/home/rjones/.cache/libvirt/qemu/log/guestfs-s0g1o2g0srkjjv
be.log" dev="dm-5" ino=1864772 scontext=unconfined_u:unconfined_r:svirt_t:s0:c11
8,c968 tcontext=unconfined_u:object_r:cache_home_t:s0 tclass=file

(and SELinux is Enforcing)

Comment 3 Daniel Walsh 2012-09-18 14:28:27 UTC
DanB can you change libvirtd to open the log file for append.  

Current policy has this labeled 

 matchpathcon /home/rjones/.cache/libvirt/qemu/log/guestfs
/home/rjones/.cache/libvirt/qemu/log/guestfs	unconfined_u:object_r:svirt_home_t:s0

Comment 4 Richard W.M. Jones 2012-09-18 14:34:55 UTC
Isn't it going to be a problem that libvirt almost always
has to create these files each time?  (The filenames are based
on the guest name, which we are generating randomly because
these guests are transient).

Comment 5 Daniel Berrangé 2012-09-18 15:01:32 UTC
Hmm, with non-root libvirtd we open the files to truncate, since there are no logrotate rules as non-root & we don't want them growing without bound. I realize now though, we could still open them for append and then simply call truncate() instead.

@rich yes a build up of logfiles from guests is a bit of a problem I've not figured out a solution for - same issue with libvirt-sandbox in general.

Comment 6 Daniel Berrangé 2012-09-21 11:19:26 UTC
Added patch to libvirt to always use open(O_APPEND) + ftruncate(), instead of  open(O_TRUNC), which I hope will keep SELinux happy

https://www.redhat.com/archives/libvir-list/2012-September/msg01532.html