Bug 1312605

Summary: Failure to install RDO Kilo via packstack on Fedora 23
Product: [Community] RDO Reporter: Boris Derzhavets <bderzhavets>
Component: openstack-novaAssignee: Russell Bryant <rbryant>
Status: CLOSED EOL QA Contact: nlevinki <nlevinki>
Severity: high Docs Contact:
Priority: unspecified    
Version: KiloCC: berrange, dasmith, eglynn, rbryant, sbauza, sferdjao, sgordon, srevivo, vromanso
Target Milestone: ---   
Target Release: Kilo   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-05-19 16:00:53 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Attachments:
Description Flags
nova-api.log is attached none

Description Boris Derzhavets 2016-02-27 19:20:42 UTC 
Created attachment 1131154 [details]
nova-api.log is attached

Description of problem:

System is installed via repo https://repos.fedorapeople.org/repos/openstack/openstack-kilo/f22/ ( it contains only f23 packages )
then `dnf -y install openstack-packstack`, run packstack AIO installation,
previously rebuilding pm-utils on F23, to avoid nova puppet failure to
install pm-utils on F23 and setting CONFIG_PROVISION_DEMO=n due to "y" results
crash provisioning demo with message "Nova API is unavailable".
The rest confirms that "Nova API" is unavailable in fact. 


When I try to launch VM error comes up in nova-api.log

2884d92687f44b395b0f360ae83c3a0 d3051803b4214d85b966576b893860de - - -] Caught error: id
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack Traceback (most recent call last):
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return req.get_response(self.application)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1317, in send
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     application, catch_exc_info=False)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1281, in call_application
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return resp(environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 634, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return self._call_app(env, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 554, in _call_app
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return self._app(env, _fake_start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return resp(environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return resp(environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     response = self.app(environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return resp(environ, start_response)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 756, in __call__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     content_type, body, accept)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 821, in _process_stack
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 911, in dispatch
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     return method(req=request, **action_args)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 636, in create
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     self._handle_create_exception(*sys.exc_info())
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 465, in _handle_create_exception
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     six.reraise(*exc_info)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/servers.py", line 621, in create
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     check_server_group_quota=check_server_group_quota)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/hooks.py", line 149, in inner
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     rv = f(*args, **kwargs)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1543, in create
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     check_server_group_quota=check_server_group_quota)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 1128, in _create_instance
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     image_id, boot_meta = self._get_image(context, image_href)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 818, in _get_image
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     image = self.image_api.get(context, image_href)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/image/api.py", line 93, in get
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     show_deleted=show_deleted)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 309, in show
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     include_locations=include_locations)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 483, in _translate_from_glance
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     include_locations=include_locations)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/image/glance.py", line 545, in _extract_attributes
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     queued = getattr(image, 'status') == 'queued'
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/glanceclient/openstack/common/apiclient/base.py", line 491, in __getattr__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     self.get()
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/glanceclient/openstack/common/apiclient/base.py", line 509, in get
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     new = self.manager.get(self.id)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/glanceclient/openstack/common/apiclient/base.py", line 494, in __getattr__
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack     raise AttributeError(k)
2016-02-27 21:41:18.368 2431 TRACE nova.api.openstack AttributeError: id


Version-Release number of selected component (if applicable):

[root@ip-192-169-142-52 ~(keystone_admin)]# rpm -qa \*nova\*
openstack-nova-conductor-2015.1.3-1.fc23.noarch
python-nova-2015.1.3-1.fc23.noarch
openstack-nova-common-2015.1.3-1.fc23.noarch
openstack-nova-cert-2015.1.3-1.fc23.noarch
openstack-nova-compute-2015.1.3-1.fc23.noarch
openstack-nova-console-2015.1.3-1.fc23.noarch
openstack-nova-api-2015.1.3-1.fc23.noarch
openstack-nova-novncproxy-2015.1.3-1.fc23.noarch
openstack-nova-scheduler-2015.1.3-1.fc23.noarch
python-novaclient-2.23.0-2.fc23.noarch


How reproducible:


Steps to Reproduce:
1. Install F23 , dnf -y update, SELINUX set to permissive,reboot
2. Enable repo  https://repos.fedorapeople.org/repos/openstack/openstack-kilo/f22/
3. dnf -y install openstack-packstack
4. generate answer-file setting CONFIG_KEYSTONE_SERVICE_NAME=httpd
5. packstack --answer-file=./answerAIO.txt
6. Tune ifcfg-br-ex and ifcfg-eth0 disabling NetworkManager and enabling
   service network,reboot. Create public,private networks,neutron router as   admin.Tune environment as usual.
7. Upload CirrOS 0.3.3 qcow2 image to glance
8. Attempt to launch VM 

Actual results:

Dashboard immediately reports server error.
Mentioned above trace every time comes to /var/log/nova/nova-api.log


Expected results:

VM gets activated, obtain private IP , may be assigned public IP
has in/outbound Internet connectivity
Additional info:
Comment 1 Boris Derzhavets 2016-02-27 19:52:45 UTC 
See also https://bugs.launchpad.net/python-glanceclient/+bug/1479296
In my case 
[root@ip-192-169-142-52 ~(keystone_admin)]# pip show python-glanceclient | grep ^Version
Version: 0.17.0
[root@ip-192-169-142-52 ~(keystone_admin)]# pip show glance-store | grep ^Version
Version: 0.4.0
Comment 2 Boris Derzhavets 2016-02-27 20:09:47 UTC 
Missed the last entry of trace :-

2016-02-27 21:24:26.473 2437 INFO nova.api.openstack [req-3bd20035-2915-486f-91bb-dd6d170007c6 f2884d92687f44b395b0f360ae83c3a0 d3051803b4214d85b966576b893860de - - -] http://192.169.142.52:8774/v2/d3051803b4214d85b966576b893860de/servers returned with HTTP 500
Comment 3 Boris Derzhavets 2016-02-27 23:22:02 UTC 
Hacking GlanceClient on F23 works for me in meantime  :-

https://review.openstack.org/gitweb?p=openstack/python-glanceclient.git;a=patch;h=eb1d8c5c94b8fac86c12f78732107b1034749c7f
Comment 4 Boris Derzhavets 2016-02-28 20:46:22 UTC 
Versions on python-urllib3 :-

RDO Kilo F23 -  1.13.1
RDO Kilo CentOS 7 - 1.10.1
RDO Liberty CentOS 7 - 1.10.4

I believe that is a reason why bug manifests on on Fedora 23 :  1.13.1 > 1.11.X
Patch helps on F23 due to per it's description :-

Subject: [PATCH] Convert headers to lower-case when parsing metadata

In urllib3 1.11.0 (and consequently, requests 2.8.0) handling was added
to preserve the casing of headers as they arrived over the wire. This
means that when iterating over a CaseInsensitiveDict from requests (as
we do in _image_meta_from_headers) we no longer get keys that are
already all lowercase. As a result, we need to ensure that the header
key is lowercased before checking its properties.
Comment 5 Chandan Kumar 2016-05-19 16:00:53 UTC 
This bug is against a Version which has reached End of Life.
If it's still present in supported release (http://releases.openstack.org), please update Version and reopen.