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

Source Code for Module buildbot.process.mtrlogobserver

  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_max=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 shutdown 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, self.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 '.*' failed", 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, failure_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)", testList))) 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
473