229 lines
8.7 KiB
Python
229 lines
8.7 KiB
Python
# Copyright 2013 Rackspace Australia
|
|
#
|
|
# Licensed under the Apache License, Version 2.0 (the "License"); you may
|
|
# not use this file except in compliance with the License. You may obtain
|
|
# a copy of the License at
|
|
#
|
|
# http://www.apache.org/licenses/LICENSE-2.0
|
|
#
|
|
# Unless required by applicable law or agreed to in writing, software
|
|
# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
|
|
# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
|
|
# License for the specific language governing permissions and limitations
|
|
# under the License.
|
|
|
|
|
|
""" Methods to handle the results of the task.
|
|
|
|
Primarily place the log files somewhere useful and optionally email
|
|
somebody """
|
|
|
|
import calendar
|
|
import time
|
|
import os
|
|
import re
|
|
|
|
|
|
MIGRATION_NUMBER_RE = re.compile('^([0-9]+).*\.py$')
|
|
MIGRATION_START_RE = re.compile('.* ([0-9]+) -\> ([0-9]+)\.\.\..*$')
|
|
MIGRATION_END_RE = re.compile('done$')
|
|
MIGRATION_FINAL_SCHEMA_RE = re.compile('Final schema version is ([0-9]+)')
|
|
INNODB_STATISTIC_RE = re.compile('.* (Innodb_.*)\t([0-9]+)')
|
|
|
|
|
|
class LogParser(object):
|
|
def __init__(self, logpath, gitpath):
|
|
self.logpath = logpath
|
|
self.gitpath = gitpath
|
|
self._reset()
|
|
|
|
def _reset(self):
|
|
self.errors = []
|
|
self.warnings = []
|
|
self.migrations = []
|
|
|
|
def find_schemas(self):
|
|
"""Return a list of the schema numbers present in git."""
|
|
|
|
# TODO(mikal): once more of the cells code lands this needs to handle
|
|
# the API migratons as well as the cells migration. Just do cells for
|
|
# now though.
|
|
cells_migration_path = os.path.join(
|
|
self.gitpath,
|
|
'nova/db/sqlalchemy/cell_migrations/migrate_repo/versions')
|
|
|
|
if not os.path.exists(cells_migration_path):
|
|
cells_migration_path = os.path.join(
|
|
self.gitpath,
|
|
'nova/db/sqlalchemy/migrate_repo/versions')
|
|
|
|
return [int(MIGRATION_NUMBER_RE.findall(f)[0]) for f in os.listdir(
|
|
cells_migration_path) if MIGRATION_NUMBER_RE.match(f)]
|
|
|
|
def process_log(self):
|
|
"""Analyse a log for errors."""
|
|
self._reset()
|
|
innodb_stats = {}
|
|
migration_stats = {}
|
|
current_migration = {}
|
|
|
|
with open(self.logpath, 'r') as fd:
|
|
migration_started = False
|
|
|
|
for line in fd:
|
|
if 'ERROR 1045' in line:
|
|
return False, "FAILURE - Could not setup seed database."
|
|
elif 'ERROR 1049' in line:
|
|
return False, "FAILURE - Could not find seed database."
|
|
elif 'ImportError' in line:
|
|
return False, "FAILURE - Could not import required module."
|
|
elif MIGRATION_START_RE.search(line):
|
|
if current_migration:
|
|
current_migration['stats'] = migration_stats
|
|
if (('start' in current_migration and
|
|
'end' in current_migration)):
|
|
current_migration['duration'] = (
|
|
current_migration['end'] -
|
|
current_migration['start'])
|
|
self.migrations.append(current_migration)
|
|
current_migration = {}
|
|
migration_stats = {}
|
|
|
|
if migration_started:
|
|
# We didn't see the last one finish,
|
|
# something must have failed
|
|
self.errors.append('FAILURE - Migration started '
|
|
'but did not end')
|
|
|
|
migration_started = True
|
|
current_migration['start'] = self.line_to_time(line)
|
|
|
|
m = MIGRATION_START_RE.match(line)
|
|
current_migration['from'] = int(m.group(1))
|
|
current_migration['to'] = int(m.group(2))
|
|
|
|
elif MIGRATION_END_RE.search(line):
|
|
if migration_started:
|
|
migration_started = False
|
|
current_migration['end'] = self.line_to_time(line)
|
|
|
|
elif INNODB_STATISTIC_RE.search(line):
|
|
# NOTE(mikal): the stats for a migration step come after
|
|
# the migration has ended, because they're the next
|
|
# command in the script. We don't record them until the
|
|
# next migration starts (or we hit the end of the file).
|
|
m = INNODB_STATISTIC_RE.match(line)
|
|
name = m.group(1)
|
|
value = int(m.group(2))
|
|
|
|
if name in innodb_stats and name not in migration_stats:
|
|
delta = value - innodb_stats[name]
|
|
if delta > 0:
|
|
migration_stats[name] = delta
|
|
|
|
innodb_stats[name] = value
|
|
|
|
elif 'Final schema version is' in line and self.gitpath:
|
|
# Check the final version is as expected
|
|
final_version = MIGRATION_FINAL_SCHEMA_RE.findall(line)[0]
|
|
if int(final_version) != max(self.find_schemas()):
|
|
self.errors.append('FAILURE - Final schema version '
|
|
'does not match expectation')
|
|
|
|
if migration_started:
|
|
# We never saw the end of a migration, something must have
|
|
# failed
|
|
self.errors.append('FAILURE - Did not find the end of a '
|
|
'migration after a start')
|
|
|
|
if current_migration:
|
|
current_migration['stats'] = migration_stats
|
|
if (('start' in current_migration and
|
|
'end' in current_migration)):
|
|
current_migration['duration'] = (
|
|
current_migration['end'] - current_migration['start'])
|
|
self.migrations.append(current_migration)
|
|
|
|
def line_to_time(self, line):
|
|
"""Extract a timestamp from a log line"""
|
|
return calendar.timegm(time.strptime(line[:23],
|
|
'%Y-%m-%d %H:%M:%S,%f'))
|
|
|
|
|
|
def check_migration(migration, attribute, value, dataset_config):
|
|
"""Checks if a given migration is within its allowed parameters.
|
|
|
|
Returns True if okay, False if it takes too long."""
|
|
|
|
migration_name = '%s->%s' % (migration['from'], migration['to'])
|
|
allowed = dataset_config[attribute].get(
|
|
migration_name, dataset_config[attribute]['default'])
|
|
if value > allowed:
|
|
return False
|
|
return True
|
|
|
|
|
|
def check_log_file(log_file, git_path, dataset):
|
|
lp = LogParser(log_file, git_path)
|
|
lp.process_log()
|
|
|
|
success = True
|
|
messages = []
|
|
|
|
if not lp.migrations:
|
|
success = False
|
|
messages.append('No migrations run')
|
|
|
|
if lp.errors:
|
|
success = False
|
|
for err in lp.errors:
|
|
messages.append(err)
|
|
|
|
if lp.warnings:
|
|
success = False
|
|
for warn in lp.warnings:
|
|
messages.append(warn)
|
|
|
|
for migration in lp.migrations:
|
|
migration.setdefault('stats', {})
|
|
|
|
# check migration completed
|
|
if not 'duration' in migration:
|
|
success = False
|
|
messages.append('WARNING - Migration %s->%s failed to complete'
|
|
% (migration['from'], migration['to']))
|
|
continue
|
|
|
|
# Check total time
|
|
if not check_migration(migration, 'maximum_migration_times',
|
|
migration['duration'], dataset['config']):
|
|
success = False
|
|
messages.append('WARNING - Migration %s->%s took too long'
|
|
% (migration['from'], migration['to']))
|
|
|
|
# Check rows changed
|
|
rows_changed = 0
|
|
for key in ['Innodb_rows_updated',
|
|
'Innodb_rows_inserted',
|
|
'Innodb_rows_deleted']:
|
|
rows_changed += migration['stats'].get(key, 0)
|
|
|
|
if not check_migration(migration, 'XInnodb_rows_changed',
|
|
rows_changed, dataset['config']):
|
|
success = False
|
|
messages.append('WARNING - Migration %s->%s changed too many '
|
|
'rows (%d)'
|
|
% (migration['from'], migration['to'],
|
|
rows_changed))
|
|
|
|
# Check rows read
|
|
rows_read = migration['stats'].get('Innodb_rows_read', 0)
|
|
if not check_migration(migration, 'Innodb_rows_read',
|
|
rows_read, dataset['config']):
|
|
success = False
|
|
messages.append('WARNING - Migration %s->%s read too many '
|
|
'rows (%d)'
|
|
% (migration['from'], migration['to'], rows_read))
|
|
|
|
return success, messages
|