openstack server list is very slow and makes too many HTTP connections

[Scott Moser]

'openstack server list' does an obscene number of HTTP requests (228 in my case) and as a result is very slow compared to 'nova list'.

By comparison, the 'nova list' command does 6.

$ openstack --debug server list > openstack.log 2>&1

real 1m48.731s
user 0m4.702s
sys 0m0.648s

$ time sstack nova --debug list >nova.log 2>&1

real 0m3.726s
user 0m1.192s
sys 0m0.105s

$ grep "GET call" nova.log | wc -l
6
$ grep "GET call" nova.log
DEBUG (session:727) GET call to None for http://10.245.161.156:5000/v3 used request id req-4c5db33a-c502-4a9e-af8b-e70a6f81a55a
GET call to compute for http://10.245.161.158:8774/v2/6286a8c4f88046b3bdf25b26ff54f1f7 used request id req-892262ec-34a9-487e-8658-b1f9ecf4e239
DEBUG (session:727) GET call to compute for http://10.245.161.158:8774/v2/6286a8c4f88046b3bdf25b26ff54f1f7 used request id req-892262ec-34a9-487e-8658-b1f9ecf4e239
GET call to compute for http://10.245.161.158:8774/v2/ used request id req-ab5317ec-a5d8-47b3-834e-f31911572c79
DEBUG (session:727) GET call to compute for http://10.245.161.158:8774/v2/ used request id req-ab5317ec-a5d8-47b3-834e-f31911572c79
DEBUG (session:727) GET call to compute for http://10.245.161.158:8774/v2/6286a8c4f88046b3bdf25b26ff54f1f7/servers/detail used request id req-842ce3f0-5922-45c7-98c2-5bda07cea0ba

$ grep "GET call" openstack.log | wc -l
228

$ grep "GET call" openstack.log
43:59:565650 1.331658 E: GET call to None for http://10.245.161.156:5000/v3 used request id req-0566d19a-3d41-467b-a1aa-bf1340ddefea
44:02:139020 3.905028 E: GET call to compute for http://10.245.161.158:8774/v2/6286a8c4f88046b3bdf25b26ff54f1f7/servers/detail used request id req-07e69f11-f5ba-4460-81f4-8804133db08f
44:02:807981 4.573989 E: GET call to image for http://10.245.161.161:9292/v2/images?limit=20 used request id req-e7c36766-66a0-4555-9a1b-5ac04a61c7ea
44:02:927457 4.693465 E: GET call to image for http://10.245.161.161:9292/v2/schemas/image used request id req-840b87f7-8d99-40bf-8790-e1dd08ec5fef
44:03:310571 5.076579 E: GET call to image for http://10.245.161.161:9292/v2/images?marker=3142f9ea-bc61-4bbf-a298-e7046e095030&limit=20 used request id req-e7c36766-66a0-4555-9a1b-5ac04a61c7ea
44:03:734247 5.500255 E: GET call to image for http://10.245.161.161:9292/v2/images?marker=de2dc82c-699c-4a68-bb1b-3232a8260235&limit=20 used request id req-e7c36766-66a0-4555-9a1b-5ac04a61c7ea
-- trim 220 similar lines --
45:46:275745 108.041753 E: GET call to image for http://10.245.161.161:9292/v2/images?marker=8018dfff-c22d-47f0-9006-9cc17a59a2ff&limit=20 used request id req-e7c36766-66a0-4555-9a1b-5ac04a61c7ea
45:46:828523 108.594531 E: GET call to compute for http://10.245.161.158:8774/v2/6286a8c4f88046b3bdf25b26ff54f1f7/flavors/detail used request id req-3ef93de0-fbb2-426d-9e1b-c00e35208e1f

ProblemType: Bug
DistroRelease: Ubuntu 17.10
Package: python-openstackclient 3.12.0-0ubuntu2
ProcVersionSignature: Ubuntu 4.13.0-16.19-generic 4.13.4
Uname: Linux 4.13.0-16-generic x86_64
NonfreeKernelModules: zfs zunicode zavl zcommon znvpair
ApportVersion: 2.20.7-0ubuntu3
Architecture: amd64
CurrentDesktop: ubuntu:GNOME
Date: Tue Oct 24 13:00:53 2017
EcryptfsInUse: Yes
InstallationDate: Installed on 2015-07-23 (824 days ago)
InstallationMedia: Ubuntu 15.10 "Wily Werewolf" - Alpha amd64 (20150722.1)
PackageArchitecture: all
ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: python-openstackclient
UpgradeStatus: No upgrade log present (probably fresh install)

[Scott Moser (smoser)]

for some more information, 'glance' is similarly slow.
We do have a large number of images (~4500).

$ time sstack glance --debug image-list >glance.log 2>&1

real 1m58.700s
user 0m4.506s
sys 0m0.413s

$ grep "GET.call" glance.log | wc -l
226

$ grep '^|' glance.log | wc -l
4476

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Scott Moser (smoser)]

Before someone responds complaining that 4500 images is too much and that is the problem, lets compare this to another popular public cloud:

$ time euca-describe-images --region=us-east-1 --all > ec2-us-east-1.log

real 0m29.942s
user 0m16.641s
sys 0m0.283s

$ grep ^IMAGE ec2-us-east-1.log | wc -l
93547

[Ian Kumlien (pomac)]

openstack --debug server list --long >server-log-debug 2>&1

grep curl server-log-debug |wc -l
45

grep curl server-log-debug |grep "images?marker=" |wc -l
40

So we actually have to list all images, in multiple requests for some reason? Isn't this highly inefficient?

[Ian Kumlien (pomac)]

time openstack server list

real 0m20.751s
user 0m4.244s
sys 0m0.248s
---
time openstack server list --name-lookup-one-by-one

real 0m2.710s
user 0m1.648s
sys 0m0.177s
---

I'm also wondering why you don't get shared (according to project), public and owned (again project) images - you'd think that it'd be less than *all*

[Ian Kumlien (pomac)]

Something like this actually makes it tolerable, the assumption is that the amount of images in the project is not that unique... And this is just a quick hack that I hope inspires a proper solution - it's most likely not in the proper location etc etc etc

time openstack server list

real 0m2.853s
user 0m1.756s
sys 0m0.195s

git stash
Saved working directory and index state WIP on master: 4e9b9298 Allow setting gateway when creating a router

time openstack server list

real 0m20.254s
user 0m4.216s
sys 0m0.240s

git diff
diff --git a/openstackclient/compute/v2/server.py b/openstackclient/compute/v2/server.py
index a18ce810..dd4c6957 100644
--- a/openstackclient/compute/v2/server.py
+++ b/openstackclient/compute/v2/server.py
@@ -2441,6 +2441,9 @@ class ListServer(command.Lister):
             marker=marker_id,
             limit=parsed_args.limit)

+ if not parsed_args.all_projects:
+ parsed_args.name_lookup_one_by_one = True
+
         images = {}
         flavors = {}
         if data and not parsed_args.no_name_lookup: