From 2c496351aa963f6844b234a69e6515929ca39d5a Mon Sep 17 00:00:00 2001 From: Bryan Gillespie Date: Mon, 30 Mar 2020 22:46:48 -0400 Subject: [PATCH] Switch to python's logging module Description: - Fix #41 - Refactor log traces to use python logging - Add `--verbose` option which sets logging level to debug - Add some debug level traces to print internal processing --- README.md | 2 +- example/build.sh | 3 +- fastcov.py | 83 +++++++++++++++++++++++++------------- test/functional/run_all.sh | 10 ++--- 4 files changed, 64 insertions(+), 34 deletions(-) diff --git a/README.md b/README.md index b619351..3454e7d 100644 --- a/README.md +++ b/README.md @@ -78,7 +78,7 @@ Here are some common filtering combinations you may find useful: ```bash $ fastcov.py --exclude /usr/include test/ # Exclude system header files and test files from final report $ fastcov.py --include src/ # Only include files with "src/" in its path in the final report -$ fastcov.py --source-files ../src/source1.cpp ../src/source2.cpp # Only include exactly ../src/source1.cpp and ../src/source2.cpp in the final rpeort +$ fastcov.py --source-files ../src/source1.cpp ../src/source2.cpp # Only include exactly ../src/source1.cpp and ../src/source2.cpp in the final report $ fastcov.py --branch-coverage # Only include most useful branches (discards exceptional branches and initializer list branches) $ fastcov.py --exceptional-branch-coverage # Include ALL branches in coverage report ``` diff --git a/example/build.sh b/example/build.sh index 086f739..a487eec 100755 --- a/example/build.sh +++ b/example/build.sh @@ -19,7 +19,8 @@ ninja ctest # Run fastcov with smart branch filtering, as well as system header (/usr/include) and cmake project test file filtering -${BASE_DIR}/fastcov.py -t ExampleTest --gcov gcov-9 --branch-coverage --exclude /usr/include cmake_project/test/ --lcov -o example.info +# ${BASE_DIR}/fastcov.py -t ExampleTest --gcov gcov-9 --branch-coverage --include cmake_project/src/ --verbose --lcov -o example.info +${BASE_DIR}/fastcov.py -t ExampleTest --gcov gcov-9 --branch-coverage --exclude /usr/include cmake_project/test/ --verbose --lcov -o example.info # Generate report with lcov's genhtml genhtml --branch-coverage example.info -o coverage_report diff --git a/fastcov.py b/fastcov.py index 43c2b77..9415556 100755 --- a/fastcov.py +++ b/fastcov.py @@ -22,6 +22,7 @@ import glob import json import time +import logging import argparse import threading import subprocess @@ -36,12 +37,14 @@ GCOVS_TOTAL = [] GCOVS_SKIPPED = [] -def logger(line, quiet=True): - if not quiet: - print("[{:.3f}s] {}".format(stopwatch(), line)) +# Disable all logging in case developers are using this as a module +logging.disable(level=logging.CRITICAL) -# Global logger defaults to quiet in case developers are using as module -log = logger +class FastcovFormatter(logging.Formatter): + def format(self, record): + record.levelname = record.levelname.lower() + log_message = super(FastcovFormatter, self).format(record) + return "[{:.3f}s] {}".format(stopwatch(), log_message) def chunks(l, n): """Yield successive n-sized chunks from l.""" @@ -79,6 +82,7 @@ def getFilteredCoverageFiles(coverage_files, exclude): def excludeGcda(gcda): for ex in exclude: if ex in gcda: + logging.debug("Omitting %s due to '--exclude-gcda %s'", gcda, ex) return False return True return list(filter(excludeGcda, coverage_files)) @@ -89,7 +93,8 @@ def findCoverageFiles(cwd, coverage_files, use_gcno): coverage_type = "gcno" if use_gcno else "gcda" coverage_files = glob.glob(os.path.join(os.path.abspath(cwd), "**/*." + coverage_type), recursive=True) - log("Found {} coverage files ({})".format(len(coverage_files), coverage_type)) + logging.info("Found {} coverage files ({})".format(len(coverage_files), coverage_type)) + logging.debug("Coverage files found:\n %s", "\n ".join(coverage_files)) return coverage_files def gcovWorker(cwd, gcov, files, chunk, gcov_filter_options, branch_coverage): @@ -117,7 +122,7 @@ def processGcdas(cwd, gcov, jobs, coverage_files, gcov_filter_options, branch_co threads.append(t) t.start() - log("Spawned {} gcov threads, each processing at most {} coverage files".format(len(threads), chunk_size)) + logging.info("Spawned {} gcov threads, each processing at most {} coverage files".format(len(threads), chunk_size)) for t in threads: t.join() @@ -131,22 +136,34 @@ def processGcov(cwd, gcov, files, gcov_filter_options): if gcov_filter_options["sources"]: if gcov["file_abs"] in gcov_filter_options["sources"]: files.append(gcov) + logging.debug("Accepted coverage for '%s'", gcov["file_abs"]) + else: + logging.debug("Skipping coverage for '%s' due to option '--source-files'", gcov["file_abs"]) return # Check exclude filter for ex in gcov_filter_options["exclude"]: if ex in gcov["file_abs"]: + logging.debug("Skipping coverage for '%s' due to option '--exclude %s'", gcov["file_abs"], ex) return # Check include filter if gcov_filter_options["include"]: + included = False for ex in gcov_filter_options["include"]: if ex in gcov["file_abs"]: + included = True files.append(gcov) + logging.debug("Accepted coverage for '%s'", gcov["file_abs"]) break + + if not included: + logging.debug("Skipping coverage for '%s' due to option '--include %s'", gcov["file_abs"], " ".join(gcov_filter_options["include"])) + return files.append(gcov) + logging.debug("Accepted coverage for '%s'", gcov["file_abs"]) def processGcovs(cwd, gcov_files, gcov_filter_options): files = [] @@ -217,7 +234,7 @@ def getSourceLines(source, fallback_encodings=[]): except UnicodeDecodeError: pass - log("Warning: could not decode '{}' with {} or fallback encodings ({}); ignoring errors".format(source, default_encoding, ",".join(fallback_encodings))) + logging.warning("Could not decode '{}' with {} or fallback encodings ({}); ignoring errors".format(source, default_encoding, ",".join(fallback_encodings))) with open(source, errors="ignore") as f: return f.readlines() @@ -272,7 +289,7 @@ def scanExclusionMarkers(fastcov_json, jobs, exclude_branches_sw, include_branch threads.append(t) t.start() - log("Spawned {} threads each scanning at most {} source files".format(len(threads), chunk_size)) + logging.info("Spawned {} threads each scanning at most {} source files".format(len(threads), chunk_size)) for t in threads: t.join() @@ -395,7 +412,7 @@ def addLists(list1, list2): return [b1 + b2 for b1, b2 in zip(list1, list2)] else: # One report had different number branch measurements than the other, print a warning - sys.stderr.write("Warning: possible loss of correctness. Different number of branches for same line when combining reports ({} vs {})\n".format(list1, list2)) + logging.warning("Possible loss of correctness. Different number of branches for same line when combining reports ({} vs {})\n".format(list1, list2)) return list1 if len(list1) > len(list2) else list2 def combineReports(base, overlay): @@ -496,25 +513,25 @@ def parseAndCombine(paths): if not base_report: base_report = report - log("Setting {} as base report".format(path)) + logging.info("Setting {} as base report".format(path)) else: combineReports(base_report, report) - log("Adding {} to base report".format(path)) + logging.info("Adding {} to base report".format(path)) return base_report def combineCoverageFiles(args): - log("Performing combine operation") + logging.info("Performing combine operation") fastcov_json = parseAndCombine(args.combine) dumpFile(fastcov_json, args) def dumpFile(fastcov_json, args): if args.lcov: dumpToLcovInfo(fastcov_json, args.output) - log("Created lcov info file '{}'".format(args.output)) + logging.info("Created lcov info file '{}'".format(args.output)) else: dumpToJson(fastcov_json, args.output) - log("Created fastcov json file '{}'".format(args.output)) + logging.info("Created fastcov json file '{}'".format(args.output)) def tupleToDotted(tup): return ".".join(map(str, tup)) @@ -558,17 +575,11 @@ def parseArgs(): parser.add_argument('-t', '--test-name', dest='test_name', default="", help='Specify a test name for the coverage. Equivalent to lcov\'s `-t`.') parser.add_argument('-C', '--add-tracefile', dest='combine', nargs="+", help='Combine multiple coverage files into one. If this flag is specified, fastcov will do a combine operation instead invoking gcov. Equivalent to lcov\'s `-a`.') + parser.add_argument('-V', '--verbose', dest="verbose", action="store_true", help="Print more detailed information about what fastcov is doing") parser.add_argument('-v', '--version', action="version", version='%(prog)s {version}'.format(version=__version__), help="Show program's version number and exit") args = parser.parse_args() - def arg_logger(line): - logger(line, quiet=args.quiet) - - # Change global logger settings to reflect arguments - global log - log = arg_logger - return args def checkPythonVersion(version): @@ -583,9 +594,26 @@ def checkGcovVersion(version): sys.stderr.write("Minimum gcov version {} required, found {}\n".format(tupleToDotted(MINIMUM_GCOV), tupleToDotted(version))) sys.exit(2) +def setupLogging(quiet, verbose): + handler = logging.StreamHandler() + handler.setFormatter(FastcovFormatter("[%(levelname)s]: %(message)s")) + + root = logging.getLogger() + root.setLevel(logging.INFO) + root.addHandler(handler) + + if not quiet: + logging.disable(level=logging.NOTSET) # Re-enable logging + + if verbose: + root.setLevel(logging.DEBUG) + def main(): args = parseArgs() + # Setup logging + setupLogging(args.quiet, args.verbose) + # Need at least python 3.5 because of use of recursive glob checkPythonVersion(sys.version_info[0:2]) @@ -603,12 +631,12 @@ def main(): # If gcda/gcno filtering is enabled, filter them out now if args.excludepre: coverage_files = getFilteredCoverageFiles(coverage_files, args.excludepre) - log("Found {} coverage files after filtering".format(len(coverage_files))) + logging.info("Found {} coverage files after filtering".format(len(coverage_files))) # We "zero" the "counters" by simply deleting all gcda files if args.zerocounters: removeFiles(coverage_files) - log("Removed {} .gcda files".format(len(coverage_files))) + logging.info("Removed {} .gcda files".format(len(coverage_files))) return # Fire up one gcov per cpu and start processing gcdas @@ -618,15 +646,16 @@ def main(): # Summarize processing results gcov_total = sum(GCOVS_TOTAL) gcov_skipped = sum(GCOVS_SKIPPED) - log("Processed {} .gcov files ({} total, {} skipped)".format(gcov_total - gcov_skipped, gcov_total, gcov_skipped)) + logging.info("Processed {} .gcov files ({} total, {} skipped)".format(gcov_total - gcov_skipped, gcov_total, gcov_skipped)) # Distill all the extraneous info gcov gives us down to the core report fastcov_json = distillReport(intermediate_json_files, args) - log("Aggregated raw gcov JSON into fastcov JSON report") + logging.info("Aggregated raw gcov JSON into fastcov JSON report") + logging.debug("Final report will contain coverage for the following %d source files:\n %s", len(fastcov_json["sources"]), "\n ".join(fastcov_json["sources"])) # Scan for exclusion markers scanExclusionMarkers(fastcov_json, args.jobs, args.exclude_branches_sw, args.include_branches_sw, args.minimum_chunk, args.fallback_encodings) - log("Scanned {} source files for exclusion markers".format(len(fastcov_json["sources"]))) + logging.info("Scanned {} source files for exclusion markers".format(len(fastcov_json["sources"]))) # Dump to desired file format dumpFile(fastcov_json, args) diff --git a/test/functional/run_all.sh b/test/functional/run_all.sh index 39f23af..089e0ad 100755 --- a/test/functional/run_all.sh +++ b/test/functional/run_all.sh @@ -34,7 +34,7 @@ ${TEST_DIR}/fastcov.py --gcov gcov-9 --zerocounters # Clear previous test cover ctest -R ctest_1 # Test (basic report generation - no branches) -coverage run --append ${TEST_DIR}/fastcov.py --gcov gcov-9 --exclude cmake_project/test/ --lcov -o test1.actual.info +coverage run --append ${TEST_DIR}/fastcov.py --gcov gcov-9 --verbose --exclude cmake_project/test/ --lcov -o test1.actual.info cmp test1.actual.info ${TEST_DIR}/expected_results/test1.expected.info coverage run --append ${TEST_DIR}/fastcov.py --gcov gcov-9 --exclude cmake_project/test/ -o test1.actual.fastcov.json @@ -52,15 +52,15 @@ coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gco ${TEST_DIR}/json_cmp.py test2.actual.fastcov.json ${TEST_DIR}/expected_results/test2.expected.fastcov.json # Test (basic lcov info - with branches; equivalent --include) -coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --include src/ --lcov -o test3.actual.info +coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --verbose --include src/ --lcov -o test3.actual.info cmp test3.actual.info ${TEST_DIR}/expected_results/test2.expected.info # Test (basic lcov info - with branches; equivalent --exclude-gcda) -coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --exclude-gcda test1.cpp.gcda --lcov -o test4.actual.info +coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --verbose --exclude-gcda test1.cpp.gcda --lcov -o test4.actual.info cmp test4.actual.info ${TEST_DIR}/expected_results/test2.expected.info # Test (basic lcov info - with branches; equivalent --source-files) -coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --source-files ../src/source1.cpp ../src/source2.cpp --lcov -o test5.actual.info +coverage run --append ${TEST_DIR}/fastcov.py --exceptional-branch-coverage --gcov gcov-9 --verbose --source-files ../src/source1.cpp ../src/source2.cpp --lcov -o test5.actual.info cmp test5.actual.info ${TEST_DIR}/expected_results/test2.expected.info # Test (basic lcov info - with branches; gcno untested file coverage) @@ -146,4 +146,4 @@ cmp multitest.actual.info ${TEST_DIR}/expected_results/multitest.expected.info # Write out coverage as xml coverage xml -o coverage.xml -# coverage html # Generate HTML report \ No newline at end of file +coverage html # Generate HTML report \ No newline at end of file