| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-07-16 | |||
| 19:14:43 | sean-k-mooney | ok now that i have tested my patch ill test your and see if it fixes it. | |
| 19:33:00 | openstackgerrit | Tobias Urdin proposed openstack/nova master: [PoC] libvirt: Broadcast RARP post live migration https://review.opendev.org/741529 | |
| 19:51:41 | sean-k-mooney | tobias-urdin: ^ that is not really a fix for the issue its just going to mask the race condition | |
| 19:55:38 | sean-k-mooney | i left a comment inline but you need to use the python bindings not virsh | |
| 20:51:30 | mnaser | hrm | |
| 20:51:56 | melwitt | mnaser: did you see my reply to you yesterday? | |
| 20:52:06 | mnaser | melwitt: oh yes, sorry, i mentally said "yes" | |
| 20:52:19 | melwitt | np, just wanted to make sure :) | |
| 20:52:33 | mnaser | my fun thing now is a vm that takes 725 seconds to provision | |
| 20:52:40 | melwitt | yikes | |
| 20:52:48 | mnaser | and the only strange thing is like | |
| 20:52:59 | mnaser | Creating image .... nothing from there until VM started | |
| 20:53:06 | mnaser | 12 minutes until it starts | |
| 20:53:34 | mnaser | and here's the thing.. the image it uses? it's 1 megabyte. and it's cached locally (verified by sha1sum the image uuid) | |
| 20:53:47 | mnaser | https://www.irccloud.com/pastebin/s9lKj7n7/ | |
| 20:54:03 | mnaser | (that's grepping the nova-compute log for that specific vm) | |
| 20:54:11 | melwitt | hm, I've seen that hang before in cases where there was something like an environmental error where there was no OSD under the root | |
| 20:55:13 | melwitt | the 'rbd import' command can hang silently and I have not yet figured out a good way to time it out or anything | |
| 20:55:44 | melwitt | but in your case it's not stuck, it just takes forever | |
| 20:56:19 | mnaser | melwitt: well and also, sorry i should clarify, its not even using ceph | |
| 20:56:24 | mnaser | so local storage, so should be trivial? | |
| 20:56:38 | melwitt | should be... | |
| 20:56:59 | mnaser | and afaik the port plugging should happen after the vm get started (then resumed when the callback arrives) | |
| 20:57:10 | mnaser | which means it isn't waiting on neutron | |
| 20:58:26 | mnaser | but this is a case where like a single compute node is starting up 15 vms with 5 ports each potentially | |
| 21:05:57 | melwitt | mnaser: looks like the "Instance spawned successfully." is after port plugging and everything, it's after it's 100% done | |
| 21:06:40 | mnaser | melwitt: i thought the pause/resume on start that happens was for networking to get plumbed? | |
| 21:06:50 | melwitt | if you're able to turn on DEBUG, you could look for this log marker, this marks the end of the creating image piece https://github.com/openstack/nova/blob/057891ac247fadfb9637d3e834f8b1ef3e39bc27/nova/virt/libvirt/driver.py#L4070-L4073 | |
| 21:07:07 | openstackgerrit | Merged openstack/nova master: libvirt: Simplify '_create_domain' function https://review.opendev.org/739208 | |
| 21:07:17 | mnaser | i think i might have to switch to debug | |
| 21:07:40 | melwitt | yeah I'm still looking re: what the pause/resume happens. I'm not familiar with that other than knowing it happens | |
| 21:08:22 | openstackgerrit | Lee Yarwood proposed openstack/nova master: WIP libvirt: Convert libvirt_volume_drivers to a dict https://review.opendev.org/741545 | |
| 21:08:22 | openstackgerrit | Lee Yarwood proposed openstack/nova master: WIP libvirt: Reintroduce native QEMU iSCSI volume support https://review.opendev.org/741546 | |
| 21:08:26 | melwitt | yeah looks like resume is after plugging https://github.com/openstack/nova/blob/057891ac247fadfb9637d3e834f8b1ef3e39bc27/nova/virt/libvirt/driver.py#L6554 | |
| 21:08:40 | mnaser | so technically its not waiting for neutron.. | |
| 21:09:02 | melwitt | it is, right? that message is the resume, after plugging no? | |
| 21:09:45 | melwitt | (Based on seeing this before the resume https://github.com/openstack/nova/blob/057891ac247fadfb9637d3e834f8b1ef3e39bc27/nova/virt/libvirt/driver.py#L6513) | |
| 21:09:49 | mnaser | melwitt: 2020-07-16 20:37:40.144 => vm started, 2020-07-16 20:37:40.283 => vm paused, 2020-07-16 20:37:40.360 => vm resumed | |
| 21:10:27 | mnaser | anyhow we also run default vif_plugging_timeout which is 300s so it would have bombed then (there are logs of other vms bombing) | |
| 21:11:02 | melwitt | oh, hm | |
| 21:11:41 | mnaser | so i wonder the fact other threads are waiting for things are causing it to stall out | |
| 21:13:00 | melwitt | yeah... I guess we have seen things like that, where we had to dial down the concurrent builds setting | |
| 21:13:42 | openstackgerrit | Lee Yarwood proposed openstack/nova stable/queens: libvirt: Don't delete disks on shared storage during evacuate https://review.opendev.org/732717 | |
| 21:14:38 | melwitt | there was also a bug around some libvirt driver green thread proxying but it was fixed awhile back https://review.opendev.org/677736 | |
| 21:18:47 | mnaser | melwitt: interesting, that's not in this stein deployemnt | |
| 21:19:13 | melwitt | yeah, the backports all got nacked awhile back :\ | |
| 21:19:26 | mnaser | yep, i see that | |
| 21:19:33 | mnaser | seems like train came out with that | |
| 21:19:39 | melwitt | yes | |
| 21:19:51 | openstackgerrit | Lee Yarwood proposed openstack/nova master: Ensure source compute is up when confirming a resize https://review.opendev.org/699291 | |
| 21:20:22 | mnaser | interestingly enough, all os_vif ops are taking almost 4-5s | |
| 21:20:51 | mnaser | and i think os_vif is just local only? | |
| 21:21:32 | melwitt | yeah, I think so | |
| 21:37:02 | dansmith | melwitt: ersum, thanks | |
| 21:37:40 | melwitt | yer welcome | |
| 21:42:22 | openstackgerrit | Stephen Finucane proposed openstack/nova master: api: Reject non-spawn operations for vTPM https://review.opendev.org/741500 | |
| 21:42:23 | openstackgerrit | Stephen Finucane proposed openstack/nova master: libvirt: Add emulated TPM support to Nova https://review.opendev.org/631363 | |
| 21:42:23 | openstackgerrit | Stephen Finucane proposed openstack/nova master: docs: Add docs for vTPM support https://review.opendev.org/739213 | |
| 21:42:24 | openstackgerrit | Stephen Finucane proposed openstack/nova master: WIP: Add support for resize and cold migration of emulated TPM files https://review.opendev.org/639934 | |
| 21:56:32 | openstackgerrit | Tobias Urdin proposed openstack/nova master: [PoC] libvirt: Broadcast RARP post live migration https://review.opendev.org/741529 | |
| 21:57:37 | openstackgerrit | Tobias Urdin proposed openstack/nova master: [PoC] libvirt: Broadcast RARP post live migration https://review.opendev.org/741529 | |
| 23:04:33 | openstackgerrit | Artom Lifshitz proposed openstack/nova master: Handle Neutron errors in _post_live_migration() https://review.opendev.org/729763 | |
| 23:12:09 | openstackgerrit | Lee Yarwood proposed openstack/nova master: WIP libvirt: Check if device is listed in the inactive config during detach https://review.opendev.org/741557 | |
| 23:44:39 | mnaser | melwitt: further investigation shows that that the vms are taking a long time because of plugging ports | |
| 23:44:57 | mnaser | but .. https://www.irccloud.com/pastebin/WAiTYOJE/ .. vif_plugging_timeout is 300, except it took almost 10 minutes to plug em | |
| 23:52:58 | openstackgerrit | Lee Yarwood proposed openstack/nova master: WIP libvirt: Handle VIR_ERR_DEVICE_MISSING when detaching devices https://review.opendev.org/741561 | |
| #openstack-nova - 2020-07-17 | |||
| 00:17:34 | openstackgerrit | Merged openstack/nova master: libvirt: Add vTPM config support https://review.opendev.org/739209 | |
| 00:31:41 | openstackgerrit | Merged openstack/nova master: zuul: remove legacy-tempest-dsvm-neutron-dvr-multinode-full https://review.opendev.org/740447 | |
| 01:29:10 | sean-k-mooney | mnaser: that general indeicates an issue with neutron or rabbitmq performance | |
| 01:29:54 | mnaser | sean-k-mooney: yeah, so based on my log tracing, the PUT is sent at :33 but n-ovs-agent doesnt actually plug until :37 | |
| 01:30:34 | sean-k-mooney | the PUT? | |
| 01:30:49 | mnaser | sorry, the PUT from n-cpu to neutron to plug the port | |
| 01:30:57 | sean-k-mooney | that is not pluging | |
| 01:31:01 | sean-k-mooney | that is port binding | |
| 01:31:08 | sean-k-mooney | they are two differnt things | |
| 01:31:18 | sean-k-mooney | binding happens before pluging starts | |
| 01:31:45 | mnaser | sean-k-mooney: what triggers the plug? | |
| 01:32:30 | sean-k-mooney | after teh ports are bound nova plugs the interface which in the case of ovs is the act of createing the ovs port | |
| 01:33:01 | sean-k-mooney | when the port is created the external_id in other_cofnig on the ovs interface is set to the neutron port uuid | |
| 01:33:21 | sean-k-mooney | that triggeres an event on a unix socket that the l2 agent is monitoring | |
| 01:33:37 | sean-k-mooney | and then the l2 agent start wiring up the port | |
| 01:33:43 | mnaser | the PUT is the only operation i'm seeing towards neutron-server which isn't read-only (aka not a GET) | |
| 01:34:06 | sean-k-mooney | when the port is wired up and the dhcps agnet has also updated the dhcp config the pluging evnet is sent | |
| 01:34:26 | sean-k-mooney | mnaser: nova does not talk to neutron during plugin | |
| 01:34:42 | sean-k-mooney | it configure the network backend and neutron watches for that | |
| 01:34:55 | sean-k-mooney | when the l2 agent finsihs it send a rpc to the neutron server | |
| 01:35:01 | sean-k-mooney | and that trivers teh event to nova | |
| 01:35:14 | sean-k-mooney | *triggers | |
| 01:35:56 | mnaser | so n-ovs-agent waits for os_vif to do its thing, and then when it sees a new port, it starts the process of wiring it up (aka the whole vlan dance), tells neutron its plugged and then neutron-server does the notify http call? | |
| 01:36:13 | sean-k-mooney | yes | |
| 01:36:24 | mnaser | (fwiw this is stein) | |
| 01:36:43 | sean-k-mooney | yep this dance has not change since neutron was qunantum | |
| 01:36:49 | sean-k-mooney | at least not for spwan | |
| 01:36:52 | mnaser | TIL a lot | |
| 01:37:05 | sean-k-mooney | live migration has changed but spawn is still the same | |
| 01:37:18 | mnaser | ok so once the port is setup by nova and it starts waiting for external event, n-ovs-agent should technically start acting right away | |
| 01:37:47 | sean-k-mooney | yes on older version when the l2 agent was using vsctl instead of the ovs python binding | |
| 01:37:57 | sean-k-mooney | it used to poll for the port updates | |
| 01:38:09 | sean-k-mooney | so there was more latency but it was minimal | |
| 01:38:42 | mnaser | sean-k-mooney: well in that case, the theory is that n-ovs-agent is taking a long time to notice the port appearing | |