[libvirt] W/ commit 9e159b5: error from service: CreateMachine: Machine 'qemu-foo' already exists

[Guido Günther]

On Sat, Sep 27, 2014 at 08:29:28PM +0530, Kashyap Chamarthy wrote:
> On Fedora 20 with:
> 
>     libvirt RPMs built from git commit: 9e159b521dbf18c6da6976e54e29c8553f831eb6
>     qemu-2.1.1-1.fc22.x86_64
> 
> Just start a guest:
> -----
> $ virsh start ostack-controller
> error: Failed to start domain ostack-controller
> error: error from service: CreateMachine: Machine 'qemu-ostack-controller' already exists
> -----
> 
> 
> QEMU CLI:
> -----
> $ tail /var/log/libvirt/qemu/ostack-controller.log
> 2014-09-27 14:01:40.544+0000: starting up
> LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=none /usr/bin/qemu-kvm -name ostack-controller -S -machine pc-i440fx-1.6,accel=kvm,usb=off -cpu host -m 2048 -realtime mlock=off -smp 4,sockets=4,cores=1,threads=1 -uuid 24099854-24b2-4664-b425-a288114a43df -nographic -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/ostack-controller.monitor,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -drive file=/var/lib/libvirt/images/ostack-controller.qcow2,if=none,id=drive-virtio-disk0,format=qcow2,cache=none -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,fd=24,id=hostnet0,vhost=on,vhostfd=25 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:7b:f3:a2,bus=pci.0,addr=0x2 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -device usb-tablet,id=input0 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x4 -msg timestamp=on
> Domain id=8 is tainted: host-cpu
> 2014-09-27 14:01:40.550+0000: shutting down
> root@~$ 
> -----
> 
> libvirtd is running:
> -----
> $ systemctl status libvirtd
> libvirtd.service - Virtualization daemon
>    Loaded: loaded (/usr/lib/systemd/system/libvirtd.service; enabled)
>    Active: active (running) since Sat 2014-09-27 19:32:24 IST; 47min ago
>      Docs: man:libvirtd(8)
>            http://libvirt.org
>  Main PID: 4569 (libvirtd)
>    CGroup: /system.slice/libvirtd.service
>            ├─1715 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
>            ├─1716 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
>            ├─1762 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/openstackvms.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
>            ├─1763 /sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/openstackvms.conf --dhcp-script=/usr/libexec/libvirt_leaseshelper
>            └─4569 /usr/sbin/libvirtd
> 
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 15
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 16
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 17
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 18
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 19
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 20
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 21
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 22
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 26
> Sep 27 19:32:40 tesla libvirtd[4569]: 2014-09-27 14:02:40.887+0000: 4682: debug : virFileClose:99 : Closed fd 29
> -----
> 
> >From the debug log, that's the only failure I see:
> 
> [. . .]
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:494 : i=4 w=5
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:494 : i=5 w=6
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:508 : EVENT_POLL_DISPATCH_HANDLE: watch=6 events=1
> 2014-09-27 14:02:40.897+0000: 4569: debug : virNetlinkEventCallback:350 : dispatching to max 0 clients, called from event watch 6
> 2014-09-27 14:02:40.897+0000: 4569: debug : virNetlinkEventCallback:363 : event not handled.
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:494 : i=7 w=8
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:494 : i=8 w=9
> 2014-09-27 14:02:40.897+0000: 4569: debug : virEventPollDispatchHandles:508 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
> 2014-09-27 14:02:40.897+0000: 4569: debug : udevEventHandleCallback:1596 : udev action: 'remove'
> 2014-09-27 14:02:40.897+0000: 4569: debug : udevRemoveOneDevice:1359 : Failed to find device to remove that has udev name '/sys/devices/virtual/net/vn
> et0/queues/rx-0'
> [. . .]
> 
> Searching the inter-webs, I see a few related old bugs, which indicate
> it's a QEMU bug of some sorts. 
> 
> Any hints? (Sorry, didn't dig deeper yet, /me is traveling).

Could you check if the patch from 

    https://www.redhat.com/archives/libvir-list/2014-September/msg01549.html

helps?
Cheers,
 -- Guido