(转载)记第一次debug openstack
转载地址:http://blog.csdn.net/hao119119/article/details/46718377
之前用devstack安装neutron一直有这种那种问题, 所以也就没深究. 这次因为想学学新的openstack docker组件所以对原有的openstack进行了升级, 结果不出意外的, 环境又不好用了. 所以开始了漫漫debug之路. 说句题外话, 之前听到很多童鞋都不太喜欢devstack, 其中很多还都是大牛. 确实devstack这种东东对于大牛来说确实意义不大, 但是像我这样的小菜, 一套可以快速部署, 容易上手的openstack环境还是很有意义的, 而且自己的环境想咋搞咋搞, 还是不错的. 最重要的是, 所有的openstack组件都支持devstack, 如果你想尝试尝试什么新东西, 不得不说没有什么比devstack更方便的.
对localrc进行几轮修改后, 终于成功的安装了openstack, 网络部分的功能还没测试, 不过至少组件都安装成功了. 嘿嘿,
好景不长,页面创建实例报错, 页面显示类似数据错误啥啥的. 第一反应f**k, 好吧, 重装, 重装, 试了几次始终不行,好吧,我承认我很笨.
于是开始查看日志
首先, 我从horizion的日志入手, 仔细查看, 发现是cinderclient报的错误,日志大致如下:
2015-07-01 09:02:57.007233 File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 302, in get
2015-07-01 09:02:57.007236 return self._cs_request(url, 'GET', **kwargs)
2015-07-01 09:02:57.007238 File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 294, in
2015-07-01 09:02:57.007236 return self._cs_request(url, 'GET', **kwargs)
2015-07-01 09:02:57.007238 File "/usr/lib/python2.7/dist-packages/cinderclient/client.py", line 294, in
_cs_request
2015-07-01 09:02:57.007241 raise exceptions.ConnectionError(msg)
2015-07-01 09:02:57.007243 ConnectionError: Unable to establish connection: ('Connection aborted.',
2015-07-01 09:02:57.007241 raise exceptions.ConnectionError(msg)
2015-07-01 09:02:57.007243 ConnectionError: Unable to establish connection: ('Connection aborted.',
BadStatusLine("''",))
检查cinderclient之后发现, 这部分代码请求了cinder-api(似乎是废话), 然后转到cinder-api的日志, 根据最后一条请求可以看出之前的函数调用了cinder/api/v2/snapshots.py detail()函数,
这个时候我又茫然了, 代码是最新的, 没有做过什么修改, 所以考虑会不会是cinderclient的版本和新下cinder版本不对应.
所以我又很二的把cinderclient给删了, 重新安装了一次, 上帝保佑这么做不会对以后有什么影响. 结果不出意外的继续不好使,
这个时候我基本确定系统可能出了什么问题, 于是我转到社区, 用我蹩脚的英语发了第一个问题帖子, 并开始了焦急的等待. 大概是时差的问题把,
很久没有人回复, 倒是有几个viewer, 我想大概是我的描述还不够准确, 所以我试着开始debug代码,
看看能不能有更多的提示.
python的debug在我之前的帖子里有介绍过, 首先我在detail中加入如下代码, 启动pycharm的远程调试功能并重启c-api
def detail(self, req): """Returns a detailed list of snapshots.""" import pydevd pydevd.settrace("127.0.0.1", port=5678) return self._items(req, entity_maker=_translate_snapshot_detail_view) pycharm很顺利的进入断点, 但是奇怪的是断点位置不对, 并且无法debug detail函数. 根据之前网上查到的资料,这很有可能是因为openstack使用的线程机制造成的(这部分后面也会做总结), 于是在cinder/cmd/api.py中顺利的找到了那只猴子, 并对猴子做了小小的修改, 注释掉的是原来的猴子, 长的是debug用的新猴子, 做过如下修改后,重启c-api,这次一切正常了,终于开始debug了.
#eventlet.monkey_patch() eventlet.monkey_patch(all=False, socket=True, time=True, thread=False) 跟踪detail函数, detail调用_item(), 在item()调用如下方法时发生异常,这里需要注意的是python发生异常时不像在java中会直接输出到控制台,如果发现代码执行流跳转异常那很有可能就是发生异常了,通常发生异常时,函数会直接返回到它的调用者.
snapshots = self.volume_api.get_all_snapshots(context,search_opts=search_opts) #1 在继续跟踪过程中就凸显了debug的优势,一方面python的函数可能有多个实现,且可以随意指定参数,所以对于代码不是很熟悉的话和可能找不到到底调用的是哪个函数, 另一方面debug过程中我们可以看到所有变量的变化, 对于理解程序的执行非常有好处.以上函数#1实际调用如下 #cinder/volume/api.py #1
get_all_snapshots(self, context, search_opts=None): check_policy(context, 'get_all_snapshots') search_opts = search_opts or {} if (context.is_admin and 'all_tenants' in search_opts): #2 # Need to remove all_tenants to pass the filtering below. del search_opts['all_tenants'] snapshots = objects.SnapshotList.get_all(context, search_opts) else: snapshots = objects.SnapshotList.get_all_by_project( context, context.project_id, search_opts) #3 return snapshots 这里根据前台传来的参数, 代码应该进入if条件, 实际情况却走了else, 这里我还有意识到有问题, 直到后面继续执行我才发现了问题. 这里我们继续跟踪代码 #cinder/objects/snapshot.py #3
get_all_by_project(cls, context, project_id, search_opts): snapshots = db.snapshot_get_all_by_project(context, project_id, search_opts) #4 #cinder/db/api.py #4
snapshot_get_all_by_project(context, project_id, filters=None): return IMPL.snapshot_get_all_by_project(context, project_id, filters) #5 #cinder/db/sqlalchemy/api.py #5 snapshot_get_all_by_project(context, project_id, filters=None):
authorize_project_context(context, project_id) query = model_query(context, models.Snapshot) if filters: query = query.filter_by(**filters) return query.filter_by(project_id=project_id).ptions(joinedload('snapshot_met adata')).all()
最终我们发现, 上面的query.fiter_by发生了异常. 而这个filter是根据**filters里面的key-value对查询结果进行过滤,观察变量发现filters的值为 MultiDict([(u'alltenants', u'1'), (u'tenant_id', u'6889d9c31549458b83a4316e97181e71')]), 而对象snapshot中根本没有这两个字段, 所以造成了错误. 于是开始返回去找这个filters从哪里传过来的,一直跟踪到#2的条件判断, 这时我们发现代码执行错误的原因是判断条件中使用的字段为all_tenants而dict中却保存的为alltenants造成代码执行路径有问题,导致后台错误.于是继续跟踪search_opts到底从哪里来的,很容易找到
_item():
search_opts = req.GET.copy() 找了这么久终于找到罪魁祸首了,这个search_opts是从url中获取的, 而这个url肯定是horizion生成的. 所以继续查找horzion的代码, 全文检索'alltenants', 终于我们在下面的代码中找到了问题 #horizon/openstack_dashboard/usage/quotas.py def _get_tenant_volume_usages(request, usages, disabled_quotas, tenant_id): if 'volumes' not in disabled_quotas: if tenant_id: opts = {'alltenants': 1, 'tenant_id': tenant_id}
把上面的alltenants修改为all_tenants后,重启horizion, 终于世界恢复了它应有的样子. 之后发现社区发的帖子也被回复了,问题和我找的一致 , 基本可以确定是个小bug, 能找到这个bug还是很兴奋的,本来想提到社区上, 后来觉得有点小题大做了, 就没发,其实主要是不知道怎么提.不过没关系,以后还有的是机会. 以上就是整个debug的过程, 还是挺有意思的, 总结几点, 遇到问题不能急, 多看看日志, 对代码的整体理解有助于解决问题, 最后平时还是要多多看看源码.