Earlier  
Posted Nick Remark
#openstack-nova - 2020-04-20
23:22:30 sean-k-mooney abaindur: libvirt will check if the qemu and libvirt on each host support it
23:22:39 sean-k-mooney and only enable it if both do i belive
23:23:38 sean-k-mooney so in principal i dont think it would have a negitive effect just be aware that you would see different behavior migration too a host with it enabled vs migrating form a host with it enabled
23:24:23 sean-k-mooney i dont recall off the top of my head which config we check to enable it but i belive it would have a asymetric behavior as i think we only check one of them
23:25:52 sean-k-mooney abaindur: for what it si worth the port binding events shoudl work with or without post copy
23:27:12 sean-k-mooney _post_live_migration is the function that cleans up the image on the source node and finishes and work reqiured on the dest
23:28:05 sean-k-mooney if you are using a nova and neutron that do not support multiple port bining _post_live_migration_at_dest is where we will do the port binding
23:29:06 sean-k-mooney but in a nova that support neutron multiple port bindign api we will prebind the port on the souce and activate it either in responce to the live migrion even tor the start of _post_live_migration
23:29:16 abaindur yea, but we noticed that in pre-copy LV mode, the port binding activate call is sent towards the end of that function. And connectivity is disrupted when VM is Paused.
23:29:18 abaindur https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L6931
23:29:45 sean-k-mooney ya so are you using ovs with the ovs firewall driver by any chance
23:29:51 abaindur and here is where the port binding activation call is invoekd: https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L7005
23:29:52 sean-k-mooney or are you using iptables
23:30:42 abaindur between those 2 lines of code, we noticed nova taking 18+ seconds - 2 seocnds for bolume cleanup, few more seconds for disconnection, 5 sec for get_instance_nw_info, 5 more sec for compute_utils.notify_about_instance_action, etc...
23:31:01 abaindur One the port binding activate call came, another 3-5 seconds for port to be plugged by OVS-agent
23:31:04 abaindur we're using iptables
23:31:26 sean-k-mooney on what release
23:31:33 abaindur Rocky
23:31:49 sean-k-mooney the iptable firewall should have less downtime the openvswithc
23:32:34 sean-k-mooney as we can pre plug the port and have neutron wire it up while we are waiting for migration too happen at the libvirt level.
23:33:08 sean-k-mooney when using the ovs firewall driver because libvirt recreate the ovs port it takes longer as neutron has to do it twice
23:33:14 abaindur as mentioned, we're seeing non-trivial downtime in that _post_live_migration() function on the src host, between the log "'_post_live_migration() is started.." (or when VM is Paused), and when neutron receives the port-binding /activate call at https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L7005
23:33:40 sean-k-mooney abaindur: yes but before the multiple port binding change it used to be even longer
23:34:04 abaindur so is that down time then to be expected or unavoidable? :(
23:34:23 sean-k-mooney no its avoidable
23:34:31 sean-k-mooney so this is the feature you are trying to use https://specs.openstack.org/openstack/nova-specs/specs/rocky/implemented/neutron-new-port-binding-api.html
23:34:52 sean-k-mooney i did not think this required post-copy but let me double check
23:35:17 abaindur well thats why we were considering trying out post-copy - to see if it speeds up when nova makes the port binding call
23:35:30 sean-k-mooney ok so yes if you want the quick setup we are waiting for VIR_DOMAIN_EVENT_SUSPENDED_POSTCOPY
23:35:43 abaindur post-copy seems to trigger that call based on VIR_DOMAIN_EVENT states
23:36:14 abaindur pre-copy waits for that _post_live_migration() on the host to invoke network_api.migrate_instance_start(), which seems to take a while for us
23:36:29 sean-k-mooney that will allow us to activate the port bidning from the souce earlier then _post_live_migration
23:37:13 abaindur Right, thats why we will try post-copy mode. But was wondering if the downtime/delay we are seeing with pre-copy is expected or unavoidable?
23:37:19 sean-k-mooney abaindur: ya so it is a littl strange that your _post_live_migration function completion is os long
23:37:39 sean-k-mooney i would not expect _post_live_migration to take multiple seconds
23:38:41 abaindur what are downsides to post copy besides that VM needs to be rebooted if theres a live migration error?
23:39:06 abaindur and page faults may slow down the VM as memory needs to be copied over the network?
23:39:17 sean-k-mooney that is the main one. if there is a network outage while its still in post copy phase then the vm will crash
23:39:35 sean-k-mooney yes page falts acroos the network might beut all write happen locally
23:39:47 sean-k-mooney so the vm will only pause if it need to read un copied data
23:40:05 sean-k-mooney and once its copied local update to that will happen to the dest memmory
23:40:19 sean-k-mooney as you pointed out we are activating the port here https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L7005
23:40:54 sean-k-mooney which happen near the star of the function so the dely is likely related to cinder performance
23:41:10 sean-k-mooney abaindur: have you tried live migrating vms that dont have cinder volumes
23:41:28 abaindur yea, we tried VMs both volume and ephemeral based
23:41:42 sean-k-mooney did you see the same delay?
23:42:03 abaindur pretty much
23:42:24 abaindur timed the volume code with some logs of our own, heres what we observed:
23:42:36 abaindur 1.913 seconds for _get_instance_block_device_info and self.driver.post_live_migration
23:42:45 abaindur about 0.4 sec for self.driver.get_volume_connector(instance)
23:42:51 abaindur 2.659 seconds for self.volume_api.terminate_connection()
23:42:58 abaindur 3.28 seconds for network_info = self.network_api.get_instance_nw_info(ctxt, instance)
23:43:03 abaindur 5.019 seconds for self._notify_about_instance_usage(ctxt, instance, "live_migration._post.start", network_info=network_info)
23:43:16 abaindur another almost 5 seconds nova spent just making the port binding activate API call, seems to be spending time in keystone and oslo_concurrency.lockutils code
23:43:25 sean-k-mooney is that absolute time of time for each function
23:43:44 abaindur yea, we just added logs throughout that post_live_migration() function
23:43:56 abaindur before/after each of those calls to see what was taking so long
23:44:01 sean-k-mooney ok so i subtrac those numebr to get the time for each
23:44:07 sean-k-mooney that is still very slow
23:44:30 abaindur for example, in one live migration, we say: VM Paused at 25:06.192
23:44:39 sean-k-mooney abaindur: are you using memcache for you keysontone auth tokens
23:45:32 abaindur by time we saw nova-compute make the port binding call, it was at: 35:24.694
23:46:20 abaindur VM Paused at 35:06.192 *
23:46:49 sean-k-mooney abaindur: can you check your nova.conf and see if you have https://zuul.opendev.org/t/openstack/build/dcde79801a624c25b195a46ead7af562/log/controller/logs/etc/nova/nova-cpu_conf.txt#62-68
23:49:04 sean-k-mooney also 10 seconds to bind the port in precopy mode is too hight so there is something else hurting performance which is why im suspecign you do not have caching of keysotne configure correctly.
23:52:47 abaindur Ok no, memcache_servers is not set...
23:52:58 abaindur this is for nova compute on the hypervisor side right?
23:53:44 sean-k-mooney https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L6982-L7008 could be safely moved to https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L6939 by the way and in the libvirt case https://github.com/openstack/nova/blob/stable/rocky/nova/compute/manager.py#L6933 woudl be fine too.
23:53:57 sean-k-mooney am it will be used both on the contoler and computes
23:54:13 sean-k-mooney so you are missing
23:54:16 sean-k-mooney [keystone_authtoken]
23:54:18 sean-k-mooney memcached_servers = localhost:11211
23:54:25 sean-k-mooney or well your actull memcache servers
23:54:45 abaindur yeah, I dont see that config opt ever ok
23:54:49 sean-k-mooney this will be used to cach auth tokens for every api call we make
23:55:16 abaindur i dont see it ever set*
23:58:21 sean-k-mooney abaindur: so at least on the contoler side it has a significnat impact on the api
23:58:25 openstack Launchpad bug 1836642 in neutron "Metadata responses are very slow sometimes" [High,Incomplete] - Assigned to Slawek Kaplonski (slaweq)
23:58:25 sean-k-mooney https://bugs.launchpad.net/nova/+bug/1836642
23:58:53 sean-k-mooney we adress this porblem in the gate by truning on caching with https://github.com/openstack/devstack/commit/d33cdd01f83b891b010e0fd238f1816910f3fd77
23:59:18 abaindur I dont see it on controller either
23:59:25 sean-k-mooney i am not sure if i tis use dby the compute node but i think it will be whenever it is calling cinder neutron or placment
23:59:35 sean-k-mooney abaindur: its optional
23:59:49 sean-k-mooney but it improves perfromacne alot
#openstack-nova - 2020-04-21
00:00:01 abaindur so for pre-copy, you are suggesting to try memcache for keystone tokens?
00:00:29 sean-k-mooney ya but im not saying dont try enableing post-copy
00:00:48 sean-k-mooney im just sugging that memcache might impove the performace enough to not need it
00:00:54 sean-k-mooney i woudl test both
00:01:12 sean-k-mooney abaindur: how did you deploy openstack by the way
00:01:23 abaindur thanks, yea we'll probably try both options then to see which leads to least downtime
00:01:51 sean-k-mooney for both options is basically just a compute agent restart and cofig update
00:03:24 openstack Launchpad bug 1836642 in neutron "Metadata responses are very slow sometimes" [High,Incomplete] - Assigned to Slawek Kaplonski (slaweq)
00:03:24 sean-k-mooney abaindur: at least in the case of https://bugs.launchpad.net/nova/+bug/1836642 we were seeing edgcaces wher ethe metadta api respoce could take upwards of 12 - 16 seconds and that went away when we enabeld the cache
00:05:00 sean-k-mooney abaindur: although to be clear we enabel both the cache section and the memcahced_server in the keystone_authoken section
00:05:18 sean-k-mooney so all of the highlight section is how we adressed the isseu https://zuul.opendev.org/t/openstack/build/dcde79801a624c25b195a46ead7af562/log/controller/logs/etc/nova/nova-cpu_conf.txt#62-68
00:09:27 sean-k-mooney abaindur: https://docs.openstack.org/keystonemiddleware/latest/middlewarearchitecture.html#improving-response-time might be of interst
00:11:30 sean-k-mooney i think that might only be relevent to the apis service however and might not apply to when we use the keystone auth client to talk to otehr apis but im not sure baout that. anyway its late here so im going to go o/
00:11:58 abaindur sean-k-mooney: oh wait, we have memcached_servers set in keystone_authtoken
00:12:05 abaindur but we dont have a [cache] section with the other configs
00:12:37 sean-k-mooney ah the cache section is novas own internal cache config

Earlier   Later