testing/peptest/peptest/pepprocess.py
author Monica Chew <mmc@mozilla.com>
Thu, 07 Mar 2013 08:35:38 -0500
changeset 124107 99ef1303095d41f4bb647fcb0e318cef22d42d3b
parent 101262 f36cf6866998430dfadda7b138350083ae374537
permissions -rw-r--r--
Bug 844392 - Fix race condition where ProcessStateChange can remove a file before cleanup. r=paolo

# This Source Code Form is subject to the terms of the Mozilla Public
# License, v. 2.0. If a copy of the MPL was not distributed with this file,
# You can obtain one at http://mozilla.org/MPL/2.0/.

from mozprocess import ProcessHandler
from pepresults import Results
from time import sleep
from threading import Thread
import mozlog
import os

results = Results()

class PepProcess(ProcessHandler):
    """
    Process handler for running peptests
    """
    def __init__(self, cmd,
                       args=None, cwd=None,
                       env=os.environ.copy(),
                       ignore_children=False,
                       **kwargs):

        ProcessHandler.__init__(self, cmd, args=args, cwd=cwd, env=env,
                                ignore_children=ignore_children, **kwargs)

        self.logger = mozlog.getLogger('PEP')
        results.fails[str(None)] = []

    def waitForQuit(self, timeout=5):
        for i in range(1, timeout):
            if self.proc.returncode != None:
                return
            sleep(1)
        self.proc.kill()

    def processOutputLine(self, line):
        """
        Callback called on each line of output
        Responsible for determining which output lines are relevant
        and writing them to a log
        """
        tokens = line.split(' ')
        if len(tokens) > 1 and tokens[0] == 'PEP':
            # The output is generated from the Peptest extension
            # Format is 'PEP <LEVEL> <MSG>' where <MSG> can have multiple tokens
            # The content of <MSG> depends on the <LEVEL>
            if line.find('Test Suite Finished') != -1:
                thread = Thread(target=self.waitForQuit)
                thread.setDaemon(True) # don't hang on quit
                thread.start()

            level = tokens[1]
            if level == 'TEST-START':
                results.currentTest = tokens[2].rstrip()
                results.fails[results.currentTest] = []
                self.logger.testStart(results.currentTest)
            elif level == 'TEST-END':
                metric = results.get_metric(results.currentTest)
                if len(tokens) > 4:
                    threshold = float(tokens[4].rstrip())
                else:
                    threshold = 0.0

                msg = '%s | fail threshold: %s' % (results.currentTest, threshold)
                if metric > threshold:
                    msg += ' < metric: %s' % metric
                    self.logger.testFail(msg)
                else:
                    msg += ' >= metric: %s' % metric
                    self.logger.testPass(msg)

                self.logger.testEnd('%s | finished in: %s ms' %
                        (results.currentTest, tokens[3].rstrip()))
                results.currentTest = None
            elif level == 'ACTION-START':
                results.currentAction = tokens[3].rstrip()
                self.logger.debug('%s | %s' % (level, results.currentAction))
            elif level == 'ACTION-END':
                self.logger.debug('%s | %s' % (level, results.currentAction))
                results.currentAction = None
            elif level in ['DEBUG', 'INFO', 'WARNING', 'ERROR']:
                line = line[len('PEP ' + level)+1:]
                getattr(self.logger, level.lower())(line.rstrip())
                if level == 'ERROR':
                    results.fails[str(results.currentTest)].append(0)
            else:
                line = line[len('PEP'):]
                self.logger.debug(line.rstrip())
        elif tokens[0] == 'MOZ_EVENT_TRACE' and results.currentAction is not None:
            # The output is generated from EventTracer
            # Format is 'MOZ_EVENT_TRACE sample <TIMESTAMP> <VALUE>
            # <VALUE> is the unresponsive time in ms
            self.logger.warning('%s | %s | unresponsive time: %s ms' %
                (results.currentTest, results.currentAction, tokens[3].rstrip()))
            results.fails[results.currentTest].append(int(tokens[3].rstrip()))