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:
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.
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)
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
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).
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.
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