Index: cfe/trunk/utils/analyzer/SATestBuild.py =================================================================== --- cfe/trunk/utils/analyzer/SATestBuild.py +++ cfe/trunk/utils/analyzer/SATestBuild.py @@ -45,32 +45,55 @@ import CmpRuns import SATestUtils -import os +from subprocess import CalledProcessError, check_call +import argparse import csv -import sys import glob +import logging import math +import multiprocessing +import os +import plistlib import shutil +import sys +import threading import time -import plistlib -import argparse -from subprocess import check_call, CalledProcessError -import multiprocessing +import Queue #------------------------------------------------------------------------------ # Helper functions. #------------------------------------------------------------------------------ +Local = threading.local() +Local.stdout = sys.stdout +Local.stderr = sys.stderr +logging.basicConfig( + level=logging.DEBUG, + format='%(asctime)s:%(levelname)s:%(name)s: %(message)s') + +class StreamToLogger(object): + def __init__(self, logger, log_level=logging.INFO): + self.logger = logger + self.log_level = log_level + + def write(self, buf): + # Rstrip in order not to write an extra newline. + self.logger.log(self.log_level, buf.rstrip()) -sys.stdout = SATestUtils.flushfile(sys.stdout) + def flush(self): + pass + + def fileno(self): + return 0 def getProjectMapPath(): ProjectMapPath = os.path.join(os.path.abspath(os.curdir), ProjectMapFile) if not os.path.exists(ProjectMapPath): - print "Error: Cannot find the Project Map file " + ProjectMapPath +\ - "\nRunning script for the wrong directory?" + Local.stdout.write("Error: Cannot find the Project Map file " + + ProjectMapPath + + "\nRunning script for the wrong directory?\n") sys.exit(1) return ProjectMapPath @@ -100,7 +123,7 @@ sys.exit(1) # Number of jobs. -Jobs = int(math.ceil(multiprocessing.cpu_count() * 0.75)) +MaxJobs = int(math.ceil(multiprocessing.cpu_count() * 0.75)) # Project map stores info about all the "registered" projects. ProjectMapFile = "projectMap.csv" @@ -170,7 +193,8 @@ """ Cwd = os.path.join(Dir, PatchedSourceDirName) ScriptPath = os.path.join(Dir, CleanupScript) - SATestUtils.runScript(ScriptPath, PBuildLogFile, Cwd) + SATestUtils.runScript(ScriptPath, PBuildLogFile, Cwd, + Stdout=Local.stdout, Stderr=Local.stderr) def runDownloadScript(Dir, PBuildLogFile): @@ -178,7 +202,8 @@ Run the script to download the project, if it exists. """ ScriptPath = os.path.join(Dir, DownloadScript) - SATestUtils.runScript(ScriptPath, PBuildLogFile, Dir) + SATestUtils.runScript(ScriptPath, PBuildLogFile, Dir, + Stdout=Local.stdout, Stderr=Local.stderr) def downloadAndPatch(Dir, PBuildLogFile): @@ -192,8 +217,8 @@ if not os.path.exists(CachedSourceDirPath): runDownloadScript(Dir, PBuildLogFile) if not os.path.exists(CachedSourceDirPath): - print "Error: '%s' not found after download." % ( - CachedSourceDirPath) + Local.stderr.write("Error: '%s' not found after download.\n" % ( + CachedSourceDirPath)) exit(1) PatchedSourceDirPath = os.path.join(Dir, PatchedSourceDirName) @@ -211,10 +236,10 @@ PatchfilePath = os.path.join(Dir, PatchfileName) PatchedSourceDirPath = os.path.join(Dir, PatchedSourceDirName) if not os.path.exists(PatchfilePath): - print " No local patches." + Local.stdout.write(" No local patches.\n") return - print " Applying patch." + Local.stdout.write(" Applying patch.\n") try: check_call("patch -p1 < '%s'" % (PatchfilePath), cwd=PatchedSourceDirPath, @@ -222,7 +247,8 @@ stdout=PBuildLogFile, shell=True) except: - print "Error: Patch failed. See %s for details." % (PBuildLogFile.name) + Local.stderr.write("Error: Patch failed. See %s for details.\n" % ( + PBuildLogFile.name)) sys.exit(1) @@ -233,7 +259,8 @@ """ BuildScriptPath = os.path.join(Dir, BuildScript) if not os.path.exists(BuildScriptPath): - print "Error: build script is not defined: %s" % BuildScriptPath + Local.stderr.write( + "Error: build script is not defined: %s\n" % BuildScriptPath) sys.exit(1) AllCheckers = Checkers @@ -263,18 +290,19 @@ # automatically use the maximum number of cores. if (Command.startswith("make ") or Command == "make") and \ "-j" not in Command: - Command += " -j%d" % Jobs + Command += " -j%d" % MaxJobs SBCommand = SBPrefix + Command + if Verbose == 1: - print " Executing: %s" % (SBCommand,) + Local.stdout.write(" Executing: %s\n" % (SBCommand,)) check_call(SBCommand, cwd=SBCwd, stderr=PBuildLogFile, stdout=PBuildLogFile, shell=True) except CalledProcessError: - print "Error: scan-build failed. Its output was: " + Local.stderr.write("Error: scan-build failed. Its output was: \n") PBuildLogFile.seek(0) - shutil.copyfileobj(PBuildLogFile, sys.stdout) + shutil.copyfileobj(PBuildLogFile, Local.stderr) sys.exit(1) @@ -283,8 +311,9 @@ Run analysis on a set of preprocessed files. """ if os.path.exists(os.path.join(Dir, BuildScript)): - print "Error: The preprocessed files project should not contain %s" % \ - BuildScript + Local.stderr.write( + "Error: The preprocessed files project should not contain %s\n" % ( + BuildScript)) raise Exception() CmdPrefix = Clang + " -cc1 " @@ -314,7 +343,8 @@ if SATestUtils.hasNoExtension(FileName): continue if not SATestUtils.isValidSingleInputFile(FileName): - print "Error: Invalid single input file %s." % (FullFileName,) + Local.stderr.write( + "Error: Invalid single input file %s.\n" % (FullFileName,)) raise Exception() # Build and call the analyzer command. @@ -323,14 +353,15 @@ LogFile = open(os.path.join(FailPath, FileName + ".stderr.txt"), "w+b") try: if Verbose == 1: - print " Executing: %s" % (Command,) + Local.stdout.write(" Executing: %s\n" % (Command,)) check_call(Command, cwd=Dir, stderr=LogFile, stdout=LogFile, shell=True) except CalledProcessError, e: - print "Error: Analyzes of %s failed. See %s for details." \ - "Error code %d." % ( - FullFileName, LogFile.name, e.returncode) + Local.stderr.write("Error: Analyzes of %s failed. " + "See %s for details." + "Error code %d.\n" % ( + FullFileName, LogFile.name, e.returncode)) Failed = True finally: LogFile.close() @@ -350,7 +381,7 @@ if (os.path.exists(BuildLogPath)): RmCommand = "rm '%s'" % BuildLogPath if Verbose == 1: - print " Executing: %s" % (RmCommand,) + Local.stdout.write(" Executing: %s\n" % (RmCommand,)) check_call(RmCommand, shell=True) @@ -358,8 +389,8 @@ TBegin = time.time() BuildLogPath = getBuildLogPath(SBOutputDir) - print "Log file: %s" % (BuildLogPath,) - print "Output directory: %s" % (SBOutputDir, ) + Local.stdout.write("Log file: %s\n" % (BuildLogPath,)) + Local.stdout.write("Output directory: %s\n" % (SBOutputDir, )) removeLogFile(SBOutputDir) @@ -367,8 +398,9 @@ if (os.path.exists(SBOutputDir)): RmCommand = "rm -r '%s'" % SBOutputDir if Verbose == 1: - print " Executing: %s" % (RmCommand,) - check_call(RmCommand, shell=True) + Local.stdout.write(" Executing: %s\n" % (RmCommand,)) + check_call(RmCommand, shell=True, stdout=Local.stdout, + stderr=Local.stderr) assert(not os.path.exists(SBOutputDir)) os.makedirs(os.path.join(SBOutputDir, LogFolderName)) @@ -385,8 +417,9 @@ runCleanupScript(Dir, PBuildLogFile) normalizeReferenceResults(Dir, SBOutputDir, ProjectBuildMode) - print "Build complete (time: %.2f). See the log for more details: %s" % \ - ((time.time() - TBegin), BuildLogPath) + Local.stdout.write("Build complete (time: %.2f). " + "See the log for more details: %s\n" % ( + (time.time() - TBegin), BuildLogPath)) def normalizeReferenceResults(Dir, SBOutputDir, ProjectBuildMode): @@ -457,14 +490,16 @@ CleanUpEmptyPlists(SBOutputDir) CleanUpEmptyFolders(SBOutputDir) Plists = glob.glob(SBOutputDir + "/*/*.plist") - print "Number of bug reports (non-empty plist files) produced: %d" %\ - len(Plists) + Local.stdout.write( + "Number of bug reports (non-empty plist files) produced: %d\n" % + len(Plists)) return - print "Error: analysis failed." - print "Total of %d failures discovered." % TotalFailed + Local.stderr.write("Error: analysis failed.\n") + Local.stderr.write("Total of %d failures discovered.\n" % TotalFailed) if TotalFailed > NumOfFailuresInSummary: - print "See the first %d below.\n" % NumOfFailuresInSummary + Local.stderr.write( + "See the first %d below.\n" % NumOfFailuresInSummary) # TODO: Add a line "See the results folder for more." Idx = 0 @@ -472,9 +507,9 @@ if Idx >= NumOfFailuresInSummary: break Idx += 1 - print "\n-- Error #%d -----------\n" % Idx + Local.stderr.write("\n-- Error #%d -----------\n" % Idx) with open(FailLogPathI, "r") as FailLogI: - shutil.copyfileobj(FailLogI, sys.stdout) + shutil.copyfileobj(FailLogI, Local.stdout) sys.exit(1) @@ -527,7 +562,8 @@ assert(RefDir != NewDir) if Verbose == 1: - print " Comparing Results: %s %s" % (RefDir, NewDir) + Local.stdout.write(" Comparing Results: %s %s\n" % ( + RefDir, NewDir)) PatchedSourceDirPath = os.path.join(Dir, PatchedSourceDirName) Opts = CmpRuns.CmpOptions(rootA="", rootB=PatchedSourceDirPath) @@ -535,17 +571,18 @@ NumDiffs, ReportsInRef, ReportsInNew = \ CmpRuns.dumpScanBuildResultsDiff(RefDir, NewDir, Opts, False) if (NumDiffs > 0): - print "Warning: %s differences in diagnostics." % NumDiffs + Local.stdout.write("Warning: %s differences in diagnostics.\n" + % NumDiffs) if Strictness >= 2 and NumDiffs > 0: - print "Error: Diffs found in strict mode (2)." + Local.stdout.write("Error: Diffs found in strict mode (2).\n") TestsPassed = False elif Strictness >= 1 and ReportsInRef != ReportsInNew: - print "Error: The number of results are different in "\ - "strict mode (1)." + Local.stdout.write("Error: The number of results are different " + + " strict mode (1).\n") TestsPassed = False - print "Diagnostic comparison complete (time: %.2f)." % ( - time.time() - TBegin) + Local.stdout.write("Diagnostic comparison complete (time: %.2f).\n" % ( + time.time() - TBegin)) return TestsPassed @@ -565,19 +602,49 @@ removeLogFile(SBOutputDir) +class TestProjectThread(threading.Thread): + def __init__(self, TasksQueue, ResultsDiffer, FailureFlag): + """ + :param ResultsDiffer: Used to signify that results differ from + the canonical ones. + :param FailureFlag: Used to signify a failure during the run. + """ + self.TasksQueue = TasksQueue + self.ResultsDiffer = ResultsDiffer + self.FailureFlag = FailureFlag + super(TestProjectThread, self).__init__() + + # Needed to gracefully handle interrupts with Ctrl-C + self.daemon = True + + def run(self): + while not self.TasksQueue.empty(): + try: + ProjArgs = self.TasksQueue.get() + Logger = logging.getLogger(ProjArgs[0]) + Local.stdout = StreamToLogger(Logger, logging.INFO) + Local.stderr = StreamToLogger(Logger, logging.ERROR) + if not testProject(*ProjArgs): + self.ResultsDiffer.set() + self.TasksQueue.task_done() + except: + self.FailureFlag.set() + raise + + def testProject(ID, ProjectBuildMode, IsReferenceBuild=False, Strictness=0): """ Test a given project. :return TestsPassed: Whether tests have passed according to the :param Strictness: criteria. """ - print " \n\n--- Building project %s" % (ID,) + Local.stdout.write(" \n\n--- Building project %s\n" % (ID,)) TBegin = time.time() Dir = getProjectDir(ID) if Verbose == 1: - print " Build directory: %s." % (Dir,) + Local.stdout.write(" Build directory: %s.\n" % (Dir,)) # Set the build results directory. RelOutputDir = getSBOutputDirName(IsReferenceBuild) @@ -593,8 +660,8 @@ else: TestsPassed = runCmpResults(Dir, Strictness) - print "Completed tests for project %s (time: %.2f)." % \ - (ID, (time.time() - TBegin)) + Local.stdout.write("Completed tests for project %s (time: %.2f).\n" % ( + ID, (time.time() - TBegin))) return TestsPassed @@ -627,17 +694,62 @@ " (single file), 1 (project), or 2(single file c++11)." raise Exception() +def singleThreadedTestAll(ProjectsToTest): + """ + Run all projects. + :return: whether tests have passed. + """ + Success = True + for ProjArgs in ProjectsToTest: + Success &= testProject(*ProjArgs) + return Success + +def multiThreadedTestAll(ProjectsToTest, Jobs): + """ + Run each project in a separate thread. + + This is OK despite GIL, as testing is blocked + on launching external processes. + + :return: whether tests have passed. + """ + TasksQueue = Queue.Queue() + + for ProjArgs in ProjectsToTest: + TasksQueue.put(ProjArgs) + + ResultsDiffer = threading.Event() + FailureFlag = threading.Event() + + for i in range(Jobs): + T = TestProjectThread(TasksQueue, ResultsDiffer, FailureFlag) + T.start() + + # Required to handle Ctrl-C gracefully. + while TasksQueue.unfinished_tasks: + time.sleep(0.1) # Seconds. + if FailureFlag.is_set(): + Local.stderr.write("Test runner crashed\n") + sys.exit(1) + return not ResultsDiffer.is_set() + + +def testAll(Args): + ProjectsToTest = [] -def testAll(IsReferenceBuild=False, Strictness=0): - TestsPassed = True with projectFileHandler() as PMapFile: validateProjectFile(PMapFile) # Test the projects. for (ProjName, ProjBuildMode) in iterateOverProjects(PMapFile): - TestsPassed &= testProject( - ProjName, int(ProjBuildMode), IsReferenceBuild, Strictness) - return TestsPassed + ProjectsToTest.append((ProjName, + int(ProjBuildMode), + Args.regenerate, + Args.strictness)) + if Args.jobs <= 1: + return singleThreadedTestAll(ProjectsToTest) + else: + return multiThreadedTestAll(ProjectsToTest, Args.jobs) if __name__ == '__main__': @@ -651,14 +763,12 @@ reference. Default is 0.') Parser.add_argument('-r', dest='regenerate', action='store_true', default=False, help='Regenerate reference output.') + Parser.add_argument('-j', '--jobs', dest='jobs', type=int, + default=0, + help='Number of projects to test concurrently') Args = Parser.parse_args() - IsReference = False - Strictness = Args.strictness - if Args.regenerate: - IsReference = True - - TestsPassed = testAll(IsReference, Strictness) + TestsPassed = testAll(Args) if not TestsPassed: print "ERROR: Tests failed." sys.exit(42) Index: cfe/trunk/utils/analyzer/SATestUtils.py =================================================================== --- cfe/trunk/utils/analyzer/SATestUtils.py +++ cfe/trunk/utils/analyzer/SATestUtils.py @@ -37,18 +37,6 @@ return None -class flushfile(object): - """ - Wrapper to flush the output after every print statement. - """ - def __init__(self, f): - self.f = f - - def write(self, x): - self.f.write(x) - self.f.flush() - - def hasNoExtension(FileName): (Root, Ext) = os.path.splitext(FileName) return (Ext == "") @@ -71,14 +59,15 @@ return check_output(Cmd, shell=True).rstrip() -def runScript(ScriptPath, PBuildLogFile, Cwd): +def runScript(ScriptPath, PBuildLogFile, Cwd, Stdout=sys.stdout, + Stderr=sys.stderr): """ Run the provided script if it exists. """ if os.path.exists(ScriptPath): try: if Verbose == 1: - print " Executing: %s" % (ScriptPath,) + Stdout.write(" Executing: %s\n" % (ScriptPath,)) check_call("chmod +x '%s'" % ScriptPath, cwd=Cwd, stderr=PBuildLogFile, stdout=PBuildLogFile, @@ -88,8 +77,8 @@ stdout=PBuildLogFile, shell=True) except: - print "Error: Running %s failed. See %s for details." % ( - ScriptPath, PBuildLogFile.name) + Stderr.write("Error: Running %s failed. See %s for details.\n" % ( + ScriptPath, PBuildLogFile.name)) sys.exit(-1)