diff --git a/python/extractor/cli-integration-test/writing-diagnostics/diagnostics.expected b/python/extractor/cli-integration-test/writing-diagnostics/diagnostics.expected index 715fb8dd12f7..4b6fceb48faf 100644 --- a/python/extractor/cli-integration-test/writing-diagnostics/diagnostics.expected +++ b/python/extractor/cli-integration-test/writing-diagnostics/diagnostics.expected @@ -163,6 +163,7 @@ } { "attributes": { + "extractor_flags": "default", "extractor_version": "7.1.10", "python_analysis_version": "3.12", "python_runtime_version": "3.12.3" diff --git a/python/extractor/cli-integration-test/writing-diagnostics/test.sh b/python/extractor/cli-integration-test/writing-diagnostics/test.sh index 32915e2d73c2..cce66c7904ca 100755 --- a/python/extractor/cli-integration-test/writing-diagnostics/test.sh +++ b/python/extractor/cli-integration-test/writing-diagnostics/test.sh @@ -18,7 +18,7 @@ echo "Testing database with various errors during extraction" $CODEQL database create db --language python --source-root repo_dir/ $CODEQL query run --database db query.ql > query.actual diff query.expected query.actual -python3 test_diagnostics_output.py +python3 test_diagnostics_output.py "$CODEQL" rm -f *.actual rm -f repo_dir/recursion_error.py diff --git a/python/extractor/cli-integration-test/writing-diagnostics/test_diagnostics_output.py b/python/extractor/cli-integration-test/writing-diagnostics/test_diagnostics_output.py index 0dce022a0f95..3ff2fcb20106 100644 --- a/python/extractor/cli-integration-test/writing-diagnostics/test_diagnostics_output.py +++ b/python/extractor/cli-integration-test/writing-diagnostics/test_diagnostics_output.py @@ -1,7 +1,40 @@ import os import sys +import json +import subprocess sys.path.append(os.path.join(os.path.dirname(__file__), "..", "..", "..", "..", "..", "integration-tests")) import diagnostics_test_utils test_db = "db" -diagnostics_test_utils.check_diagnostics(".", test_db, skip_attributes=True) +actual = subprocess.run( + [sys.argv[1], "database", "export-diagnostics", "--format", "raw", "--", test_db], + stdout=subprocess.PIPE, + universal_newlines=True, + check=True, +).stdout +diagnostics = json.loads(actual) +summary = [ + diagnostic + for diagnostic in diagnostics + if diagnostic["source"]["id"] == "py/extractor/summary" +] +assert len(summary) == 1 +assert summary[0]["attributes"]["extractor_flags"] == "default" +parser_statistics = [ + diagnostic + for diagnostic in diagnostics + if diagnostic["source"]["id"] == "py/extractor/parser-statistics" +] +assert sum( + diagnostic["attributes"]["old_parser_file_count"] + + diagnostic["attributes"]["tree_sitter_parser_file_count"] + for diagnostic in parser_statistics +) == 2 +diagnostics = [ + diagnostic + for diagnostic in diagnostics + if diagnostic["source"]["id"] != "py/extractor/parser-statistics" +] +diagnostics_test_utils.check_diagnostics( + ".", test_db, actual=json.dumps(diagnostics), skip_attributes=True +) diff --git a/python/extractor/semmle/cmdline.py b/python/extractor/semmle/cmdline.py index 47007c065fdc..213a1f4affae 100644 --- a/python/extractor/semmle/cmdline.py +++ b/python/extractor/semmle/cmdline.py @@ -1,4 +1,4 @@ -from optparse import OptionParser, OptionGroup, HelpFormatter +from optparse import Option, OptionParser, OptionGroup, HelpFormatter import shlex import sys import os @@ -8,9 +8,21 @@ from semmle.util import VERSION +DEFAULT_AUTOBUILDER_FLAGS = {"R", "c", "v", "verbosity", "z"} + + +class RecordingOption(Option): + def process(self, opt, value, values, parser): + flag = (self._short_opts or self._long_opts)[0].lstrip("-") + if flag not in DEFAULT_AUTOBUILDER_FLAGS: + parser.extractor_flags.add(flag) + return Option.process(self, opt, value, values, parser) + + def make_parser(): '''Parse command_line, returning options, arguments''' - parser = OptionParser(add_help_option=False, version='%s' % VERSION) + parser = OptionParser(option_class=RecordingOption, add_help_option=False, version='%s' % VERSION) + parser.extractor_flags = set() import_options = OptionGroup(parser, "Import following options", description="Note that -a -n -g and -t are included for backwards compatibility. They are ignored") @@ -172,6 +184,7 @@ def parse(command_line): setattr(options, attr, dval) args.extend(extra_args) del options.file + options.extractor_flags = sorted(parser.extractor_flags) if options.help: if options.verbose: for opt in parser._get_all_options(): diff --git a/python/extractor/semmle/extractors/module_printer.py b/python/extractor/semmle/extractors/module_printer.py index d2f4a6cc92bd..aeaa8e63f5eb 100644 --- a/python/extractor/semmle/extractors/module_printer.py +++ b/python/extractor/semmle/extractors/module_printer.py @@ -6,9 +6,9 @@ class ModulePrinter(object): name = "module printer" - def __init__(self, options, trap_folder, src_archive, renamer, logger): + def __init__(self, options, trap_folder, src_archive, renamer, logger, diagnostics_writer): self.logger = logger - self.py_extractor = PythonExtractor(options, trap_folder, src_archive, logger) + self.py_extractor = PythonExtractor(options, trap_folder, src_archive, logger, diagnostics_writer) def process(self, unit): imports = () diff --git a/python/extractor/semmle/extractors/py_extractor.py b/python/extractor/semmle/extractors/py_extractor.py index 8014063b3cb8..3b5a37fb7a96 100644 --- a/python/extractor/semmle/extractors/py_extractor.py +++ b/python/extractor/semmle/extractors/py_extractor.py @@ -16,6 +16,7 @@ def __init__(self, options, trap_folder, src_archive, logger: Logger, diagnostic self.module_extractor = extractor.Extractor.from_options(options, trap_folder, src_archive, logger, diagnostics_writer) self.finder = finder.Finder.from_options_and_env(options, logger) self.importer = imports.importer_from_options(options, self.finder, logger) + self.diagnostics_writer = diagnostics_writer def _get_module_and_imports(self, unit): if not isinstance(unit, util.FileExtractable): @@ -24,7 +25,7 @@ def _get_module_and_imports(self, unit): module = self.finder.from_extractable(unit) if module is None: return None, () - py_module = module.load(self.logger) + py_module = module.load(self.logger, self.diagnostics_writer) if py_module is None: return None, () imports = set(mod.get_extractable() for mod in self.importer.get_imports(module, py_module)) diff --git a/python/extractor/semmle/logging.py b/python/extractor/semmle/logging.py index 369592534676..652ab810d0fb 100644 --- a/python/extractor/semmle/logging.py +++ b/python/extractor/semmle/logging.py @@ -358,12 +358,21 @@ def with_timestamp(self, timestamp): self.timestamp = timestamp return self -def extractor_telemetry_message(): +def extractor_telemetry_message(extractor_flags): return (DiagnosticMessage(Source("py/extractor/summary", "Python extractor telemetry"), Severity.NOTE) .markdown("Internal telemetry for the Python extractor.\n\nNo action needed.") .attribute("python_analysis_version", get_analysis_version()) .attribute("python_runtime_version", platform.python_version()) .attribute("extractor_version", VERSION) + .attribute("extractor_flags", " ".join(extractor_flags) or "default") + .telemetry() + ) + +def parser_statistics_telemetry_message(old_parser_file_count, tree_sitter_parser_file_count): + return (DiagnosticMessage(Source("py/extractor/parser-statistics", "Python parser statistics"), Severity.NOTE) + .markdown("Internal parser telemetry for the Python extractor.\n\nNo action needed.") + .attribute("old_parser_file_count", old_parser_file_count) + .attribute("tree_sitter_parser_file_count", tree_sitter_parser_file_count) .telemetry() ) diff --git a/python/extractor/semmle/python/finder.py b/python/extractor/semmle/python/finder.py index 632ef920d055..46e63f5e578f 100644 --- a/python/extractor/semmle/python/finder.py +++ b/python/extractor/semmle/python/finder.py @@ -65,8 +65,8 @@ def all_sub_modules(self): def get_extractable(self): return FileExtractable(self.path) - def load(self, logger=None): - return PythonSourceModule(self.name, self.path, logger=logger) + def load(self, logger, diagnostics_writer): + return PythonSourceModule(self.name, self.path, logger=logger, diagnostics_writer=diagnostics_writer) def __str__(self): return "Python module at %s" % self.path diff --git a/python/extractor/semmle/python/modules.py b/python/extractor/semmle/python/modules.py index 810c4e060f7b..7192f97cfb11 100644 --- a/python/extractor/semmle/python/modules.py +++ b/python/extractor/semmle/python/modules.py @@ -18,7 +18,7 @@ class PythonSourceModule(object): kind = None - def __init__(self, name, path, logger, bytes_source = None): + def __init__(self, name, path, logger, diagnostics_writer, bytes_source = None): assert isinstance(path, str), path self.name = name # May be None self.path = path @@ -34,6 +34,7 @@ def __init__(self, name, path, logger, bytes_source = None): self._line_types = None self._comments = None self._tokens = None + self.diagnostics_writer = diagnostics_writer self.logger = logger with timers["decode"]: self.encoding, self.bytes_source = semmle.python.parser.tokenizer.encoding_from_source(bytes_source) @@ -113,6 +114,7 @@ def old_py_ast(self): self.logger.debug("Trying old parser on %s", self.path) self._py_ast = semmle.python.parser.parse(self.tokens, self.logger) self.logger.debug("Old parser successful on %s", self.path) + self.diagnostics_writer.record_old_parser() else: self.logger.debug("Found (during old_py_ast) parse tree for %s in cache", self.path) return self._py_ast @@ -147,6 +149,7 @@ def py_ast(self): self.logger.debug("Trying tsg-python on %s", self.path) self._py_ast = semmle.python.parser.tsg_parser.parse(self.path, self.logger) self.logger.debug("tsg-python successful on %s", self.path) + self.diagnostics_writer.record_tree_sitter_parser() else: self.logger.debug("Found (during py_ast) parse tree for %s in cache", self.path) return self._py_ast diff --git a/python/extractor/semmle/python/parser/dump_ast.py b/python/extractor/semmle/python/parser/dump_ast.py index 3a7db5ab0713..97abb502e59a 100644 --- a/python/extractor/semmle/python/parser/dump_ast.py +++ b/python/extractor/semmle/python/parser/dump_ast.py @@ -119,7 +119,8 @@ def reset_error_count(self): self.error_count = 0 def old_parser(inputfile, logger): - mod = PythonSourceModule(None, inputfile, logger) + from semmle.worker import DiagnosticsWriter + mod = PythonSourceModule(None, inputfile, logger, DiagnosticsWriter(0)) logger.close() return mod.old_py_ast diff --git a/python/extractor/semmle/python/passes/flow.py b/python/extractor/semmle/python/passes/flow.py index 6ea5405a8540..a100bbae7c9c 100755 --- a/python/extractor/semmle/python/passes/flow.py +++ b/python/extractor/semmle/python/passes/flow.py @@ -1916,7 +1916,8 @@ def write_ssa_phi(out, phi, arg): import semmle.python.parser.tsg_parser parsed_ast = semmle.python.parser.tsg_parser.parse(inputfile, FakeLogger()) else: - module = modules.PythonSourceModule("__main__", inputfile, FakeLogger()) + from semmle.worker import DiagnosticsWriter + module = modules.PythonSourceModule("__main__", inputfile, FakeLogger(), DiagnosticsWriter(0)) parsed_ast = module.ast FlowPass(options.split, options.prune, options.unroll).extract(parsed_ast, writer) writer.close() diff --git a/python/extractor/semmle/worker.py b/python/extractor/semmle/worker.py index 8d771828ada8..15b7b556bf88 100644 --- a/python/extractor/semmle/worker.py +++ b/python/extractor/semmle/worker.py @@ -11,6 +11,7 @@ from semmle.profiling import get_profiler from semmle.path_rename import renamer_from_options_and_env from semmle.logging import WARN, recursion_error_message, internal_error_message, extractor_telemetry_message, Logger +from semmle.logging import parser_statistics_telemetry_message from semmle.util import FileExtractable, FolderExtractable class ExtractorFailure(Exception): @@ -239,15 +240,35 @@ def _drain_queue(queue): #Emptied queue as best we can. pass -def _write_extractor_telemetry(diagnostics_writer, logger: Logger): +def _write_extractor_telemetry(diagnostics_writer, logger: Logger, extractor_flags): try: - diagnostics_writer.write(extractor_telemetry_message()) + diagnostics_writer.write(extractor_telemetry_message(extractor_flags)) except OSError as ex: logger.warning("Failed to write extractor telemetry: %s", ex) +def _write_parser_statistics_telemetry(diagnostics_writer, logger: Logger): + counts = diagnostics_writer.parser_statistics() + if counts == (0, 0): + return + try: + diagnostics_writer.write(parser_statistics_telemetry_message(*counts)) + except OSError as ex: + logger.warning("Failed to write parser statistics telemetry: %s", ex) + class DiagnosticsWriter(object): def __init__(self, proc_id): self.proc_id = proc_id + self.old_parser_file_count = 0 + self.tree_sitter_parser_file_count = 0 + + def record_old_parser(self): + self.old_parser_file_count += 1 + + def record_tree_sitter_parser(self): + self.tree_sitter_parser_file_count += 1 + + def parser_statistics(self): + return self.old_parser_file_count, self.tree_sitter_parser_file_count def write(self, message): dir = os.environ.get("CODEQL_EXTRACTOR_PYTHON_DIAGNOSTIC_DIR") @@ -283,10 +304,10 @@ def _extract_loop(proc_id, queue, trap_dir, archive, options, reply_queue, logge sys.exit(2) logger.set_process_id(proc_id) if write_global_data: - _write_extractor_telemetry(diagnostics_writer, logger) + _write_extractor_telemetry(diagnostics_writer, logger, options.extractor_flags) try: if options.trace_only: - extractor = ModulePrinter(options, trap_dir, archive, renamer, logger) + extractor = ModulePrinter(options, trap_dir, archive, renamer, logger, diagnostics_writer) else: extractor = SuperExtractor(options, trap_dir, archive, renamer, logger, diagnostics_writer) profiler = get_profiler(options, id, logger) @@ -299,6 +320,7 @@ def _extract_loop(proc_id, queue, trap_dir, archive, options, reply_queue, logge if write_global_data: extractor.write_global_data() extractor.close() + _write_parser_statistics_telemetry(diagnostics_writer, logger) return try: start = time.time() @@ -352,4 +374,5 @@ def _extract_loop(proc_id, queue, trap_dir, archive, options, reply_queue, logge except _Empty: #Cleared queue enough to avoid deadlock. pass + _write_parser_statistics_telemetry(diagnostics_writer, logger) sys.exit(2) diff --git a/python/extractor/tests/test_cmdline.py b/python/extractor/tests/test_cmdline.py new file mode 100644 index 000000000000..76f2fe951b57 --- /dev/null +++ b/python/extractor/tests/test_cmdline.py @@ -0,0 +1,34 @@ +from semmle import cmdline + + +def test_records_flags_without_values(): + options, args = cmdline.parse( + [ + "--verbosity=3", + "-zall", + "-R", + "/src", + "-vv", + "--path", + "/lib", + "-p", + "/other-lib", + "module", + ] + ) + + assert options.extractor_flags == ["p"] + assert args == ["module"] + + +def test_records_flags_from_option_file(tmp_path): + options_file = tmp_path / "extractor-options" + options_file.write_text("--colorize --max-import-depth 2") + + options, _ = cmdline.parse(["-f", str(options_file)]) + + assert options.extractor_flags == [ + "colorize", + "f", + "max-import-depth", + ] diff --git a/python/extractor/tests/test_diagnostics.py b/python/extractor/tests/test_diagnostics.py index a40f339e3e4b..ddfd22436de9 100644 --- a/python/extractor/tests/test_diagnostics.py +++ b/python/extractor/tests/test_diagnostics.py @@ -3,12 +3,13 @@ from semmle import logging from semmle import util from semmle import worker +from semmle.python.modules import PythonSourceModule def test_extractor_telemetry_message(mocker): mocker.patch("semmle.logging.get_analysis_version", return_value="3.13") - message = logging.extractor_telemetry_message().to_dict() + message = logging.extractor_telemetry_message(["colorize", "p"]).to_dict() message.pop("timestamp") assert message == { @@ -28,17 +29,56 @@ def test_extractor_telemetry_message(mocker): "python_analysis_version": "3.13", "python_runtime_version": platform.python_version(), "extractor_version": util.VERSION, + "extractor_flags": "colorize p", }, } +def test_parser_statistics_telemetry_message(): + message = logging.parser_statistics_telemetry_message( + old_parser_file_count=12, tree_sitter_parser_file_count=3 + ).to_dict() + message.pop("timestamp") + + assert message == { + "source": { + "id": "py/extractor/parser-statistics", + "name": "Python parser statistics", + "extractorName": "python", + }, + "severity": "note", + "markdownMessage": "Internal parser telemetry for the Python extractor.\n\nNo action needed.", + "visibility": { + "statusPage": False, + "cliSummaryTable": False, + "telemetry": True, + }, + "attributes": { + "old_parser_file_count": 12, + "tree_sitter_parser_file_count": 3, + }, + } + + +def test_extractor_telemetry_message_includes_empty_flags(): + message = logging.extractor_telemetry_message([]).to_dict() + + assert message["attributes"]["extractor_flags"] == "default" + + def test_write_extractor_telemetry(mocker): diagnostics_writer = mocker.Mock() logger = mocker.Mock() - worker._write_extractor_telemetry(diagnostics_writer, logger) + worker._write_extractor_telemetry(diagnostics_writer, logger, ["quiet"]) diagnostics_writer.write.assert_called_once() + assert diagnostics_writer.write.call_args.args[0].to_dict()["attributes"] == { + "python_analysis_version": util.get_analysis_version(), + "python_runtime_version": platform.python_version(), + "extractor_version": util.VERSION, + "extractor_flags": "quiet", + } logger.warning.assert_not_called() @@ -47,8 +87,81 @@ def test_write_extractor_telemetry_handles_io_error(mocker): diagnostics_writer.write.side_effect = OSError("write failed") logger = mocker.Mock() - worker._write_extractor_telemetry(diagnostics_writer, logger) + worker._write_extractor_telemetry(diagnostics_writer, logger, []) logger.warning.assert_called_once_with( "Failed to write extractor telemetry: %s", diagnostics_writer.write.side_effect ) + + +def test_write_parser_statistics_telemetry(mocker): + diagnostics_writer = mocker.Mock() + diagnostics_writer.parser_statistics.return_value = (1, 1) + logger = mocker.Mock() + + worker._write_parser_statistics_telemetry(diagnostics_writer, logger) + + diagnostics_writer.write.assert_called_once() + assert diagnostics_writer.write.call_args.args[0].to_dict()["attributes"] == { + "old_parser_file_count": 1, + "tree_sitter_parser_file_count": 1, + } + logger.warning.assert_not_called() + + +def test_does_not_write_empty_parser_statistics_telemetry(mocker): + diagnostics_writer = mocker.Mock() + diagnostics_writer.parser_statistics.return_value = (0, 0) + logger = mocker.Mock() + + worker._write_parser_statistics_telemetry(diagnostics_writer, logger) + + diagnostics_writer.write.assert_not_called() + logger.warning.assert_not_called() + + +def test_records_old_parser_usage_once(mocker, monkeypatch): + monkeypatch.delenv("CODEQL_PYTHON_DISABLE_OLD_PARSER", raising=False) + monkeypatch.delenv("CODEQL_PYTHON_DISABLE_TSG_PARSER", raising=False) + old_ast = object() + mocker.patch("semmle.python.parser.parse", return_value=old_ast) + diagnostics_writer = worker.DiagnosticsWriter(1) + module = PythonSourceModule( + None, + "test.py", + mocker.Mock(), + diagnostics_writer, + bytes_source=b"x = 1\n", + ) + + parsed_ast = module.py_ast + # Access the cached AST again to verify that it is not counted twice. + _ = module.py_ast + + assert parsed_ast is old_ast + assert diagnostics_writer.parser_statistics() == (1, 0) + + +def test_records_tree_sitter_parser_usage_once(mocker, monkeypatch): + monkeypatch.delenv("CODEQL_PYTHON_DISABLE_OLD_PARSER", raising=False) + monkeypatch.delenv("CODEQL_PYTHON_DISABLE_TSG_PARSER", raising=False) + tree_sitter_ast = object() + mocker.patch("semmle.python.parser.parse", side_effect=SyntaxError("old parser failed")) + mocker.patch( + "semmle.python.parser.tsg_parser.parse", return_value=tree_sitter_ast + ) + diagnostics_writer = worker.DiagnosticsWriter(1) + module = PythonSourceModule( + None, + "test.py", + mocker.Mock(), + diagnostics_writer, + bytes_source=b"x = 1\n", + ) + + parsed_ast = module.py_ast + # Access the cached AST again to verify that it is not counted twice. + _ = module.py_ast + + assert parsed_ast is tree_sitter_ast + assert diagnostics_writer.parser_statistics() == (0, 1)