Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2018-08-21
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
16:08:26 danpb oh, so you're just looking at the lifecycle events
16:08:40 mdbooth mriedem: ack. Was looking at _live_migration_monitor.
16:08:59 danpb i'm not convinced that's not a desirable way to determine success vs failure
16:09:09 mriedem we're getting VIR_DOMAIN_EVENT_SUSPENDED_MIGRATED
16:09:17 mriedem and assuming it's success
16:09:23 danpb the the job status from the _live_migration_monitor is better way to check for failure
16:09:31 mriedem yeah, but we're on different threads here
16:09:43 mriedem we have the domain, could we get the jobState from that?
16:09:54 danpb mriedem: that VIR_DOMAIN_EVENT_SUSPENDED_MIGRATED just says that the guest has been paused, as a result of the live migration operation
16:10:03 danpb it doesn't say anything about the operation being success or failure
16:10:14 mriedem right, and that's our bug :)
16:10:18 danpb so you definitely can't assume success from that
16:11:22 mriedem right,
16:11:26 mriedem so i can remove that to fix this quick
16:11:39 mriedem or try to find the jobState from the domain and check the status?
16:11:42 dansmith Kevin_Zheng: okay I've changed my mind for the moment.. the api code is so generator-unfriendly that a quick hack to test this is more involved than I thought
16:11:59 danpb mriedem: if there's some action that needs to take place during the migration operation
16:12:18 danpb mriedem: then my gut feeling would be to hav the _live_migration_monitor thread take care of it
16:12:26 sean-k-mooney mriedem: well im not sure we need to change that code. where is the EVENT_LIFECYCLE_MIGRATION_COMPLETED event consumed because we have stopped moving stuff at this point we jsut dont know if it succeded
16:12:41 mriedem danpb: yeah most likely - and that's inline with what dansmith said on the review for this change
16:12:53 mriedem since it was baking libvirt logic into the compute manager lifecycle callback handler
16:13:09 danpb if the lifecycle events are needed, then forward those onto that thread too
16:13:09 mriedem sean-k-mooney: ComputeManager.handle_lifecycle_event
16:15:51 sean-k-mooney mriedem: so what we actully need to do is check the job status here https://github.com/openstack/nova/blob/master/nova/compute/manager.py#L1126-L1139
16:16:09 mriedem we're not going to do that in the compute manager
16:16:25 openstackgerrit Dan Smith proposed openstack/nova master: Batch results per cell when doing cross-cell listing https://review.openstack.org/592698
16:16:26 openstackgerrit Dan Smith proposed openstack/nova master: List instances from all cells explicitly https://review.openstack.org/593717
16:16:27 openstackgerrit Dan Smith proposed openstack/nova master: Make instance_list perform per-cell batching https://review.openstack.org/593131
16:16:58 openstackgerrit Eric Fried proposed openstack/nova master: [placement] Add /reshaper handler for POST https://review.openstack.org/576927
16:16:59 openstackgerrit Eric Fried proposed openstack/nova master: reshaper: Look up provider if not in inventories https://review.openstack.org/585033
16:17:00 openstackgerrit Eric Fried proposed openstack/nova master: Make get_allocations_for_resource_provider sane https://review.openstack.org/584598
16:17:01 openstackgerrit Eric Fried proposed openstack/nova master: Report client: Real get_allocs_for_consumer https://review.openstack.org/584599
16:17:02 openstackgerrit Eric Fried proposed openstack/nova master: Report client: get_allocations_for_provider_tree https://review.openstack.org/584648
16:17:03 openstackgerrit Eric Fried proposed openstack/nova master: Report client: _reshape helper, placement min bump https://review.openstack.org/585034
16:17:04 openstackgerrit Eric Fried proposed openstack/nova master: Report client: update_from_provider_tree w/reshape https://review.openstack.org/585049

Earlier   Later