Re: [libvirt-users] libvirtd not accepting connections
[adding back the ML, you probably hit reply instead of reply-all, this way other people might help if they know more] On Fri, Jun 02, 2017 at 08:10:01AM -0400, Michael C. Cambria wrote:
Hi,
libvirtd never seems to get notified that there is work to do. journalct -f indicated that nothing was logged when connections were attempted via virsh.
I also tried 'LIBVIRT_DEBUG=1 libvirtd --verbose' and once startup finished, there were no more log entries even though virsh attempts were made.
That's because it gets overridden by the configuration files. This might be a bug, but it's not related to what's happening.
"ps ax" shows about a dozen "qemu-system-alpha" processes. I don't know if it matters but I didn't expect to see this. I didn't intentionally configure alpha emulations (assuming that's what it is) and certainly don't want to waste resources having it running.
Libvirt caches the capabilities of the emulators it can find in your system in order not to waste resources. These processes are expected to go away after they reply with all libvirt asks them for. However, it seems like the initialization cannot be completed precisely due to the fact that these processes don't communicate. There might be some details about qemu-system-alpha that are different when compared to, e.g. qemu-system-x86 and libvirt is not (yet) adapted to them, but I installed that emulator and libvirt daemon runs as usual. It looks like a problem in QEMU. Could you, as a workaround, try uninstalling that qemu binary from your system and restarting the service? Also, what versions of libvirt and qemu do you have installed?
Here is gdb output:
$ sudo gdb -batch -p $(pidof libvirtd) -ex "t a a bt full" > batch.out [mcc@eastie-fid4-com triage]$ cat batch.out [New LWP 17587] [New LWP 17588] [New LWP 17589] [New LWP 17590] [New LWP 17591] [New LWP 17592] [New LWP 17593] [New LWP 17594] [New LWP 17595] [New LWP 17596] [New LWP 17597] [New LWP 17598] [New LWP 17599] [New LWP 17600] [New LWP 17601] [New LWP 17602] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". 0x00007fcd6b4a501d in poll () at ../sysdeps/unix/syscall-template.S:84 84 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
Thread 17 (Thread 0x7fcd3bf18700 (LWP 17602)): #0 0x00007fcd6b4a501d in poll () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007fcd6b4c310e in __poll_chk (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>, fdslen=<optimized out>) at poll_chk.c:27 No locals. #2 0x00007fcd6f07bf41 in poll (__timeout=-1, __nfds=<optimized out>, __fds=0x7fcd3bf16ec0) at /usr/include/bits/poll2.h:41 No locals. #3 virCommandProcessIO (cmd=cmd@entry=0x7fcd344228f0) at util/vircommand.c:2049 i = <optimized out> fds = {{fd = 22, events = 1, revents = 0}, {fd = 24, events = 1, revents = 0}, {fd = 1802946632, events = 32717, revents = 0}} nfds = <optimized out> outfd = <optimized out> errfd = 24 inlen = 0 outlen = 0 errlen = 0 inoff = 0 ret = 0 __func__ = "virCommandProcessIO" __FUNCTION__ = "virCommandProcessIO" #4 0x00007fcd6f08025a in virCommandRun (cmd=cmd@entry=0x7fcd344228f0, exitstatus=exitstatus@entry=0x7fcd3bf1749c) at util/vircommand.c:2274 ret = 0 outbuf = 0x7fcd341c1850 "`\030\034\064\315\177" errbuf = 0x0 st = {st_dev = 140519450702688, st_ino = 5007254661694877440, st_nlink = 140519321774352, st_mode = 1862726288, st_uid = 32717, st_gid = 1865325018, __pad0 = 32717, st_rdev = 140732281970554, st_size = 0, st_blksize = 11, st_blocks = 8, st_atim = {tv_sec = 140519321774368, tv_nsec = 140519450703056}, st_mtim = {tv_sec = 140519321774352, tv_nsec = 140519450703024}, st_ctim = {tv_sec = 140520244259750, tv_nsec = 140520310044608}, __glibc_reserved = {140520244259750, 140520310041179, 140519321774320}} string_io = <optimized out> async_io = <optimized out> str = 0x7fcd3bf17420 "\260t\361;\315\177" tmpfd = <optimized out> __FUNCTION__ = "virCommandRun" __func__ = "virCommandRun" #5 0x00007fcd404a27cf in virQEMUCapsInitQMP (qmperr=0x7fcd3bf174a0, runGid=107, runUid=107, libDir=<optimized out>, qemuCaps=0x7fcd340fd3e0) at qemu/qemu_capabilities.c:3700 cmd = 0x7fcd344228f0 pid = 0 ret = -1 mon = 0x0 status = 0 monarg = 0x7fcd343a2570 "unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait" vm = 0x0 config = {type = 9, data = {file = {path = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", append = 0}, nmdm = {master = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", slave = 0x0}, tcp = {host = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", service = 0x0, listen = false, protocol = 0}, udp = {bindHost = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", bindService = 0x0, connectHost = 0x0, connectService = 0x0}, nix = {path = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", listen = false}, spicevmc = 873799056, spiceport = {channel = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock"}}, logfile = 0x0, logappend = 0} monpath = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock" pidfile = 0x7fcd341ad8b0 "/var/lib/libvirt/qemu/capabilities.pidfile" xmlopt = 0x0 #6 virQEMUCapsNewForBinaryInternal (binary=binary@entry=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha", libDir=<optimized out>, cacheDir=0x7fcd343be860 "/var/cache/libvirt/qemu", runUid=107, runGid=107, qmpOnly=qmpOnly@entry=false) at qemu/qemu_capabilities.c:3830 qemuCaps = 0x7fcd340fd3e0 sb = {st_dev = 64768, st_ino = 1838294, st_nlink = 1, st_mode = 33261, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 8829680, st_blksize = 4096, st_blocks = 17248, st_atim = {tv_sec = 1496358589, tv_nsec = 77994286}, st_mtim = {tv_sec = 1492132244, tv_nsec = 0}, st_ctim = {tv_sec = 1494196699, tv_nsec = 451929606}, __glibc_reserved = {0, 0, 0}} rv = <optimized out> qmperr = 0x7fcd341c1870 "" __FUNCTION__ = "virQEMUCapsNewForBinaryInternal" #7 0x00007fcd404a3a73 in virQEMUCapsNewForBinary (runGid=<optimized out>, runUid=<optimized out>, cacheDir=<optimized out>, libDir=<optimized out>, binary=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha") at qemu/qemu_capabilities.c:3871 No locals. #8 virQEMUCapsCacheLookup (cache=cache@entry=0x7fcd341c9000, binary=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha") at qemu/qemu_capabilities.c:3986 ret = 0x0 __func__ = "virQEMUCapsCacheLookup" #9 0x00007fcd404a3d22 in virQEMUCapsInitGuest (guestarch=VIR_ARCH_ALPHA, hostarch=VIR_ARCH_X86_64, cache=0x7fcd341c9000, caps=0x7fcd341a9980) at qemu/qemu_capabilities.c:824 qemubinCaps = 0x0 x86_32on64_kvm = <optimized out> ppc64_kvm = <optimized out> kvmbin = 0x0 ret = -1 i = <optimized out> binary = 0x7fcd34016cb0 "/usr/bin/qemu-system-alpha" kvmbinCaps = 0x0 native_kvm = <optimized out> arm_32on64_kvm = <optimized out> #10 virQEMUCapsInit (cache=0x7fcd341c9000) at qemu/qemu_capabilities.c:1109 caps = 0x7fcd341a9980 i = 1 hostarch = VIR_ARCH_X86_64 __func__ = "virQEMUCapsInit" #11 0x00007fcd404def20 in virQEMUDriverCreateCapabilities (driver=driver@entry=0x7fcd34342370) at qemu/qemu_conf.c:766 i = <optimized out> j = <optimized out> caps = <optimized out> sec_managers = 0x0 doi = <optimized out> model = <optimized out> lbl = <optimized out> type = <optimized out> cfg = 0x7fcd3448cbb0 virtTypes = {3, 1} __FUNCTION__ = "virQEMUDriverCreateCapabilities" __func__ = "virQEMUDriverCreateCapabilities" #12 0x00007fcd4051fef3 in qemuStateInitialize (privileged=true, callback=<optimized out>, opaque=<optimized out>) at qemu/qemu_driver.c:844 driverConf = 0x0 conn = 0x0 cfg = 0x7fcd3448cbb0 run_uid = <optimized out> run_gid = <optimized out> hugepagePath = 0x0 i = <optimized out> __FUNCTION__ = "qemuStateInitialize" #13 0x00007fcd6f1789af in virStateInitialize (privileged=<optimized out>, callback=0x55f56a9b3180 <daemonInhibitCallback>, opaque=0x55f56be1cf00) at libvirt.c:770 i = 9 __func__ = "virStateInitialize" #14 0x000055f56a9b31db in daemonRunStateInit (opaque=0x55f56be1cf00) at libvirtd.c:959 dmn = 0x55f56be1cf00 sysident = 0x7fcd34000910 __func__ = "daemonRunStateInit" #15 0x00007fcd6f0d98f2 in virThreadHelper (data=<optimized out>) at util/virthread.c:206 args = 0x0 local = {func = 0x55f56a9b31a0 <daemonRunStateInit>, funcName = 0x55f56a9f28d3 "daemonRunStateInit", worker = false, opaque = 0x55f56be1cf00} #16 0x00007fcd6b7766ca in start_thread (arg=0x7fcd3bf18700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fcd3bf18700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140519450707712, -3574063505887647860, 0, 140732281962543, 140519450708416, 140519450707712, 3601779982174594956, 3601954753778231180}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #17 0x00007fcd6b4b0f7f in clone () at .../sysdeps/unix/sysv/linux/x86_64/clone.S:105 No locals.
[...]
On 06/02/2017 09:43 AM, Martin Kletzander wrote:
[adding back the ML, you probably hit reply instead of reply-all, this way other people might help if they know more]
On Fri, Jun 02, 2017 at 08:10:01AM -0400, Michael C. Cambria wrote:
Hi,
libvirtd never seems to get notified that there is work to do. journalct -f indicated that nothing was logged when connections were attempted via virsh.
I also tried 'LIBVIRT_DEBUG=1 libvirtd --verbose' and once startup finished, there were no more log entries even though virsh attempts were made.
That's because it gets overridden by the configuration files. This might be a bug, but it's not related to what's happening.
"ps ax" shows about a dozen "qemu-system-alpha" processes. I don't know if it matters but I didn't expect to see this. I didn't intentionally configure alpha emulations (assuming that's what it is) and certainly don't want to waste resources having it running.
Libvirt caches the capabilities of the emulators it can find in your system in order not to waste resources. These processes are expected to go away after they reply with all libvirt asks them for. However, it seems like the initialization cannot be completed precisely due to the fact that these processes don't communicate.
There might be some details about qemu-system-alpha that are different when compared to, e.g. qemu-system-x86 and libvirt is not (yet) adapted to them, but I installed that emulator and libvirt daemon runs as usual. It looks like a problem in QEMU. Could you, as a workaround, try uninstalling that qemu binary from your system and restarting the service?
Also, what versions of libvirt and qemu do you have installed?
# LIBVIRT_DEBUG=1 libvirtd --verbose 2017-06-02 00:16:30.317+0000: 18088: info : libvirt version: 2.2.1, package: 1.fc25 (Fedora Project, 2017-05-10-22:06:21, buildvm-29.phx2.fedoraproject.org) I'll check on qemu as soon as I can get to the machine. The version should be the latest one gets via 'dnf update' on fedora 25
Here is gdb output:
$ sudo gdb -batch -p $(pidof libvirtd) -ex "t a a bt full" > batch.out [mcc@eastie-fid4-com triage]$ cat batch.out [New LWP 17587] [New LWP 17588] [New LWP 17589] [New LWP 17590] [New LWP 17591] [New LWP 17592] [New LWP 17593] [New LWP 17594] [New LWP 17595] [New LWP 17596] [New LWP 17597] [New LWP 17598] [New LWP 17599] [New LWP 17600] [New LWP 17601] [New LWP 17602] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". 0x00007fcd6b4a501d in poll () at ../sysdeps/unix/syscall-template.S:84 84 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
Thread 17 (Thread 0x7fcd3bf18700 (LWP 17602)): #0 0x00007fcd6b4a501d in poll () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007fcd6b4c310e in __poll_chk (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>, fdslen=<optimized out>) at poll_chk.c:27 No locals. #2 0x00007fcd6f07bf41 in poll (__timeout=-1, __nfds=<optimized out>, __fds=0x7fcd3bf16ec0) at /usr/include/bits/poll2.h:41 No locals. #3 virCommandProcessIO (cmd=cmd@entry=0x7fcd344228f0) at util/vircommand.c:2049 i = <optimized out> fds = {{fd = 22, events = 1, revents = 0}, {fd = 24, events = 1, revents = 0}, {fd = 1802946632, events = 32717, revents = 0}} nfds = <optimized out> outfd = <optimized out> errfd = 24 inlen = 0 outlen = 0 errlen = 0 inoff = 0 ret = 0 __func__ = "virCommandProcessIO" __FUNCTION__ = "virCommandProcessIO" #4 0x00007fcd6f08025a in virCommandRun (cmd=cmd@entry=0x7fcd344228f0, exitstatus=exitstatus@entry=0x7fcd3bf1749c) at util/vircommand.c:2274 ret = 0 outbuf = 0x7fcd341c1850 "`\030\034\064\315\177" errbuf = 0x0 st = {st_dev = 140519450702688, st_ino = 5007254661694877440, st_nlink = 140519321774352, st_mode = 1862726288, st_uid = 32717, st_gid = 1865325018, __pad0 = 32717, st_rdev = 140732281970554, st_size = 0, st_blksize = 11, st_blocks = 8, st_atim = {tv_sec = 140519321774368, tv_nsec = 140519450703056}, st_mtim = {tv_sec = 140519321774352, tv_nsec = 140519450703024}, st_ctim = {tv_sec = 140520244259750, tv_nsec = 140520310044608}, __glibc_reserved = {140520244259750, 140520310041179, 140519321774320}} string_io = <optimized out> async_io = <optimized out> str = 0x7fcd3bf17420 "\260t\361;\315\177" tmpfd = <optimized out> __FUNCTION__ = "virCommandRun" __func__ = "virCommandRun" #5 0x00007fcd404a27cf in virQEMUCapsInitQMP (qmperr=0x7fcd3bf174a0, runGid=107, runUid=107, libDir=<optimized out>, qemuCaps=0x7fcd340fd3e0) at qemu/qemu_capabilities.c:3700 cmd = 0x7fcd344228f0 pid = 0 ret = -1 mon = 0x0 status = 0 monarg = 0x7fcd343a2570 "unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait" vm = 0x0 config = {type = 9, data = {file = {path = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", append = 0}, nmdm = {master = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", slave = 0x0}, tcp = {host = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", service = 0x0, listen = false, protocol = 0}, udp = {bindHost = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", bindService = 0x0, connectHost = 0x0, connectService = 0x0}, nix = {path = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock", listen = false}, spicevmc = 873799056, spiceport = {channel = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock"}}, logfile = 0x0, logappend = 0} monpath = 0x7fcd34151d90 "/var/lib/libvirt/qemu/capabilities.monitor.sock" pidfile = 0x7fcd341ad8b0 "/var/lib/libvirt/qemu/capabilities.pidfile" xmlopt = 0x0 #6 virQEMUCapsNewForBinaryInternal (binary=binary@entry=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha", libDir=<optimized out>, cacheDir=0x7fcd343be860 "/var/cache/libvirt/qemu", runUid=107, runGid=107, qmpOnly=qmpOnly@entry=false) at qemu/qemu_capabilities.c:3830 qemuCaps = 0x7fcd340fd3e0 sb = {st_dev = 64768, st_ino = 1838294, st_nlink = 1, st_mode = 33261, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 8829680, st_blksize = 4096, st_blocks = 17248, st_atim = {tv_sec = 1496358589, tv_nsec = 77994286}, st_mtim = {tv_sec = 1492132244, tv_nsec = 0}, st_ctim = {tv_sec = 1494196699, tv_nsec = 451929606}, __glibc_reserved = {0, 0, 0}} rv = <optimized out> qmperr = 0x7fcd341c1870 "" __FUNCTION__ = "virQEMUCapsNewForBinaryInternal" #7 0x00007fcd404a3a73 in virQEMUCapsNewForBinary (runGid=<optimized out>, runUid=<optimized out>, cacheDir=<optimized out>, libDir=<optimized out>, binary=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha") at qemu/qemu_capabilities.c:3871 No locals. #8 virQEMUCapsCacheLookup (cache=cache@entry=0x7fcd341c9000, binary=0x7fcd34016cb0 "/usr/bin/qemu-system-alpha") at qemu/qemu_capabilities.c:3986 ret = 0x0 __func__ = "virQEMUCapsCacheLookup" #9 0x00007fcd404a3d22 in virQEMUCapsInitGuest (guestarch=VIR_ARCH_ALPHA, hostarch=VIR_ARCH_X86_64, cache=0x7fcd341c9000, caps=0x7fcd341a9980) at qemu/qemu_capabilities.c:824 qemubinCaps = 0x0 x86_32on64_kvm = <optimized out> ppc64_kvm = <optimized out> kvmbin = 0x0 ret = -1 i = <optimized out> binary = 0x7fcd34016cb0 "/usr/bin/qemu-system-alpha" kvmbinCaps = 0x0 native_kvm = <optimized out> arm_32on64_kvm = <optimized out> #10 virQEMUCapsInit (cache=0x7fcd341c9000) at qemu/qemu_capabilities.c:1109 caps = 0x7fcd341a9980 i = 1 hostarch = VIR_ARCH_X86_64 __func__ = "virQEMUCapsInit" #11 0x00007fcd404def20 in virQEMUDriverCreateCapabilities (driver=driver@entry=0x7fcd34342370) at qemu/qemu_conf.c:766 i = <optimized out> j = <optimized out> caps = <optimized out> sec_managers = 0x0 doi = <optimized out> model = <optimized out> lbl = <optimized out> type = <optimized out> cfg = 0x7fcd3448cbb0 virtTypes = {3, 1} __FUNCTION__ = "virQEMUDriverCreateCapabilities" __func__ = "virQEMUDriverCreateCapabilities" #12 0x00007fcd4051fef3 in qemuStateInitialize (privileged=true, callback=<optimized out>, opaque=<optimized out>) at qemu/qemu_driver.c:844 driverConf = 0x0 conn = 0x0 cfg = 0x7fcd3448cbb0 run_uid = <optimized out> run_gid = <optimized out> hugepagePath = 0x0 i = <optimized out> __FUNCTION__ = "qemuStateInitialize" #13 0x00007fcd6f1789af in virStateInitialize (privileged=<optimized out>, callback=0x55f56a9b3180 <daemonInhibitCallback>, opaque=0x55f56be1cf00) at libvirt.c:770 i = 9 __func__ = "virStateInitialize" #14 0x000055f56a9b31db in daemonRunStateInit (opaque=0x55f56be1cf00) at libvirtd.c:959 dmn = 0x55f56be1cf00 sysident = 0x7fcd34000910 __func__ = "daemonRunStateInit" #15 0x00007fcd6f0d98f2 in virThreadHelper (data=<optimized out>) at util/virthread.c:206 args = 0x0 local = {func = 0x55f56a9b31a0 <daemonRunStateInit>, funcName = 0x55f56a9f28d3 "daemonRunStateInit", worker = false, opaque = 0x55f56be1cf00} #16 0x00007fcd6b7766ca in start_thread (arg=0x7fcd3bf18700) at pthread_create.c:333 __res = <optimized out> pd = 0x7fcd3bf18700 now = <optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140519450707712, -3574063505887647860, 0, 140732281962543, 140519450708416, 140519450707712, 3601779982174594956, 3601954753778231180}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <optimized out> pagesize_m1 = <optimized out> sp = <optimized out> freesize = <optimized out> __PRETTY_FUNCTION__ = "start_thread" #17 0x00007fcd6b4b0f7f in clone () at .../sysdeps/unix/sysv/linux/x86_64/clone.S:105 No locals.
[...]
On 06/02/2017 09:53 AM, Michael C. Cambria wrote:
On 06/02/2017 09:43 AM, Martin Kletzander wrote:
[adding back the ML, you probably hit reply instead of reply-all, this way other people might help if they know more]
On Fri, Jun 02, 2017 at 08:10:01AM -0400, Michael C. Cambria wrote:
Hi,
libvirtd never seems to get notified that there is work to do. journalct -f indicated that nothing was logged when connections were attempted via virsh.
I also tried 'LIBVIRT_DEBUG=1 libvirtd --verbose' and once startup finished, there were no more log entries even though virsh attempts were made.
That's because it gets overridden by the configuration files. This might be a bug, but it's not related to what's happening.
"ps ax" shows about a dozen "qemu-system-alpha" processes. I don't know if it matters but I didn't expect to see this. I didn't intentionally configure alpha emulations (assuming that's what it is) and certainly don't want to waste resources having it running.
Libvirt caches the capabilities of the emulators it can find in your system in order not to waste resources. These processes are expected to go away after they reply with all libvirt asks them for. However, it seems like the initialization cannot be completed precisely due to the fact that these processes don't communicate.
There might be some details about qemu-system-alpha that are different when compared to, e.g. qemu-system-x86 and libvirt is not (yet) adapted to them, but I installed that emulator and libvirt daemon runs as usual. It looks like a problem in QEMU. Could you, as a workaround, try uninstalling that qemu binary from your system and restarting the service?
With qemu-system-alpha gone, I now see qemu-system-arm. With all qemu-system-* removed (using dnf remove) and stopping, then starting libvirtd, I still see qemu-system-arm even though the executable doesn't exist: # ls -al /usr/bin | grep qemu-system -rwxr-xr-x. 1 root root 9993416 Apr 13 21:10 qemu-system-i386 -rwxr-xr-x. 1 root root 10036032 Apr 13 21:10 qemu-system-x86_64 # systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 09:12:19 EDT; 8min ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 5965 (libvirtd) Tasks: 23 (limit: 4915) Memory: 128.2M CPU: 411ms CGroup: /system.slice/libvirtd.service ├─1537 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─1638 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─5965 /usr/sbin/libvirtd ├─5999 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server, └─6001 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server, Jun 03 09:12:19 example.com systemd[1]: Starting Virtualization daemon... Jun 03 09:12:19 example.com systemd[1]: Started Virtualization daemon.
Also, what versions of libvirt and qemu do you have installed?
# LIBVIRT_DEBUG=1 libvirtd --verbose 2017-06-02 00:16:30.317+0000: 18088: info : libvirt version: 2.2.1, package: 1.fc25 (Fedora Project, 2017-05-10-22:06:21, buildvm-29.phx2.fedoraproject.org)
I'll check on qemu as soon as I can get to the machine. The version should be the latest one gets via 'dnf update' on fedora 25
# /usr/sbin/libvirtd --version /usr/sbin/libvirtd (libvirt) 2.2.1 # qemu-x86_64 --version qemu-x86_64 version 2.7.1(qemu-2.7.1-6.fc25), Copyright (c) 2003-2016 Fabrice Bellard and the QEMU Project developers [ gdb output deleted]
On Sat, Jun 03, 2017 at 09:22:58AM -0400, Michael C Cambria wrote:
On 06/02/2017 09:53 AM, Michael C. Cambria wrote:
On 06/02/2017 09:43 AM, Martin Kletzander wrote:
[adding back the ML, you probably hit reply instead of reply-all, this way other people might help if they know more]
On Fri, Jun 02, 2017 at 08:10:01AM -0400, Michael C. Cambria wrote:
Hi,
libvirtd never seems to get notified that there is work to do. journalct -f indicated that nothing was logged when connections were attempted via virsh.
I also tried 'LIBVIRT_DEBUG=1 libvirtd --verbose' and once startup finished, there were no more log entries even though virsh attempts were made.
That's because it gets overridden by the configuration files. This might be a bug, but it's not related to what's happening.
"ps ax" shows about a dozen "qemu-system-alpha" processes. I don't know if it matters but I didn't expect to see this. I didn't intentionally configure alpha emulations (assuming that's what it is) and certainly don't want to waste resources having it running.
Libvirt caches the capabilities of the emulators it can find in your system in order not to waste resources. These processes are expected to go away after they reply with all libvirt asks them for. However, it seems like the initialization cannot be completed precisely due to the fact that these processes don't communicate.
There might be some details about qemu-system-alpha that are different when compared to, e.g. qemu-system-x86 and libvirt is not (yet) adapted to them, but I installed that emulator and libvirt daemon runs as usual. It looks like a problem in QEMU. Could you, as a workaround, try uninstalling that qemu binary from your system and restarting the service?
With qemu-system-alpha gone, I now see qemu-system-arm. With all qemu-system-* removed (using dnf remove) and stopping, then starting libvirtd, I still see qemu-system-arm even though the executable doesn't exist:
# ls -al /usr/bin | grep qemu-system -rwxr-xr-x. 1 root root 9993416 Apr 13 21:10 qemu-system-i386 -rwxr-xr-x. 1 root root 10036032 Apr 13 21:10 qemu-system-x86_64 # systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 09:12:19 EDT; 8min ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 5965 (libvirtd) Tasks: 23 (limit: 4915) Memory: 128.2M CPU: 411ms CGroup: /system.slice/libvirtd.service ├─1537 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─1638 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─5965 /usr/sbin/libvirtd ├─5999 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server, └─6001 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,
Jun 03 09:12:19 example.com systemd[1]: Starting Virtualization daemon... Jun 03 09:12:19 example.com systemd[1]: Started Virtualization daemon.
Those look like leftovers from the previous run. I have no idea why they keep running, probably the same bug why they are not responding. Would you mind trying one more thing: Stopping the service, killing all these processes, and then starting it? Let's leave the QEMU issue on a side until we figure this out first, then we can focus on the second issue. I must say this is quite bizarre.
Also, what versions of libvirt and qemu do you have installed?
# LIBVIRT_DEBUG=1 libvirtd --verbose 2017-06-02 00:16:30.317+0000: 18088: info : libvirt version: 2.2.1, package: 1.fc25 (Fedora Project, 2017-05-10-22:06:21, buildvm-29.phx2.fedoraproject.org)
I'll check on qemu as soon as I can get to the machine. The version should be the latest one gets via 'dnf update' on fedora 25
# /usr/sbin/libvirtd --version /usr/sbin/libvirtd (libvirt) 2.2.1 # qemu-x86_64 --version qemu-x86_64 version 2.7.1(qemu-2.7.1-6.fc25), Copyright (c) 2003-2016 Fabrice Bellard and the QEMU Project developers
[ gdb output deleted]
On 06/03/2017 04:22 PM, Martin Kletzander wrote:
On Sat, Jun 03, 2017 at 09:22:58AM -0400, Michael C Cambria wrote:
On 06/02/2017 09:53 AM, Michael C. Cambria wrote:
On 06/02/2017 09:43 AM, Martin Kletzander wrote:
[adding back the ML, you probably hit reply instead of reply-all, this way other people might help if they know more]
On Fri, Jun 02, 2017 at 08:10:01AM -0400, Michael C. Cambria wrote:
Hi,
libvirtd never seems to get notified that there is work to do. journalct -f indicated that nothing was logged when connections were attempted via virsh.
I also tried 'LIBVIRT_DEBUG=1 libvirtd --verbose' and once startup finished, there were no more log entries even though virsh attempts were made.
That's because it gets overridden by the configuration files. This might be a bug, but it's not related to what's happening.
"ps ax" shows about a dozen "qemu-system-alpha" processes. I don't know if it matters but I didn't expect to see this. I didn't intentionally configure alpha emulations (assuming that's what it is) and certainly don't want to waste resources having it running.
Libvirt caches the capabilities of the emulators it can find in your system in order not to waste resources. These processes are expected to go away after they reply with all libvirt asks them for. However, it seems like the initialization cannot be completed precisely due to the fact that these processes don't communicate.
There might be some details about qemu-system-alpha that are different when compared to, e.g. qemu-system-x86 and libvirt is not (yet) adapted to them, but I installed that emulator and libvirt daemon runs as usual. It looks like a problem in QEMU. Could you, as a workaround, try uninstalling that qemu binary from your system and restarting the service?
With qemu-system-alpha gone, I now see qemu-system-arm. With all qemu-system-* removed (using dnf remove) and stopping, then starting libvirtd, I still see qemu-system-arm even though the executable doesn't exist:
# ls -al /usr/bin | grep qemu-system -rwxr-xr-x. 1 root root 9993416 Apr 13 21:10 qemu-system-i386 -rwxr-xr-x. 1 root root 10036032 Apr 13 21:10 qemu-system-x86_64 # systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 09:12:19 EDT; 8min ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 5965 (libvirtd) Tasks: 23 (limit: 4915) Memory: 128.2M CPU: 411ms CGroup: /system.slice/libvirtd.service ├─1537 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─1638 /usr/bin/qemu-system-arm -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,n ├─5965 /usr/sbin/libvirtd ├─5999 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server, └─6001 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,
Jun 03 09:12:19 example.com systemd[1]: Starting Virtualization daemon... Jun 03 09:12:19 example.com systemd[1]: Started Virtualization daemon.
Those look like leftovers from the previous run. I have no idea why they keep running, probably the same bug why they are not responding. I dnf remove'ed every qemu-system-* in /usr/bin that dnf allowed me to. The only things are:
$ ls -al /usr/bin | grep qemu-system -rwxr-xr-x. 1 root root 9993416 Apr 13 21:10 qemu-system-i386 -rwxr-xr-x. 1 root root 10036032 Apr 13 21:10 qemu-system-x86_64 $ Is there a way to remove them? I still have the original problem, though at least arm and alpha don't show up. $ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 16:59:40 EDT; 7min ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 1200 (libvirtd) Tasks: 20 (limit: 4915) Memory: 101.4M CPU: 361ms CGroup: /system.slice/libvirtd.service ├─1200 /usr/sbin/libvirtd ├─1481 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. └─1658 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. Jun 03 16:59:32 eastie.fid4.com systemd[1]: Starting Virtualization daemon... Jun 03 16:59:40 eastie.fid4.com systemd[1]: Started Virtualization daemon. $
Would you mind trying one more thing: Stopping the service, killing all these processes, and then starting it? Let's leave the QEMU issue on a side until we figure this out first, then we can focus on the second issue. I must say this is quite bizarre.
As requested... $ sudo systemctl stop libvirtd.service $ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: inactive (dead) since Sat 2017-06-03 17:09:16 EDT; 1s ago Docs: man:libvirtd(8) http://libvirt.org Process: 1200 ExecStart=/usr/sbin/libvirtd $LIBVIRTD_ARGS (code=exited, status=0/SUCCESS) Main PID: 1200 (code=exited, status=0/SUCCESS) Tasks: 3 (limit: 4915) Memory: 92.4M CPU: 386ms CGroup: /system.slice/libvirtd.service ├─1481 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. └─1658 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. Jun 03 16:59:32 exampl.com systemd[1]: Starting Virtualization daemon... Jun 03 16:59:40 example.com systemd[1]: Started Virtualization daemon. Jun 03 17:09:16 example.com systemd[1]: Stopping Virtualization daemon... Jun 03 17:09:16 example.com systemd[1]: Stopped Virtualization daemon. $ ps ax | grep virt 1481 ? Sl 0:00 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 1658 ? S 0:00 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 3111 pts/1 S+ 0:00 grep --color=auto virt $ sudo kill -9 1481 $ sudo kill -9 1658 $ ps ax | grep virt 3120 pts/1 S+ 0:00 grep --color=auto virt $ sudo systemctl start libvirtd.service $ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:09:52 EDT; 4s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3124 (libvirtd) Tasks: 20 (limit: 4915) Memory: 103.4M CPU: 232ms CGroup: /system.slice/libvirtd.service ├─3124 /usr/sbin/libvirtd ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. └─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. Jun 03 17:09:52 example.com systemd[1]: Starting Virtualization daemon... Jun 03 17:09:52 example.com systemd[1]: Started Virtualization daemon. $ ps ax | grep virt 3124 ? Ssl 0:00 /usr/sbin/libvirtd 3158 ? Sl 0:00 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 3160 ? S 0:00 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 3166 pts/1 S+ 0:00 grep --color=auto virt $ Problem still exists. I also tried stopping libvirtd, renaming both qemu-system-i386 and qemu-system-x86_64, start libvirtd. Things get further along; dnsmasq log messages show up. $ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:14:25 EDT; 7s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3246 (libvirtd) Tasks: 21 (limit: 4915) Memory: 107.4M CPU: 300ms CGroup: /system.slice/libvirtd.service ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3246 /usr/sbin/libvirtd ├─3457 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper └─3458 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper Jun 03 17:14:25 example.com libvirtd[3246]: Failed to probe capabilities for /usr/bin/qemu-kvm: internal error: Child process (LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-k Jun 03 17:14:26 example.com dnsmasq[3457]: started, version 2.76 cachesize 150 Jun 03 17:14:26 example.com dnsmasq[3457]: compile time options: IPv6 GNU-getopt DBus no-i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, IP range 192.168.122.2 -- 192.168.122.254, lease time 1h Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, sockets bound exclusively to interface virbr0 Jun 03 17:14:26 example.com dnsmasq[3457]: reading /etc/resolv.conf Jun 03 17:14:26 example.com dnsmasq[3457]: using nameserver 172.16.8.1#53 Jun 03 17:14:26 example.com dnsmasq[3457]: read /etc/hosts - 2 addresses Jun 03 17:14:26 example.com dnsmasq[3457]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: read /var/lib/libvirt/dnsmasq/default.hostsfile $ sudo virsh list Id Name State ---------------------------------------------------- $ As you can see, none of my vm's show up. I'm guessing the "qemu-kvm: internal error" results from renaming qemu-system-x86_64?? Could something else (selinux?) be involved?
Also, what versions of libvirt and qemu do you have installed?
# LIBVIRT_DEBUG=1 libvirtd --verbose 2017-06-02 00:16:30.317+0000: 18088: info : libvirt version: 2.2.1, package: 1.fc25 (Fedora Project, 2017-05-10-22:06:21, buildvm-29.phx2.fedoraproject.org)
I'll check on qemu as soon as I can get to the machine. The version should be the latest one gets via 'dnf update' on fedora 25
# /usr/sbin/libvirtd --version /usr/sbin/libvirtd (libvirt) 2.2.1 # qemu-x86_64 --version qemu-x86_64 version 2.7.1(qemu-2.7.1-6.fc25), Copyright (c) 2003-2016 Fabrice Bellard and the QEMU Project developers
[ gdb output deleted]
On Sat, Jun 03, 2017 at 05:20:47PM -0400, Michael C Cambria wrote:
I also tried stopping libvirtd, renaming both qemu-system-i386 and qemu-system-x86_64, start libvirtd. Things get further along; dnsmasq log messages show up.
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:14:25 EDT; 7s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3246 (libvirtd) Tasks: 21 (limit: 4915) Memory: 107.4M CPU: 300ms CGroup: /system.slice/libvirtd.service ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3246 /usr/sbin/libvirtd ├─3457 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper └─3458 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper
Jun 03 17:14:25 example.com libvirtd[3246]: Failed to probe capabilities for /usr/bin/qemu-kvm: internal error: Child process (LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-k Jun 03 17:14:26 example.com dnsmasq[3457]: started, version 2.76 cachesize 150 Jun 03 17:14:26 example.com dnsmasq[3457]: compile time options: IPv6 GNU-getopt DBus no-i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, IP range 192.168.122.2 -- 192.168.122.254, lease time 1h Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, sockets bound exclusively to interface virbr0 Jun 03 17:14:26 example.com dnsmasq[3457]: reading /etc/resolv.conf Jun 03 17:14:26 example.com dnsmasq[3457]: using nameserver 172.16.8.1#53 Jun 03 17:14:26 example.com dnsmasq[3457]: read /etc/hosts - 2 addresses Jun 03 17:14:26 example.com dnsmasq[3457]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: read /var/lib/libvirt/dnsmasq/default.hostsfile
$ sudo virsh list Id Name State ----------------------------------------------------
$
As you can see, none of my vm's show up. I'm guessing the "qemu-kvm: internal error" results from renaming qemu-system-x86_64??
Yeah, feel free to move them back.
Could something else (selinux?) be involved?
It should not. Now we know it is QEMU, but becuase it is disrupting libvirt in its initialization phase, it looks like nothing works. You could grab a backtrace of the qemu process and try on qemu-devel ML. Also, if you want to make sure (or see after what command gets stuck), you can enable debug logs for libvirt into some file and then grep that for QEMU_MONITOR_ and you'll see. [1] http://wiki.libvirt.org/page/DebugLogs [2] I'm not sure about the whole thing to look for, but this is enough)
On 06/03/2017 05:47 PM, Martin Kletzander wrote:
On Sat, Jun 03, 2017 at 05:20:47PM -0400, Michael C Cambria wrote:
I also tried stopping libvirtd, renaming both qemu-system-i386 and qemu-system-x86_64, start libvirtd. Things get further along; dnsmasq log messages show up.
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:14:25 EDT; 7s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3246 (libvirtd) Tasks: 21 (limit: 4915) Memory: 107.4M CPU: 300ms CGroup: /system.slice/libvirtd.service ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3246 /usr/sbin/libvirtd ├─3457 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper └─3458 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper
Jun 03 17:14:25 example.com libvirtd[3246]: Failed to probe capabilities for /usr/bin/qemu-kvm: internal error: Child process (LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-k Jun 03 17:14:26 example.com dnsmasq[3457]: started, version 2.76 cachesize 150 Jun 03 17:14:26 example.com dnsmasq[3457]: compile time options: IPv6 GNU-getopt DBus no-i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, IP range 192.168.122.2 -- 192.168.122.254, lease time 1h Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, sockets bound exclusively to interface virbr0 Jun 03 17:14:26 example.com dnsmasq[3457]: reading /etc/resolv.conf Jun 03 17:14:26 example.com dnsmasq[3457]: using nameserver 172.16.8.1#53 Jun 03 17:14:26 example.com dnsmasq[3457]: read /etc/hosts - 2 addresses Jun 03 17:14:26 example.com dnsmasq[3457]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: read /var/lib/libvirt/dnsmasq/default.hostsfile
$ sudo virsh list Id Name State ----------------------------------------------------
$
As you can see, none of my vm's show up. I'm guessing the "qemu-kvm: internal error" results from renaming qemu-system-x86_64??
Yeah, feel free to move them back.
Could something else (selinux?) be involved?
It should not. Now we know it is QEMU, but becuase it is disrupting libvirt in its initialization phase, it looks like nothing works.
You could grab a backtrace of the qemu process and try on qemu-devel ML. Also, if you want to make sure (or see after what command gets stuck), you can enable debug logs for libvirt into some file and then grep that for QEMU_MONITOR_ and you'll see.
What should I be looking for? I see QEMU_MONITOR_ in the source (https://github.com/libvirt/libvirt/tree/v2.2-maint) but never see it in the logs. # pwd /etc/libvirt # diff libvirtd.conf libvirtd.conf.hold 1,4d0 < log_level = 1 < log_filters="3:remote 4:event 3:json 3:rpc" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # # ls -al /var/log/libvirt/libvirtd.log ls: cannot access '/var/log/libvirt/libvirtd.log': No such file or directory # systemctl restart libvirtd.service # ls -al /var/log/libvirt/libvirtd.log -rw-------. 1 root root 801113 Jun 3 19:56 /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_ /var/log/libvirt/libvirtd.log # grep QEMU /var/log/libvirt/libvirtd.log 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:684 : driver=0x7fa3f6c2e0e0 name=QEMU 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:695 : registering QEMU as driver 9 2017-06-04 00:04:14.302+0000: 3379: debug : virStateInitialize:769 : Running global init for QEMU state driver 2017-06-04 00:04:14.303+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d0122250 classname=virQEMUDriverConfig 2017-06-04 00:04:14.305+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580f40 (selinux) virtDriver=QEMU flags=a 2017-06-04 00:04:14.305+0000: 3379: debug : virSecuritySELinuxInitialize:561 : SELinuxInitialize QEMU 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:516 : Loaded domain context 'system_u:system_r:svirt_t:s0', alt domain context 'system_u:system_r:svirt_tcg_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:537 : Loaded file context 'system_u:object_r:svirt_image_t:s0', content context 'system_u:object_r:virt_content_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580cc0 (stack) virtDriver=QEMU flags=a 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580de0 (dac) virtDriver=QEMU flags=a 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml' for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 [root@eastie libvirt]# Here are the last few lines of that log file: 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virFileMakePathHelper:2837 : path=/var/cache/libvirt/qemu/capabilities mode=0777 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml' for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 2017-06-04 00:04:14.313+0000: 3379: debug : virCommandRunAsync:2434 : About to run LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-system-alpha -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 21 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 23 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 25 2017-06-04 00:04:14.314+0000: 3379: debug : virCommandRunAsync:2437 : Command result 0, with PID 3405 # I changed the log filters to: log_filters="1:remote 1:event 1:json 1:rpc" Tried again, QEMU_MONITOR_ isn't in the log. Thanks again for your help.
[1] http://wiki.libvirt.org/page/DebugLogs [2] I'm not sure about the whole thing to look for, but this is enough)
On Sat, Jun 03, 2017 at 08:27:08PM -0400, Michael C Cambria wrote:
On 06/03/2017 05:47 PM, Martin Kletzander wrote:
On Sat, Jun 03, 2017 at 05:20:47PM -0400, Michael C Cambria wrote:
I also tried stopping libvirtd, renaming both qemu-system-i386 and qemu-system-x86_64, start libvirtd. Things get further along; dnsmasq log messages show up.
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:14:25 EDT; 7s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3246 (libvirtd) Tasks: 21 (limit: 4915) Memory: 107.4M CPU: 300ms CGroup: /system.slice/libvirtd.service ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3246 /usr/sbin/libvirtd ├─3457 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper └─3458 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper
Jun 03 17:14:25 example.com libvirtd[3246]: Failed to probe capabilities for /usr/bin/qemu-kvm: internal error: Child process (LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-k Jun 03 17:14:26 example.com dnsmasq[3457]: started, version 2.76 cachesize 150 Jun 03 17:14:26 example.com dnsmasq[3457]: compile time options: IPv6 GNU-getopt DBus no-i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, IP range 192.168.122.2 -- 192.168.122.254, lease time 1h Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, sockets bound exclusively to interface virbr0 Jun 03 17:14:26 example.com dnsmasq[3457]: reading /etc/resolv.conf Jun 03 17:14:26 example.com dnsmasq[3457]: using nameserver 172.16.8.1#53 Jun 03 17:14:26 example.com dnsmasq[3457]: read /etc/hosts - 2 addresses Jun 03 17:14:26 example.com dnsmasq[3457]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: read /var/lib/libvirt/dnsmasq/default.hostsfile
$ sudo virsh list Id Name State ----------------------------------------------------
$
As you can see, none of my vm's show up. I'm guessing the "qemu-kvm: internal error" results from renaming qemu-system-x86_64??
Yeah, feel free to move them back.
Could something else (selinux?) be involved?
It should not. Now we know it is QEMU, but becuase it is disrupting libvirt in its initialization phase, it looks like nothing works.
You could grab a backtrace of the qemu process and try on qemu-devel ML. Also, if you want to make sure (or see after what command gets stuck), you can enable debug logs for libvirt into some file and then grep that for QEMU_MONITOR_ and you'll see.
What should I be looking for? I see QEMU_MONITOR_ in the source (https://github.com/libvirt/libvirt/tree/v2.2-maint) but never see it in the logs.
# pwd /etc/libvirt # diff libvirtd.conf libvirtd.conf.hold 1,4d0 < log_level = 1 < log_filters="3:remote 4:event 3:json 3:rpc" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # # ls -al /var/log/libvirt/libvirtd.log ls: cannot access '/var/log/libvirt/libvirtd.log': No such file or directory # systemctl restart libvirtd.service # ls -al /var/log/libvirt/libvirtd.log -rw-------. 1 root root 801113 Jun 3 19:56 /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_ /var/log/libvirt/libvirtd.log # grep QEMU /var/log/libvirt/libvirtd.log 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:684 : driver=0x7fa3f6c2e0e0 name=QEMU 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:695 : registering QEMU as driver 9 2017-06-04 00:04:14.302+0000: 3379: debug : virStateInitialize:769 : Running global init for QEMU state driver 2017-06-04 00:04:14.303+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d0122250 classname=virQEMUDriverConfig 2017-06-04 00:04:14.305+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580f40 (selinux) virtDriver=QEMU flags=a 2017-06-04 00:04:14.305+0000: 3379: debug : virSecuritySELinuxInitialize:561 : SELinuxInitialize QEMU 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:516 : Loaded domain context 'system_u:system_r:svirt_t:s0', alt domain context 'system_u:system_r:svirt_tcg_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:537 : Loaded file context 'system_u:object_r:svirt_image_t:s0', content context 'system_u:object_r:virt_content_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580cc0 (stack) virtDriver=QEMU flags=a 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580de0 (dac) virtDriver=QEMU flags=a 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml' for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 [root@eastie libvirt]#
Here are the last few lines of that log file:
2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virFileMakePathHelper:2837 : path=/var/cache/libvirt/qemu/capabilities mode=0777 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml' for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 2017-06-04 00:04:14.313+0000: 3379: debug : virCommandRunAsync:2434 : About to run LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-system-alpha -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 21 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 23 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 25 2017-06-04 00:04:14.314+0000: 3379: debug : virCommandRunAsync:2437 : Command result 0, with PID 3405 #
I changed the log filters to:
log_filters="1:remote 1:event 1:json 1:rpc"
you can remove this line completely, it just limits some of the messages if there are higher numbers than the log_level.
Tried again, QEMU_MONITOR_ isn't in the log.
Now this is weird. I would try a few more things, but it's lengthy explaining them in the mail. Plus we would be dealing with QEMU issues at this point. But what baffles me the most is, how come there aren't more people having the same problem? Anyway, if you'd like to try some more things, feel free to catch me on IRC, although I probably won't be available during this weekend.
Thanks again for your help.
Not at all. I didn't help much, did I? :)
[1] http://wiki.libvirt.org/page/DebugLogs [2] I'm not sure about the whole thing to look for, but this is enough)
_______________________________________________ libvirt-users mailing list libvirt-users@redhat.com https://www.redhat.com/mailman/listinfo/libvirt-users
On 06/04/2017 05:46 AM, Martin Kletzander wrote:
On Sat, Jun 03, 2017 at 08:27:08PM -0400, Michael C Cambria wrote:
On 06/03/2017 05:47 PM, Martin Kletzander wrote:
On Sat, Jun 03, 2017 at 05:20:47PM -0400, Michael C Cambria wrote:
I also tried stopping libvirtd, renaming both qemu-system-i386 and qemu-system-x86_64, start libvirtd. Things get further along; dnsmasq log messages show up.
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Sat 2017-06-03 17:14:25 EDT; 7s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 3246 (libvirtd) Tasks: 21 (limit: 4915) Memory: 107.4M CPU: 300ms CGroup: /system.slice/libvirtd.service ├─3158 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3160 /usr/bin/qemu-system-i386 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities. ├─3246 /usr/sbin/libvirtd ├─3457 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper └─3458 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/libexec/libvirt_leaseshelper
Jun 03 17:14:25 example.com libvirtd[3246]: Failed to probe capabilities for /usr/bin/qemu-kvm: internal error: Child process (LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-k Jun 03 17:14:26 example.com dnsmasq[3457]: started, version 2.76 cachesize 150 Jun 03 17:14:26 example.com dnsmasq[3457]: compile time options: IPv6 GNU-getopt DBus no-i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset auth DNSSEC loop-detect inotify Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, IP range 192.168.122.2 -- 192.168.122.254, lease time 1h Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: DHCP, sockets bound exclusively to interface virbr0 Jun 03 17:14:26 example.com dnsmasq[3457]: reading /etc/resolv.conf Jun 03 17:14:26 example.com dnsmasq[3457]: using nameserver 172.16.8.1#53 Jun 03 17:14:26 example.com dnsmasq[3457]: read /etc/hosts - 2 addresses Jun 03 17:14:26 example.com dnsmasq[3457]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses Jun 03 17:14:26 example.com dnsmasq-dhcp[3457]: read /var/lib/libvirt/dnsmasq/default.hostsfile
$ sudo virsh list Id Name State ----------------------------------------------------
$
As you can see, none of my vm's show up. I'm guessing the "qemu-kvm: internal error" results from renaming qemu-system-x86_64??
Yeah, feel free to move them back.
Could something else (selinux?) be involved?
It should not. Now we know it is QEMU, but becuase it is disrupting libvirt in its initialization phase, it looks like nothing works.
You could grab a backtrace of the qemu process and try on qemu-devel ML. Also, if you want to make sure (or see after what command gets stuck), you can enable debug logs for libvirt into some file and then grep that for QEMU_MONITOR_ and you'll see.
What should I be looking for? I see QEMU_MONITOR_ in the source (https://github.com/libvirt/libvirt/tree/v2.2-maint) but never see it in the logs.
# pwd /etc/libvirt # diff libvirtd.conf libvirtd.conf.hold 1,4d0 < log_level = 1 < log_filters="3:remote 4:event 3:json 3:rpc" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # # ls -al /var/log/libvirt/libvirtd.log ls: cannot access '/var/log/libvirt/libvirtd.log': No such file or directory # systemctl restart libvirtd.service # ls -al /var/log/libvirt/libvirtd.log -rw-------. 1 root root 801113 Jun 3 19:56 /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_MONITOR_ /var/log/libvirt/libvirtd.log # grep QEMU_ /var/log/libvirt/libvirtd.log # grep QEMU /var/log/libvirt/libvirtd.log 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:684 : driver=0x7fa3f6c2e0e0 name=QEMU 2017-06-04 00:04:13.825+0000: 3363: debug : virRegisterConnectDriver:695 : registering QEMU as driver 9 2017-06-04 00:04:14.302+0000: 3379: debug : virStateInitialize:769 : Running global init for QEMU state driver 2017-06-04 00:04:14.303+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d0122250 classname=virQEMUDriverConfig 2017-06-04 00:04:14.305+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580f40 (selinux) virtDriver=QEMU flags=a 2017-06-04 00:04:14.305+0000: 3379: debug : virSecuritySELinuxInitialize:561 : SELinuxInitialize QEMU 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:516 : Loaded domain context 'system_u:system_r:svirt_t:s0', alt domain context 'system_u:system_r:svirt_tcg_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecuritySELinuxQEMUInitialize:537 : Loaded file context 'system_u:object_r:svirt_image_t:s0', content context 'system_u:object_r:virt_content_t:s0' 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580cc0 (stack) virtDriver=QEMU flags=a 2017-06-04 00:04:14.307+0000: 3379: debug : virSecurityManagerNewDriver:86 : drv=0x7fa44d580de0 (dac) virtDriver=QEMU flags=a 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml'
for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 [root@eastie libvirt]#
Here are the last few lines of that log file:
2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsCacheLookup:3985 : Creating capabilities for /usr/bin/qemu-system-alpha 2017-06-04 00:04:14.313+0000: 3379: info : virObjectNew:202 : OBJECT_NEW: obj=0x7fa3d010bb00 classname=virQEMUCaps 2017-06-04 00:04:14.313+0000: 3379: debug : virFileMakePathHelper:2837 : path=/var/cache/libvirt/qemu/capabilities mode=0777 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitCached:3292 : No cached capabilities '/var/cache/libvirt/qemu/capabilities/4b21437223cbdecdb4e776fe0bb40302a421554fc350bfbb986908518557721d.xml'
for '/usr/bin/qemu-system-alpha' 2017-06-04 00:04:14.313+0000: 3379: debug : virQEMUCapsInitQMP:3673 : Try to get caps via QMP qemuCaps=0x7fa3d010bb00 2017-06-04 00:04:14.313+0000: 3379: debug : virCommandRunAsync:2434 : About to run LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin /usr/bin/qemu-system-alpha -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 21 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 23 2017-06-04 00:04:14.314+0000: 3379: debug : virFileClose:102 : Closed fd 25 2017-06-04 00:04:14.314+0000: 3379: debug : virCommandRunAsync:2437 : Command result 0, with PID 3405 #
I changed the log filters to:
log_filters="1:remote 1:event 1:json 1:rpc"
you can remove this line completely, it just limits some of the messages if there are higher numbers than the log_level.
Tried again, QEMU_MONITOR_ isn't in the log.
Now this is weird. I would try a few more things, but it's lengthy explaining them in the mail. Plus we would be dealing with QEMU issues at this point. But what baffles me the most is, how come there aren't more people having the same problem?
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25. Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got? I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin) Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before: # virsh list Id Name State ---------------------------------------------------- # virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes # VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group: $ sudo systemctl stop libvirtd.service $ sudo ip addr show virbr0 7: virbr0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN group default qlen 1000 link/ether 52:54:00:5b:f7:0b brd ff:ff:ff:ff:ff:ff inet 192.168.122.1/24 brd 192.168.122.255 scope global virbr0 valid_lft forever preferred_lft forever $ sudo ip link del virbr0 $ sudo ip addr show virbr0 Device "virbr0" does not exist. $ sudo systemctl start libvirtd.service $ sudo ip addr show virbr0 9: virbr0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN group default qlen 1000 link/ether 52:54:00:5b:f7:0b brd ff:ff:ff:ff:ff:ff inet 192.168.122.1/24 brd 192.168.122.255 scope global virbr0 valid_lft forever preferred_lft forever $
Anyway, if you'd like to try some more things, feel free to catch me on IRC, although I probably won't be available during this weekend.
Not a problem. I appreciate your help.
Thanks again for your help.
Not at all. I didn't help much, did I? :)
[1] http://wiki.libvirt.org/page/DebugLogs [2] I'm not sure about the whole thing to look for, but this is enough)
_______________________________________________ libvirt-users mailing list libvirt-users@redhat.com https://www.redhat.com/mailman/listinfo/libvirt-users
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator. You can try installing from source, but putting it in /usr/bin, you can also remove that installation, put back the one from the package and try running: { for i in qmp_capabilities query-commands quit; do echo "{'execute':'$i'}"; done } | qemu-system-x86_64 -nographic -nodefaults -no-user-config -M none -qmp stdio And see whether the QEMU process quits, what it outputs and if it gets stuck, you can attach gdb and see what it's waiting for. Or maybe try running it with strace. You can also do a thing I used to do a lot. You can rename /usr/bin/qemu-system-x86_64 (for example) and create a script with that filename that for example execs as qemu in strace with the output of strace put in some file, or similar. I can't think of anything else for now, sorry. Have a nice day, Martin P.S.: If qemu gets stuc even with that easy command, then it's definitely its fault.
On 06/05/2017 10:46 AM, Martin Kletzander wrote:
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
"rpm -aV" didn't turn up anything obvious: S.5....T. c /etc/libvirt/libvirtd.conf was modified for logging: # diff libvirtd.conf libvirtd.conf.rpmnew 1,4d0 < log_level = 1 < log_filters="1:remote 1:event 1:json 1:rpc 1:qemu" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # #
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Yes I'm sure. I wish that was all it was <g>
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator.
You can try installing from source, but putting it in /usr/bin,
I put qemu-system-x86_64 and qemu-x86_64 in /usr/bin as requested. No luck. It seems /usr/local/bin/qemu-xxx is found (see CGroup: output) $ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Mon 2017-06-05 18:21:20 EDT; 3s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 7076 (libvirtd) Tasks: 19 (limit: 4915) Memory: 124.7M CPU: 3.649s CGroup: /system.slice/libvirtd.service ├─7076 /usr/sbin/libvirtd └─7208 /usr/local/bin/qemu-system-sh4eb -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabi $ sudo virsh list --all Id Name State ---------------------------------------------------- $ sudo virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes $
you can also remove that installation, put back the one from the package and try running:
{ for i in qmp_capabilities query-commands quit; do echo "{'execute':'$i'}"; done } | qemu-system-x86_64 -nographic -nodefaults -no-user-config -M none -qmp stdio
And see whether the QEMU process quits, what it outputs and if it gets stuck, you can attach gdb and see what it's waiting for. Or maybe try running it with strace.
This completed almost instantly.
You can also do a thing I used to do a lot. You can rename /usr/bin/qemu-system-x86_64 (for example) and create a script with that filename that for example execs as qemu in strace with the output of strace put in some file, or similar. I can't think of anything else for now, sorry.
I'll try this ASAP. First I'll look at all the QEMU_MONITOR_* log entries that contain "error" that I *am* getting with qemu installed from source (in /usr/local/bin/qemu-*) 2017-06-05 23:06:39.884+0000: 15559: info : virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1 2017-06-05 23:06:39.884+0000: 15559: info : virObjectRef:296 : OBJECT_REF: obj=0x7f0a603d33b0 2017-06-05 23:06:39.884+0000: 15559: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f0a603d33b0 buf={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}^M len=120 2017-06-05 23:06:39.884+0000: 15559: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}] 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONValueFromString:1604 : string={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}} 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONParserHandleStartMap:1478 : parser=0x7ffe4440afd0
Have a nice day, Martin
Thank you, you too!
On Mon, Jun 05, 2017 at 07:52:58PM -0400, Michael C Cambria wrote:
On 06/05/2017 10:46 AM, Martin Kletzander wrote:
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
"rpm -aV" didn't turn up anything obvious:
S.5....T. c /etc/libvirt/libvirtd.conf was modified for logging: # diff libvirtd.conf libvirtd.conf.rpmnew 1,4d0 < log_level = 1 < log_filters="1:remote 1:event 1:json 1:rpc 1:qemu" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # #
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Yes I'm sure. I wish that was all it was <g>
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator.
You can try installing from source, but putting it in /usr/bin,
I put qemu-system-x86_64 and qemu-x86_64 in /usr/bin as requested. No luck. It seems /usr/local/bin/qemu-xxx is found (see CGroup: output)
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Mon 2017-06-05 18:21:20 EDT; 3s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 7076 (libvirtd) Tasks: 19 (limit: 4915) Memory: 124.7M CPU: 3.649s CGroup: /system.slice/libvirtd.service ├─7076 /usr/sbin/libvirtd └─7208 /usr/local/bin/qemu-system-sh4eb -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabi
So this is now only with the qemu from source installed on the system?
$ sudo virsh list --all Id Name State ----------------------------------------------------
$ sudo virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
$
you can also remove that installation, put back the one from the package and try running:
{ for i in qmp_capabilities query-commands quit; do echo "{'execute':'$i'}"; done } | qemu-system-x86_64 -nographic -nodefaults -no-user-config -M none -qmp stdio
And see whether the QEMU process quits, what it outputs and if it gets stuck, you can attach gdb and see what it's waiting for. Or maybe try running it with strace.
This completed almost instantly.
And that is with the QEMU installed form the package, right?
You can also do a thing I used to do a lot. You can rename /usr/bin/qemu-system-x86_64 (for example) and create a script with that filename that for example execs as qemu in strace with the output of strace put in some file, or similar. I can't think of anything else for now, sorry.
I'll try this ASAP. First I'll look at all the QEMU_MONITOR_* log entries that contain "error" that I *am* getting with qemu installed from source (in /usr/local/bin/qemu-*)
2017-06-05 23:06:39.884+0000: 15559: info : virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1 2017-06-05 23:06:39.884+0000: 15559: info : virObjectRef:296 : OBJECT_REF: obj=0x7f0a603d33b0 2017-06-05 23:06:39.884+0000: 15559: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f0a603d33b0 buf={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}^M len=120
Well, at least QEMU_MONITOR_ messages are showing, finally. The non-x86 machines might be missing lot of commands that libvirt needs. Like 'query-commands' which we need to know which commands we can run (bit of a catch 22 right there). But these should not happen with x86, x86_64, arm, arm64 (or aarch64), and few others. Those are being maintained continuously.
2017-06-05 23:06:39.884+0000: 15559: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}] 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONValueFromString:1604 : string={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}} 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONParserHandleStartMap:1478 : parser=0x7ffe4440afd0
Have a nice day, Martin
Thank you, you too!
_______________________________________________ libvirt-users mailing list libvirt-users@redhat.com https://www.redhat.com/mailman/listinfo/libvirt-users
On 06/06/2017 04:43 AM, Martin Kletzander wrote:
On Mon, Jun 05, 2017 at 07:52:58PM -0400, Michael C Cambria wrote:
On 06/05/2017 10:46 AM, Martin Kletzander wrote:
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
"rpm -aV" didn't turn up anything obvious:
S.5....T. c /etc/libvirt/libvirtd.conf was modified for logging: # diff libvirtd.conf libvirtd.conf.rpmnew 1,4d0 < log_level = 1 < log_filters="1:remote 1:event 1:json 1:rpc 1:qemu" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # #
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Yes I'm sure. I wish that was all it was <g>
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator.
You can try installing from source, but putting it in /usr/bin,
I put qemu-system-x86_64 and qemu-x86_64 in /usr/bin as requested. No luck. It seems /usr/local/bin/qemu-xxx is found (see CGroup: output)
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Mon 2017-06-05 18:21:20 EDT; 3s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 7076 (libvirtd) Tasks: 19 (limit: 4915) Memory: 124.7M CPU: 3.649s CGroup: /system.slice/libvirtd.service ├─7076 /usr/sbin/libvirtd └─7208 /usr/local/bin/qemu-system-sh4eb -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabi
So this is now only with the qemu from source installed on the system?
Correct.
$ sudo virsh list --all Id Name State ----------------------------------------------------
$ sudo virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
$
you can also remove that installation, put back the one from the package and try running:
{ for i in qmp_capabilities query-commands quit; do echo "{'execute':'$i'}"; done } | qemu-system-x86_64 -nographic -nodefaults -no-user-config -M none -qmp stdio
And see whether the QEMU process quits, what it outputs and if it gets stuck, you can attach gdb and see what it's waiting for. Or maybe try running it with strace.
This completed almost instantly.
And that is with the QEMU installed form the package, right?
Correct
You can also do a thing I used to do a lot. You can rename /usr/bin/qemu-system-x86_64 (for example) and create a script with that filename that for example execs as qemu in strace with the output of strace put in some file, or similar. I can't think of anything else for now, sorry.
I'll try this ASAP. First I'll look at all the QEMU_MONITOR_* log entries that contain "error" that I *am* getting with qemu installed from source (in /usr/local/bin/qemu-*)
2017-06-05 23:06:39.884+0000: 15559: info : virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1 2017-06-05 23:06:39.884+0000: 15559: info : virObjectRef:296 : OBJECT_REF: obj=0x7f0a603d33b0 2017-06-05 23:06:39.884+0000: 15559: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f0a603d33b0 buf={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}^M len=120
Well, at least QEMU_MONITOR_ messages are showing, finally. The non-x86 machines might be missing lot of commands that libvirt needs. Like 'query-commands' which we need to know which commands we can run (bit of a catch 22 right there). But these should not happen with x86, x86_64, arm, arm64 (or aarch64), and few others. Those are being maintained continuously.
The messages only show when qemu is "sudo make install" from sources. In case it matters, all my existing VM's are x86_64.
2017-06-05 23:06:39.884+0000: 15559: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}] 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONValueFromString:1604 : string={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}} 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONParserHandleStartMap:1478 : parser=0x7ffe4440afd0
Have a nice day, Martin
Thank you, you too!
_______________________________________________ libvirt-users mailing list libvirt-users@redhat.com https://www.redhat.com/mailman/listinfo/libvirt-users
On Tue, Jun 06, 2017 at 08:17:07AM -0400, Michael C. Cambria wrote:
On 06/06/2017 04:43 AM, Martin Kletzander wrote:
On Mon, Jun 05, 2017 at 07:52:58PM -0400, Michael C Cambria wrote:
On 06/05/2017 10:46 AM, Martin Kletzander wrote:
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
"rpm -aV" didn't turn up anything obvious:
S.5....T. c /etc/libvirt/libvirtd.conf was modified for logging: # diff libvirtd.conf libvirtd.conf.rpmnew 1,4d0 < log_level = 1 < log_filters="1:remote 1:event 1:json 1:rpc 1:qemu" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # #
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Yes I'm sure. I wish that was all it was <g>
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator.
You can try installing from source, but putting it in /usr/bin,
I put qemu-system-x86_64 and qemu-x86_64 in /usr/bin as requested. No luck. It seems /usr/local/bin/qemu-xxx is found (see CGroup: output)
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Mon 2017-06-05 18:21:20 EDT; 3s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 7076 (libvirtd) Tasks: 19 (limit: 4915) Memory: 124.7M CPU: 3.649s CGroup: /system.slice/libvirtd.service ├─7076 /usr/sbin/libvirtd └─7208 /usr/local/bin/qemu-system-sh4eb -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabi
So this is now only with the qemu from source installed on the system?
Correct.
$ sudo virsh list --all Id Name State ----------------------------------------------------
$ sudo virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
$
you can also remove that installation, put back the one from the package and try running:
{ for i in qmp_capabilities query-commands quit; do echo "{'execute':'$i'}"; done } | qemu-system-x86_64 -nographic -nodefaults -no-user-config -M none -qmp stdio
And see whether the QEMU process quits, what it outputs and if it gets stuck, you can attach gdb and see what it's waiting for. Or maybe try running it with strace.
This completed almost instantly.
And that is with the QEMU installed form the package, right?
Correct
You can also do a thing I used to do a lot. You can rename /usr/bin/qemu-system-x86_64 (for example) and create a script with that filename that for example execs as qemu in strace with the output of strace put in some file, or similar. I can't think of anything else for now, sorry.
I'll try this ASAP. First I'll look at all the QEMU_MONITOR_* log entries that contain "error" that I *am* getting with qemu installed from source (in /usr/local/bin/qemu-*)
2017-06-05 23:06:39.884+0000: 15559: info : virEventPollDispatchHandles:506 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1 2017-06-05 23:06:39.884+0000: 15559: info : virObjectRef:296 : OBJECT_REF: obj=0x7f0a603d33b0 2017-06-05 23:06:39.884+0000: 15559: info : qemuMonitorIOProcess:429 : QEMU_MONITOR_IO_PROCESS: mon=0x7f0a603d33b0 buf={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}^M len=120
Well, at least QEMU_MONITOR_ messages are showing, finally. The non-x86 machines might be missing lot of commands that libvirt needs. Like 'query-commands' which we need to know which commands we can run (bit of a catch 22 right there). But these should not happen with x86, x86_64, arm, arm64 (or aarch64), and few others. Those are being maintained continuously.
The messages only show when qemu is "sudo make install" from sources.
And what are they related to? Can you post the full log somewhere and send a link to it? I'll see if there's something usable.
In case it matters, all my existing VM's are x86_64.
2017-06-05 23:06:39.884+0000: 15559: debug : qemuMonitorJSONIOProcessLine:191 : Line [{"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}}] 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONValueFromString:1604 : string={"id": "libvirt-41", "error": {"class": "GenericError", "desc": "this feature or command is not currently supported"}} 2017-06-05 23:06:39.884+0000: 15559: debug : virJSONParserHandleStartMap:1478 : parser=0x7ffe4440afd0
Have a nice day, Martin
Thank you, you too!
_______________________________________________ libvirt-users mailing list libvirt-users@redhat.com https://www.redhat.com/mailman/listinfo/libvirt-users
On 06/06/2017 08:17 AM, Michael C. Cambria wrote:
On 06/06/2017 04:43 AM, Martin Kletzander wrote:
On Mon, Jun 05, 2017 at 07:52:58PM -0400, Michael C Cambria wrote:
On 06/05/2017 10:46 AM, Martin Kletzander wrote:
On Sun, Jun 04, 2017 at 06:42:39PM -0400, Michael C Cambria wrote:
I've upgraded from Fedora 20; probably missed a merge of rpmnew with existing .conf; permission problem, some other mistake along the way to Fedora 25.
Yeah, probably some 'rpm -qV' (or whatever the command to verify all packages is) could help as well.
"rpm -aV" didn't turn up anything obvious:
S.5....T. c /etc/libvirt/libvirtd.conf was modified for logging: # diff libvirtd.conf libvirtd.conf.rpmnew 1,4d0 < log_level = 1 < log_filters="1:remote 1:event 1:json 1:rpc 1:qemu" < log_outputs="1:file:/var/log/libvirt/libvirtd.log" < # #
Is there a "how to" similar to [1] that lets one qemu to log that it was invoked and how far it got?
I removed qemu (dnf remote qemu; sudo dnf remove qemu-common) build qemu 2.2-maint (assuming this relates to 2:2.7.1-6.fc25) from github sources installed qemu from sources (into /usr/local/bin)
Things are a bit better. Where something like "sudo virsh pool-list" would just hang before, now my storage pools actually are listed. No luck listing my VM's, but "virsh list" and "virsh list --all" do not hang like before:
# virsh list
Are you sure you didn't miss the --all?
Yes I'm sure. I wish that was all it was <g>
Id Name State ----------------------------------------------------
# virsh pool-list Name State Autostart ------------------------------------------- default active yes Downloads active yes guest_images_lvm active yes
#
VM xml is /etc/libvirt/qemu. The network, virbr0 is in /etc/libvirt/qemu/networks, and that gets created just fine. All have root:root owner:group:
The VMs are not visible because the XML cannot be parsed if the binaries are not on the system (the XML contains the whole path). Also, I think this works because libvirt doesn't look into /usr/local/bin, but I might be wrong. Check whether 'virsh capabilities' tells you something about any emulator.
You can try installing from source, but putting it in /usr/bin,
I put qemu-system-x86_64 and qemu-x86_64 in /usr/bin as requested. No luck. It seems /usr/local/bin/qemu-xxx is found (see CGroup: output)
$ sudo systemctl status libvirtd.service ● libvirtd.service - Virtualization daemon Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled; vendor preset: enabled) Active: active (running) since Mon 2017-06-05 18:21:20 EDT; 3s ago Docs: man:libvirtd(8) http://libvirt.org Main PID: 7076 (libvirtd) Tasks: 19 (limit: 4915) Memory: 124.7M CPU: 3.649s CGroup: /system.slice/libvirtd.service ├─7076 /usr/sbin/libvirtd └─7208 /usr/local/bin/qemu-system-sh4eb -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabi
So this is now only with the qemu from source installed on the system?
Correct.
Using qemu installed from source, I decided to try to create a VM. It worked. I cut/pasted a script I used to create a centos72 VM, renamed the name and cut the disk size down: $ cat debug-centos.sh #/bin/bash sudo virt-install -n dbgcent72 \ --ram=4096 \ --vcpus 2 \ --disk path=/dev/vg_guest_images/dbgcent72,device=disk,size=5 \ --description "Centos 7.2 64Bit" \ --network bridge:brguest0,model=e1000 \ --cdrom /home/mcc/Downloads/CentOS-7-x86_64-DVD-1511.iso \ --vnc \ --noautoconsole \ --hvm \ --os-type=linux \ --os-variant centos7.0 \ --video=vmvga $ ./debug-centos.sh Starting install... Domain installation still in progress. You can reconnect to the console to complete the installation process. $ sudo virsh list --all Id Name State ---------------------------------------------------- 1 dbgcent72 running The xml is placed next to the xml for all the other VM's that don't seem to be found: # pwd /etc/libvirt/qemu # ls -al total 80 drwx------. 3 root root 4096 Jun 6 09:36 . drwx------. 5 root root 4096 Jun 6 08:38 .. -rw-------. 1 root root 3870 Jun 6 09:36 dbgcent72.xml -rw-------. 1 root root 3853 Jun 14 2016 dcos-bp.xml -rw-------. 1 root root 3551 Mar 21 2015 fbsd100.xml -rw-------. 1 root root 3273 Mar 23 2015 fbsd101.xml -rw-------. 1 root root 3867 Feb 21 2015 fedora20.xml drwx------. 3 root root 4096 May 10 18:08 networks -rw-------. 1 root root 3510 Oct 11 2015 u1404s.xml -rw-------. 1 root root 5017 Oct 11 2015 u1404.xml -rw-------. 1 root root 3507 Jun 5 19:33 wheezy.xml -rw-------. 1 root root 3489 Feb 21 2015 win7.xml # lvs LV VG Attr LSize Pool Origin Data% Meta% Move Log Cpy%Sync Convert [deleted] dbgcent72 vg_guest_images -wi-ao---- 5.00g dcos-bp vg_guest_images -wi-a----- 50.00g fbsd100 vg_guest_images -wi-a----- 20.00g fbsd101 vg_guest_images -wi-a----- 20.00g fedora20 vg_guest_images -wi-a----- 50.00g u1404s.qcow vg_guest_images -wi-a----- 40.00g wheezy vg_guest_images -wi-a----- 20.00g win7 vg_guest_images -wi-a----- 70.00g # ls -al /var/lib/libvirt/images total 12494552 drwx--x--x. 2 root root 4096 May 10 18:08 . drwxr-xr-x. 12 root root 4096 May 10 18:08 .. -rw-------. 1 root root 22552248320 May 29 2016 u1404.qcow2 #
On Tue, Jun 06, 2017 at 10:19:32AM -0400, Michael C. Cambria wrote:
Using qemu installed from source, I decided to try to create a VM. It worked. I cut/pasted a script I used to create a centos72 VM, renamed the name and cut the disk size down:
$ cat debug-centos.sh #/bin/bash
sudo virt-install -n dbgcent72 \ --ram=4096 \ --vcpus 2 \ --disk path=/dev/vg_guest_images/dbgcent72,device=disk,size=5 \ --description "Centos 7.2 64Bit" \ --network bridge:brguest0,model=e1000 \ --cdrom /home/mcc/Downloads/CentOS-7-x86_64-DVD-1511.iso \ --vnc \ --noautoconsole \ --hvm \ --os-type=linux \ --os-variant centos7.0 \ --video=vmvga
$ ./debug-centos.sh
Starting install... Domain installation still in progress. You can reconnect to the console to complete the installation process.
$ sudo virsh list --all Id Name State ---------------------------------------------------- 1 dbgcent72 running
The xml is placed next to the xml for all the other VM's that don't seem to be found:
# pwd /etc/libvirt/qemu # ls -al total 80 drwx------. 3 root root 4096 Jun 6 09:36 . drwx------. 5 root root 4096 Jun 6 08:38 .. -rw-------. 1 root root 3870 Jun 6 09:36 dbgcent72.xml -rw-------. 1 root root 3853 Jun 14 2016 dcos-bp.xml -rw-------. 1 root root 3551 Mar 21 2015 fbsd100.xml -rw-------. 1 root root 3273 Mar 23 2015 fbsd101.xml -rw-------. 1 root root 3867 Feb 21 2015 fedora20.xml drwx------. 3 root root 4096 May 10 18:08 networks -rw-------. 1 root root 3510 Oct 11 2015 u1404s.xml -rw-------. 1 root root 5017 Oct 11 2015 u1404.xml -rw-------. 1 root root 3507 Jun 5 19:33 wheezy.xml -rw-------. 1 root root 3489 Feb 21 2015 win7.xml
Well, in this case, even though you should not do that, normally, you can do the following. Backup your XMLs from this folder, and then try feeding them to libvirt using 'virsh define /path/to/the/backup.xml'. It is "essentially" what is happening when libvirt is starting, so it will tell you why they cannot be loaded. If they can, then compare the output of 'virsh dumpxml $domain' to the backup XML and if it is the same, then you restored your machines. But that's very unlikely to happen, because that'd mean I have no idea there's a codepath that could fail. Hopefully this will at least give us some more info about where to look for the source of the problem. Martin
participants (3)
-
Martin Kletzander -
Michael C Cambria -
Michael C. Cambria