| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2021-05-19 | |||
| 09:04:40 | kashyap | (1) Set the log output file: $> virt-admin daemon-log-outputs "1:file:/var/log/libvirt/libvirtd.log" | |
| 09:04:40 | kashyap | (1) Set the log output file: $> virt-admin daemon-log-outputs "1:file:/var/log/libvirt/libvirtd.log" | |
| 09:04:49 | kashyap | (2) Configure the dynamic filters: | |
| 09:04:49 | kashyap | (2) Configure the dynamic filters: | |
| 09:04:54 | kashyap | $> virt-admin daemon-log-filters \ "1:libvirt 1:qemu 1:conf 1:security 3:event 3:json 3:file 3:object 1:util" | |
| 09:04:55 | kashyap | $> virt-admin daemon-log-filters \ "1:libvirt 1:qemu 1:conf 1:security 3:event 3:json 3:file 3:object 1:util" | |
| 09:05:05 | kashyap | (Remove that "\") | |
| 09:05:05 | kashyap | (Remove that "\") | |
| 09:05:14 | ignaziocassano | kashyap: on messages it reports: 19:22:29 podvc-kvm04 libvirtd: 2021-05-16 17:22:29.562+0000: 166295: error : qemuMonitorIO:718 : internal error: End of file from qemu monitor | |
| 09:05:14 | ignaziocassano | kashyap: on messages it reports: 19:22:29 podvc-kvm04 libvirtd: 2021-05-16 17:22:29.562+0000: 166295: error : qemuMonitorIO:718 : internal error: End of file from qemu monitor | |
| 09:05:17 | kashyap | And then re-run the migration of the affected instances | |
| 09:05:17 | kashyap | And then re-run the migration of the affected instances | |
| 09:05:41 | kashyap | ignaziocassano: Yeah; that's also "normal" / "expected"; doesn't tell much still | |
| 09:05:41 | kashyap | ignaziocassano: Yeah; that's also "normal" / "expected"; doesn't tell much still | |
| 09:06:06 | kashyap | ignaziocassano: BTW, can you quickly try this: | |
| 09:06:06 | kashyap | ignaziocassano: BTW, can you quickly try this: | |
| 09:06:14 | kashyap | $> journalctl -u libvirtd -l --since=yesterday -p err | |
| 09:06:14 | kashyap | $> journalctl -u libvirtd -l --since=yesterday -p err | |
| 09:08:11 | ignaziocassano | error : qemuDomainObjBeginJobInternal:6825 : Timed out during operation: cannot acquire state change lock (held by monitor=remo | |
| 09:08:11 | ignaziocassano | error : qemuDomainObjBeginJobInternal:6825 : Timed out during operation: cannot acquire state change lock (held by monitor=remo | |
| 09:08:53 | kashyap | Ugh, this one... | |
| 09:08:53 | kashyap | Ugh, this one... | |
| 09:09:31 | ignaziocassano | unfortunately I cannot try to move further vm because they are in production and I must inform my customers | |
| 09:09:31 | ignaziocassano | unfortunately I cannot try to move further vm because they are in production and I must inform my customers | |
| 09:10:11 | ignaziocassano | it us very strange because for some instances it works fine | |
| 09:10:11 | ignaziocassano | it us very strange because for some instances it works fine | |
| 09:10:33 | kashyap | ignaziocassano: So this is one of the most painful errors to debug from libvirt. I recently wrote a response on a Red Hat bugzilla | |
| 09:10:34 | kashyap | ignaziocassano: So this is one of the most painful errors to debug from libvirt. I recently wrote a response on a Red Hat bugzilla | |
| 09:10:54 | kashyap | Let me get that for you (beware: no easy solution here :-() | |
| 09:10:54 | kashyap | Let me get that for you (beware: no easy solution here :-() | |
| 09:11:42 | ignaziocassano | kashyap, I read some red hat suggestions, but they include the instance restart :-( | |
| 09:11:42 | ignaziocassano | kashyap, I read some red hat suggestions, but they include the instance restart :-( | |
| 09:12:11 | kashyap | ignaziocassano: Yes, you're not wrong, afraid. | |
| 09:12:11 | kashyap | ignaziocassano: Yes, you're not wrong, afraid. | |
| 09:12:39 | kashyap | ignaziocassano: These "cannot acquire state change lock" errors are notorious; and it could be due to QEMU getting hung, which in turn could be caused by stuck I/O | |
| 09:12:39 | kashyap | ignaziocassano: These "cannot acquire state change lock" errors are notorious; and it could be due to QEMU getting hung, which in turn could be caused by stuck I/O | |
| 09:14:07 | ignaziocassano | I did not see any nfs stale on my compute node | |
| 09:14:08 | ignaziocassano | I did not see any nfs stale on my compute node | |
| 09:15:52 | kashyap | ignaziocassano: Can you post the affected guest log from /var/log/libvir/qemu/instance-YYYY.log? | |
| 09:15:52 | kashyap | ignaziocassano: Can you post the affected guest log from /var/log/libvir/qemu/instance-YYYY.log? | |
| 09:16:11 | kashyap | It _might_ sometimes havea clue | |
| 09:16:11 | kashyap | It _might_ sometimes havea clue | |
| 09:16:26 | openstackgerrit | liuzhuangzhuang proposed openstack/nova master: Fix RBD timeout https://review.opendev.org/c/openstack/nova/+/786588 | |
| 09:16:35 | kashyap | And also this (if the output is long, use a paste-bin): `journalctl -u libvirtd -r` | |
| 09:16:35 | kashyap | And also this (if the output is long, use a paste-bin): `journalctl -u libvirtd -r` | |
| 09:20:38 | ignaziocassano | kashyap, unfortunately since the affected vm remained in pause on source and destination, I had to destroy them so the log files contains only: | |
| 09:20:38 | ignaziocassano | kashyap, unfortunately since the affected vm remained in pause on source and destination, I had to destroy them so the log files contains only: | |
| 09:20:42 | ignaziocassano | 2021-05-19 08:12:30.446+0000: shutting down, reason=destroyed | |
| 09:20:42 | ignaziocassano | 021-05-19 08:11:19.800+0000: initiating migration | |
| 09:20:42 | ignaziocassano | 021-05-19 08:11:19.800+0000: initiating migration | |
| 09:20:43 | ignaziocassano | 2021-05-19 08:12:30.446+0000: shutting down, reason=destroyed | |
| 09:21:00 | kashyap | Hm; that won't help us much, afraid | |
| 09:21:00 | kashyap | Hm; that won't help us much, afraid | |
| 09:21:12 | ignaziocassano | I could try on destination host if there is something else | |
| 09:21:12 | ignaziocassano | I could try on destination host if there is something else | |
| 09:22:10 | admin0 | hi guys .. i have a strange issue: openstack server show $uuid shows its host on hypervisor => h7 . on the hypervisor, hostname, hostname -f and virsh hostname returns h7 , but during migration of this instance ( ceph backed ) to say h9 or h10, it says h7 host not found .. .. how can i address/solve this ? | |
| 09:22:10 | admin0 | hi guys .. i have a strange issue: openstack server show $uuid shows its host on hypervisor => h7 . on the hypervisor, hostname, hostname -f and virsh hostname returns h7 , but during migration of this instance ( ceph backed ) to say h9 or h10, it says h7 host not found .. .. how can i address/solve this ? | |
| 09:22:19 | ignaziocassano | yes | |
| 09:22:19 | ignaziocassano | yes | |
| 09:22:41 | ignaziocassano | I post it on openstack pastebin | |
| 09:22:41 | ignaziocassano | I post it on openstack pastebin | |
| 09:22:46 | ignaziocassano | :q! | |
| 09:22:46 | ignaziocassano | :q! | |
| 09:22:47 | admin0 | https://gist.github.com/a1git/c22ec0c17aaa9dcf95fd7485eb76af2f looks like my hostnames cycled from h7, h7. h7.openstack.local .. so now i am unable to migrate anything off of the hosts | |
| 09:22:47 | admin0 | https://gist.github.com/a1git/c22ec0c17aaa9dcf95fd7485eb76af2f looks like my hostnames cycled from h7, h7. h7.openstack.local .. so now i am unable to migrate anything off of the hosts | |
| 09:24:06 | ignaziocassano | kashyap: http://paste.openstack.org/show/805476/ | |
| 09:24:06 | ignaziocassano | kashyap: http://paste.openstack.org/show/805476/ | |
| 09:25:44 | kashyap | ignaziocassano: Ha, see this: | |
| 09:25:45 | kashyap | ignaziocassano: Ha, see this: | |
| 09:25:51 | kashyap | 2021-05-19T08:12:30.397606Z qemu-kvm: error while loading state for instance 0x0 of device '0000:00:08.0/virtio-blk' | |
| 09:25:51 | kashyap | --- | |
| 09:25:52 | kashyap | 2021-05-19T08:12:30.397606Z qemu-kvm: error while loading state for instance 0x0 of device '0000:00:08.0/virtio-blk' | |
| 09:25:55 | kashyap | 2021-05-19T08:12:30.399542Z qemu-kvm: load of migration failed: Input/output error | |
| 09:25:55 | kashyap | 2021-05-19T08:12:30.399542Z qemu-kvm: load of migration failed: Input/output error | |
| 09:25:58 | kashyap | 2021-05-19 08:12:31.022+0000: shutting down, reason=crashed | |
| 09:25:58 | kashyap | 2021-05-19 08:12:31.022+0000: shutting down, reason=crashed | |
| 09:26:00 | kashyap | --- | |
| 09:26:00 | kashyap | --- | |
| 09:26:03 | kashyap | I've pretty sure seen that 'virtio-blk' error before | |
| 09:26:04 | kashyap | I've pretty sure seen that 'virtio-blk' error before | |
| 09:27:12 | ignaziocassano | kashyap: so do you think instanance not worked fine also before live migration ? | |
| 09:27:12 | ignaziocassano | kashyap: so do you think instanance not worked fine also before live migration ? | |
| 09:27:43 | kashyap | ignaziocassano: See this bug (comments are complex; browse it from the bottom): https://bugs.launchpad.net/nova/+bug/1761798 | |
| 09:27:45 | openstack | Launchpad bug 1761798 in OpenStack Compute (nova) "live migration intermittently fails in CI with "VQ 0 size 0x80 Guest index 0x12c inconsistent with Host index 0x134: delta 0xfff8"" [Medium,Confirmed] | |
| 09:27:45 | openstack | Launchpad bug 1761798 in OpenStack Compute (nova) "live migration intermittently fails in CI with "VQ 0 size 0x80 Guest index 0x12c inconsistent with Host index 0x134: delta 0xfff8"" [Medium,Confirmed] | |
| 09:27:45 | kashyap | ignaziocassano: See this bug (comments are complex; browse it from the bottom): https://bugs.launchpad.net/nova/+bug/1761798 | |
| 09:28:25 | kashyap | ignaziocassano: No, not really; see this bit from the logs: | |
| 09:28:25 | kashyap | ignaziocassano: No, not really; see this bit from the logs: | |
| 09:28:26 | kashyap | [quote] | |
| 09:28:26 | kashyap | [quote] | |
| 09:28:27 | kashyap | we get this "guest index inconsistent" error when the migrated RAM is inconsistent with the migrated 'virtio' device state. And a common case is where a 'virtio' device does an operation after the vCPU is stopped and after RAM has been transmitted. | |
| 09:28:28 | kashyap | we get this "guest index inconsistent" error when the migrated RAM is inconsistent with the migrated 'virtio' device state. And a common case is where a 'virtio' device does an operation after the vCPU is stopped and after RAM has been transmitted. | |
| 09:28:32 | kashyap | [/quote] | |
| 09:28:32 | kashyap | [/quote] | |
| 09:28:59 | kashyap | (From my comment#11) | |
| 09:29:00 | kashyap | (From my comment#11) | |
| 09:30:38 | ignaziocassano | kashyap: my englush is poor but I did not read a conclusion. | |
| 09:30:38 | ignaziocassano | kashyap: my englush is poor but I did not read a conclusion. | |
| 09:31:22 | ignaziocassano | kayshap: do you think post_copy and autoconverge can help ? | |
| 09:31:22 | ignaziocassano | kayshap: do you think post_copy and autoconverge can help ? | |