Package buildbot :: Package process :: Module mtrlogobserver
[frames] | no frames]

Source Code for Module buildbot.process.mtrlogobserver

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