On 04/27/2017 04:31 PM, Stefano Ricci wrote:> Here is the backtrace of the libvirt process just started[Just a side note, you shouldn't top post on technical lists. Gmail sucks at this.]> > https://pastebin.com/R66myzFpLooks like libvirtd is trying to spawn /usr/bin/qemu-system-x86_64 but it takes ages to init. In the debug logs you might see the actual command line that libvirt tries to execute. You can try running it by hand and see if it takes about the same time. If so, then it's a qemu bug. http://wiki.libvirt.org/page/DebugLogs Michal
2017-04-28 14:33 GMT+02:00 Michal Privoznik <mprivozn@redhat.com>:> On 04/27/2017 04:31 PM, Stefano Ricci wrote: >> Here is the backtrace of the libvirt process just started > > [Just a side note, you shouldn't top post on technical lists. Gmail > sucks at this.] > >> >> https://pastebin.com/R66myzFp > > Looks like libvirtd is trying to spawn /usr/bin/qemu-system-x86_64 but > it takes ages to init. In the debug logs you might see the actual > command line that libvirt tries to execute. You can try running it by > hand and see if it takes about the same time. If so, then it's a qemu bug. > > http://wiki.libvirt.org/page/DebugLogs > > MichalThe line that comes from the libvirt log is as follows: LC_ALL=C PATH=/bin:/usr/bin:/sbin:/usr/sbin HOME=/ USER=root /usr/bin/qemu-system-x86_64 -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 Before I run the command manually I added the -D parameter to write the qemu process stderr in a log file. Once the command is executed, the log file is blank then error-free and the process seems to respond correctly. I have connected with the following command: nc -U /var/lib/libvirt/qemu/capabilities.monitor.sock and this is an extract of qemu output to my requests: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 8, "major": 2}, "package": ""}, "capabilities": []}} { "execute": "qmp_capabilities" } {"return": {}} { "execute": "query-commands" } {"return": [{"name": "xen-set-global-dirty-log"}, {"name": "xen-save-devices-state"}, {"name": "xen-load-devices-state"}, {"name": "x-colo-lost-heartbeat"}, {"name": "x-blockdev-remove-medium"}, {"name": "x-blockdev-insert-medium"}, {"name": "x-blockdev-del"}, {"name": "x-blockdev-change"}, {"name": "transaction"}, {"name": "trace-event-set-state"}, {"name": "trace-event-get-state"}, {"name": "system_wakeup"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "stop"}, {"name": "set_password"}, {"name": "set_link"}, {"name": "send-key"}, {"name": "screendump"}, {"name": "rtc-reset-reinjection"}, {"name": "ringbuf-write"}, {"name": "ringbuf-read"}, {"name": "remove-fd"}, {"name": "quit"}, {"name": "query-vnc-servers"}, {"name": "query-vnc"}, {"name": "query-version"}, {"name": "query-uuid"}, {"name": "query-tpm-types"}, {"name": "query-tpm-models"}, {"name": "query-tpm"}, {"name": "query-target"}, {"name": "query-status"}, {"name": "query-spice"}, {"name": "query-rx-filter"}, {"name": "query-rocker-ports"}, {"name": "query-rocker-of-dpa-groups"}, {"name": "query-rocker-of-dpa-flows"}, {"name": "query-rocker"}, {"name": "query-pci"}, {"name": "query-named-block-nodes"}, {"name": "query-name"}, {"name": "query-migrate-parameters"}, {"name": "query-migrate-capabilities"}, {"name": "query-migrate-cache-size"}, {"name": "query-migrate"}, {"name": "query-mice"}, {"name": "query-memory-devices"}, {"name": "query-memdev"}, {"name": "query-machines"}, {"name": "query-kvm"}, {"name": "query-iothreads"}, {"name": "query-hotpluggable-cpus"}, {"name": "query-fdsets"}, {"name": "query-events"}, {"name": "query-dump-guest-memory-capability"}, {"name": "query-dump"}, {"name": "query-cpus"}, {"name": "query-cpu-definitions"}, {"name": "query-commands"}, {"name": "query-command-line-options"}, {"name": "query-chardev-backends"}, {"name": "query-chardev"}, {"name": "query-blockstats"}, {"name": "query-block-jobs"}, {"name": "query-block"}, {"name": "query-balloon"}, {"name": "query-acpi-ospm-status"}, {"name": "qom-set"}, {"name": "qom-list-types"}, {"name": "qom-list"}, {"name": "qom-get"}, {"name": "qmp_capabilities"}, {"name": "pmemsave"}, {"name": "object-del"}, {"name": "object-add"}, {"name": "netdev_del"} ....... So it would not look like a qemu bug. Stefano
On 04/29/2017 04:38 AM, Stefano Ricci wrote:> 2017-04-28 14:33 GMT+02:00 Michal Privoznik <mprivozn@redhat.com>: >> On 04/27/2017 04:31 PM, Stefano Ricci wrote: >>> Here is the backtrace of the libvirt process just started >> >> [Just a side note, you shouldn't top post on technical lists. Gmail >> sucks at this.] >> >>> >>> https://pastebin.com/R66myzFp >> >> Looks like libvirtd is trying to spawn /usr/bin/qemu-system-x86_64 but >> it takes ages to init. In the debug logs you might see the actual >> command line that libvirt tries to execute. You can try running it by >> hand and see if it takes about the same time. If so, then it's a qemu bug. >> >> http://wiki.libvirt.org/page/DebugLogs >> >> Michal > > The line that comes from the libvirt log is as follows: > LC_ALL=C PATH=/bin:/usr/bin:/sbin:/usr/sbin HOME=/ USER=root > /usr/bin/qemu-system-x86_64 -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 > Before I run the command manually I added the -D parameter to write > the qemu process stderr in a log file. > Once the command is executed, the log file is blank then error-free > and the process seems to respond correctly. > I have connected with the following command: nc -U > /var/lib/libvirt/qemu/capabilities.monitor.sock > and this is an extract of qemu output to my requests: > {"QMP": {"version": {"qemu": {"micro": 1, "minor": 8, "major": 2}, > "package": ""}, "capabilities": []}} > { "execute": "qmp_capabilities" } > {"return": {}} > { "execute": "query-commands" } > {"return": [{"name": "xen-set-global-dirty-log"}, {"name": > "xen-save-devices-state"}, {"name": "xen-load-devices-state"}, > {"name": "x-colo-lost-heartbeat"}, {"name": > "x-blockdev-remove-medium"}, {"name": "x-blockdev-insert-medium"}, > {"name": "x-blockdev-del"}, {"name": "x-blockdev-change"}, {"name": > "transaction"}, {"name": "trace-event-set-state"}, {"name": > "trace-event-get-state"}, {"name": "system_wakeup"}, {"name": > "system_reset"}, {"name": "system_powerdown"}, {"name": "stop"}, > {"name": "set_password"}, {"name": "set_link"}, {"name": "send-key"}, > {"name": "screendump"}, {"name": "rtc-reset-reinjection"}, {"name": > "ringbuf-write"}, {"name": "ringbuf-read"}, {"name": "remove-fd"}, > {"name": "quit"}, {"name": "query-vnc-servers"}, {"name": > "query-vnc"}, {"name": "query-version"}, {"name": "query-uuid"}, > {"name": "query-tpm-types"}, {"name": "query-tpm-models"}, {"name": > "query-tpm"}, {"name": "query-target"}, {"name": "query-status"}, > {"name": "query-spice"}, {"name": "query-rx-filter"}, {"name": > "query-rocker-ports"}, {"name": "query-rocker-of-dpa-groups"}, > {"name": "query-rocker-of-dpa-flows"}, {"name": "query-rocker"}, > {"name": "query-pci"}, {"name": "query-named-block-nodes"}, {"name": > "query-name"}, {"name": "query-migrate-parameters"}, {"name": > "query-migrate-capabilities"}, {"name": "query-migrate-cache-size"}, > {"name": "query-migrate"}, {"name": "query-mice"}, {"name": > "query-memory-devices"}, {"name": "query-memdev"}, {"name": > "query-machines"}, {"name": "query-kvm"}, {"name": "query-iothreads"}, > {"name": "query-hotpluggable-cpus"}, {"name": "query-fdsets"}, > {"name": "query-events"}, {"name": > "query-dump-guest-memory-capability"}, {"name": "query-dump"}, > {"name": "query-cpus"}, {"name": "query-cpu-definitions"}, {"name": > "query-commands"}, {"name": "query-command-line-options"}, {"name": > "query-chardev-backends"}, {"name": "query-chardev"}, {"name": > "query-blockstats"}, {"name": "query-block-jobs"}, {"name": > "query-block"}, {"name": "query-balloon"}, {"name": > "query-acpi-ospm-status"}, {"name": "qom-set"}, {"name": > "qom-list-types"}, {"name": "qom-list"}, {"name": "qom-get"}, {"name": > "qmp_capabilities"}, {"name": "pmemsave"}, {"name": "object-del"}, > {"name": "object-add"}, {"name": "netdev_del"} ....... > So it would not look like a qemu bug.Well, this does not prove that qemu replies to all commands issued by libvirt. For that we would need debug logs as referred to above. BTW: The stack trace looks a bit old (the line number do not match with the current git HEAD) - what's the release you're running and does the problem occur with the current git HEAD too? Michal