Cinder 调试 - cinder service 状态为 down
1. 问题
我们经常会发现某个cinder service 的状态为 down。比如下面例子中 controller 上的 cinder-scheduler 和 block1 节点上 cinder-volume 的状态都为 down。
s1@controller:~$ cinder service-list
+------------------+---------------------------+------+---------+-------+----------------------------+-----------------+
| Binary | Host | Zone | Status | State | Updated_at | Disabled Reason |
+------------------+---------------------------+------+---------+-------+----------------------------+-----------------+
| cinder-backup | controller | nova | enabled | up | 2015-03-30T00:53:32.000000 | None |
| cinder-scheduler | controller | nova | enabled | down | 2015-03-30T00:51:53.000000 | None |
| cinder-volume | block1 | nova | enabled | down | 2015-03-30T00:54:43.000000 | None |
| cinder-volume | block2@lvmdriver-b21 | az1 | enabled | up | 2015-03-30T00:54:14.000000 | None |
| cinder-volume | block2@lvmdriver-b22 | az1 | enabled | up | 2015-03-30T00:54:13.000000 | None |
| cinder-volume | network@lvmdriver-network | nova | enabled | up | 2015-03-30T00:54:08.000000 | None |
+------------------+---------------------------+------+---------+-------+----------------------------+-----------------+
先来看看 cinder-list 的实现代码:
class ServiceController(wsgi.Controller): @wsgi.serializers(xml=ServicesIndexTemplate) def index(self, req): """Return a list of all running services. Filter by host & service name. """ context = req.environ['cinder.context'] authorize(context) detailed = self.ext_mgr.is_loaded('os-extended-services') now = timeutils.utcnow() //获取controller 当前的时间 services = db.service_get_all(context) //从 db 获取所有的 cinder service 列表 ... svcs = [] for svc in services: //轮询每个 service delta = now - (svc['updated_at'] or svc['created_at']) //获取 updated_at。不存在的话,获取 created_at,并和当前时间计算时间差 alive = abs(utils.total_seconds(delta)) <= CONF.service_down_time //获取时间差值的绝对值,并检查是否小于配置的 server_down_time,该配置项默认是60秒 art = (alive and "up") or "down" //如果差值小于60,则service 状态为 up,否则为 down active = 'enabled' ...... svcs.append(ret_fields) return {'services': svcs}
可见 service 的 up/down 状态取决于数据库中 service 表对应某 service 的行的 updated_at 列的值和当前 controller 节点的时间的差值是否在配置的范围之内。
2. Cinder Service 的 update_at 值更新机制
cinder 的各种service,比如cinder-api,cinder-backup 等,都是 /cinder/service.py 文件中 class Service(service.Service) 的一个实例,该类的 start 方法如下:
def start(self): version_string = version.version_string() LOG.info(_('Starting %(topic)s node (version %(version_string)s)'), {'topic': self.topic, 'version_string': version_string}) ...if self.report_interval: //如果设置了 report_interval 配置项,那么该 service 将启动一个无限循环来执行 report_state 方法,运行间隔就是 report_interval,其默认值是 10 秒 pulse = loopingcall.FixedIntervalLoopingCall( self.report_state) pulse.start(interval=self.report_interval, initial_delay=self.report_interval) self.timers.append(pulse)
report_state 方法会更新 db 中serive 的各个属性,其中 updated_at 的值就是所在节点上执行一次该方法的时刻。
def report_state(self): """Update the state of this service in the datastore.""" ctxt = context.get_admin_context() zone = CONF.storage_availability_zone state_catalog = {} try: ... service_ref = db.service_get(ctxt, self.service_id) // 获取service 的 ref ... db.service_update(ctxt, self.service_id, state_catalog) //更新该 service ...
3. 问题定位步骤
(1)看看是不是在 cinder.conf 中 report_interval 配置项的值是多少,如果超过了 service_down_time 配置项默认的 60 秒,那么该service 的状态肯定就是 'down' 了。
(2)看 service 所在节点的时间,它的时间和 controller 节点的时间误差必须在 [service_down_time - report_interval ] 之内,也就是在使用默认配置情况下,时间差必须在 50 秒之内。
(3)看看 service 的 log 文件中,确认 report_state 方法是不是都按时被调用了,不方便看的话,在代码中加个注释吧。比如:
2015-04-11 15:26:24.210 8517 DEBUG cinder.service [-] enter report_state .. report_state /usr/lib/python2.7/dist-packages/cinder/service.py:283
4. 问题解决
(1). 检查 block1 的时间
发现 block1 的时间 和 controller 不同步。通过同步 block1 和 controller 的时间,block1 上的 cinder-volume 的状态变为了 up。
(2). 检查 cinder-scheduler service 的 updated_at
发现 cinder-scheduler 的 updated_at 是 2015-03-30 01:32:26, 而 controller 的当前时间是 2015-04-11 02:26:20。排除时间差因素,基本可以确定是该服务的时间上报出了问题。检查 cinder-schedule 的log,发现因为 bug 该 service 真的down了。fix bug,然后重启服务,其状态变为 up。