OLD | NEW |
| (Empty) |
1 import sys | |
2 import re | |
3 import exceptions | |
4 from twisted.python import log | |
5 from twisted.internet import defer | |
6 from twisted.enterprise import adbapi | |
7 from buildbot.process.buildstep import LogLineObserver | |
8 from buildbot.steps.shell import Test | |
9 | |
10 class EqConnectionPool(adbapi.ConnectionPool): | |
11 """This class works the same way as | |
12 twisted.enterprise.adbapi.ConnectionPool. But it adds the ability to | |
13 compare connection pools for equality (by comparing the arguments | |
14 passed to the constructor). | |
15 | |
16 This is useful when passing the ConnectionPool to a BuildStep, as | |
17 otherwise Buildbot will consider the buildstep (and hence the | |
18 containing buildfactory) to have changed every time the configuration | |
19 is reloaded. | |
20 | |
21 It also sets some defaults differently from adbapi.ConnectionPool that | |
22 are more suitable for use in MTR. | |
23 """ | |
24 def __init__(self, *args, **kwargs): | |
25 self._eqKey = (args, kwargs) | |
26 return adbapi.ConnectionPool.__init__(self, | |
27 cp_reconnect=True, cp_min=1, cp_ma
x=3, | |
28 *args, **kwargs) | |
29 | |
30 def __eq__(self, other): | |
31 if isinstance(other, EqConnectionPool): | |
32 return self._eqKey == other._eqKey | |
33 else: | |
34 return False | |
35 | |
36 def __ne__(self, other): | |
37 return not self.__eq__(other) | |
38 | |
39 | |
40 class MtrTestFailData: | |
41 def __init__(self, testname, variant, result, info, text, callback): | |
42 self.testname = testname | |
43 self.variant = variant | |
44 self.result = result | |
45 self.info = info | |
46 self.text = text | |
47 self.callback = callback | |
48 | |
49 def add(self, line): | |
50 self.text+= line | |
51 | |
52 def fireCallback(self): | |
53 return self.callback(self.testname, self.variant, self.result, self.info
, self.text) | |
54 | |
55 | |
56 class MtrLogObserver(LogLineObserver): | |
57 """ | |
58 Class implementing a log observer (can be passed to | |
59 BuildStep.addLogObserver(). | |
60 | |
61 It parses the output of mysql-test-run.pl as used in MySQL, | |
62 MariaDB, Drizzle, etc. | |
63 | |
64 It counts number of tests run and uses it to provide more accurate | |
65 completion estimates. | |
66 | |
67 It parses out test failures from the output and summarises the results on | |
68 the Waterfall page. It also passes the information to methods that can be | |
69 overridden in a subclass to do further processing on the information.""" | |
70 | |
71 _line_re = re.compile(r"^([-._0-9a-zA-z]+)( '[-_ a-zA-Z]+')?\s+(w[0-9]+\s+)?
\[ (fail|pass) \]\s*(.*)$") | |
72 _line_re2 = re.compile(r"^[-._0-9a-zA-z]+( '[-_ a-zA-Z]+')?\s+(w[0-9]+\s+)?\
[ [-a-z]+ \]") | |
73 _line_re3 = re.compile(r"^\*\*\*Warnings generated in error logs during shut
down after running tests: (.*)") | |
74 _line_re4 = re.compile(r"^The servers were restarted [0-9]+ times$") | |
75 _line_re5 = re.compile(r"^Only\s+[0-9]+\s+of\s+[0-9]+\s+completed.$") | |
76 | |
77 def __init__(self, textLimit=5, testNameLimit=16, testType=None): | |
78 self.textLimit = textLimit | |
79 self.testNameLimit = testNameLimit | |
80 self.testType = testType | |
81 self.numTests = 0 | |
82 self.testFail = None | |
83 self.failList = [] | |
84 self.warnList = [] | |
85 LogLineObserver.__init__(self) | |
86 | |
87 def setLog(self, loog): | |
88 LogLineObserver.setLog(self, loog) | |
89 d= loog.waitUntilFinished() | |
90 d.addCallback(lambda l: self.closeTestFail()) | |
91 | |
92 def outLineReceived(self, line): | |
93 stripLine = line.strip("\r\n") | |
94 m = self._line_re.search(stripLine) | |
95 if m: | |
96 testname, variant, worker, result, info = m.groups() | |
97 self.closeTestFail() | |
98 self.numTests += 1 | |
99 self.step.setProgress('tests', self.numTests) | |
100 | |
101 if result == "fail": | |
102 if variant == None: | |
103 variant = "" | |
104 else: | |
105 variant = variant[2:-1] | |
106 self.openTestFail(testname, variant, result, info, stripLine + "
\n") | |
107 | |
108 else: | |
109 m = self._line_re3.search(stripLine) | |
110 if m: | |
111 stuff = m.group(1) | |
112 self.closeTestFail() | |
113 testList = stuff.split(" ") | |
114 self.doCollectWarningTests(testList) | |
115 | |
116 elif (self._line_re2.search(stripLine) or | |
117 self._line_re4.search(stripLine) or | |
118 self._line_re5.search(stripLine) or | |
119 stripLine == "Test suite timeout! Terminating..." or | |
120 stripLine.startswith("mysql-test-run: *** ERROR: Not all tests
completed") or | |
121 (stripLine.startswith("---------------------------------------
---------------------") | |
122 and self.testFail != None)): | |
123 self.closeTestFail() | |
124 | |
125 else: | |
126 self.addTestFailOutput(stripLine + "\n") | |
127 | |
128 def openTestFail(self, testname, variant, result, info, line): | |
129 self.testFail = MtrTestFailData(testname, variant, result, info, line, s
elf.doCollectTestFail) | |
130 | |
131 def addTestFailOutput(self, line): | |
132 if self.testFail != None: | |
133 self.testFail.add(line) | |
134 | |
135 def closeTestFail(self): | |
136 if self.testFail != None: | |
137 self.testFail.fireCallback() | |
138 self.testFail = None | |
139 | |
140 def addToText(self, src, dst): | |
141 lastOne = None | |
142 count = 0 | |
143 for t in src: | |
144 if t != lastOne: | |
145 dst.append(t) | |
146 count += 1 | |
147 if count >= self.textLimit: | |
148 break | |
149 | |
150 def makeText(self, done): | |
151 if done: | |
152 text = ["test"] | |
153 else: | |
154 text = ["testing"] | |
155 if self.testType: | |
156 text.append(self.testType) | |
157 fails = self.failList[:] | |
158 fails.sort() | |
159 self.addToText(fails, text) | |
160 warns = self.warnList[:] | |
161 warns.sort() | |
162 self.addToText(warns, text) | |
163 return text | |
164 | |
165 # Update waterfall status. | |
166 def updateText(self): | |
167 self.step.step_status.setText(self.makeText(False)) | |
168 | |
169 strip_re = re.compile(r"^[a-z]+\.") | |
170 | |
171 def displayTestName(self, testname): | |
172 | |
173 displayTestName = self.strip_re.sub("", testname) | |
174 | |
175 if len(displayTestName) > self.testNameLimit: | |
176 displayTestName = displayTestName[:(self.testNameLimit-2)] + "..." | |
177 return displayTestName | |
178 | |
179 def doCollectTestFail(self, testname, variant, result, info, text): | |
180 self.failList.append("F:" + self.displayTestName(testname)) | |
181 self.updateText() | |
182 self.collectTestFail(testname, variant, result, info, text) | |
183 | |
184 def doCollectWarningTests(self, testList): | |
185 for t in testList: | |
186 self.warnList.append("W:" + self.displayTestName(t)) | |
187 self.updateText() | |
188 self.collectWarningTests(testList) | |
189 | |
190 # These two methods are overridden to actually do something with the data. | |
191 def collectTestFail(self, testname, variant, result, info, text): | |
192 pass | |
193 def collectWarningTests(self, testList): | |
194 pass | |
195 | |
196 class MTR(Test): | |
197 """ | |
198 Build step that runs mysql-test-run.pl, as used in MySQL, Drizzle, | |
199 MariaDB, etc. | |
200 | |
201 It uses class MtrLogObserver to parse test results out from the | |
202 output of mysql-test-run.pl, providing better completion time | |
203 estimates and summarising test failures on the waterfall page. | |
204 | |
205 It also provides access to mysqld server error logs from the test | |
206 run to help debugging any problems. | |
207 | |
208 Optionally, it can insert into a database data about the test run, | |
209 including details of any test failures. | |
210 | |
211 Parameters: | |
212 | |
213 textLimit | |
214 Maximum number of test failures to show on the waterfall page | |
215 (to not flood the page in case of a large number of test | |
216 failures. Defaults to 5. | |
217 | |
218 testNameLimit | |
219 Maximum length of test names to show unabbreviated in the | |
220 waterfall page, to avoid excessive column width. Defaults to 16. | |
221 | |
222 parallel | |
223 Value of --parallel option used for mysql-test-run.pl (number | |
224 of processes used to run the test suite in parallel). Defaults | |
225 to 4. This is used to determine the number of server error log | |
226 files to download from the slave. Specifying a too high value | |
227 does not hurt (as nonexisting error logs will be ignored), | |
228 however if using --parallel value greater than the default it | |
229 needs to be specified, or some server error logs will be | |
230 missing. | |
231 | |
232 dbpool | |
233 An instance of twisted.enterprise.adbapi.ConnectionPool, or None. | |
234 Defaults to None. If specified, results are inserted into the database | |
235 using the ConnectionPool. | |
236 | |
237 The class process.mtrlogobserver.EqConnectionPool subclass of | |
238 ConnectionPool can be useful to pass as value for dbpool, to | |
239 avoid having config reloads think the Buildstep is changed | |
240 just because it gets a new ConnectionPool instance (even | |
241 though connection parameters are unchanged). | |
242 | |
243 autoCreateTables | |
244 Boolean, defaults to False. If True (and dbpool is specified), the | |
245 necessary database tables will be created automatically if they do | |
246 not exist already. Alternatively, the tables can be created manually | |
247 from the SQL statements found in the mtrlogobserver.py source file. | |
248 | |
249 test_type | |
250 test_info | |
251 Two descriptive strings that will be inserted in the database tables if | |
252 dbpool is specified. The test_type string, if specified, will also | |
253 appear on the waterfall page.""" | |
254 | |
255 def __init__(self, dbpool=None, test_type=None, test_info="", | |
256 description=None, descriptionDone=None, | |
257 autoCreateTables=False, textLimit=5, testNameLimit=16, | |
258 parallel=4, logfiles = {}, lazylogfiles = True, | |
259 warningPattern="MTR's internal check of the test case '.*' fail
ed", | |
260 mtr_subdir="mysql-test", **kwargs): | |
261 | |
262 if description is None: | |
263 description = ["testing"] | |
264 if test_type: | |
265 description.append(test_type) | |
266 if descriptionDone is None: | |
267 descriptionDone = ["test"] | |
268 if test_type: | |
269 descriptionDone.append(test_type) | |
270 Test.__init__(self, logfiles=logfiles, lazylogfiles=lazylogfiles, | |
271 description=description, descriptionDone=descriptionDone, | |
272 warningPattern=warningPattern, **kwargs) | |
273 self.dbpool = dbpool | |
274 self.test_type = test_type | |
275 self.test_info = test_info | |
276 self.autoCreateTables = autoCreateTables | |
277 self.textLimit = textLimit | |
278 self.testNameLimit = testNameLimit | |
279 self.parallel = parallel | |
280 self.mtr_subdir = mtr_subdir | |
281 self.progressMetrics += ('tests',) | |
282 | |
283 self.addFactoryArguments(dbpool=self.dbpool, | |
284 test_type=self.test_type, | |
285 test_info=self.test_info, | |
286 autoCreateTables=self.autoCreateTables, | |
287 textLimit=self.textLimit, | |
288 testNameLimit=self.testNameLimit, | |
289 parallel=self.parallel, | |
290 mtr_subdir=self.mtr_subdir) | |
291 | |
292 def start(self): | |
293 properties = self.build.getProperties() | |
294 subdir = properties.render(self.mtr_subdir) | |
295 | |
296 # Add mysql server logfiles. | |
297 for mtr in range(0, self.parallel+1): | |
298 for mysqld in range(1, 4+1): | |
299 if mtr == 0: | |
300 logname = "mysqld.%d.err" % mysqld | |
301 filename = "var/log/mysqld.%d.err" % mysqld | |
302 else: | |
303 logname = "mysqld.%d.err.%d" % (mysqld, mtr) | |
304 filename = "var/%d/log/mysqld.%d.err" % (mtr, mysqld) | |
305 self.addLogFile(logname, subdir + "/" + filename) | |
306 | |
307 self.myMtr = self.MyMtrLogObserver(textLimit=self.textLimit, | |
308 testNameLimit=self.testNameLimit, | |
309 testType=self.test_type) | |
310 self.addLogObserver("stdio", self.myMtr) | |
311 # Insert a row for this test run into the database and set up | |
312 # build properties, then start the command proper. | |
313 d = self.registerInDB() | |
314 d.addCallback(self.afterRegisterInDB) | |
315 d.addErrback(self.failed) | |
316 | |
317 def getText(self, command, results): | |
318 return self.myMtr.makeText(True) | |
319 | |
320 def runInteractionWithRetry(self, actionFn, *args, **kw): | |
321 """ | |
322 Run a database transaction with dbpool.runInteraction, but retry the | |
323 transaction in case of a temporary error (like connection lost). | |
324 | |
325 This is needed to be robust against things like database connection | |
326 idle timeouts. | |
327 | |
328 The passed callable that implements the transaction must be retryable, | |
329 ie. it must not have any destructive side effects in the case where | |
330 an exception is thrown and/or rollback occurs that would prevent it | |
331 from functioning correctly when called again.""" | |
332 | |
333 def runWithRetry(txn, *args, **kw): | |
334 retryCount = 0 | |
335 while(True): | |
336 try: | |
337 return actionFn(txn, *args, **kw) | |
338 except txn.OperationalError: | |
339 retryCount += 1 | |
340 if retryCount >= 5: | |
341 raise | |
342 excType, excValue, excTraceback = sys.exc_info() | |
343 log.msg("Database transaction failed (caught exception %s(%s
)), retrying ..." % (excType, excValue)) | |
344 txn.close() | |
345 txn.reconnect() | |
346 txn.reopen() | |
347 | |
348 return self.dbpool.runInteraction(runWithRetry, *args, **kw) | |
349 | |
350 def runQueryWithRetry(self, *args, **kw): | |
351 """ | |
352 Run a database query, like with dbpool.runQuery, but retry the query in | |
353 case of a temporary error (like connection lost). | |
354 | |
355 This is needed to be robust against things like database connection | |
356 idle timeouts.""" | |
357 | |
358 def runQuery(txn, *args, **kw): | |
359 txn.execute(*args, **kw) | |
360 return txn.fetchall() | |
361 | |
362 return self.runInteractionWithRetry(runQuery, *args, **kw) | |
363 | |
364 def registerInDB(self): | |
365 if self.dbpool: | |
366 return self.runInteractionWithRetry(self.doRegisterInDB) | |
367 else: | |
368 return defer.succeed(0) | |
369 | |
370 # The real database work is done in a thread in a synchronous way. | |
371 def doRegisterInDB(self, txn): | |
372 # Auto create tables. | |
373 # This is off by default, as it gives warnings in log file | |
374 # about tables already existing (and I did not find the issue | |
375 # important enough to find a better fix). | |
376 if self.autoCreateTables: | |
377 txn.execute(""" | |
378 CREATE TABLE IF NOT EXISTS test_run( | |
379 id INT PRIMARY KEY AUTO_INCREMENT, | |
380 branch VARCHAR(100), | |
381 revision VARCHAR(32) NOT NULL, | |
382 platform VARCHAR(100) NOT NULL, | |
383 dt TIMESTAMP NOT NULL, | |
384 bbnum INT NOT NULL, | |
385 typ VARCHAR(32) NOT NULL, | |
386 info VARCHAR(255), | |
387 KEY (branch, revision), | |
388 KEY (dt), | |
389 KEY (platform, bbnum) | |
390 ) ENGINE=innodb | |
391 """) | |
392 txn.execute(""" | |
393 CREATE TABLE IF NOT EXISTS test_failure( | |
394 test_run_id INT NOT NULL, | |
395 test_name VARCHAR(100) NOT NULL, | |
396 test_variant VARCHAR(16) NOT NULL, | |
397 info_text VARCHAR(255), | |
398 failure_text TEXT, | |
399 PRIMARY KEY (test_run_id, test_name, test_variant) | |
400 ) ENGINE=innodb | |
401 """) | |
402 txn.execute(""" | |
403 CREATE TABLE IF NOT EXISTS test_warnings( | |
404 test_run_id INT NOT NULL, | |
405 list_id INT NOT NULL, | |
406 list_idx INT NOT NULL, | |
407 test_name VARCHAR(100) NOT NULL, | |
408 PRIMARY KEY (test_run_id, list_id, list_idx) | |
409 ) ENGINE=innodb | |
410 """) | |
411 | |
412 revision = None | |
413 try: | |
414 revision = self.getProperty("got_revision") | |
415 except exceptions.KeyError: | |
416 revision = self.getProperty("revision") | |
417 typ = "mtr" | |
418 if self.test_type: | |
419 typ = self.test_type | |
420 txn.execute(""" | |
421 INSERT INTO test_run(branch, revision, platform, dt, bbnum, typ, info) | |
422 VALUES (%s, %s, %s, CURRENT_TIMESTAMP(), %s, %s, %s) | |
423 """, (self.getProperty("branch"), revision, | |
424 self.getProperty("buildername"), self.getProperty("buildnumber"), | |
425 typ, self.test_info)) | |
426 | |
427 return txn.lastrowid | |
428 | |
429 def afterRegisterInDB(self, insert_id): | |
430 self.setProperty("mtr_id", insert_id) | |
431 self.setProperty("mtr_warn_id", 0) | |
432 | |
433 Test.start(self) | |
434 | |
435 def reportError(self, err): | |
436 log.msg("Error in async insert into database: %s" % err) | |
437 | |
438 class MyMtrLogObserver(MtrLogObserver): | |
439 def collectTestFail(self, testname, variant, result, info, text): | |
440 # Insert asynchronously into database. | |
441 dbpool = self.step.dbpool | |
442 run_id = self.step.getProperty("mtr_id") | |
443 if dbpool == None: | |
444 return defer.succeed(None) | |
445 if variant == None: | |
446 variant = "" | |
447 d = self.step.runQueryWithRetry(""" | |
448 INSERT INTO test_failure(test_run_id, test_name, test_variant, info_text, failur
e_text) | |
449 VALUES (%s, %s, %s, %s, %s) | |
450 """, (run_id, testname, variant, info, text)) | |
451 | |
452 d.addErrback(self.step.reportError) | |
453 return d | |
454 | |
455 def collectWarningTests(self, testList): | |
456 # Insert asynchronously into database. | |
457 dbpool = self.step.dbpool | |
458 if dbpool == None: | |
459 return defer.succeed(None) | |
460 run_id = self.step.getProperty("mtr_id") | |
461 warn_id = self.step.getProperty("mtr_warn_id") | |
462 self.step.setProperty("mtr_warn_id", warn_id + 1) | |
463 q = ("INSERT INTO test_warnings(test_run_id, list_id, list_idx, test
_name) " + | |
464 "VALUES " + ", ".join(map(lambda x: "(%s, %s, %s, %s)", testLis
t))) | |
465 v = [] | |
466 idx = 0 | |
467 for t in testList: | |
468 v.extend([run_id, warn_id, idx, t]) | |
469 idx = idx + 1 | |
470 d = self.step.runQueryWithRetry(q, tuple(v)) | |
471 d.addErrback(self.step.reportError) | |
472 return d | |
OLD | NEW |