Client failing with six =>1.6 error

[Denis M.]

13:20:45 + screen -S stack -p key -X stuff 'cd /opt/stack/keystone && /opt/stack/keystone/bin/keystone-all --config-file /etc/keystone/keystone.conf --debug & echo $! >/opt/stack/status/stack/key.pid; fg || echo "key failed to start" | tee "/opt/stack/status/stack/key.failure"
'
13:20:45 Waiting for keystone to start...
13:20:45 + echo 'Waiting for keystone to start...'
13:20:45 + timeout 60 sh -c 'while ! curl --noproxy '\''*'\'' -k -s http://10.5.141.237:5000/v2.0/ >/dev/null; do sleep 1; done'
13:20:46 + is_service_enabled tls-proxy
13:20:46 ++ set +o
13:20:46 ++ grep xtrace
13:20:46 + local 'xtrace=set -o xtrace'
13:20:46 + set +o xtrace
13:20:46 + return 1
13:20:46 + SERVICE_ENDPOINT=http://10.5.141.237:35357/v2.0
13:20:46 + is_service_enabled tls-proxy
13:20:46 ++ set +o
13:20:46 ++ grep xtrace
13:20:46 + local 'xtrace=set -o xtrace'
13:20:46 + set +o xtrace
13:20:46 + return 1
13:20:46 + export OS_TOKEN=be19c524ddc92109a224
13:20:46 + OS_TOKEN=be19c524ddc92109a224
13:20:46 + export OS_URL=http://10.5.141.237:35357/v2.0
13:20:46 + OS_URL=http://10.5.141.237:35357/v2.0
13:20:46 + create_keystone_accounts
13:20:46 ++ openstack project create admin
13:20:46 ++ grep ' id '
13:20:46 ++ get_field 2
13:20:46 ++ read data
13:20:46 ERROR: openstackclient.shell Exception raised: six>=1.6.0
13:20:46 + ADMIN_TENANT=
13:20:46 ++ openstack user create admin --project '' --email <email address hidden> --password 3de4922d8b6ac5a1aad9
13:20:46 ++ grep ' id '
13:20:46 ++ get_field 2
13:20:46 ++ read data
13:20:47 ERROR: openstackclient.shell Exception raised: six>=1.6.0
13:20:47 + ADMIN_USER=
13:20:47 ++ openstack role create admin
13:20:47 ++ grep ' id '
13:20:47 ++ get_field 2
13:20:47 ++ read data
13:20:47 ERROR: openstackclient.shell Exception raised: six>=1.6.0
13:20:47 + ADMIN_ROLE=
13:20:47 + openstack role add --project --user
13:20:47 ERROR: openstackclient.shell Exception raised: six>=1.6.0
13:20:47 + exit_trap
13:20:47 + local r=1
13:20:47 ++ jobs -p
13:20:47 + jobs=
13:20:47 + [[ -n '' ]]
13:20:47 + kill_spinner
13:20:47 + '[' '!' -z '' ']'
13:20:47 + exit 1

https://rdjenkins.dyndns.org/job/Trove-Gate/3974/console

[SnowDust (nilakhya-chatterjee)]

cliff is throwing the error as its not able to find "six"

> /usr/lib/python2.7/dist-packages/pkg_resources.py(576)resolve()
-> dist = best[req.key] = env.best_match(req, self, installer)
(Pdb) req
Requirement.parse('six>=1.6.0')
(Pdb) installer
(Pdb) env.best_match(req,self,installer)
(Pdb) n
> /usr/lib/python2.7/dist-packages/pkg_resources.py(577)resolve()
-> if dist is None:
(Pdb) n
> /usr/lib/python2.7/dist-packages/pkg_resources.py(584)resolve()
-> raise DistributionNotFound(req)

[SnowDust (nilakhya-chatterjee)]

more info for the cliff call, at line 67

/usr/local/lib/python2.7/dist-packages/cliff/commandmanager.py

 58 search_args = argv[:]
 59 name = ''
 60 while search_args:
 61 if search_args[0].startswith('-'):
 62 raise ValueError('Invalid command %r' % search_args[0])
 63 next_val = search_args.pop(0)
 64 name = '%s %s' % (name, next_val) if name else next_val
 65 if name in self.commands:
 66 cmd_ep = self.commands[name]
 67 cmd_factory = cmd_ep.load()
 68 return (cmd_factory, name, search_args)

[Doug Hellmann (doug-hellmann)]

This sort of error is usually caused by conflicting requirements between different python packages. Something may want a specific version of six which is less than the version wanted by cliff. To find what package that is, you need to study the log of what was installed and watch for messages about uninstalling six to install a different version.

[Karl Hallin (kjhallin)]

Scanning the log file, this seems to be oslo.config, which has this dialog in my stack.sh.log:

2014-06-05 18:13:39.079 | Downloading/unpacking six>=1.5.2 (from oslo.config)
2014-06-05 18:13:39.080 | Downloading six-1.6.1-py2.py3-none-any.whl
2014-06-05 18:13:39.082 | Storing download in cache at /var/cache/pip/https%3A%2F%2Fpypi.python.org%2Fpackages%2F3.3%2Fs%2Fsix%2Fsix-1.6.1-py2.py3-none-any.whl
2014-06-05 18:13:39.083 | Installing collected packages: oslo.config, six
2014-06-05 18:13:39.085 | Running setup.py install for oslo.config
2014-06-05 18:13:39.087 | [pbr] Reusing existing SOURCES.txt
2014-06-05 18:13:39.088 | Skipping installation of /usr/local/lib/python2.7/dist-packages/oslo/__init__.py (namespace package)
2014-06-05 18:13:39.090 | Installing /usr/local/lib/python2.7/dist-packages/oslo.config-1.3.0-nspkg.pth
2014-06-05 18:13:39.092 | Successfully installed oslo.config six
2014-06-05 18:13:39.093 | Cleaning up...
2014-06-05 18:13:39.095 | + sudo rm -rf /tmp/pip-build.Ql6m3
2014-06-05 18:13:39.096 | + sudo /usr/local/bin/pip uninstall -y oslo.config
2014-06-05 18:13:39.098 | Uninstalling oslo.config:
2014-06-05 18:13:39.100 | Successfully uninstalled oslo.config
2014-06-05 18:13:39.101 | + git_clone git://git.openstack.org/openstack/cliff.git /opt/stack/cliff master

then later when keystone tries to make accounts, we see this:

2014-06-05 18:24:30.449 | + export OS_TOKEN=a682f596-76f3-11e3-b3b2-e716f9080d50
2014-06-05 18:24:30.450 | + OS_TOKEN=a682f596-76f3-11e3-b3b2-e716f9080d50
2014-06-05 18:24:30.452 | + export OS_URL=http://192.168.122.174:35357/v2.0
2014-06-05 18:24:30.453 | + OS_URL=http://192.168.122.174:35357/v2.0
2014-06-05 18:24:30.455 | + create_keystone_accounts
2014-06-05 18:24:30.456 | ++ openstack project create admin
2014-06-05 18:24:30.458 | ++ grep ' id '
2014-06-05 18:24:30.459 | ++ get_field 2
2014-06-05 18:24:30.461 | ++ read data
2014-06-05 18:24:30.462 | ERROR: openstackclient.shell Exception raised: six>=1.6.0
2014-06-05 18:24:30.464 | + ADMIN_TENANT=
2014-06-05 18:24:30.465 | ++ get_field 2
2014-06-05 18:24:30.467 | ++ grep ' id '
2014-06-05 18:24:30.468 | ++ read data
2014-06-05 18:24:30.469 | ++ openstack user create admin --project '' --email <email address hidden> --password nomoresecrete
2014-06-05 18:24:30.471 | ERROR: openstackclient.shell Exception raised: six>=1.6.0
2014-06-05 18:24:30.472 | + ADMIN_USER=
2014-06-05 18:24:30.474 | ++ openstack role create admin
2014-06-05 18:24:30.476 | ++ grep ' id '
2014-06-05 18:24:30.477 | ++ get_field 2
2014-06-05 18:24:30.478 | ++ read data
2014-06-05 18:24:30.480 | ERROR: openstackclient.shell Exception raised: six>=1.6.0
2014-06-05 18:24:30.481 | + ADMIN_ROLE=
2014-06-05 18:24:30.483 | + openstack role add --project --user
2014-06-05 18:24:30.484 | ERROR: openstackclient.shell Exception raised: six>=1.6.0
2014-06-05 18:24:30.486 | + exit_trap
2014-06-05 18:24:30.487 | + local r=1
2014-06-05 18:24:30.489 | ++ jobs -p
2014-06-05 18:24:30.490 | + jobs=
2014-06-05 18:24:30.492 | + [[ -n '' ]]
2014-06-05 18:24:30.493 | + kill_spinner
2014-06-05 18:24:30.495 | + '[' '!' -z '' ']'
2014-06-05 18:24:30.496 | + exit 1

[Doug Hellmann (doug-hellmann)]

oslo.config seems to be causing the first installation of a version that cliff should find acceptable. Is there another place where six is installed with a different required version? It will probably say "Found existing installation: six" with a version number after it, and then "Uninstalling six" followed by messages about installing six.

[Denis M. (dmakogon)]

Doug, oslo.config https://github.com/openstack/oslo.config/blob/master/requirements.txt#L2 has correct requirement at upstream, i would say that we need to release new version of oslo.config because it blocks gate jobs.

[Denis M. (dmakogon)]

It seems that several projects have old vesrion of oslo.config, 1.2.0 still have old version of six.

https://github.com/openstack/keystone/blob/master/requirements.txt#L17 - => 1.2.0
etc ...

[Denis M. (dmakogon)]

The easiest solution is to update oslo.config version in
https://github.com/openstack/requirements/blob/master/global-requirements.txt#L51 and, i hope, it'll fix our problems.

[Doug Hellmann (doug-hellmann)]

Because oslo.config has an unbounded requirement on six, it will always install the newest version. In this case, oslo.config clearly installed version 1.6.1 of six, which meets cliff's requirements of >=1.6.0.

[Denis M. (dmakogon)]

oslo.config 1.2.0 has bounded six version
https://github.com/openstack/oslo.config/commit/a55037577a69b6c3c7e425f1da7bea1575a93a8f
All projects are using oslo.config 1.2.0

As i said, we probably update version of oslo.config in global requirements and then sync them into all other projects.

[Karl Hallin (kjhallin)]

Just in case it helps, a grep for every reference to six in my failing log is here:

2014-06-05 18:13:39.079 | Downloading/unpacking six>=1.5.2 (from oslo.config)
2014-06-05 18:13:39.080 | Downloading six-1.6.1-py2.py3-none-any.whl
2014-06-05 18:13:39.082 | Storing download in cache at /var/cache/pip/https%3A%2F%2Fpypi.python.org%2Fpackages%2F3.3%2Fs%2Fsix%2Fsix-1.6.1-py2.py3-none-any.whl
2014-06-05 18:13:39.083 | Installing collected packages: oslo.config, six
2014-06-05 18:13:39.092 | Successfully installed oslo.config six
2014-06-05 18:13:52.885 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from cliff==1.6.1.2.g4bdf5fc)
2014-06-05 18:13:57.273 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from oslo.config==1.3.0.17.gdcef87a)
2014-06-05 18:14:14.340 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from oslo.messaging==1.3.0.41.gea989b8)
2014-06-05 18:14:18.771 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from oslo.rootwrap==1.2.0.3.gb7a1a7b)
2014-06-05 18:14:30.173 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from oslo.vmware==0.3.22.gc4e0294)
2014-06-05 18:14:40.698 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from pycadf==0.5.1.1.g6ac5531)
2014-06-05 18:15:05.487 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from taskflow==0.3.10.g598cd79)
2014-06-05 18:15:14.160 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-keystoneclient==0.9.0.4.g53a175e)
2014-06-05 18:15:19.601 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-keystoneclient>=0.9.0->python-glanceclient==0.12.0.100.g08aaa46)
2014-06-05 18:15:25.079 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-cinderclient==1.0.9.4.g1f7a95f)
2014-06-05 18:15:28.065 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-novaclient==2.17.0.128.g15ac2c9)
2014-06-05 18:15:29.003 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-swiftclient==2.1.0.9.g3d0de79)
2014-06-05 18:15:35.377 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-neutronclient==2.3.4.70.g6cec9fe)
2014-06-05 18:15:38.858 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from python-heatclient==0.2.9.21.gc29e863)
2014-06-05 18:15:44.328 | Requirement already satisfied (use --upgrade to upgrade): six>=1.6.0 in /usr/local/lib/python2.7/dist-packages (from pyt...

[Doug Hellmann (doug-hellmann)]

@Karl, can you post the full log somewhere?

[Karl Hallin (kjhallin)]

I would, but I just scrapped the disk. I can regenerate it quickly tho.

[Karl Hallin (kjhallin)]

this is the original log. I found it.

[Mathieu Mitchell (mat128)]

More logs in 1326925. Same symptoms.

[Doug Hellmann (doug-hellmann)]

@Denis, oslo.config has a *lower* bound for six. It does not have an upper bound.

If this is devstack, oslo.config should be installed from source anyway. Are all of your repositories in /opt/stack up to date?

I'm running devstack on a clean VM right now to try to reproduce this.

[Doug Hellmann (doug-hellmann)]

In a discussion in #openstack-infra, mgagne reported that this problem is caused by https://github.com/openstack-dev/devstack/commit/7b63c5ec9e9aea54024105a6521a754efc9f9983 which changes the version of pip devstack installs. The newer version of pip apparently resolves dependencies differently from 1.4.1, which is the last version known to work.

[Doug Hellmann (doug-hellmann)]

I can't reproduce this locally. Can someone with the problem post their localrc so I can see what services are enabled in devstack?

[Doug Hellmann (doug-hellmann)]

It would also help to have the output of "pip freeze" on a system where things are broken.

[LaMs (sylvain-lamontagne)]

Pip freeze for an affected system:
https://gist.github.com/slamont/c01a591b1dac450f7e84

[Nikhil Manchanda (slicknik)]

It looks like a setuptools issue.

If you're using an older version of setuptools, (prior to 0.6.28) it doesn't understand .dist-info and so it doesn't see the six package as installed.

[Nikhil Manchanda (slicknik)]

I can confirm that upgrading setuptools (explicitly by 'pip install --upgrade setuptools') fixes the issue.

[Mathieu Gagné (mgagne)]

Updating setuptools to the latest version right after installing pip looks to fix the issue.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/98263

[John Garbutt (johngarbutt)]

This happens for me on Ubuntu 12.04

[Chris Wessels (undefined-za)]

For those running devstack in a Vagrant VM, I've pushed a configuration that works around this bug here: https://github.com/chriswessels/vagrant-devstack/tree/pip_fix

[Mathieu Gagné (mgagne)]

Here is a bit more details about the issue:

Previously, in devstack, pip was installed by downloading a specific version (1.4.1) from a tarball from pypi. Since devstack 7b63c5e [1], pip is now installed with get-pip.py. Until recently, the version installed by get-pip.py was 1.4.1.

At about the same time, get-pip.py has been updated [2] to install pip 1.5.6 instead.

Beginning with pip 1.5.1, you don't need to have setuptools installed prior to pip installation. If setuptools is not found, it will be installed for you, otherwise it won't. Note that no particular setuptools version is required. [3]

How does it relate to the six package? Well, it looks like the six package is installed from wheel. (which uses the .dist-info directory)

Support for .dist-info directories (used by wheel packages) was added in setuptools 0.6.28. Ubuntu Precise 12.04 provides setuptools 0.6.24 [4] which is too old for our needs.

Although pip now bundles setuptools (since 1.5.1) [3], other packages are still using the system version of setuptools to discover installed packages. For six to be found by other packages, we need to install/update setuptools >= 0.6.28.

This is why we need to update setuptools to the latest to provide us the needed version to make six discoverable again.

[1] https://github.com/openstack-dev/devstack/commit/7b63c5ec9e9aea54024105a6521a754efc9f9983
[2] https://github.com/pypa/pip/commit/2b0b2f8ff3d5fc8674665c847cf9b1947f70418b
[3] http://pip.readthedocs.org/en/latest/news.html
[4] http://packages.ubuntu.com/precise/python-setuptools

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/98263
Committed: https://git.openstack.org/cgit/openstack-dev/devstack/commit/?id=76ed427ca17fb271974b4882c0b5e3c18ed3d889
Submitter: Jenkins
Branch: master

commit 76ed427ca17fb271974b4882c0b5e3c18ed3d889
Author: Mathieu Gagné <email address hidden>
Date: Thu Jun 5 16:50:40 2014 -0400

    Update setuptools to latest for .dist-info support

    Support for .dist-info directories was added in setuptools 0.6.28.

    At this moment, Ubuntu Precise 12.04 provides setuptools 0.6.24
    which is too old for our needs.

    Six is installed from wheel which uses the .dist-info directory.
    For six to be found, we need to install setuptools >= 0.6.28.

    Updating setuptools to the latest version using pip will provide use
    the needed version to make six discoverable.

    Closes-bug: #1326811
    Change-Id: I761d0aeb2b8b593cee38d512afc8fed6a2d1fe37