Nova becomes slow when 1 controller down, extremely slow when 2 controllers are down

Other services also become slower, but not to the extent to which Nova does with this "nova list" example, especially considering there are no VMs in running the cloud. Let me know if you want any additional information, meanwhile I will try to debug this on my own.

Can you verify if nova consumes all that time and not keystone token validation?

Dmitry,

Could you please provide logs? atop dumps?

As I mentioned in the comment to https://bugs.launchpad.net/mos/+bug/1498867 we gave it a try on 9.0 release ISO and did not see anything like that.

If you have an environment where this is reproduced and can hand it to us for RCA, that would help a lot.

http://paste.openstack.org/raw/569256/ response time is not really consistent...

In [22]: times
Out[22]: [15.451, 16.227, 20.95, 1.543, 9.61, 2.434, 3.541, 9.432, 22.269]

In [23]: numpy.min(times)
Out[23]: 1.5429999999999999

In [24]: numpy.mean(times)
Out[24]: 11.273

In [25]: numpy.max(times)
Out[25]: 22.268999999999998

In [26]: numpy.std(times)
Out[26]: 7.4183978503897094

It would be nice to see haproxy and services logs...

Eugene,

Keystone may take some of this time, not sure how much. Other services however do not suffer - "neutron port-list" will be slow 2-3 times (7-8 seconds), then speeds up to 0.4 seconds stable. "glance image-list" is always fast, no slowdown detected. Nova is very consistently slow.

Roman,

I use MTE (you can search our Wiki for Mobile test environments), I have destroyed the environemnt for now because I need it for another support case, but I will try to launch one for you on a lab server today or tomorrow, bring it into 1 controller state and provide you with access (in Slack). You can also clone MTE, download the 9.0-regular env and start it on any Linux machine with enough RAM (16G enough) and an SSD.

Dmitry,

Are you sure you have enough memory on controller nodes? The information on the Wiki says it's 2 GB of RAM per node... That would mean you *always* use swap.

Roman,

I increased RAM to 4 GB for one of the controllers (which I left alive) in env.cfg to verify it's not an issue with RAM. ATOP did not show any significant swap activity, I checked that.

What is most interesting is that if I just move two controllers to standby mode and keep them online, then stop most services on them, like nova services, memcached, keystone, and the rest - nova is still fast. But when I shutdown - it becomes slow. I either have failed to sto pservices which impact the issue, or the fact that node is unreachable causes the slowdown. whereas when it is reachable but has no services it's ok.

typical scenario: 95% of the time consumed by two keystone operations: issuing the token (client requests it), service validates the token.

This issue has also been observed in a customer's env - 32 cores & 128GB ram on controllers.

I think it still points to keystone & memcached.
If you leave controller up, you get 'connection refused' which is instant.
If it's down, it's much longer delay before connection is considered timed out

Eugene is absolutely right: the problem is that two of three memcached servers are down and we wait $socket_timeout to understand that, as the node is down and can't reply with 'connection refused'.

Please note the timings:

root@node-2:~# time nova list
+----+------+--------+------------+-------------+----------+
| ID | Name | Status | Task State | Power State | Networks |
+----+------+--------+------------+-------------+----------+
+----+------+--------+------------+-------------+----------+

real 0m8.651s
user 0m0.590s
sys 0m0.109s

http://paste.openstack.org/show/569331/

^ as you can see in haproxy logs both Keystone and Nova slowed down (as they both use memcached: Keystone uses it directly and in nova-api it's keystone_authmiddleware which stores validated tokens in memcached).

strace'ing nova-api allows to see that we try to connect to a memcached server and wait $socket_timeout (3s by default):

http://paste.openstack.org/show/569327/

until we finally find a server thats works.

The memcache client we use allows to set $socket_timeout and $dead_retry (for how long to ignore this particular memcache server if we could not connect to it) values, but this is done per process and we run multiple forks of nova-api and keystone to handle concurrent requests, thus you'll need to "warm up" those first. When you do, you'll see, that nova-api responds quickly:

http://paste.openstack.org/show/570138/

On what we could do here:

1) we could tweak $socket_timeout and set it to a lower value in both keystone and nova configs, e.g. 1 second

2) we could increase $dead_retry to a bigger value in both keystone and nova configs, e.g. 300 seconds

optionally:

3) turn off caching token validation results for keystone_authmiddleware for nova-api

In the future, we could probably try to use haproxy for managing memcached backends, so that haproxy would regularly do health checks and remove "dead" memcached servers from the list. In this case nova and keystone would only know about the haproxy frontend endpoint. Both active-active and active-backup modes should be ok for us, as long as we use memcache as a cache (I may be wrong, but I think Keystone can use it for lock management).

Removing offline memcache servers from config and restarting nova-api and keystone is enough to bring nova back up to speed - of course this is a manual and temporary change only during the period when there is only 1 controller, but so is the crm policy change, so as a workaround I believe that is ok for now.

Still this issue should be visible even with 1 controller down, and we should try to implement a better approach to memcache.

We can fully imitate the current mamcache setup with haproxy and overcome this issue by making X endpoints (according to the amount of controllers). Each endpoint will point to a single controller. However, all endpoints will be accessible all the time aven if some controllers are down, thanks to HAProxy, so we will get rejects quickly from haproxy instead of timed out connections.

Incomplete - moved to 9.2

I suggest we either choose the option 3) from https://bugs.launchpad.net/mos/+bug/1621541/comments/13 (as nova-api seems to be the only service for which we configure caching of token validation in keystonemiddleware.auth_token by the means of memcached http://paste.openstack.org/show/585192/) or, alternatively, only point keystonemiddleware.auth_token to the *local* memcached, if we *really* want to reuse the results of token validation between multiple nova-api processes (we usually run multiple forks).

MOS DA team, could you please take a look at this one? ^

> or, alternatively, only point keystonemiddleware.auth_token to the *local* memcached, if we *really* want to reuse the results of token validation between multiple nova-api processes (we usually run multiple forks).

That will work.

I tested nova performance in such cases:

1) with this patch https://review.openstack.org/#/c/391869/, all controllers up:

http://paste.openstack.org/show/587643/

haproxy log - http://paste.openstack.org/show/587651/

2) with this patch https://review.openstack.org/#/c/391869/, 1 controller down:

http://paste.openstack.org/show/587644/

there are big times of request serving in keystone, it can be seen in haproxy log - http://paste.openstack.org/show/587649/

3) with this patch https://review.openstack.org/#/c/391869/, and keystone pointed to local memcached, 1 controller down:

http://paste.openstack.org/show/587647/

4) without patch https://review.openstack.org/#/c/391869/, keystone is pointed to local memcached, 1 controller down:

http://paste.openstack.org/show/587646/

So as you can see performance is improved only when:

nova.conf:
[keystone_authtoken]
memcached_servers=*local_ip*:port

AND

keystone.conf:
[cache]
memcache_servers = *local_ip*:port

so @bbobrov how do you think is it possible to set memcache_servers = *local_ip*:port in keystone.conf? or it can lead to some issues?

> how do you think is it possible to set memcache_servers = *local_ip*:port in keystone.conf? or it can lead to some issues?

It will definitely lead to issues. And should not be done.

Last time we tested things on scale, emulating production-like load, performance was worse, but acceptable. It is also known issue that first requests after controller shutdown take more time. I suggest you to make you not 10 queries, but 100 or 150, probably in parallel.

I did simple rally testing of booting/deleting 10 vms concurrently with and without fix (https://review.openstack.org/#/c/391869/):

http://paste.openstack.org/show/587773/

so it looks like the patch improves the situation, will drop the wip from it

fix for nova is merged to master - https://review.openstack.org/#/c/391869/

With one controller down time is 3-5sec, with two controllers down time is up to 7 secs.
Verified on:
cat /etc/fuel_build_id:
 495
cat /etc/fuel_build_number:
 495
cat /etc/fuel_release:
 9.0
cat /etc/fuel_openstack_version:
 mitaka-9.0
rpm -qa | egrep 'fuel|astute|network-checker|nailgun|packetary|shotgun':
 fuel-migrate-9.0.0-1.mos8662.noarch
 fuel-release-9.0.0-1.mos6359.noarch
 fuel-library9.0-9.0.0-1.mos8662.noarch
 fuel-openstack-metadata-9.0.0-1.mos8915.noarch
 shotgun-9.0.0-1.mos90.noarch
 python-fuelclient-9.0.0-1.mos363.noarch
 fuel-mirror-9.0.0-1.mos158.noarch
 fuel-utils-9.0.0-1.mos8662.noarch
 fuel-provisioning-scripts-9.0.0-1.mos8915.noarch
 fuel-9.0.0-1.mos6359.noarch
 nailgun-mcagents-9.0.0-1.mos782.noarch
 fuel-notify-9.0.0-1.mos8662.noarch
 rubygem-astute-9.0.0-1.mos782.noarch
 fuel-misc-9.0.0-1.mos8662.noarch
 fuel-ostf-9.0.0-1.mos947.noarch
 fuel-ui-9.0.0-1.mos2848.noarch
 fuel-nailgun-9.0.0-1.mos8915.noarch
 network-checker-9.0.0-1.mos77.x86_64
 fuel-agent-9.0.0-1.mos291.noarch
 python-packetary-9.0.0-1.mos158.noarch
 fuelmenu-9.0.0-1.mos276.noarch
 fuel-bootstrap-cli-9.0.0-1.mos291.noarch
 fuel-setup-9.0.0-1.mos6359.noarch

This issue was fixed in the openstack/fuel-library 11.0.0.0rc1 release candidate.

Why not haproxy to support memcached service?