"Fossies" - the Fresh Open Source Software Archive

Member "buildbot-2.5.1/buildbot/steps/mtrlogobserver.py" (24 Nov 2019, 18000 Bytes) of package /linux/misc/buildbot-2.5.1.tar.gz:


As a special service "Fossies" has tried to format the requested source page into HTML format using (guessed) Python source code syntax highlighting (style: standard) with prefixed line numbers. Alternatively you can here view or download the uninterpreted source code file. For more information about "mtrlogobserver.py" see the Fossies "Dox" file reference documentation and the last Fossies "Diffs" side-by-side code changes report: 2.3.1_vs_2.4.0.

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