Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2018-08-21
15:23:56 mriedem maciejjozefczyk: if you're around https://review.openstack.org/#/c/591607/
15:23:57 dansmith Kevin_Zheng: but with the batching, we *might* be better off doing that in the batches instead of at the top to reduce latency
15:24:08 mriedem maciejjozefczyk: our public cloud ops team reported the same issue
15:24:12 Kevin_Zheng So instead all instances, we do what?
15:24:55 dansmith Kevin_Zheng: well, we'd do it in the batch handler, so we fill faults on ~100 instances at a time in "parallel" instead of on 1000 instances serially
15:25:12 mriedem efried: i guess we can land this now huh https://review.openstack.org/#/c/520024/
15:25:16 Kevin_Zheng Oh OK
15:25:47 dansmith Kevin_Zheng: sounds like if I come up with a test patch you could run it again and compare to without the patch just to see if it helps or hurts?
15:25:59 Kevin_Zheng Guess I have to generate some error instance then
15:26:14 cdent yay! on 520024
15:26:15 Kevin_Zheng Yeah we can do it
15:26:28 mriedem you insert them right into the cell db right?
15:26:35 Kevin_Zheng Yes
15:26:41 dansmith Kevin_Zheng: well, the first test would still be all active, just to measure what the perf impact of unrolling that loop is
15:27:05 dansmith Kevin_Zheng: then we'd test a patch with some error instances to see if we lose all of that with the fault handling, or only a fraction of the gain we made
15:27:50 Kevin_Zheng Ok
15:30:20 dansmith Kevin_Zheng: I'll try cooking something up and will add you to the review
15:30:57 Kevin_Zheng Cool, I will go to bed and check in the morning
15:31:01 dansmith thanks
15:33:01 sean-k-mooney mriedem: so regarding the live migration bug. the source node is activating the binding on the dest host binding after the migration aborts and this is also racing with the deltion of the binding on the dest host ...
15:33:12 efried mriedem: Yes, on 024, thanks.
15:37:58 mriedem sean-k-mooney: so we're hitting post-copy and then aborting?
15:38:19 mriedem there are only 2 places that live migration activates the dest host port binding:
15:38:27 mriedem 1. post-copy event callback from libvirt
15:38:38 mriedem 2. _post_live_migration after the hypervisor said the live migration was successful
15:42:08 openstackgerrit Matt Riedemann proposed openstack/nova master: Explicitly fail if trying to attach SR-IOV port https://review.openstack.org/591898
15:42:26 sean-k-mooney mriedem: http://paste.openstack.org/show/728534/
15:42:27 dansmith ugh, the expectation that we return an instancelist from get_all makes this harder than I thought
15:42:53 sean-k-mooney i think we are geting an updat form neutron and that is trigering the activate. perhaps hitting the _pos_live_migration code
15:45:05 sean-k-mooney mriedem: lines 43-50 are teh ones im suspicous of
15:45:43 mriedem a neutron event wouldn't make us activate a port
15:45:47 mriedem just refresh the info cache
15:46:17 mriedem Aug 21 16:19:17 devstack2 nova-compute[25894]: WARNING nova.compute.manager [None req-594840ec-7af2-47d2-929b-cef9dda07bb8 service nova] [instance: fead1ca6-beab-4c47-a73e-a3ab7f7c4de2] Received unexpected event network-vif-unplugged-ef02ea3f-9a11-4519-bcd3-2bfca97edf26 for instance with vm_state active and task_state migrating.
15:46:20 mriedem means we ignore it
15:47:23 sean-k-mooney hum ok well on line 50 we activate the port binding for devstack5 which was the destination node. but the migration has already aborted
15:47:58 mriedem Aug 21 16:19:17 devstack2 nova-compute[25894]: DEBUG nova.network.neutronv2.api [None req-c8b07cbc-52f7-4d20-aacc-f3036ad90c8d None None] Activated binding for port ef02ea3f-9a11-4519-bcd3-2bfca97edf26 and host devstack5. {{(pid=25894) activate_port_binding /opt/stack/nova/nova/network/neutronv2/api.py:1352}}
15:47:58 mriedem hmm
15:48:00 mriedem indeed
15:50:11 mriedem sean-k-mooney: do you see any "(Lifecycle Event)" messages right before the traceback on the source node?
15:50:36 sean-k-mooney checking
15:51:37 mriedem should have also seen "Binding ports to destination host" if it was handle_lifecycle_event was what was activating the binding
15:51:42 mriedem er,
15:51:50 mriedem sean-k-mooney: are these the logs before or after my patch from a few hours ago?
15:53:04 sean-k-mooney before. and ya the migration competes...
15:53:13 sean-k-mooney ill paste the log section
15:53:43 mriedem so you're seeing the "Migration completed" lifecycle event
15:53:46 mriedem ?
15:54:02 mriedem maybe that's sent in both failure and success cases
15:54:22 sean-k-mooney http://paste.openstack.org/show/728539/
15:54:56 mriedem Aug 21 16:19:16 devstack2 nova-compute[25894]: INFO nova.compute.manager [None req-c8b07cbc-52f7-4d20-aacc-f3036ad90c8d None None] [instance: fead1ca6-beab-4c47-a73e-a3ab7f7c4de2] VM Migration completed (Lifecycle Event)
15:54:56 mriedem bingo
15:55:02 sean-k-mooney line 25 is the completion and line 31 is the failue
15:55:13 mriedem Aug 21 16:19:17 devstack2 nova-compute[25894]: DEBUG nova.compute.manager [None req-c8b07cbc-52f7-4d20-aacc-f3036ad90c8d None None] [instance: fead1ca6-beab-4c47-a73e-a3ab7f7c4de2] Binding ports to destination host: devstack5 {{(pid=25894) handle_lifecycle_event /opt/stack/nova/nova/compute/manager.py:1130}}
15:55:28 sean-k-mooney ya i just saw that too
15:55:30 mriedem Aug 21 16:19:17 devstack2 nova-compute[25894]: ERROR nova.virt.libvirt.driver [-] [instance: fead1ca6-beab-4c47-a73e-a3ab7f7c4de2] Live Migration failure: internal error: qemu unexpectedly closed the monitor: 2018-08-21T15:19:15.187710Z qemu-kvm: -chardev socket,id=charnet0,path=/var/run/openvswitch/vhuef02ea3f-9a,server: info: QEMU waiting
15:55:44 mriedem yeah so the driver is sending the 'migration completed' event even though the job failed
15:55:46 mriedem that's the bug
15:55:52 mriedem and that's why we are activating the dest host port bindings on failure
15:56:03 mriedem and then deleting them in rollback :)
15:56:30 sean-k-mooney ya. so libvirt bug?
15:56:36 mriedem libvirt driver bug yeah
15:57:04 sean-k-mooney well the live migration completion event is comming from libvirt no?
15:57:22 mriedem yes, but the driver should check the job status to see if it failed or not
15:57:23 mriedem if we can
15:57:27 mriedem otherwise i don't think we can rely on that event
15:57:50 sean-k-mooney let me see if danpb is about
15:57:52 openstackgerrit Chris Dent proposed openstack/nova master: Set policy_opt defaults in placement deploy unit test https://review.openstack.org/594334
15:59:49 sean-k-mooney danpb: thanks. am regarding http://paste.openstack.org/show/728539/. does the live migration completion event from libvirt have a status we can check for failures?
15:59:50 mriedem i've updated https://review.openstack.org/#/c/594139/ with comments
15:59:52 danpb sean-k-mooney: you summoned me :-)
16:00:04 mriedem how many goats had to be sacrificed?
16:00:29 sean-k-mooney haha TBD
16:01:29 danpb sean-k-mooney: you have any more context than just that log file ?
16:01:56 sean-k-mooney danpb: yes im testing live migration between ovs to ovs-dpdk in this case
16:02:07 sean-k-mooney that is causing qemu to have an internal error
16:02:30 mdbooth mriedem: I think if we've reached the point of post-copy, we shouldn't rollback.
16:02:30 danpb yep, looks like QEMU on target saw error in expected state & exited
16:02:40 sean-k-mooney nova is assuming that when we get the live migration complete event that everything worked fine bug in this case qemu explodes and the migration failes
16:02:41 danpb whcih should have caused libvirt to abort migration & nova to rollback
16:02:46 mdbooth mriedem: Because the guest was actually running on the destination at that point.
16:03:19 mdbooth Guessing that could be tricky with the current code structure, though...
16:03:23 danpb mdbooth: this logfile isn't showing post-coyp is it ? looks like normal pre-copy to me
16:03:38 sean-k-mooney mdbooth: the guest is still running fine after this. is netwroking is messed up but its still running on the host
16:03:43 mriedem mdbooth: we aren't hitting post-copy
16:03:44 mdbooth danpb: We could be talking about different things. I was referring to https://review.openstack.org/#/c/594139/
16:04:11 danpb oh fun, two different live migration discussions in parallel :-)
16:04:22 sean-k-mooney mdbooth: danpb its the same one
16:04:25 mriedem danpb: so this is all new code since you've been in nova
16:04:28 sean-k-mooney i reproduced it
16:04:52 mriedem we're just assuming "migration completed" means it was successful, which is wrong in this case
16:05:11 mriedem so just need to not send that event callback up to the compute manager if the job failed
16:05:19 mriedem which i think we can glean from the jobState object
16:05:35 mriedem assuming that info is available to us in the params to _event_lifecycle_callback
16:06:19 mriedem i'm not sure that it does though, we get event and detail
16:06:22 mriedem but not the job status
16:07:07 danpb mriedem: which migration events are you referring to ?
16:07:45 mdbooth I don't think we're actually consuming events. We're polling the migration job.
16:07:51 mriedem https://github.com/openstack/nova/blob/master/nova/virt/libvirt/host.py#L179-L184
16:07:59 mriedem mdbooth: no
16:08:03 mriedem not for this

Earlier   Later