Comment 6 for bug 1912310

Revision history for this message
Lee Yarwood (lyarwood) wrote :

I assumed this had something to do with bug #1929446 but it's still reproducing now:

https://46859657da8176be8119-30b0a72bc63e960bd7a500e425d4bd8d.ssl.cf5.rackcdn.com/779275/3/check/nova-live-migration/1122e93/controller/logs/libvirt/libvirtd_log.txt

 86445 2021-06-24 11:16:50.947+0000: 73097: info : qemuMonitorIOWrite:450 : QEMU_MONITOR_IO_WRITE: mon=0x7f6a600d7180 buf={"execute":"migrate-incoming","arguments":{"uri":"tcp:[::]:49152"},"id":"libvirt-373"}^M
 86446 len=88 ret=88 errno=0
 86447 2021-06-24 11:16:50.948+0000: 73097: debug : qemuMonitorJSONIOProcessLine:220 : Line [{"timestamp": {"seconds": 1624533410, "microseconds": 948823}, "event": "MIGRATION", "data": {"status": "setup"}}]
 86448 2021-06-24 11:16:50.948+0000: 73097: info : qemuMonitorJSONIOProcessLine:234 : QEMU_MONITOR_RECV_EVENT: mon=0x7f6a600d7180 event={"timestamp": {"seconds": 1624533410, "microseconds": 948823}, "event": "MIGRATION", "data": {"status": "setup"}}
 86449 2021-06-24 11:16:50.948+0000: 73097: debug : qemuMonitorJSONIOProcessEvent:181 : mon=0x7f6a600d7180 obj=0x55a2c5a87b20
 86450 2021-06-24 11:16:50.948+0000: 73097: debug : qemuMonitorEmitEvent:1198 : mon=0x7f6a600d7180 event=MIGRATION
 86451 2021-06-24 11:16:50.948+0000: 73097: debug : qemuProcessHandleEvent:549 : vm=0x7f6a600d4e70
 86452 2021-06-24 11:16:50.948+0000: 73097: debug : virObjectEventNew:631 : obj=0x55a2c5a8ac10
 86453 2021-06-24 11:16:50.949+0000: 73097: debug : qemuMonitorJSONIOProcessEvent:205 : handle MIGRATION handler=0x7f6a841388f0 data=0x55a2c58fec00
 86454 2021-06-24 11:16:50.949+0000: 73097: debug : qemuMonitorEmitMigrationStatus:1484 : mon=0x7f6a600d7180, status=setup
 86455 2021-06-24 11:16:50.949+0000: 73097: debug : qemuProcessHandleMigrationStatus:1642 : Migration of domain 0x7f6a600d4e70 instance-0000000e changed state to setup
 86456 2021-06-24 11:16:50.949+0000: 73097: debug : virObjectEventDispose:124 : obj=0x55a2c5a8ac10
 86457 2021-06-24 11:16:50.949+0000: 73097: debug : virNetlinkEventCallback:862 : dispatching to max 0 clients, called from event watch 7
 86458 2021-06-24 11:16:50.949+0000: 73097: debug : virNetlinkEventCallback:876 : event not handled.
 86459 2021-06-24 11:16:50.949+0000: 73097: debug : qemuMonitorJSONIOProcessLine:220 : Line [{"return": {}, "id": "libvirt-373"}]
 86460 2021-06-24 11:16:50.949+0000: 73097: info : qemuMonitorJSONIOProcessLine:239 : QEMU_MONITOR_RECV_REPLY: mon=0x7f6a600d7180 reply={"return": {}, "id": "libvirt-373"}
[..]
87097 2021-06-24 11:17:20.249+0000: 73097: error : virKeepAliveTimerInternal:137 : internal error: connection closed due to keepalive timeout

I'm going to see if I can play around with the keepalive libvirtd configurables in devstack to address this.