Comment 3 for bug 1894804

Note that there are many VMs running, so it is important to isolate logs for just one of them, by matching on mon=0xXXXXXXXX.

For example considering this

$ grep 0x7f021c0b9c70 libvirtd.log | grep -E 'QEMU_MONITOR_(RECV_REPLY|RECV_EVENT|SEND_MSG)'

We can see the "device_del" request:

2020-09-03 19:53:47.114+0000: 65331: info : qemuMonitorSend:993 : QEMU_MONITOR_SEND_MSG: mon=0x7f021c0b9c70 msg={"execute":"device_del","arguments":{"id":"virtio-disk1"},"id":"libvirt-367"}
2020-09-03 19:53:47.116+0000: 65328: info : qemuMonitorJSONIOProcessLine:239 : QEMU_MONITOR_RECV_REPLY: mon=0x7f021c0b9c70 reply={"return": {}, "id": "libvirt-367"}

and then the first DEVICE_DELETED event:

2020-09-03 19:53:52.539+0000: 65328: info : qemuMonitorJSONIOProcessLine:234 : QEMU_MONITOR_RECV_EVENT: mon=0x7f021c0b9c70 event={"timestamp": {"seconds": 1599162832, "microseconds": 539721}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral/virtio-disk1/virtio-backend"}}

The second, important, DEVICE_DELETED event never arrives. OpenStack hopelessly just retries device_del forever more.

Note in normal case the first DEVICE_DELETED event (for "/machine/peripheral/virtio-disk1/virtio-backend") gets emitted from VCPU thread context. The second DEVICE_DELETED event (for "/machine/peripheral/virtio-disk1/") is emitted from the RCU thread, and that one is missing here. THe second one is the event that libvirt needs in order to determine that unplug is complete.