ceph/teuthology/task/mon_clock_skew_check.py
Joao Eduardo Luis 7ca59dfae1 task: mon_clock_skew_check: missing 'str'.format() key crashed the test
Signed-off-by: Joao Eduardo Luis <joao.luis@inktank.com>
2013-07-19 21:54:28 -07:00

223 lines
7.4 KiB
Python

import logging
import contextlib
import ceph_manager
import time
import gevent
from teuthology import misc as teuthology
log = logging.getLogger(__name__)
class ClockSkewCheck:
"""
Periodically check if there are any clock skews among the monitors in the
quorum. By default, assume no skews are supposed to exist; that can be
changed using the 'expect-skew' option. If 'fail-on-skew' is set to false,
then we will always succeed and only report skews if any are found.
This class does not spawn a thread. It assumes that, if that is indeed
wanted, it should be done by a third party (for instance, the task using
this class). We intend it as such in order to reuse this class if need be.
This task accepts the following options:
interval amount of seconds to wait in-between checks. (default: 30.0)
max-skew maximum skew, in seconds, that is considered tolerable before
issuing a warning. (default: 0.05)
expect-skew 'true' or 'false', to indicate whether to expect a skew during
the run or not. If 'true', the test will fail if no skew is
found, and succeed if a skew is indeed found; if 'false', it's
the other way around. (default: false)
never-fail Don't fail the run if a skew is detected and we weren't
expecting it, or if no skew is detected and we were expecting
it. (default: False)
at-least-once Runs at least once, even if we are told to stop.
(default: True)
at-least-once-timeout If we were told to stop but we are attempting to
run at least once, timeout after this many seconds.
(default: 600)
Example:
Expect a skew higher than 0.05 seconds, but only report it without failing
the teuthology run.
- mon_clock_skew_check:
interval: 30
max-skew: 0.05
expect_skew: true
never-fail: true
"""
def __init__(self, ctx, manager, config, logger):
self.ctx = ctx
self.manager = manager;
self.stopping = False
self.logger = logger
self.config = config
if self.config is None:
self.config = dict()
self.check_interval = float(self.config.get('interval', 30.0))
self.max_skew = float(self.config.get('max-skew', 0.05))
self.expect_skew = self.config.get('expect-skew', False)
self.never_fail = self.config.get('never-fail', False)
self.at_least_once = self.config.get('at-least-once', True)
self.at_least_once_timeout = self.config.get('at-least-once-timeout', 600.0)
def info(self, x):
self.logger.info(x)
def warn(self, x):
self.logger.warn(x)
def debug(self, x):
self.logger.debug(x)
def finish(self):
self.stopping = True
def sleep_interval(self):
if self.check_interval > 0.0:
self.debug('sleeping for {s} seconds'.format(
s=self.check_interval))
time.sleep(self.check_interval)
def print_skews(self, skews):
total = len(skews)
if total > 0:
self.info('---------- found {n} skews ----------'.format(n=total))
for mon_id,values in skews.iteritems():
self.info('mon.{id}: {v}'.format(id=mon_id,v=values))
self.info('-------------------------------------')
else:
self.info('---------- no skews were found ----------')
def do_check(self):
self.info('start checking for clock skews')
skews = dict()
ran_once = False
started_on = None
while not self.stopping or (self.at_least_once and not ran_once):
if self.at_least_once and not ran_once and self.stopping:
if started_on is None:
self.info('kicking-off timeout (if any)')
started_on = time.time()
elif self.at_least_once_timeout > 0.0:
assert time.time() - started_on < self.at_least_once_timeout, \
'failed to obtain a timecheck before timeout expired'
quorum_size = len(teuthology.get_mon_names(self.ctx))
self.manager.wait_for_mon_quorum_size(quorum_size)
health = self.manager.get_mon_health(True)
timechecks = health['timechecks']
clean_check = False
if timechecks['round_status'] == 'finished':
assert (timechecks['round'] % 2) == 0, \
'timecheck marked as finished but round ' \
'disagrees (r {r})'.format(
r=timechecks['round'])
clean_check = True
else:
assert timechecks['round_status'] == 'on-going', \
'timecheck status expected \'on-going\' ' \
'but found \'{s}\' instead'.format(
s=timechecks['round_status'])
if 'mons' in timechecks.keys() and len(timechecks['mons']) > 1:
self.info('round still on-going, but there are available reports')
else:
self.info('no timechecks available just yet')
self.sleep_interval()
continue
assert len(timechecks['mons']) > 1, \
'there are not enough reported timechecks; ' \
'expected > 1 found {n}'.format(n=len(timechecks['mons']))
for check in timechecks['mons']:
mon_skew = float(check['skew'])
mon_health = check['health']
mon_id = check['name']
if abs(mon_skew) > self.max_skew:
assert mon_health == 'HEALTH_WARN', \
'mon.{id} health is \'{health}\' but skew {s} > max {ms}'.format(
id=mon_id,health=mon_health,s=abs(mon_skew),ms=self.max_skew)
log_str = 'mon.{id} with skew {s} > max {ms}'.format(
id=mon_id,s=abs(mon_skew),ms=self.max_skew)
""" add to skew list """
details = check['details']
skews[mon_id] = {'skew': mon_skew, 'details': details}
if self.expect_skew:
self.info('expected skew: {str}'.format(str=log_str))
else:
self.warn('unexpected skew: {str}'.format(str=log_str))
if clean_check or (self.expect_skew and len(skews) > 0):
ran_once = True
self.print_skews(skews)
self.sleep_interval()
total = len(skews)
self.print_skews(skews)
error_str = ''
found_error = False
if self.expect_skew:
if total == 0:
error_str = 'We were expecting a skew, but none was found!'
found_error = True
else:
if total > 0:
error_str = 'We were not expecting a skew, but we did find it!'
found_error = True
if found_error:
self.info(error_str)
if not self.never_fail:
assert False, error_str
@contextlib.contextmanager
def task(ctx, config):
"""
Use clas ClockSkewCheck to check for clock skews on the monitors.
This task will spawn a thread running ClockSkewCheck's do_check().
All the configuration will be directly handled by ClockSkewCheck,
so please refer to the class documentation for further information.
"""
if config is None:
config = {}
assert isinstance(config, dict), \
'mon_clock_skew_check task only accepts a dict for configuration'
log.info('Beginning mon_clock_skew_check...')
first_mon = teuthology.get_first_mon(ctx, config)
(mon,) = ctx.cluster.only(first_mon).remotes.iterkeys()
manager = ceph_manager.CephManager(
mon,
ctx=ctx,
logger=log.getChild('ceph_manager'),
)
skew_check = ClockSkewCheck(ctx,
manager, config,
logger=log.getChild('mon_clock_skew_check'))
skew_check_thread = gevent.spawn(skew_check.do_check)
try:
yield
finally:
log.info('joining mon_clock_skew_check')
skew_check.finish()
skew_check_thread.get()