Unexpected API Error: oslo_config.cfg.ConfigFileValueError

[Rich Art]

OpenStack version: Newton

$ dpkg -l | grep nova
ii nova-api 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - API frontend
ii nova-common 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - common files
ii nova-conductor 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - conductor service
ii nova-consoleauth 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - Console Authenticator
ii nova-novncproxy 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - NoVNC proxy
ii nova-scheduler 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute - virtual machine scheduler
ii python-nova 2:14.0.1-0ubuntu1~cloud0 all OpenStack Compute Python libraries
ii python-novaclient 2:6.0.0-0ubuntu1~cloud0 all client library for OpenStack Compute API - Python 2.7

When issuing:
openstack server create --flavor m1.nano --image cirros --nic net-id=84afca3b-da51-45a5-aaa1-f49d7302da48 --security-group default --key-name mykey provider-instance

I get following error:
Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_config.cfg.ConfigFileValueError'> (HTTP 500) (Request-ID: req-c4d4fb05-26d1-4ea7-8261-79553c7bf000)

here is the Nova API log:
2016-11-04 22:44:09.094 22682 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 294, in switch
2016-11-04 22:44:09.094 22682 ERROR sqlalchemy.pool.QueuePool return self.greenlet.switch()
2016-11-04 22:44:09.094 22682 ERROR sqlalchemy.pool.QueuePool GreenletExit
2016-11-04 22:44:09.094 22682 ERROR sqlalchemy.pool.QueuePool
2016-11-04 22:44:09.145 22683 INFO oslo_service.service [-] Parent process has died unexpectedly, exiting
2016-11-04 22:44:09.146 22683 INFO nova.wsgi [-] Stopping WSGI server.
2016-11-04 22:44:09.147 22683 INFO nova.wsgi [-] Stopping WSGI server.
2016-11-04 22:44:09.159 22687 INFO oslo_service.service [-] Parent process has died unexpectedly, exiting
2016-11-04 22:44:09.160 22687 INFO nova.wsgi [-] Stopping WSGI server.
2016-11-04 22:44:09.161 22687 INFO nova.wsgi [-] Stopping WSGI server.
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool [req-00fcf45d-96b5-424b-ad93-52aa38e6000d - - - - -] Exception during reset or similar
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool Traceback (most recent call last):
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 636, in _finalize_fairy
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool fairy._reset(pool)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 774, in _reset
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self._reset_agent.rollback()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1563, in rollback
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self._do_rollback()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1601, in _do_rollback
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self.connection._rollback_impl()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 670, in _rollback_impl
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self._handle_dbapi_exception(e, None, None, None, None)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1353, in _handle_dbapi_exception
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self.engine.pool._invalidate(dbapi_conn_wrapper, e)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 340, in _invalidate
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool connection.invalidate(exception)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 843, in invalidate
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self._checkin()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 758, in _checkin
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool self._pool, None, self._echo, fairy=self)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 650, in _finalize_fairy
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool connection_record.checkin()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 509, in checkin
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool pool.dispatch.checkin(connection, self)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/sqlalchemy/event/attr.py", line 256, in __call__
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool fn(*args, **kw)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py", line 50, in _thread_yield
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool time.sleep(0)
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 34, in sleep
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool hub.switch()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 294, in switch
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool return self.greenlet.switch()
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool GreenletExit
2016-11-04 22:44:09.161 22687 ERROR sqlalchemy.pool.QueuePool

[Matt Riedemann (mriedem)]

Where is the actual ConfigFileValueError stacktrace?

[Matt Riedemann (mriedem)]

This might be a duplicate of bug 1632538.

[Rich Art (riccardo-patane-ch)]

where can I find the actual ConfigFileValueError stacktrace?
From the Nova API log?

[Rich Art (riccardo-patane-ch)]

What about this:

2016-11-04 23:51:46.690 29720 INFO nova.wsgi [req-03b32a34-c385-418e-b765-f1a0fc97d6aa - - - - -] metadata listening on 0.0.0.0:8775
2016-11-04 23:51:46.692 29720 INFO oslo_service.service [req-03b32a34-c385-418e-b765-f1a0fc97d6aa - - - - -] Starting 8 workers
2016-11-04 23:51:46.772 29720 CRITICAL nova [req-03b32a34-c385-418e-b765-f1a0fc97d6aa - - - - -] ConfigFileValueError: Value for option url is not valid: invalid URI: 'http://openstack-controller:9696'
2016-11-04 23:51:46.772 29720 ERROR nova Traceback (most recent call last):
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/bin/nova-api", line 10, in <module>
2016-11-04 23:51:46.772 29720 ERROR nova sys.exit(main())
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/nova/cmd/api.py", line 73, in main
2016-11-04 23:51:46.772 29720 ERROR nova launcher.wait()
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/oslo_service/service.py", line 568, in wait
2016-11-04 23:51:46.772 29720 ERROR nova self.conf.log_opt_values(LOG, logging.DEBUG)
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/oslo_config/cfg.py", line 2626, in log_opt_values
2016-11-04 23:51:46.772 29720 ERROR nova _sanitize(opt, getattr(group_attr, opt_name)))
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/oslo_config/cfg.py", line 3057, in __getattr__
2016-11-04 23:51:46.772 29720 ERROR nova return self._conf._get(name, self._group)
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/oslo_config/cfg.py", line 2668, in _get
2016-11-04 23:51:46.772 29720 ERROR nova value = self._do_get(name, group, namespace)
2016-11-04 23:51:46.772 29720 ERROR nova File "/usr/lib/python2.7/dist-packages/oslo_config/cfg.py", line 2711, in _do_get
2016-11-04 23:51:46.772 29720 ERROR nova % (opt.name, str(ve)))
2016-11-04 23:51:46.772 29720 ERROR nova ConfigFileValueError: Value for option url is not valid: invalid URI: 'http://openstack-controller:9696'
2016-11-04 23:51:46.772 29720 ERROR nova
2016-11-04 23:51:47.019 29908 INFO nova.metadata.wsgi.server [req-552dbbd2-67a5-46ba-833a-bae7decb0574 - - - - -] (29908) wsgi starting up on http://0.0.0.0:8775
2016-11-04 23:51:47.164 29914 INFO nova.metadata.wsgi.server [req-e7d7e52d-233b-43a7-a873-8b0131056e86 - - - - -] (29914) wsgi starting up on http://0.0.0.0:8775
2016-11-04 23:51:47.164 29907 INFO nova.metadata.wsgi.server [req-8281b638-af19-4d56-92fc-c8e06b918d2e - - - - -] (29907) wsgi starting up on http://0.0.0.0:8775
2016-11-04 23:51:47.226 29909 INFO nova.metadata.wsgi.server [req-e21d65f8-ba57-4c0f-b400-10d5d1a84f6e - - - - -] (29909) wsgi starting up on http://0.0.0.0:8775
2016-11-04 23:51:47.233 29914 INFO oslo_service.service [-] Parent process has died unexpectedly, exiting
2016-11-04 23:51:47.233 29914 INFO nova.wsgi [-] Stopping WSGI server.
2016-11-04 23:51:47.233 29860 INFO oslo_service.service [-] Parent process has died unexpectedly, exiting
2016-11-04 23:51:47.234 29914 INFO nova.metadata.wsgi.server [req-e7d7e52d-233b-43a7-a873-8b0131056e86 - - - - -] (29914) wsgi exited,...

[Matt Riedemann (mriedem)]

2016-11-04 23:51:46.772 29720 CRITICAL nova [req-03b32a34-c385-418e-b765-f1a0fc97d6aa - - - - -] ConfigFileValueError: Value for option url is not valid: invalid URI: 'http://openstack-controller:9696'

Yeah, it's likely a duplicate of bug 1632538.

[Rich Art (riccardo-patane-ch)]

Matt, so how can I fix my problem? I cannot create VMs.

[Julio César García Vizcaíno (z-julio-b)]

Hi,

I also have the same bug. I attach my log in case that you may need it.