1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
|
# 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
|
