一次devstack环境创建vm失败的调试过程




问题比较简单,就是搭好了Mitaka版本devstack环境后(nova+neutron+glance+keystone+cinder),nova boot创建vm,nova-api一直报错:

2017-09-19 15:10:37.263 ERROR nova.api.openstack.extensions [req-326f3a8c-4b51-4f69-bf97-a70bc2c456b4 admin admin] Unexpected exception in API method
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions Traceback (most recent call last):
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return f(*args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return func(*args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return func(*args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return func(*args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 629, in create
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     **create_kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/hooks.py", line 154, in inner
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     rv = f(*args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 1563, in create
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     check_server_group_quota=check_server_group_quota)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 1146, in _create_instance
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     reservation_id, max_count)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 835, in _validate_and_build_base_options
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     requested_networks, max_count)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/compute/api.py", line 449, in _check_requested_networks
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     max_count)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/network/api.py", line 49, in wrapped
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return func(self, context, *args, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/network/api.py", line 399, in validate_networks
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     requested_networks)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/opt/stack/nova/nova/network/rpcapi.py", line 212, in validate_networks
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return self.client.call(ctxt, 'validate_networks', networks=networks)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 413, in call
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     return self.prepare().call(ctxt, method, **kwargs)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 158, in call
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     retry=self.retry)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     timeout=timeout, retry=retry)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 470, in send
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     retry=retry)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 459, in _send
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     result = self._waiter.wait(msg_id, timeout)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 342, in wait
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     message = self.waiters.get(msg_id, timeout=timeout)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 244, in get
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions     'to message ID %s' % msg_id)
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions MessagingTimeout: Timed out waiting for a reply to message ID 75675446dc7b46f8a9818350bf9f6f36
2017-09-19 15:10:37.263 TRACE nova.api.openstack.extensions 
2017-09-19 15:10:37.265 INFO nova.api.openstack.wsgi [req-326f3a8c-4b51-4f69-bf97-a70bc2c456b4 admin admin] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.exceptions.MessagingTimeout'>

看错误信息是发送的RabbitMQ消息没有收到consumer回复,最后超时报错了。

看代码是为了验证创建vm使用的网络是否有足够的port可用,然后nova做不了判断,需要发rpc出去给“neutron”帮忙确认,注意这里的“neutron”加了引号。

刚开始我以为是RabbitMQ的配置不对,比如用户名密码或者用户权限没配置好,就修改配置文件改用MQ默认的guest、guest用户密码来发送rpc消息,结果还是超时。

然后就对比了看了物理环境的MQ里的queue和exchange,没发现异常,决定下ipdb断点调试,单步调试了很久,看到使用的exchange是nova,topic是network,通过RabbitMQ的web插件(rabbitmq-plugins enable rabbitmq_management启用该插件,默认端口号是15672)看了下nova这个exchange,里面没有network队列,其他正常的环境也没有。

neutron那边没有注册上来?但是重启了neutron-server也没看到异常日志,并且显示MQ已正常连接了。

只能去正常的环境里打断点调试对比了,结果发现走的代码流程不一样,应该是走到nova.network.neutronv2.api.API#validate_networks,而不是nova.network.api.API#validate_networks,这时才恍然大悟,原来是nova配置文件有问题,少配置了use_neutron = True(默认值是False),导致走到了nova-network流程,nova-api试图发rpc请求给nova-network服务来验证网络参数。

修改nova.conf加上use_neutron = True之后,重启nova-api服务,再进行nova boot创建vm,一切正常了。。。。