Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2018-07-27
01:58:07 melwitt oh, I'm not 100% sure it makes live migration "fail", I meant to change that to "raises"
01:59:35 mriedem e-r query https://review.openstack.org/#/c/586389/
01:59:41 mriedem it fails
01:59:55 mriedem http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Live%20migration%20failed%5C%22%20AND%20message%3A%5C%22Unsupported%20VIF%20type%20unbound%20convert%20'_nova_to_osvif_vif_unbound'%5C%22%20AND%20tags%3A%5C%22screen-n-cpu.txt%5C%22&from=7d
02:00:05 melwitt although yeah, all the logstash hits containing the message are build failures
02:00:20 melwitt bah *changes it back*
02:01:22 melwitt cool, thanks for adding the e-r query
02:07:37 sean-k-mooney so im going to sleep now but http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_01_083831 looks like its happening because we are calling unplug on the source node after we have activated the binding on the dest
02:08:19 melwitt sean-k-mooney: thanks. so maybe something we need to adjust given the use of the new binding API? I dunno
02:08:46 melwitt I'll add your comment to the bug
02:09:40 openstackgerrit Matt Riedemann proposed openstack/nova master: Temporarily disable port binding flows for live migration https://review.openstack.org/586391
02:09:48 mriedem ^ is an option for temporarily disabling this while debugging a fix
02:10:03 mriedem i hope it doesn't have to come to that, but would understand if it's causing a lot of failures
02:10:41 sean-k-mooney melwitt: i can try and reporduce this in the morning. we proably need to stor the original vif type and use that to constuct the vif object and use that or do the unplug on the host.
02:11:19 melwitt mriedem: okay, we'll decide what to do in the morning tomorrow when other people are around
02:11:48 openstackgerrit Merged openstack/nova-specs master: Fix problem description number in deprecate file injection spec https://review.openstack.org/586385
02:12:00 mriedem yeah the error is from unplugging vifs in _post_live_migration which happens on the source,
02:12:41 mriedem https://github.com/openstack/nova/blob/2afc5fed1f60077e7ff0b9e81b64cff4e4dbabfc/nova/compute/manager.py#L6581
02:12:53 mriedem right before that,
02:12:54 mriedem https://github.com/openstack/nova/blob/2afc5fed1f60077e7ff0b9e81b64cff4e4dbabfc/nova/compute/manager.py#L6572
02:13:01 mriedem we activate the port bindings for the dest host
02:13:47 melwitt ah, I see
02:13:56 sean-k-mooney mriedem: yep that will deactivaate all other port bindings for that port meaning it will be in the unbound state on the sorce host
02:13:59 melwitt so just flip that?
02:14:02 mriedem https://github.com/openstack/nova/blob/2afc5fed1f60077e7ff0b9e81b64cff4e4dbabfc/nova/network/neutronv2/api.py#L2534
02:14:26 mriedem i didn't know we couldn't unplug a deactivated port...
02:14:32 melwitt I wonder how it doesn't fail 100% of the time
02:14:36 mriedem melwitt: race
02:14:39 mriedem apparently
02:14:40 melwitt ah
02:14:59 melwitt yeah, what luck that the actual change *didn't* fail
02:15:05 sean-k-mooney mriedem: your raising with the notification neutron send for the port status change
02:15:16 mriedem hmm http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_00_974248
02:15:40 mriedem melwitt: i had seen this once in the series and mlavalle debugged it and couldn't find anything wrong
02:15:52 mriedem Jul 27 01:44:00.974248 ubuntu-xenial-rax-dfw-0001002000 nova-compute[2629]: DEBUG nova.network.neutronv2.api [None req-33283139-ba55-4106-b76c-8751a025f153 service nova] [instance: 6b72a721-0995-446e-848f-f407b788c7f4] Port 21095ff0-6bcd-414b-9d6f-b63e03aacb23 binding to destination host ubuntu-xenial-rax-dfw-0001002004 is already ACTIVE. {{(pid=2629) migrate_instance_start /opt/stack/new/nova/nova/network/neutronv2/api.py:25
02:15:56 melwitt ah, okay
02:16:01 mriedem oh i know why it's already active,
02:16:10 mriedem because we activate the dest host port binding during post-copy
02:16:26 mriedem which is the whole point of the blueprint - to shorten the window of time that you don't have networking on the dest host
02:17:08 melwitt right
02:17:21 melwitt shorten the window
02:18:06 mriedem this is the unplug event http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_00_069526
02:18:40 mriedem this is where we activate the ports on the dest host during post-copy http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_43_58_561391
02:19:53 mriedem we could have the live migration method wait for the unplug event before starting with post live migration, but (1) i'm not sure that helps anything and (2) it might not work that way for all virt drivers - only libvirt + post-copy has this
02:20:18 melwitt yeah, events are sketch depending on which networking backend too, right
02:20:30 melwitt like ovs vs other
02:20:30 openstackgerrit Yikun Jiang (Kero) proposed openstack/nova master: Change deprecated policies to policy https://review.openstack.org/583434
02:20:36 mriedem melwitt: shouldn't be in this case,
02:20:44 mriedem odl should send the event on host binding changes
02:20:46 openstackgerrit Yikun Jiang (Kero) proposed openstack/nova master: Fix all invalid obj_make_compatible test case https://review.openstack.org/574240
02:20:48 openstackgerrit Yikun Jiang (Kero) proposed openstack/nova master: Fix all invalid obj_make_compatible test case https://review.openstack.org/574240
02:20:49 mriedem just not plug/unplug
02:20:51 melwitt oh, because neutron knows about it and not relying on anything else? ok
02:21:20 melwitt just remember getting burned by the whole plug event thing for reboot
02:21:50 melwitt but that was because we so os-vif plug only, not any call to neutron and the agent (or something) has to notice it
02:22:27 sean-k-mooney melwitt: the binding change is handeld in the common ml2 layer if i rember corrrectly yes. the port wire up/tear down event however has to come form the backend not the common layer hence the delta between odl/ovs in that case
02:22:53 melwitt sean-k-mooney: yeah, I was having trouble remembering what the deal was. thanks
02:24:20 sean-k-mooney melwitt: the reason it did not work with linux bridge is its pools. the reason it did not work for odl was they were missing the handeler for the event in odl to send it to the websocket creeated by netowrking odl. i think they have fixed that. maybe
02:27:54 sean-k-mooney any way nova is reciving the port update event in this case from neutron and its updating the network info cacche so by the time we call nova_to_osvif_vif the vif_type is set to unbound and boom. if we still have the migration data object at this point we should have a copy of the original vif object that we could use instead of the info_cache versions to work around it.
02:28:23 mriedem so migrate_instance_start() was always a noop before this series,
02:28:49 mriedem so its order in _post_live_migration would have never mattered except for nova-network
02:29:14 mriedem given we already call migrate_instance_start during post-copy, i don't think moving the order of those calls in _post_live_migration will matter,
02:29:33 mriedem because from these logs, i can see that when we call migrate_instance_start from _post_live_migration, it's a noop b/c the dest port binding is already active
02:30:03 mriedem http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_00_974248
02:30:19 mriedem so i would think it means, we need to handle unbound vifs during unplug in the driver?
02:30:29 mriedem or just not call unplug_vifs in certain cases
02:30:32 mriedem not totally sure though
02:31:33 mriedem all the libvirt driver does in post_live_migration_at_source is unplug_vifs
02:32:11 sean-k-mooney if we dont call unplug_vif we could leak the linux bridges we create for ovs hybrid plug
02:33:06 mriedem umm...
02:33:15 mriedem oh i see what you were saying about storing off the vif_type then
02:33:44 mriedem b/c i was going to say, we could just not call unplug_vifs if the vif type (after refreshing the network info cache from neutron) was now 'unbound'
02:33:59 mriedem if it is, we can temporarily heal that using migrate_data.vifs
02:34:01 mriedem that has the vif type in it
02:34:15 sean-k-mooney mriedem: yep
02:34:34 mriedem ok i could try cooking something up real quick,
02:34:39 mriedem my wife is going to kill me though
02:34:59 melwitt you could do tomorrow morning?
02:35:12 sean-k-mooney i can try this in the morning too. i just need a 2 node vanila devstack install right
02:35:13 melwitt unless you were thinking to fast-approve this tonight
02:36:26 mriedem why would the vif type be unbound?
02:36:30 mriedem shouldn't it be bound to the dest host?
02:36:35 mriedem since we activated it there?
02:37:13 sean-k-mooney mriedem: it is. each host has its own binding now. only one will be in the bound state all the rest will be unbound
02:38:36 mriedem but i think the port in our info cache is not host-aware...
02:38:39 mriedem i need to check
02:39:56 mriedem http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_00_726935
02:40:04 mriedem that's where we refresh the info cache in _post_live_migration
02:40:10 mriedem after activating the dest host port binding
02:40:23 mriedem [{"profile": {"migrating_to": "ubuntu-xenial-rax-dfw-0001002004"}, "ovs_interfaceid": null, "preserve_on_delete": false, "network": {"bridge": null, "subnets": [{"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "10.1.0.10"}], "version": 4, "meta": {}, "dns": [], "routes": [], "cidr": "10.1.0.0/28", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "10.1.0.1"}}], "meta": {"in
02:40:23 mriedem ed": false, "tenant_id": "7dbeedd7076e472091193779ebbcf887", "mtu": 1400}, "id": "1d8de970-331e-46b5-8c7b-574821e891e5", "label": "tempest-LiveMigrationTest-411356071-network"}, "devname": "tap21095ff0-6b", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {}, "address": "fa:16:3e:34:c9:90", "active": false, "type": "unbound", "id": "21095ff0-6bcd-414b-9d6f-b63e03aacb23", "qbg_params": null}]
02:40:50 mriedem yeah...that's wrong
02:40:55 mriedem it should be bound to the dest host
02:44:42 sean-k-mooney well it was bound shortly before http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_43_59_311896
02:46:49 mriedem yup we hit post-copy callback here and activate the dest host port binding http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_43_58_561391
02:47:34 mriedem refresh nw info cache here http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_43_59_310738
02:48:16 mriedem then we get an unplugged vif event from neutron
02:48:19 mriedem could be concurrently
02:48:19 sean-k-mooney whats happening is liekly that when the ovs neutron agent sees the tap device disapear it is sending an update to notify us the port state has changed on the souce node.
02:48:50 mriedem yeah we get the unplugged event and refresh the cache and it's unbound http://logs.openstack.org/63/585163/1/check/nova-live-migration/1b2aebb/logs/screen-n-cpu.txt#_Jul_27_01_44_00_726935

Earlier   Later