diff --git a/CHANGELOG.rst b/CHANGELOG.rst index 0ca0cd22..c6e5085d 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -11,10 +11,19 @@ Changes * FIX: Fixed explicit profiling of class methods; added handling for profiling static, bound, and partial methods, ``functools.partial`` objects, (cached) properties, and async generator functions * FIX: Fixed namespace bug when running ``kernprof -m`` on certain modules (e.g. ``calendar`` on Python 3.12+). * FIX: Fixed ``@contextlib.contextmanager`` bug where the cleanup code (e.g. restoration of ``sys`` attributes) is not run if exceptions occurred inside the context -* ENH: Added CLI arguments ``-c`` to ``kernprof`` for (auto-)profiling module/package/inline-script execution instead of that of script files; passing ``'-'`` as the script-file name now also reads from and profiles ``stdin`` +* ENH: Added CLI arguments ``-c`` to ``kernprof`` for (auto-)profiling inline-script execution instead of that of script files; passing ``'-'`` as the script-file name now also reads from and profiles ``stdin`` * ENH: In Python >=3.11, profiled objects are reported using their qualified name. * ENH: Highlight final summary using rich if enabled * ENH: Made it possible to use multiple profiler instances simultaneously +* ENH: various improvements related to auto-profiling: + * ``kernprof -p`` target entities are now imported and profiled regardless of + whether they are directly imported in the run script/module/code (old + behavior restored by passing ``--no-preimports``) + * ``kernprof -v`` and the new ``-q`` now control the verbosity level instead + of being a boolean, allowing diagnostic outputs or output suppression + * On-import profiling is now more aggressive so that it doesn't miss entities + like class methods and properties + * ``LineProfiler`` can now be used as a class decorator 4.2.0 ~~~~~ diff --git a/docs/source/auto/line_profiler.autoprofile.ast_profle_transformer.rst b/docs/source/auto/line_profiler.autoprofile.ast_profile_transformer.rst similarity index 100% rename from docs/source/auto/line_profiler.autoprofile.ast_profle_transformer.rst rename to docs/source/auto/line_profiler.autoprofile.ast_profile_transformer.rst diff --git a/docs/source/auto/line_profiler.autoprofile.eager_preimports.rst b/docs/source/auto/line_profiler.autoprofile.eager_preimports.rst new file mode 100644 index 00000000..6803f2db --- /dev/null +++ b/docs/source/auto/line_profiler.autoprofile.eager_preimports.rst @@ -0,0 +1,8 @@ +line\_profiler.autoprofile.eager\_preimports module +=================================================== + +.. automodule:: line_profiler.autoprofile.eager_preimports + :members: + :undoc-members: + :show-inheritance: + :private-members: diff --git a/docs/source/auto/line_profiler.autoprofile.rst b/docs/source/auto/line_profiler.autoprofile.rst index 74ced100..4f6b40d7 100644 --- a/docs/source/auto/line_profiler.autoprofile.rst +++ b/docs/source/auto/line_profiler.autoprofile.rst @@ -10,8 +10,10 @@ Submodules line_profiler.autoprofile.ast_profile_transformer line_profiler.autoprofile.ast_tree_profiler line_profiler.autoprofile.autoprofile + line_profiler.autoprofile.eager_preimports line_profiler.autoprofile.line_profiler_utils line_profiler.autoprofile.profmod_extractor + line_profiler.autoprofile.run_module line_profiler.autoprofile.util_static Module contents diff --git a/docs/source/auto/line_profiler.autoprofile.run_module.rst b/docs/source/auto/line_profiler.autoprofile.run_module.rst new file mode 100644 index 00000000..238d24e2 --- /dev/null +++ b/docs/source/auto/line_profiler.autoprofile.run_module.rst @@ -0,0 +1,8 @@ +line\_profiler.autoprofile.run\_module module +============================================= + +.. automodule:: line_profiler.autoprofile.run_module + :members: + :undoc-members: + :show-inheritance: + :private-members: diff --git a/docs/source/auto/line_profiler.profiler_mixin.rst b/docs/source/auto/line_profiler.profiler_mixin.rst new file mode 100644 index 00000000..82e600f1 --- /dev/null +++ b/docs/source/auto/line_profiler.profiler_mixin.rst @@ -0,0 +1,8 @@ +line\_profiler.profiler\_mixin module +===================================== + +.. automodule:: line_profiler.profiler_mixin + :members: + :undoc-members: + :show-inheritance: + :private-members: diff --git a/docs/source/auto/line_profiler.rst b/docs/source/auto/line_profiler.rst index 4cdaccef..a2b108b3 100644 --- a/docs/source/auto/line_profiler.rst +++ b/docs/source/auto/line_profiler.rst @@ -20,6 +20,8 @@ Submodules line_profiler.explicit_profiler line_profiler.ipython_extension line_profiler.line_profiler + line_profiler.profiler_mixin + line_profiler.scoping_policy Module contents --------------- diff --git a/docs/source/auto/line_profiler.scoping_policy.rst b/docs/source/auto/line_profiler.scoping_policy.rst new file mode 100644 index 00000000..20ce4822 --- /dev/null +++ b/docs/source/auto/line_profiler.scoping_policy.rst @@ -0,0 +1,8 @@ +line\_profiler.scoping\_policy module +===================================== + +.. automodule:: line_profiler.scoping_policy + :members: + :undoc-members: + :show-inheritance: + :private-members: diff --git a/kernprof.py b/kernprof.py index 39bbfde5..a11cb2ad 100755 --- a/kernprof.py +++ b/kernprof.py @@ -1,8 +1,10 @@ #!/usr/bin/env python """ -Script to conveniently run profilers on code in a variety of circumstances. +Script to conveniently run profilers on code in a variety of +circumstances. -To profile a script, decorate the functions of interest with ``@profile`` +To profile a script, decorate the functions of interest with +:py:deco:`profile `: .. code:: bash @@ -15,25 +17,29 @@ def main(): NOTE: - New in 4.1.0: Instead of relying on injecting ``profile`` into the builtins - you can now ``import line_profiler`` and use ``line_profiler.profile`` to - decorate your functions. This allows the script to remain functional even - if it is not actively profiled. See :py:mod:`line_profiler` for details. + New in 4.1.0: Instead of relying on injecting :py:deco:`profile` + into the builtins you can now ``import line_profiler`` and use + :py:deco:`line_profiler.profile ` + to decorate your functions. This allows the script to remain + functional even if it is not actively profiled. See + :py:mod:`!line_profiler` (:ref:`link `) for + details. -Then run the script using kernprof: +Then run the script using :program:`kernprof`: .. code:: bash kernprof -b script_to_profile.py -By default this runs with the default :py:mod:`cProfile` profiler and does not -require compiled modules. Instructions to view the results will be given in the -output. Alternatively, adding ``-v`` to the command line will write results to -stdout. +By default this runs with the default :py:mod:`cProfile` profiler and +does not require compiled modules. Instructions to view the results will +be given in the output. Alternatively, adding :option:`!-v` to the +command line will write results to stdout. -To enable line-by-line profiling, then :py:mod:`line_profiler` must be -available and compiled. Add the ``-l`` argument to the kernprof invocation. +To enable line-by-line profiling, :py:mod:`line_profiler` must be +available and compiled, and the :option:`!-l` argument should be added to +the :program:`kernprof` invocation: .. code:: bash @@ -41,19 +47,23 @@ def main(): NOTE: - New in 4.3.0: more code execution options are added: + New in 4.3.0: More code execution options are added: - * ``kernprof -m some.module `` parallels - ``python -m`` and runs the provided module as ``__main__``. - * ``kernprof -c "some code" `` parallels - ``python -c`` and executes the provided literal code. - * ``kernprof - `` parallels ``python -`` and - executes literal code passed via the ``stdin``. + * :command:`kernprof -m some.module ` + parallels :command:`python -m` and runs the provided module as + :py:mod:`__main__`. + * :command:`kernprof -c "some code" ` + parallels :command:`python -c` and executes the provided literal + code. + * :command:`kernprof - ` parallels + :command:`python -` and executes literal code passed via the + :file:`stdin`. - See also :doc:`kernprof invocations `. + See also + :doc:`kernprof invocations `. For more details and options, refer to the CLI help. -To view kernprof help run: +To view the :program:`kernprof` help text run: .. code:: bash @@ -63,7 +73,8 @@ def main(): .. code:: - usage: kernprof [-h] [-V] [-l] [-b] [-o OUTFILE] [-s SETUP] [-v] [-r] [-u UNIT] [-z] [-i [OUTPUT_INTERVAL]] [-p PROF_MOD] [--prof-imports] + usage: kernprof [-h] [-V] [-l] [-b] [-o OUTFILE] [-s SETUP] [-v] [-q] [-r] [-u UNIT] [-z] [-i [OUTPUT_INTERVAL]] [-p {path/to/script | object.dotted.path}[,...]] + [--no-preimports] [--prof-imports] {path/to/script | -m path.to.module | -c "literal code"} ... Run and profile a python script. @@ -81,18 +92,43 @@ def main(): -o, --outfile OUTFILE Save stats to (default: 'scriptname.lprof' with --line-by-line, 'scriptname.prof' without) -s, --setup SETUP Code to execute before the code to profile - -v, --view View the results of the profile in addition to saving it + -v, --verbose, --view + Increase verbosity level. At level 1, view the profiling results in addition to saving them; at level 2, show other diagnostic info. + -q, --quiet Decrease verbosity level. At level -1, disable helpful messages (e.g. "Wrote profile results to <...>"); at level -2, silence the stdout; at level -3, + silence the stderr. -r, --rich Use rich formatting if viewing output -u, --unit UNIT Output unit (in seconds) in which the timing info is displayed (default: 1e-6) -z, --skip-zero Hide functions which have not been called -i, --output-interval [OUTPUT_INTERVAL] Enables outputting of cumulative profiling results to file every n seconds. Uses the threading module. Minimum value is 1 (second). Defaults to disabled. - -p, --prof-mod PROF_MOD - List of modules, functions and/or classes to profile specified by their name or path. List is comma separated, adding the current script path profiles - the full script. Multiple copies of this flag can be supplied and the.list is extended. Only works with line_profiler -l, --line-by-line + -p, --prof-mod {path/to/script | object.dotted.path}[,...] + List of modules, functions and/or classes to profile specified by their name or path. These profiling targets can be supplied both as comma-separated + items, or separately with multiple copies of this flag. Packages are automatically recursed into unless they are specified with `.__init__`. Adding + the current script/module profiles the entirety of it. Only works with line_profiler -l, --line-by-line. + --no-preimports Instead of eagerly importing all profiling targets specified via -p and profiling them, only profile those that are directly imported in the profiled + code. Only works with line_profiler -l, --line-by-line. --prof-imports If specified, modules specified to `--prof-mod` will also autoprofile modules that they import. Only works with line_profiler -l, --line-by-line + +NOTE: + + New in 4.3.0: For more intuitive profiling behavior, profiling + targets in :option:`!--prof-mod` (except the profiled script/code) + are now: + + * Eagerly pre-imported to be profiled (see + :py:mod:`line_profiler.autoprofile.eager_preimports`), + regardless of whether those imports directly occur in the profiled + script/module/code. + * Descended/Recursed into if they are packages; pass + ``.__init__`` instead of ```` to curtail + descent and limit profiling to classes and functions in the local + namespace of the :file:`__init__.py`. + + To restore the old behavior, pass the :option:`!--no-preimports` + flag. """ +import atexit import builtins import functools import os @@ -100,10 +136,20 @@ def main(): import threading import asyncio # NOQA import concurrent.futures # NOQA +import contextlib +import shutil import tempfile import time +import warnings from argparse import ArgumentError, ArgumentParser +from io import StringIO +from operator import methodcaller from runpy import run_module +from pathlib import Path +from pprint import pformat +from shlex import quote +from textwrap import indent, dedent +from types import MethodType, SimpleNamespace # NOTE: This version needs to be manually maintained in # line_profiler/line_profiler.py and line_profiler/__init__.py as well @@ -117,18 +163,23 @@ def main(): from profile import Profile # type: ignore[assignment,no-redef] from line_profiler.profiler_mixin import ByCountProfilerMixin +from line_profiler._logger import Logger +from line_profiler import _diagnostics as diagnostics + + +DIAGNOSITICS_VERBOSITY = 2 def execfile(filename, globals=None, locals=None): - """ Python 3.x doesn't have 'execfile' builtin """ + """ Python 3.x doesn't have :py:func:`execfile` builtin """ with open(filename, 'rb') as f: exec(compile(f.read(), filename, 'exec'), globals, locals) # ===================================== class ContextualProfile(ByCountProfilerMixin, Profile): - """ A subclass of Profile that adds a context manager for Python - 2.5 with: statements and a decorator. + """ A subclass of :py:class:`Profile` that adds a context manager + for Python 2.5 with: statements and a decorator. """ def __init__(self, *args, **kwds): super(ByCountProfilerMixin, self).__init__(*args, **kwds) @@ -160,7 +211,7 @@ def disable_by_count(self): class RepeatedTimer: """ - Background timer for outputting file every n seconds. + Background timer for outputting file every ``n`` seconds. Adapted from [SO474528]_. @@ -206,10 +257,10 @@ def find_module_script(module_name): raise SystemExit(1) -def find_script(script_name): +def find_script(script_name, exit_on_error=True): """ Find the script. - If the input is not a file, then $PATH will be searched. + If the input is not a file, then :envvar:`PATH` will be searched. """ if os.path.isfile(script_name): return script_name @@ -221,54 +272,71 @@ def find_script(script_name): if os.path.isfile(fn): return fn - sys.stderr.write('Could not find script %s\n' % script_name) - raise SystemExit(1) + msg = f'Could not find script {script_name!r}' + if exit_on_error: + print(msg, file=sys.stderr) + raise SystemExit(1) + else: + raise FileNotFoundError(msg) def _python_command(): """ - Return a command that corresponds to :py:obj:`sys.executable`. + Return a command that corresponds to :py:data:`sys.executable`. """ - import shutil for abbr in 'python', 'python3': if os.path.samefile(shutil.which(abbr), sys.executable): return abbr return sys.executable -class _restore_list: +def _normalize_profiling_targets(targets): + """ + Normalize the parsed :option:`!--prof-mod` by: + + * Normalizing file paths with :py:func:`find_script()`, and + subsequently to absolute paths. + * Splitting non-file paths at commas into (presumably) file paths + and/or dotted paths. + * Removing duplicates. + """ + def find(path): + try: + path = find_script(path, exit_on_error=False) + except FileNotFoundError: + return None + return os.path.abspath(path) + + results = {} + for chunk in targets: + filename = find(chunk) + if filename is not None: + results.setdefault(filename) + continue + for subchunk in chunk.split(','): + filename = find(subchunk) + results.setdefault(subchunk if filename is None else filename) + return list(results) + + +class _restore: """ - Restore a list like `sys.path` after running code which potentially - modifies it. - - Example - ------- - >>> l = [1, 2, 3] - >>> - >>> - >>> with _restore_list(l): - ... print(l) - ... l.append(4) - ... print(l) - ... l[:] = 5, 6 - ... print(l) - ... - [1, 2, 3] - [1, 2, 3, 4] - [5, 6] - >>> l - [1, 2, 3] + Restore a collection like :py:data:`sys.path` after running code + which potentially modifies it. """ - def __init__(self, lst): - self.lst = lst + def __init__(self, obj, getter, setter): + self.obj = obj + self.setter = setter + self.getter = getter self.old = None def __enter__(self): assert self.old is None - self.old = self.lst.copy() + self.old = self.getter(self.obj) def __exit__(self, *_, **__): - self.old, self.lst[:] = None, self.old + self.setter(self.obj, self.old) + self.old = None def __call__(self, func): @functools.wraps(func) @@ -278,11 +346,93 @@ def wrapper(*args, **kwargs): return wrapper + @classmethod + def sequence(cls, seq): + """ + Example + ------- + >>> l = [1, 2, 3] + >>> + >>> with _restore.sequence(l): + ... print(l) + ... l.append(4) + ... print(l) + ... l[:] = 5, 6 + ... print(l) + ... + [1, 2, 3] + [1, 2, 3, 4] + [5, 6] + >>> l + [1, 2, 3] + """ + def set_list(orig, copy): + orig[:] = copy + + return cls(seq, methodcaller('copy'), set_list) + + @classmethod + def mapping(cls, mpg): + """ + Example + ------- + >>> d = {1: 2} + >>> + >>> with _restore.mapping(d): + ... print(d) + ... d[2] = 3 + ... print(d) + ... d.clear() + ... d.update({1: 4, 3: 5}) + ... print(d) + ... + {1: 2} + {1: 2, 2: 3} + {1: 4, 3: 5} + >>> d + {1: 2} + """ + def set_mapping(orig, copy): + orig.clear() + orig.update(copy) + + return cls(mpg, methodcaller('copy'), set_mapping) + + @classmethod + def instance_dict(cls, obj): + """ + Example + ------- + >>> class Obj: + ... def __init__(self, x, y): + ... self.x, self.y = x, y + ... + ... def __repr__(self): + ... return 'Obj({0.x!r}, {0.y!r})'.format(self) + ... + >>> + >>> obj = Obj(1, 2) + >>> + >>> with _restore.instance_dict(obj): + ... print(obj) + ... obj.x, obj.y, obj.z = 4, 5, 6 + ... print(obj, obj.z) + ... + Obj(1, 2) + Obj(4, 5) 6 + >>> obj + Obj(1, 2) + >>> hasattr(obj, 'z') + False + """ + return cls.mapping(vars(obj)) + def pre_parse_single_arg_directive(args, flag, sep='--'): """ - Pre-parse high-priority single-argument directives like `-m module` - to emulate the behavior of `python [...]`. + Pre-parse high-priority single-argument directives like + :option:`!-m module` to emulate the behavior of + :command:`python [...]`. Examples -------- @@ -336,24 +486,90 @@ def pre_parse_single_arg_directive(args, flag, sep='--'): return args, None, [] if i_flag == len(args) - 1: # Last element raise ValueError(f'argument expected for the {flag} option') - return args[:i_flag], args[i_flag + 1], args[i_flag + 2:] + args, thing, post_args = args[:i_flag], args[i_flag + 1], args[i_flag + 2:] + return args, thing, post_args -@_restore_list(sys.argv) -@_restore_list(sys.path) -def main(args=None): +def positive_float(value): + val = float(value) + if val <= 0: + raise ArgumentError + return val + + +def no_op(*_, **__) -> None: + pass + + +def _add_core_parser_arguments(parser): """ - Runs the command line interface + Add the core kernprof args to a ArgumentParser """ - def positive_float(value): - val = float(value) - if val <= 0: - raise ArgumentError - return val - - create_parser = functools.partial( - ArgumentParser, - description='Run and profile a python script.') + parser.add_argument('-V', '--version', action='version', version=__version__) + parser.add_argument('-l', '--line-by-line', action='store_true', + help='Use the line-by-line profiler instead of cProfile. Implies --builtin.') + parser.add_argument('-b', '--builtin', action='store_true', + help="Put 'profile' in the builtins. Use 'profile.enable()'/'.disable()', " + "'@profile' to decorate functions, or 'with profile:' to profile a " + 'section of code.') + parser.add_argument('-o', '--outfile', + help="Save stats to (default: 'scriptname.lprof' with " + "--line-by-line, 'scriptname.prof' without)") + parser.add_argument('-s', '--setup', + help='Code to execute before the code to profile') + parser.add_argument('-v', '--verbose', '--view', + action='count', default=0, + help='Increase verbosity level. ' + 'At level 1, view the profiling results ' + 'in addition to saving them; ' + 'at level 2, show other diagnostic info.') + parser.add_argument('-q', '--quiet', + action='count', default=0, + help='Decrease verbosity level. ' + 'At level -1, disable helpful messages ' + '(e.g. "Wrote profile results to <...>"); ' + 'at level -2, silence the stdout; ' + 'at level -3, silence the stderr.') + parser.add_argument('-r', '--rich', action='store_true', + help='Use rich formatting if viewing output') + parser.add_argument('-u', '--unit', default='1e-6', type=positive_float, + help='Output unit (in seconds) in which the timing info is ' + 'displayed (default: 1e-6)') + parser.add_argument('-z', '--skip-zero', action='store_true', + help="Hide functions which have not been called") + parser.add_argument('-i', '--output-interval', type=int, default=0, const=0, nargs='?', + help="Enables outputting of cumulative profiling results to file every n seconds. Uses the threading module. " + "Minimum value is 1 (second). Defaults to disabled.") + parser.add_argument('-p', '--prof-mod', + action='append', + metavar=("{path/to/script | object.dotted.path}" + "[,...]"), + help="List of modules, functions and/or classes " + "to profile specified by their name or path. " + "These profiling targets can be supplied both as " + "comma-separated items, or separately with " + "multiple copies of this flag. " + "Packages are automatically recursed into unless " + "they are specified with `.__init__`. " + "Adding the current script/module profiles the " + "entirety of it. " + "Only works with line_profiler -l, --line-by-line.") + parser.add_argument('--no-preimports', + action='store_true', + help="Instead of eagerly importing all profiling " + "targets specified via -p and profiling them, " + "only profile those that are directly imported in " + "the profiled code. " + "Only works with line_profiler -l, --line-by-line.") + parser.add_argument('--prof-imports', action='store_true', + help="If specified, modules specified to `--prof-mod` will also autoprofile modules that they import. " + "Only works with line_profiler -l, --line-by-line") + + +def _build_parsers(args=None): + parser_kwargs = { + 'description': 'Run and profile a python script.', + } if args is None: args = sys.argv[1:] @@ -374,7 +590,7 @@ def positive_float(value): module, literal_code = None, thing if module is literal_code is None: # Normal execution - real_parser, = parsers = [create_parser()] + real_parser, = parsers = [ArgumentParser(**parser_kwargs)] help_parser = None else: # We've already consumed the `-m `, so we need a dummy @@ -382,43 +598,12 @@ def positive_float(value): # but the real parser should not consume the `options.script` # positional arg, and it it got the `--help` option, it should # hand off the the dummy parser - real_parser = create_parser(add_help=False) + real_parser = ArgumentParser(add_help=False, **parser_kwargs) real_parser.add_argument('-h', '--help', action='store_true') - help_parser = create_parser() + help_parser = ArgumentParser(**parser_kwargs) parsers = [real_parser, help_parser] for parser in parsers: - parser.add_argument('-V', '--version', action='version', version=__version__) - parser.add_argument('-l', '--line-by-line', action='store_true', - help='Use the line-by-line profiler instead of cProfile. Implies --builtin.') - parser.add_argument('-b', '--builtin', action='store_true', - help="Put 'profile' in the builtins. Use 'profile.enable()'/'.disable()', " - "'@profile' to decorate functions, or 'with profile:' to profile a " - 'section of code.') - parser.add_argument('-o', '--outfile', - help="Save stats to (default: 'scriptname.lprof' with " - "--line-by-line, 'scriptname.prof' without)") - parser.add_argument('-s', '--setup', - help='Code to execute before the code to profile') - parser.add_argument('-v', '--view', action='store_true', - help='View the results of the profile in addition to saving it') - parser.add_argument('-r', '--rich', action='store_true', - help='Use rich formatting if viewing output') - parser.add_argument('-u', '--unit', default='1e-6', type=positive_float, - help='Output unit (in seconds) in which the timing info is ' - 'displayed (default: 1e-6)') - parser.add_argument('-z', '--skip-zero', action='store_true', - help="Hide functions which have not been called") - parser.add_argument('-i', '--output-interval', type=int, default=0, const=0, nargs='?', - help="Enables outputting of cumulative profiling results to file every n seconds. Uses the threading module. " - "Minimum value is 1 (second). Defaults to disabled.") - parser.add_argument('-p', '--prof-mod', action='append', type=str, - help="List of modules, functions and/or classes to profile specified by their name or path. " - "List is comma separated, adding the current script path profiles the full script. " - "Multiple copies of this flag can be supplied and the.list is extended. " - "Only works with line_profiler -l, --line-by-line") - parser.add_argument('--prof-imports', action='store_true', - help="If specified, modules specified to `--prof-mod` will also autoprofile modules that they import. " - "Only works with line_profiler -l, --line-by-line") + _add_core_parser_arguments(parser) if parser is help_parser or module is literal_code is None: parser.add_argument('script', @@ -427,10 +612,27 @@ def positive_float(value): help='The python script file, module, or ' 'literal code to run') parser.add_argument('args', nargs='...', help='Optional script arguments') + special_info = { + 'module': module, + 'literal_code': literal_code, + 'post_args': post_args, + 'args': args, + } + return real_parser, help_parser, special_info + + +def _parse_arguments(real_parser, help_parser, special_info, args): + + module = special_info['module'] + literal_code = special_info['literal_code'] + post_args = special_info['post_args'] # Hand off to the dummy parser if necessary to generate the help # text - options = real_parser.parse_args(args) + options = SimpleNamespace(**vars(real_parser.parse_args(args))) + # TODO: make flags later where appropriate + options.dryrun = diagnostics.NO_EXEC + options.static = diagnostics.STATIC_ANALYSIS if help_parser and getattr(options, 'help', False): help_parser.print_help() exit() @@ -450,28 +652,129 @@ def positive_float(value): elif options.script == '-' and not module: tempfile_source_and_content = 'stdin', sys.stdin.read() - if tempfile_source_and_content: - with tempfile.TemporaryDirectory() as tmpdir: - _write_tempfile(*tempfile_source_and_content, options, tmpdir) - return _main(options, module) + # Handle output + options.verbose -= options.quiet + options.debug = (diagnostics.DEBUG + or options.verbose >= DIAGNOSITICS_VERBOSITY) + logger_kwargs = {'name': 'kernprof'} + logger_kwargs['backend'] = 'auto' + if options.debug: + # Debugging forces the stdlib logger + logger_kwargs['verbose'] = 2 + logger_kwargs['backend'] = 'stdlib' + elif options.verbose > -1: + logger_kwargs['verbose'] = 1 else: - return _main(options, module) + logger_kwargs['verbose'] = 0 + logger_kwargs['stream'] = { + 'format': '[%(name)s %(asctime)s %(levelname)s] %(message)s', + } + # Reinitialize the diagnostic logs, we are very likely the main script. + diagnostics.log = Logger(**logger_kwargs) + if options.rich: + try: + import rich # noqa: F401 + except ImportError: + options.rich = False + diagnostics.log.debug('`rich` not installed, unsetting --rich') + + return options, tempfile_source_and_content -def _write_tempfile(source, content, options, tmpdir): +@_restore.sequence(sys.argv) +@_restore.sequence(sys.path) +@_restore.instance_dict(diagnostics) +def main(args=None): """ - Called by ``main()`` to handle ``kernprof -c`` and ``kernprof -``; - not to be invoked on its own. + Runs the command line interface + + Note: + To help with traceback formatting, the deletion of temporary + files created during execution may be deferred to when the + interpreter exits. """ - import textwrap + real_parser, help_parser, special_info = _build_parsers(args=args) + args = special_info['args'] + module = special_info['module'] + options, tempfile_source_and_content = _parse_arguments( + real_parser, help_parser, special_info, args) + + if module is not None: + diagnostics.log.debug(f'Profiling module: {module}') + elif tempfile_source_and_content: + diagnostics.log.debug( + f'Profiling script read from: {tempfile_source_and_content[0]}') + else: + diagnostics.log.debug(f'Profiling script: {options.script}') + + with contextlib.ExitStack() as stack: + enter = stack.enter_context + if options.verbose < -1: # Suppress stdout + devnull = enter(open(os.devnull, mode='w')) + enter(contextlib.redirect_stdout(devnull)) + if options.verbose < -2: # Suppress stderr + enter(contextlib.redirect_stderr(devnull)) + # Instead of relying on `tempfile.TemporaryDirectory`, manually + # manage a tempdir to ensure that files exist at + # traceback-formatting time if needs be + options.tmpdir = tmpdir = tempfile.mkdtemp() + if diagnostics.KEEP_TEMPDIRS: + cleanup = no_op + else: + cleanup = functools.partial( + _remove, tmpdir, recursive=True, missing_ok=True, + ) + if tempfile_source_and_content: + try: + _write_tempfile(*tempfile_source_and_content, options) + except Exception: + # Tempfile creation failed, delete the tempdir ASAP + cleanup() + raise + try: + _main_profile(options, module) + except BaseException: + # Defer deletion to after the traceback has been formatted + # if needs be + if os.listdir(tmpdir): + atexit.register(cleanup) + else: # Empty tempdir, just delete it + cleanup() + raise + else: # Execution succeeded, delete the tempdir ASAP + cleanup() + + +def _touch_tempfile(*args, **kwargs): + """ + Wrapper around :py:func:`tempfile.mkstemp()` which drops and closes + the integer handle (which we don't need and may cause issues on some + platforms). + """ + handle, path = tempfile.mkstemp(*args, **kwargs) + try: + os.close(handle) + except Exception: + os.remove(path) + raise + return path + + +def _write_tempfile(source, content, options): + """ + Called by :py:func:`main()` to handle :command:`kernprof -c` and + :command:`kernprof -`; + not to be invoked on its own. + """ # Set up the script to be run file_prefix = f'kernprof-{source}' # Do what 3.14 does (#103998)... and also just to be user-friendly - content = textwrap.dedent(content) - fname = os.path.join(tmpdir, file_prefix + '.py') + content = dedent(content) + fname = os.path.join(options.tmpdir, file_prefix + '.py') with open(fname, mode='w') as fobj: print(content, file=fobj) + diagnostics.log.debug(f'Wrote temporary script file to {fname!r}:') options.script = fname # Add the tempfile to `--prof-mod` if options.prof_mod: @@ -482,19 +785,192 @@ def _write_tempfile(source, content, options, tmpdir): # filename clash) if not options.outfile: extension = 'lprof' if options.line_by_line else 'prof' - _, options.outfile = tempfile.mkstemp(dir=os.curdir, - prefix=file_prefix + '-', - suffix='.' + extension) + options.outfile = _touch_tempfile(dir=os.curdir, + prefix=file_prefix + '-', + suffix='.' + extension) + diagnostics.log.debug( + f'Using default output destination {options.outfile!r}') + + +def _gather_preimport_targets(options, exclude): + """ + Used in _write_preimports + """ + from line_profiler.autoprofile.util_static import modpath_to_modname + from line_profiler.autoprofile.eager_preimports import is_dotted_path + filtered_targets = [] + recurse_targets = [] + invalid_targets = [] + for target in options.prof_mod: + if is_dotted_path(target): + modname = target + else: + # Paths already normalized by + # `_normalize_profiling_targets()` + if not os.path.exists(target): + invalid_targets.append(target) + continue + if any(os.path.samefile(target, excluded) for excluded in exclude): + # Ignore the script to be run in eager importing + # (`line_profiler.autoprofile.autoprofile.run()` will + # handle it) + continue + modname = modpath_to_modname(target, hide_init=False) + if modname is None: # Not import-able + invalid_targets.append(target) + continue + if modname.endswith('.__init__'): + modname = modname.rpartition('.')[0] + filtered_targets.append(modname) + else: + recurse_targets.append(modname) + if invalid_targets: + invalid_targets = sorted(set(invalid_targets)) + msg = ('{} profile-on-import target{} cannot be converted to ' + 'dotted-path form: {!r}' + .format(len(invalid_targets), + '' if len(invalid_targets) == 1 else 's', + invalid_targets)) + warnings.warn(msg) + diagnostics.log.warn(msg) + + return filtered_targets, recurse_targets -def _main(options, module=False): +def _write_preimports(prof, options, exclude): """ - Called by ``main()`` for the actual execution and profiling of code; + Called by :py:func:`main()` to handle eager pre-imports; not to be invoked on its own. """ + from line_profiler.autoprofile.eager_preimports import write_eager_import_module + from line_profiler.autoprofile.autoprofile import ( + _extend_line_profiler_for_profiling_imports as upgrade_profiler) + + filtered_targets, recurse_targets = _gather_preimport_targets(options, exclude) + if not (filtered_targets or recurse_targets): + return + # We could've done everything in-memory with `io.StringIO` and `exec()`, + # but that results in indecipherable tracebacks should anything goes wrong; + # so we write to a tempfile and `execfile()` it + upgrade_profiler(prof) + temp_mod_path = _touch_tempfile(dir=options.tmpdir, + prefix='kernprof-eager-preimports-', + suffix='.py') + write_module_kwargs = { + 'dotted_paths': filtered_targets, + 'recurse': recurse_targets, + 'static': options.static, + } + temp_file = open(temp_mod_path, mode='w') + if options.debug: + with StringIO() as sio: + write_eager_import_module(stream=sio, **write_module_kwargs) + code = sio.getvalue() + with temp_file as fobj: + print(code, file=fobj) + diagnostics.log.debug( + 'Wrote temporary module for pre-imports ' + f'to {temp_mod_path!r}:') + else: + with temp_file as fobj: + write_eager_import_module(stream=fobj, **write_module_kwargs) + if not options.dryrun: + ns = {} # Use a fresh namespace + execfile(temp_mod_path, ns, ns) + # Delete the tempfile ASAP if its execution succeeded + if not diagnostics.KEEP_TEMPDIRS: + _remove(temp_mod_path) + + +def _remove(path, *, recursive=False, missing_ok=False): + path = Path(path) + if path.is_dir(): + if recursive: + shutil.rmtree(path, ignore_errors=missing_ok) + else: + path.rmdir() + else: + path.unlink(missing_ok=missing_ok) + + +def _dump_filtered_stats(tmpdir, prof, filename): + import os + import pickle + + # Build list of known temp file paths + tempfile_paths = [ + os.path.join(dirpath, fname) + for dirpath, _, fnames in os.walk(tmpdir) + for fname in fnames + ] + + if not tempfile_paths: + prof.dump_stats(filename) + return + + # Filter the filenames to remove data from tempfiles, which will + # have been deleted by the time the results are viewed in a + # separate process + stats = prof.get_stats() + timings = stats.timings + for key in set(timings): + fname = key[0] + try: + if any(os.path.samefile(fname, tmp) for tmp in tempfile_paths): + del timings[key] + except OSError: + del timings[key] + + with open(filename, 'wb') as f: + pickle.dump(stats, f, protocol=pickle.HIGHEST_PROTOCOL) + + +def _format_call_message(func, *args, **kwargs): + if isinstance(func, MethodType): + obj = func.__self__ + func_repr = ( + '{0.__module__}.{0.__qualname__}(...).{1.__name__}' + .format(type(obj), func.__func__)) + else: + func_repr = '{0.__module__}.{0.__qualname__}'.format(func) + args_repr = dedent(' ' + pformat(args)[len('['):-len(']')]) + lprefix = len('namespace(') + kwargs_repr = dedent( + ' ' * lprefix + + pformat(SimpleNamespace(**kwargs))[lprefix:-len(')')]) + if args_repr and kwargs_repr: + all_args_repr = f'{args_repr},\n{kwargs_repr}' + else: + all_args_repr = args_repr or kwargs_repr + if all_args_repr: + call = '{}(\n{})'.format( + func_repr, indent(all_args_repr, ' ')) + else: + call = func_repr + '()' + return call + + +def _call_with_diagnostics(options, func, *args, **kwargs): + if options.debug: + call = _format_call_message(func, *args, **kwargs) + diagnostics.log.debug(f'Calling: {call}') + if options.dryrun: + return + return func(*args, **kwargs) + + +def _pre_profile(options, module): + """ + Prepare the environment to execute profiling with requested options. + + Note: + modifies ``options`` with extra attributes. + """ if not options.outfile: extension = 'lprof' if options.line_by_line else 'prof' - options.outfile = '%s.%s' % (os.path.basename(options.script), extension) + options.outfile = f'{os.path.basename(options.script)}.{extension}' + diagnostics.log.debug( + f'Using default output destination {options.outfile!r}') sys.argv = [options.script] + options.args if module: @@ -507,13 +983,14 @@ def _main(options, module=False): # Run some setup code outside of the profiler. This is good for large # imports. setup_file = find_script(options.setup) - __file__ = setup_file - __name__ = '__main__' # Make sure the script's directory is on sys.path instead of just # kernprof.py's. sys.path.insert(0, os.path.dirname(setup_file)) - ns = locals() - execfile(setup_file, ns, ns) + ns = {'__file__': setup_file, '__name__': '__main__'} + diagnostics.log.debug( + f'Executing file {setup_file!r} as pre-profiling setup') + if not options.dryrun: + execfile(setup_file, ns, ns) if options.line_by_line: import line_profiler @@ -547,67 +1024,112 @@ def _main(options, module=False): # Make sure the script's directory is on sys.path instead of # just kernprof.py's. sys.path.insert(0, os.path.dirname(script_file)) - __file__ = script_file - __name__ = '__main__' - - if options.output_interval: - rt = RepeatedTimer(max(options.output_interval, 1), prof.dump_stats, options.outfile) - original_stdout = sys.stdout - if options.output_interval: - rt = RepeatedTimer(max(options.output_interval, 1), prof.dump_stats, options.outfile) + + # If using eager pre-imports, write a dummy module which contains + # all those imports and marks them for profiling, then run it + if options.prof_mod: + # Note: `prof_mod` entries can be filenames (which can contain + # commas), so check against existing filenames before splitting + # them + options.prof_mod = _normalize_profiling_targets(options.prof_mod) + if not options.prof_mod: + options.no_preimports = True + if options.line_by_line and not options.no_preimports: + # We assume most items in `.prof_mod` to be import-able without + # significant side effects, but the same cannot be said if it + # contains the script file to be run. E.g. the script may not + # even have a `if __name__ == '__main__': ...` guard. So don't + # eager-import it. + exclude = set() if module else {script_file} + _write_preimports(prof, options, exclude) + + options.global_profiler = global_profiler + options.install_profiler = install_profiler + if options.output_interval and not options.dryrun: + options.rt = RepeatedTimer(max(options.output_interval, 1), prof.dump_stats, options.outfile) + else: + options.rt = None + options.original_stdout = sys.stdout + return script_file, prof + + +def _main_profile(options, module=False): + """ + Called by :py:func:`main()` for the actual execution and profiling of code + after initial parsing of options; not to be invoked on its own. + """ + script_file, prof = _pre_profile(options, module) try: try: - execfile_ = execfile - rmod_ = functools.partial(run_module, - run_name='__main__', alter_sys=True) - ns = locals() + rmod = functools.partial(run_module, + run_name='__main__', alter_sys=True) + ns = {'__file__': script_file, '__name__': '__main__', + 'execfile': execfile, 'rmod': rmod, + 'prof': prof} if options.prof_mod and options.line_by_line: from line_profiler.autoprofile import autoprofile - # Note: `prof_mod` entries can be filenames (which can - # contain commas), so check against existing filenames - # before splitting them - prof_mod = sum( - ([spec] if os.path.exists(spec) else spec.split(',') - for spec in options.prof_mod), - []) - autoprofile.run(script_file, - ns, - prof_mod=prof_mod, - profile_imports=options.prof_imports, - as_module=module is not None) + _call_with_diagnostics( + options, + autoprofile.run, script_file, ns, + prof_mod=options.prof_mod, + profile_imports=options.prof_imports, + as_module=module is not None) elif module and options.builtin: - rmod_(options.script, ns) + _call_with_diagnostics(options, rmod, options.script, ns) elif options.builtin: - execfile(script_file, ns, ns) + _call_with_diagnostics(options, execfile, script_file, ns, ns) elif module: - prof.runctx(f'rmod_({options.script!r}, globals())', ns, ns) + _call_with_diagnostics( + options, + prof.runctx, f'rmod({options.script!r}, globals())', + ns, ns) else: - prof.runctx('execfile_(%r, globals())' % (script_file,), ns, ns) + _call_with_diagnostics( + options, + prof.runctx, f'execfile({script_file!r}, globals())', + ns, ns) except (KeyboardInterrupt, SystemExit): pass finally: - if options.output_interval: - rt.stop() - prof.dump_stats(options.outfile) - print('Wrote profile results to %s' % options.outfile) - if options.view: - if isinstance(prof, ContextualProfile): - prof.print_stats() - else: - prof.print_stats(output_unit=options.unit, - stripzeros=options.skip_zero, - rich=options.rich, - stream=original_stdout) + _post_profile(options, prof) + + +def _post_profile(options, prof): + """ + Cleanup setup after executing a main profile + """ + if options.rt is not None: + options.rt.stop() + if not options.dryrun: + _dump_filtered_stats(options.tmpdir, prof, options.outfile) + diagnostics.log.info( + ('Profile results would have been written to ' + if options.dryrun else + 'Wrote profile results ') + + f'to {options.outfile!r}') + if options.verbose > 0 and not options.dryrun: + if isinstance(prof, ContextualProfile): + prof.print_stats() else: - print('Inspect results with:') - py_exe = _python_command() - if isinstance(prof, ContextualProfile): - print(f'{py_exe} -m pstats "{options.outfile}"') - else: - print(f'{py_exe} -m line_profiler -rmt "{options.outfile}"') - # Restore the state of the global `@line_profiler.profile` - if global_profiler: - install_profiler(None) + prof.print_stats(output_unit=options.unit, + stripzeros=options.skip_zero, + rich=options.rich, + stream=options.original_stdout) + else: + py_exe = _python_command() + if isinstance(prof, ContextualProfile): + show_mod = 'pstats' + else: + show_mod = 'line_profiler -rmt' + diagnostics.log.info('Inspect results with:\n' + f'{quote(py_exe)} -m {show_mod} ' + f'{quote(options.outfile)}') + # Fully disable the profiler + for _ in range(prof.enable_count): + prof.disable_by_count() + # Restore the state of the global `@line_profiler.profile` + if options.global_profiler: + options.install_profiler(None) if __name__ == '__main__': diff --git a/line_profiler/__init__.py b/line_profiler/__init__.py index 20a640e3..4259070e 100644 --- a/line_profiler/__init__.py +++ b/line_profiler/__init__.py @@ -33,11 +33,13 @@ pip install line_profiler[all] +.. _line-profiler-basic-usage: + Line Profiler Basic Usage ========================= To demonstrate line profiling, we first need to generate a Python script to -profile. Write the following code to a file called ``demo_primes.py``. +profile. Write the following code to a file called :file:`demo_primes.py`: .. code:: python @@ -80,8 +82,10 @@ def main(): main() -In this script we explicitly import the ``profile`` function from -``line_profiler``, and then we decorate function of interest with ``@profile``. +In this script we explicitly import the +:py:deco:`profile ` function +from :py:mod:`line_profiler`, and then we decorate function of interest with +:py:deco:`profile`. By default nothing is profiled when running the script. @@ -99,17 +103,18 @@ def main(): The quickest way to enable profiling is to set the environment variable -``LINE_PROFILE=1`` and running your script as normal. - -.... todo: add a link that points to docs showing all the different ways to enable profiling. +:envvar:`LINE_PROFILE=1 ` and running your script as normal. +.. .. todo: add a link that points to docs showing all the different ways to +.. .. to enable profiling. .. code:: bash LINE_PROFILE=1 python demo_primes.py -This will output 3 files: profile_output.txt, profile_output_.txt, -and profile_output.lprof and stdout will look something like: +This will output 3 files: :file:`profile_output.txt`, +:file:`profile_output_.txt`, and :file:`profile_output.lprof`; and +:file:`stdout` will look something like: .. code:: @@ -219,7 +224,7 @@ def main(): * `timeit `_: The builtin timeit module for profiling single statements. -* `timerit `_: A multi-statements alternative to the builtin ``timeit`` module. +* `timerit `_: A multi-statements alternative to the builtin :py:mod:`timeit` module. * `torch.profiler `_ tools for profiling torch code. diff --git a/line_profiler/_diagnostics.py b/line_profiler/_diagnostics.py new file mode 100644 index 00000000..8ef2cc68 --- /dev/null +++ b/line_profiler/_diagnostics.py @@ -0,0 +1,27 @@ +""" +Global state initialized at import time. +Used for hidden arguments and developer features. +""" +from line_profiler import _logger +import os + + +def _boolean_environ(key): + """ + Args: + key (str) + + Returns: + bool + """ + value = os.environ.get(key, '').lower() + TRUTHY_ENVIRONS = {'true', 'on', 'yes', '1'} + return value in TRUTHY_ENVIRONS + + +DEBUG = _boolean_environ('LINE_PROFILER_DEBUG') +NO_EXEC = _boolean_environ('LINE_PROFILER_NO_EXEC') +KEEP_TEMPDIRS = _boolean_environ('LINE_PROFILER_KEEP_TEMPDIRS') +STATIC_ANALYSIS = _boolean_environ('LINE_PROFILER_STATIC_ANALYSIS') + +log = _logger.Logger('line_profiler', backend='auto') diff --git a/line_profiler/_logger.py b/line_profiler/_logger.py new file mode 100644 index 00000000..83fac0fb --- /dev/null +++ b/line_profiler/_logger.py @@ -0,0 +1,296 @@ +""" +# Ported from kwutil +""" +# import os +import logging +from abc import ABC, abstractmethod +import sys +from typing import ClassVar +from logging import INFO, DEBUG, ERROR, WARNING, CRITICAL # NOQA + + +class _LogBackend(ABC): + """ + Abstract base class for our logger implementations. + """ + backend: ClassVar[str] + + def __init__(self, name): + self.name = name + + @abstractmethod + def configure(self, *args, **kwarg): + """ + Note: + Implementations should take the arguments it needs and + return the instance. + """ + + @abstractmethod + def debug(self, msg, *args, **kwargs): + pass + + @abstractmethod + def info(self, msg, *args, **kwargs): + pass + + @abstractmethod + def warning(self, msg, *args, **kwargs): + pass + + @abstractmethod + def error(self, msg, *args, **kwargs): + pass + + @abstractmethod + def critical(self, msg, *args, **kwargs): + pass + + +class _PrintLogBackend(_LogBackend): + """ + A simple print-based logger that falls back to print output if no logging configuration + is set up. + + Example: + >>> pl = _PrintLogBackend(name='print', level=INFO) + >>> pl.info('Hello %s', 'world') + Hello world + >>> pl.debug('Should not appear') + """ + backend = 'print' + + def __init__(self, name="", level=logging.INFO): + super().__init__(name) + self.level = level + + def isEnabledFor(self, level): + return level >= self.level + + def _log(self, level, msg, *args, **kwargs): + if self.isEnabledFor(level): + # Mimic logging formatting (ignoring extra kwargs for simplicity) + print(msg % args) + + def debug(self, msg, *args, **kwargs): + self._log(logging.DEBUG, msg, *args, **kwargs) + + def info(self, msg, *args, **kwargs): + self._log(logging.INFO, msg, *args, **kwargs) + + def warning(self, msg, *args, **kwargs): + self._log(logging.WARNING, msg, *args, **kwargs) + + def error(self, msg, *args, **kwargs): + self._log(logging.ERROR, msg, *args, **kwargs) + + def critical(self, msg, *args, **kwargs): + self._log(logging.CRITICAL, msg, *args, **kwargs) + + def configure(self, level=None, **_): + if level is not None: + self.level = level + return self + + +class _StdlibLogBackend(_LogBackend): + """ + A wrapper for Python's standard logging.Logger. + + The constructor optionally adds a StreamHandler (to stdout) and/or a logging.FileHandler if file is specified. + + Example: + >>> import os + >>> import ubelt as ub + >>> import logging + >>> dpath = ub.Path.appdir('kwutil/test/logging').ensuredir() + >>> fpath = (dpath / 'test.log').delete() + >>> sl = _StdlibLogBackend('stdlib').configure( + >>> level=logging.INFO, + >>> stream={ + >>> 'format': '%(asctime)s : [stream] %(levelname)s : %(message)s', + >>> }, + >>> file={ + >>> 'path': fpath, + >>> 'format': '%(asctime)s : [file] %(levelname)s : %(message)s', + >>> } + >>> ) + >>> sl.info('Hello %s', 'world') + >>> # Check that the log file has been written to + >>> text = fpath.read_text() + >>> print(text) + >>> assert text.strip().endswith('Hello world') + """ + backend = 'stdlib' + + def __init__(self, name): + super().__init__(name) + self.logger = logging.getLogger(name) + + def configure( + self, + level=None, + stream='auto', + file=None, + **_, + ): + """ + Configure the underlying stdlib logger. + + Parameters: + level: the logging level to set (e.g. logging.INFO) + stream: either a dict with configuration or a boolean/'auto' + - If dict, expected keys include 'format' + - If 'auto', the stream handler is enabled if no handlers are set + - If a boolean, True enables the stream handler. + file: either a dict with configuration or a path string. + - If dict, expected keys include 'path' and 'format' + - If a string, it is taken as the file path + + + Note: + For special attributes for the ``format`` argument of ``stream`` + and ``file`` see + https://docs.python.org/3/library/logging.html#logrecord-attributes + + Returns: + self (the configured _StdlibLogBackend instance) + """ + if level is not None: + self.logger.setLevel(level) + + # Default settings for file and stream handlers + fileinfo = { + 'path': None, + 'format': '%(asctime)s : [file] %(levelname)s : %(message)s' + } + streaminfo = { + '__enable__': None, # will be determined below + 'format': '%(levelname)s: %(message)s', + } + + # Update stream info if stream is a dict + if isinstance(stream, dict): + streaminfo.update(stream) + # If not specified otherwise, enable the stream handler. + if streaminfo.get('__enable__') is None: + streaminfo['__enable__'] = True + else: + # If stream is not a dict, treat it as a boolean or 'auto' + streaminfo['__enable__'] = stream + + # If stream is 'auto', enable stream only if no handlers are present. + if streaminfo['__enable__'] == 'auto': + streaminfo['__enable__'] = not bool(self.logger.handlers) + + # Update file info if file is a dict + if isinstance(file, dict): + fileinfo.update(file) + else: + fileinfo['path'] = file + + # Add a stream handler if enabled + if streaminfo['__enable__']: + streamformat = streaminfo.get('format') + sh = logging.StreamHandler(sys.stdout) + sh.setFormatter(logging.Formatter(streamformat)) + self.logger.addHandler(sh) + + # Add a file handler if a valid path is provided + path = fileinfo.get('path') + if path: + fileformat = fileinfo.get('format') + fh = logging.FileHandler(path) + fh.setFormatter(logging.Formatter(fileformat)) + self.logger.addHandler(fh) + return self + + # def _setup_handlers(self, stream, file): + # # Only add handlers if none exist, so as not to duplicate logs. + # if not self.logger.handlers: + + def debug(self, msg, *args, **kwargs): + kwargs['stacklevel'] = kwargs.get('stacklevel', 1) + 1 + self.logger.debug(msg, *args, **kwargs) + + def info(self, msg, *args, **kwargs): + kwargs['stacklevel'] = kwargs.get('stacklevel', 1) + 1 + self.logger.info(msg, *args, **kwargs) + + def warning(self, msg, *args, **kwargs): + kwargs['stacklevel'] = kwargs.get('stacklevel', 1) + 1 + self.logger.warning(msg, *args, **kwargs) + + def error(self, msg, *args, **kwargs): + kwargs['stacklevel'] = kwargs.get('stacklevel', 1) + 1 + self.logger.error(msg, *args, **kwargs) + + def critical(self, msg, *args, **kwargs): + kwargs['stacklevel'] = kwargs.get('stacklevel', 1) + 1 + self.logger.critical(msg, *args, **kwargs) + + +class Logger: + """ + The main Logger class that automatically selects the backend. + + If backend='auto' and a global logging configuration exists (i.e. logging.getLogger(name) has handlers), + it uses _StdlibLogBackend; otherwise, it falls back to _PrintLogBackend. + + Optional parameters: + - verbose: controls log level via an integer (0: CRITICAL, 1: INFO, 2: DEBUG, etc.) + - file: if provided, file logging is enabled (only used with _StdlibLogBackend) + - stream: if True, a logging.StreamHandler to stdout is added (only used with _StdlibLogBackend) + + Example: + >>> # With no global handlers, defaults to _PrintLogBackend + >>> logger = Logger('TestLogger', verbose=2, backend='auto') + >>> logger.info('Hello %s', 'world') + Hello world + >>> # Forcing use of _PrintLogBackend + >>> logger = Logger('TestLogger', verbose=2, backend='print') + >>> logger.debug('Debug %d', 123) + Debug 123 + >>> # Forcing use of Stdlib Logger + >>> logger = Logger('TestLogger', verbose=2, backend='stdlib') + >>> logger.debug('Debug %d', 123) + + Example: + >>> # Forcing use of Stdlib Logger + >>> logger = Logger('TestLogger', verbose=2, backend='stdlib').configure( + >>> stream={'format': '%(asctime)s : %(pathname)s:%(lineno)d %(funcName)s %(levelname)s : %(message)s'}) + >>> logger.debug('Debug %d', 123) + >>> logger.info('Hello %d', 123) + """ + def __init__(self, name="Logger", verbose=1, backend="auto", file=None, stream=True): + # Map verbose level to logging levels. If verbose > 1, show DEBUG, else INFO. + self.name = name + self.configure(verbose=verbose, backend=backend, file=file, stream=stream) + + def configure(self, backend='auto', verbose=1, file=None, stream=None): + name = self.name + kwargs = dict(file=file, stream=stream) + kwargs['level'] = { + 0: logging.CRITICAL, + 1: logging.INFO, + 2: logging.DEBUG}.get(verbose, logging.DEBUG) + if backend == "auto": + # Choose _StdlibLogBackend if a logger with handlers exists. + if logging.getLogger(name).handlers: + backend = 'stdlib' + else: + backend = 'print' + try: + Backend = {'print': _PrintLogBackend, + 'stdlib': _StdlibLogBackend}[backend] + except KeyError: + raise ValueError( + "Unsupported backend. " + "Use 'auto', 'print', or 'stdlib'.") from None + self._backend = Backend(name).configure(**kwargs) + return self + + def __getattr__(self, attr): + # We should not need to modify stacklevel here as we are directly + # returning the backend function and not wrapping it. + return getattr(self._backend, attr) diff --git a/line_profiler/autoprofile/eager_preimports.py b/line_profiler/autoprofile/eager_preimports.py new file mode 100644 index 00000000..2e184046 --- /dev/null +++ b/line_profiler/autoprofile/eager_preimports.py @@ -0,0 +1,567 @@ +""" +Tools for eagerly pre-importing everything as specified in +``line_profiler.autoprof.run(prof_mod=...)``. +""" +import ast +import functools +import itertools +from collections import namedtuple +from collections.abc import Collection +from keyword import iskeyword +from importlib.util import find_spec +from pkgutil import walk_packages +from textwrap import dedent, indent as indent_ +from warnings import warn +from .util_static import ( + modname_to_modpath, modpath_to_modname, package_modpaths) + + +__all__ = ('is_dotted_path', 'split_dotted_path', + 'resolve_profiling_targets', 'write_eager_import_module') + + +def is_dotted_path(obj): + """ + Example: + >>> assert not is_dotted_path(object()) + >>> assert is_dotted_path('foo') + >>> assert is_dotted_path('foo.bar') + >>> assert not is_dotted_path('not an identifier') + >>> assert not is_dotted_path('keyword.return.not.allowed') + """ + if not (isinstance(obj, str) and obj): + return False + for chunk in obj.split('.'): + if iskeyword(chunk) or not chunk.isidentifier(): + return False + return True + + +def get_expression(obj): + """ + Example: + >>> assert not get_expression(object()) + >>> assert not get_expression('') + >>> assert not get_expression('foo; bar') + >>> assert get_expression('foo') + >>> assert get_expression('lambda x: x') + >>> assert not get_expression('def foo(x): return x') + """ + if not (isinstance(obj, str) and obj): + return None + try: + return ast.parse(obj, mode='eval') + except SyntaxError: + return None + + +def split_dotted_path(dotted_path, static=True): + """ + Arguments: + dotted_path (str): + Dotted path indicating an import target (module, package, or + a ``from ... import ...``-able name under that), or an + object accessible via (chained) attribute access thereon + static (bool): + Whether to use static analysis (true) or the import system + (false) to resolve targets + + Returns: + module, target (tuple[str, Union[str, None]]): + + * ``module``: dotted path indicating the module that should be + imported + * ``target``: dotted path indicating the chained-attribute + access target on the imported module corresponding to + ``dotted_path``; + if the import is just a module, this is set to + :py:const:`None` + + Raises: + TypeError + If ``dotted_path`` is not a dotted path (Python identifiers + joined by periods) + ModuleNotFoundError + If a matching module cannot be found + + Note: + ``static=False`` can cause the ancestor module objects of + ``dotted_path`` to be imported (and hence alter the state of + :py:data:`sys.modules`. + + Example: + >>> split_dotted_path('importlib.util.find_spec') + ('importlib.util', 'find_spec') + >>> split_dotted_path('importlib.util') + ('importlib.util', None) + >>> split_dotted_path('importlib.abc.Loader.exec_module') + ('importlib.abc', 'Loader.exec_module') + >>> split_dotted_path( # doctest: +NORMALIZE_WHITESPACE + ... 'not a dotted path') + Traceback (most recent call last): + ... + TypeError: dotted_path = 'not a dotted path': + expected a dotted path (string of period-joined identifiers) + >>> split_dotted_path( # doctest: +NORMALIZE_WHITESPACE + ... 'foo.bar.baz') + Traceback (most recent call last): + ... + ModuleNotFoundError: dotted_path = 'foo.bar.baz': + none of the below looks like an importable module: + ['foo.bar.baz', 'foo.bar', 'foo'] + """ + if not is_dotted_path(dotted_path): + raise TypeError(f'dotted_path = {dotted_path!r}: ' + 'expected a dotted path ' + '(string of period-joined identifiers)') + chunks = dotted_path.split('.') + checked_locs = [] + check = modname_to_modpath if static else find_spec + for slicing_point in range(len(chunks), 0, -1): + module = '.'.join(chunks[:slicing_point]) + target = '.'.join(chunks[slicing_point:]) or None + try: + result = check(module) + except ImportError: + result = None + if result is None: + checked_locs.append(module) + continue + return module, target + raise ModuleNotFoundError(f'dotted_path = {dotted_path!r}: ' + 'none of the below looks like an importable ' + f'module: {checked_locs!r}') + + +def strip(s): + return dedent(s).strip('\n') + + +class LoadedNameFinder(ast.NodeVisitor): + """ + Find the names loaded in an AST. A name is considered to be loaded + if it appears with the context :py:class:`ast.Load()` and is not an + argument of any surrounding function-definition contexts + (``def func(...): ...``, ``async def func(...): ...``, or + ``lambda ...: ...``). + + Example: + >>> import ast + >>> + >>> + >>> module = ''' + ... def foo(x, **k): + ... def bar(y, **z): + ... pass + ... + ... return bar(x, **{**k, 'baz': foobar}) + ... + ... spam = lambda x, *y, **z: (x, y, z, a) + ... + ... str('ham') + ... ''' + >>> names = LoadedNameFinder.find(ast.parse(module)) + >>> assert names == {'bar', 'foobar', 'a', 'str'}, names + """ + def __init__(self): + self.names = set() + self.contexts = [] + + def visit_Name(self, node): + if not isinstance(node.ctx, ast.Load): + return + name = node.id + if not any(name in ctx for ctx in self.contexts): + self.names.add(node.id) + + def _visit_func_def(self, node): + args = node.args + arg_names = { + arg.arg + for arg_list in (args.posonlyargs, args.args, args.kwonlyargs) + for arg in arg_list} + if args.vararg: + arg_names.add(args.vararg.arg) + if args.kwarg: + arg_names.add(args.kwarg.arg) + self.contexts.append(arg_names) + self.generic_visit(node) + self.contexts.pop() + + visit_FunctionDef = visit_AsyncFunctionDef = visit_Lambda = _visit_func_def + + @classmethod + def find(cls, node): + finder = cls() + finder.visit(node) + return finder.names + + +def propose_names(prefixes): + """ + Generate names based on prefixes. + + Arguments: + prefixes (Collection[str]): + String identifier prefixes + + Yields: + name (str): + String identifier + + Example: + >>> import itertools + >>> + >>> + >>> list(itertools.islice(propose_names(['func', 'f', 'foo']), + ... 10)) # doctest: +NORMALIZE_WHITESPACE + ['func', 'f', 'foo', + 'func_0', 'f0', 'foo_0', + 'func_1', 'f1', 'foo_1', + 'func_2'] + """ + prefixes = list(dict.fromkeys(prefixes)) # Preserve order + if not all(is_dotted_path(p) and '.' not in p for p in prefixes): + raise TypeError(f'prefixes = {prefixes!r}: ' + 'expected string identifiers') + # Yield all the provided prefixes + yield from prefixes + # Yield the prefixes in order with numeric suffixes + prefixes_and_patterns = [ + (prefix, ('{}{}' if len(prefix) == 1 else '{}_{}').format) + for prefix in prefixes] + for i in itertools.count(): + for prefix, pattern in prefixes_and_patterns: + yield pattern(prefix, i) + + +def resolve_profiling_targets(dotted_paths, static=True, recurse=False): + """ + Arguments: + dotted_paths (Collection[str]): + Dotted paths (strings of period-joined identifiers) + indicating what should be profiled + static (bool): + Whether to use static analysis (true) or the import system + (false) to resolve targets + recurse (Union[Collection[str], bool]): + Dotted paths (strings of period-joined identifiers) + indicating the profiling targets that should be recursed + into if they are packages; + can also be a boolean value, indicating: + + :py:const:`True` + Recurse into any entry in ``dotted_paths`` that is a + package + :py:const:`False` + Don't recurse into any entry + + Returns: + result (ResolvedResult): + 3-named-tuple with the following fields/items: + + ``.targets`` (dict[str, set[str | None]]): + Mapping from module names to the names of the attributes + therein that should be passed to the profiler; + if the attribute name is :py:const:`None`, the whole + module is to be passed to the profiler + ``.indirect`` (set[str]): + Set of subpackage/-module names included only via + ``recurse``-ing into packages (i.e. not directly in + either ``dotted_paths`` or ``recurse``) + ``.unresolved`` (list[str]): + List of unresolved profiling targets, i.e. those which + cannot be resolved into a module part and an attribute + part by :py:func:`~.split_dotted_path` + + Note: + ``static=False`` can cause the ancestor module objects of + ``dotted_paths`` and ``recurse`` to be imported (and hence alter + the state of :py:data:`sys.modules`. + """ + def walk_packages_static(pkg): + # Note: this probably can't handle namespace packages + path = modname_to_modpath(pkg) + if not path: + return + for subpath in package_modpaths(path, with_pkg=True): + submod = modpath_to_modname(subpath) + if submod: + yield submod + + def walk_packages_import_sys(pkg): + spec = find_spec(pkg) + if not spec: + return + paths = spec.submodule_search_locations or [] + if not paths: + return + for info in walk_packages(paths, prefix=pkg + '.'): + yield info.name + + dotted_paths = set(dotted_paths) + if isinstance(recurse, Collection): + recurse = set(recurse) + else: + recurse = dotted_paths if recurse else set() + dotted_paths |= recurse + indirect_submods = set() + + all_targets = {} + unknown_locs = [] + split_path = functools.partial(split_dotted_path, static=static) + walk = walk_packages_static if static else walk_packages_import_sys + for path in sorted(set(dotted_paths)): + try: + module, target = split_path(path) + except ModuleNotFoundError: + unknown_locs.append(path) + continue + all_targets.setdefault(module, set()).add(target) + if path in recurse and target is None: + for submod in walk(path): + all_targets.setdefault(submod, set()).add(None) + indirect_submods.add(submod) + indirect_submods -= dotted_paths + return ResolvedResult(all_targets, indirect_submods, unknown_locs) + + +def write_eager_import_module(dotted_paths, stream=None, *, + static=True, + recurse=False, + adder='profile.add_imported_function_or_module', + indent=' '): + r""" + Write a module which autoprofiles all its imports. + + Arguments: + dotted_paths (Collection[str]): + Dotted paths (strings of period-joined identifiers) + indicating what should be profiled + stream (Union[TextIO, None]): + Optional text-mode writable file object to which to write + the module + static (bool): + Whether to use static analysis (true) or the import system + (false) to resolve targets + recurse (Union[Collection[str], bool]): + Dotted paths (strings of period-joined identifiers) + indicating the profiling targets that should be recursed + into if they are packages; + can also be a boolean value, indicating: + + :py:const:`True` + Recurse into any entry in ``dotted_paths`` that is a + package + :py:const:`False` + Don't recurse into any entry + adder (str): + Single-line string ``ast.parse(mode='eval')``-able to a + single expression, indicating the callable (which is assumed + to exist in the builtin namespace by the time the module is + executed) to be called to add the profiling target + indent (str): + Single-line, non-empty whitespace string to indent the + output with + + Side effects: + * ``stream`` (or :py:data:`sys.stdout` if :py:const:`None`) + written to + * Warning issued if the module can't be located for one or more + dotted paths + + Raises: + TypeError + If ``adder`` and ``indent`` are not strings, **OR** + if ``dotted_paths`` is not a collection of dotted paths + ValueError + If ``adder`` is a non-single-line string or is not parsable + to a single expression, **OR** + if ``indent`` isn't single-line, non-empty, and whitespace + + Example: + >>> import io + >>> import textwrap + >>> import warnings + >>> + >>> + >>> def strip(s): + ... return textwrap.dedent(s).strip('\n') + ... + >>> + >>> with warnings.catch_warnings(record=True) as record: + ... with io.StringIO() as sio: + ... write_eager_import_module( + ... ['importlib.util', + ... 'foo.bar', + ... 'importlib.abc.Loader.exec_module', + ... 'importlib.abc.Loader.find_module'], + ... sio) + ... written = strip(sio.getvalue()) + ... + >>> assert written == strip(''' + ... add = profile.add_imported_function_or_module # noqa: F821 + ... failures = [] + ... + ... + ... try: + ... import importlib.abc as module + ... except ImportError: + ... pass + ... else: + ... try: + ... add(module.Loader.exec_module) + ... except AttributeError: + ... failures.append('importlib.abc.Loader.exec_module') + ... try: + ... add(module.Loader.find_module) + ... except AttributeError: + ... failures.append('importlib.abc.Loader.find_module') + ... + ... try: + ... import importlib.util as module + ... except ImportError: + ... failures.append('importlib.util') + ... else: + ... add(module) + ... + ... + ... if failures: + ... import warnings + ... + ... msg = '{} target{} cannot be imported: {!r}'.format( + ... len(failures), + ... '' if len(failures) == 1 else 's', + ... failures) + ... warnings.warn(msg, stacklevel=2) + ... '''), written + >>> assert len(record) == 1 + >>> assert (record[0].message.args[0] + ... == ("1 import target cannot be resolved: " + ... "['foo.bar']")) + + Note: + ``static=False`` can cause the ancestor module objects of + ``dotted_paths`` and ``recurse`` to be imported (and hence alter + the state of :py:data:`sys.modules`. + """ + if not isinstance(adder, str): + AdderError = TypeError + elif len(adder.splitlines()) != 1: + AdderError = ValueError + else: + expr = get_expression(adder) + if expr: + AdderError = None + else: + AdderError = ValueError + if AdderError: + raise AdderError(f'adder = {adder!r}: ' + 'expected a single-line string parsable to a single ' + 'expression') + if not isinstance(indent, str): + IndentError = TypeError + elif len(indent.splitlines()) == 1 and indent.isspace(): + IndentError = None + else: + IndentError = ValueError + if IndentError: + raise IndentError(f'indent = {indent!r}: ' + 'expected a single-line non-empty whitespace string') + + # Get the names loaded by `adder`; + # these names are not allowed in the namespace + forbidden_names = LoadedNameFinder.find(expr) + # We need three free names: + # - One for `adder` + # - One for a list of failed targets + # - One for the imported module + adder_name = next( + name for name in propose_names(['add', 'add_func', 'a', 'f']) + if name not in forbidden_names) + forbidden_names.add(adder_name) + failures_name = next( + name + for name in propose_names(['failures', 'failed_targets', 'f', '_']) + if name not in forbidden_names) + forbidden_names.add(failures_name) + module_name = next( + name for name in propose_names(['module', 'mod', 'imported', 'm', '_']) + if name not in forbidden_names) + + # Figure out the import targets to profile + resolved = resolve_profiling_targets( + dotted_paths, static=static, recurse=recurse) + + # Warn against failed imports + if resolved.unresolved: + msg = '{} import target{} cannot be resolved: {!r}'.format( + len(resolved.unresolved), + '' if len(resolved.unresolved) == 1 else 's', + resolved.unresolved) + warn(msg, stacklevel=2) + + # Do the imports and add them with `adder` + write = functools.partial(print, file=stream) + write(f'{adder_name} = {adder} # noqa: F821\n{failures_name} = []') + for i, (module, targets) in enumerate(resolved.targets.items()): + assert targets + # Write one more empty line so that the imports are separated + # from the preambles by 2 lines + if not i: + write() + # Allow arbitrary errors for modules that are only added + # indirectly (via descent/recursion) + if module in resolved.indirect: + allowed_error = 'Exception' + else: + allowed_error = 'ImportError' + # Is the module itself a direct target? + try: + targets.remove(None) + except KeyError: # Not found + profile_whole_module = False + else: + profile_whole_module = True + if profile_whole_module: + on_error = f'{failures_name}.append({module!r})' + else: + on_error = 'pass' + write('\n' + + strip(f""" + try: + {indent}import {module} as {module_name} + except {allowed_error}: + {indent}{on_error} + else: + """)) + chunks = [] + if profile_whole_module: + chunks.append(f'{adder_name}({module_name})') + for target in sorted(targets): + path = f'{module}.{target}' + chunks.append(strip(f""" + try: + {indent}{adder_name}({module_name}.{target}) + except AttributeError: + {indent}{failures_name}.append({path!r}) + """)) + for chunk in chunks: + write(indent_(chunk, indent)) + # Issue a warning if any of the targets doesn't exist + if resolved.targets: + write('\n') + write(strip(f""" + if {failures_name}: + {indent}import warnings + + {indent}msg = '{{}} target{{}} cannot be imported: {{!r}}'.format( + {indent * 2}len({failures_name}), + {indent * 2}'' if len({failures_name}) == 1 else 's', + {indent * 2}{failures_name}) + {indent}warnings.warn(msg, stacklevel=2) + """)) + + +ResolvedResult = namedtuple('ResolvedResult', + ('targets', 'indirect', 'unresolved')) diff --git a/line_profiler/autoprofile/eager_preimports.pyi b/line_profiler/autoprofile/eager_preimports.pyi new file mode 100644 index 00000000..756a6b7b --- /dev/null +++ b/line_profiler/autoprofile/eager_preimports.pyi @@ -0,0 +1,67 @@ +import ast +from typing import ( + Any, Union, + Collection, Dict, Generator, List, NamedTuple, Set, Tuple, + TextIO) + + +def is_dotted_path(obj: Any) -> bool: + ... + + +def get_expression(obj: Any) -> Union[ast.Expression, None]: + ... + + +def split_dotted_path( + dotted_path: str, static: bool = True) -> Tuple[str, Union[str, None]]: + ... + + +def strip(s: str) -> str: + ... + + +class LoadedNameFinder(ast.NodeVisitor): + names: Set[str] + contexts: List[Set[str]] + + def visit_Name(self, node: ast.Name) -> None: + ... + + def visit_FunctionDef(self, + node: Union[ast.FunctionDef, ast.AsyncFunctionDef, + ast.Lambda]) -> None: + ... + + visit_AsyncFunctionDef = visit_Lambda = visit_FunctionDef + + @classmethod + def find(cls, node: ast.AST) -> Set[str]: + ... + + +def propose_names(prefixes: Collection[str]) -> Generator[str, None, None]: + ... + + +def resolve_profiling_targets( + dotted_paths: Collection[str], + static: bool = True, + recurse: Union[Collection[str], bool] = False) -> 'ResolvedResult': + ... + + +def write_eager_import_module( + dotted_paths: Collection[str], stream: Union[TextIO, None] = None, *, + static: bool = True, + recurse: Union[Collection[str], bool] = False, + adder: str = 'profile.add_imported_function_or_module', + indent: str = ' ') -> None: + ... + + +class ResolvedResult(NamedTuple): + targets: Dict[str, Set[Union[str, None]]] + indirect: Set[str] + unresolved: List[str] diff --git a/line_profiler/autoprofile/line_profiler_utils.py b/line_profiler/autoprofile/line_profiler_utils.py index d7f63bc3..c4e736d1 100644 --- a/line_profiler/autoprofile/line_profiler_utils.py +++ b/line_profiler/autoprofile/line_profiler_utils.py @@ -1,25 +1,70 @@ import inspect -def add_imported_function_or_module(self, item): - """Method to add an object to LineProfiler to be profiled. +def add_imported_function_or_module(self, item, *, + scoping_policy=None, wrap=False): + """ + Method to add an object to + :py:class:`~.line_profiler.LineProfiler` to be profiled. - This method is used to extend an instance of LineProfiler so it can identify - whether an object is function/method, class or module and handle it's - profiling accordingly. + This method is used to extend an instance of + :py:class:`~.line_profiler.LineProfiler` so it can identify whether + an object is a callable (wrapper), a class, or a module, and handle + its profiling accordingly. Args: - item (Callable | Type | ModuleType): - object to be profiled. + item (Union[Callable, Type, ModuleType]): + Object to be profiled. + scoping_policy (Union[ScopingPolicy, str, ScopingPolicyDict, \ +None]): + Whether (and how) to match the scope of members and decide + on whether to add them: + + :py:class:`str` (incl. :py:class:`~.ScopingPolicy`): + Strings are converted to :py:class:`~.ScopingPolicy` + instances in a case-insensitive manner, and the same + policy applies to all members. + + ``{'func': ..., 'class': ..., 'module': ...}`` + Mapping specifying individual policies to be enacted for + the corresponding member types. + + :py:const:`None` + The default, equivalent to + :py:data:`~line_profiler.line_profiler\ +.DEFAULT_SCOPING_POLICIES`. + + See :py:class:`line_profiler.line_profiler.ScopingPolicy` + and :py:meth:`~.ScopingPolicy.to_policies` for details. + wrap (bool): + Whether to replace the wrapped members with wrappers which + automatically enable/disable the profiler when called. + + Returns: + 1 if any function is added to the profiler, 0 otherwise. + + See also: + :py:data:`~line_profiler.line_profiler\ +.DEFAULT_SCOPING_POLICIES`, + :py:meth:`.LineProfiler.add_callable()`, + :py:meth:`.LineProfiler.add_module()`, + :py:meth:`.LineProfiler.add_class()`, + :py:class:`~.ScopingPolicy`, + :py:meth:`ScopingPolicy.to_policies() \ +` """ - if inspect.isfunction(item): - self.add_function(item) - elif inspect.isclass(item): - for k, v in item.__dict__.items(): - if inspect.isfunction(v): - self.add_function(v) + if inspect.isclass(item): + count = self.add_class(item, scoping_policy=scoping_policy, wrap=wrap) elif inspect.ismodule(item): - self.add_module(item) + count = self.add_module(item, scoping_policy=scoping_policy, wrap=wrap) else: - return - self.enable_by_count() + try: + count = self.add_callable(item) + except TypeError: + count = 0 + if count: + # Session-wide enabling means that we no longer have to wrap + # individual callables to enable/disable the profiler when + # they're called + self.enable_by_count() + return 1 if count else 0 diff --git a/line_profiler/autoprofile/line_profiler_utils.pyi b/line_profiler/autoprofile/line_profiler_utils.pyi index 467c10e7..b710b577 100644 --- a/line_profiler/autoprofile/line_profiler_utils.pyi +++ b/line_profiler/autoprofile/line_profiler_utils.pyi @@ -1,8 +1,25 @@ -from typing import Callable -from typing import Type from types import ModuleType +from typing import overload, Any, Literal, TYPE_CHECKING +if TYPE_CHECKING: # Stub-only annotations + from ..line_profiler import CallableLike + from ..profiler_mixin import CLevelCallable + from ..scoping_policy import ScopingPolicy, ScopingPolicyDict + +@overload +def add_imported_function_or_module( + self, item: CLevelCallable | Any, + scoping_policy: ( + ScopingPolicy | str | ScopingPolicyDict | None) = None, + wrap: bool = False) -> Literal[0]: + ... + + +@overload def add_imported_function_or_module( - self, item: Callable | Type | ModuleType) -> None: + self, item: CallableLike | ModuleType, + scoping_policy: ( + ScopingPolicy | str | ScopingPolicyDict | None) = None, + wrap: bool = False) -> Literal[0, 1]: ... diff --git a/line_profiler/line_profiler.py b/line_profiler/line_profiler.py index 0e0fd74c..5c7c40ea 100755 --- a/line_profiler/line_profiler.py +++ b/line_profiler/line_profiler.py @@ -4,13 +4,16 @@ inspect its output. This depends on the :py:mod:`line_profiler._line_profiler` Cython backend. """ +import functools import inspect import linecache import os import pickle import sys import tempfile +import types from argparse import ArgumentError, ArgumentParser +from datetime import datetime try: from ._line_profiler import LineProfiler as CLineProfiler @@ -19,17 +22,14 @@ 'The line_profiler._line_profiler c-extension is not importable. ' f'Has it been compiled? Underlying error is ex={ex!r}' ) -from .profiler_mixin import (ByCountProfilerMixin, - is_property, is_cached_property, - is_boundmethod, is_classmethod, is_staticmethod, - is_partial, is_partialmethod) +from . import _diagnostics as diagnostics +from .profiler_mixin import ByCountProfilerMixin, is_c_level_callable +from .scoping_policy import ScopingPolicy # NOTE: This needs to be in sync with ../kernprof.py and __init__.py __version__ = '4.3.0' -is_function = inspect.isfunction - def load_ipython_extension(ip): """ API for IPython to recognize this module as an IPython extension. @@ -38,34 +38,6 @@ def load_ipython_extension(ip): ip.register_magics(LineProfilerMagics) -def _get_underlying_functions(func): - """ - Get the underlying function objects of a callable or an adjacent - object. - - Returns: - funcs (list[Callable]) - """ - if any(check(func) - for check in (is_boundmethod, is_classmethod, is_staticmethod)): - return _get_underlying_functions(func.__func__) - if any(check(func) - for check in (is_partial, is_partialmethod, is_cached_property)): - return _get_underlying_functions(func.func) - if is_property(func): - result = [] - for impl in func.fget, func.fset, func.fdel: - if impl is not None: - result.extend(_get_underlying_functions(impl)) - return result - if not callable(func): - raise TypeError(f'func = {func!r}: ' - f'cannot get functions from {type(func)} objects') - if is_function(func): - return [func] - return [type(func).__call__] - - class _WrapperInfo: """ Helper object for holding the state of a wrapper function. @@ -100,28 +72,57 @@ class LineProfiler(CLineProfiler, ByCountProfilerMixin): """ def __call__(self, func): """ - Decorate a function, method, property, partial object etc. to - start the profiler on function entry and stop it on function - exit. + Decorate a function, method, :py:class:`property`, + :py:func:`~functools.partial` object etc. to start the profiler + on function entry and stop it on function exit. """ - # Note: if `func` is a `types.FunctionType` which is already - # decorated by the profiler, the same object is returned; + # The same object is returned when: + # - `func` is a `types.FunctionType` which is already + # decorated by the profiler, + # - `func` is a class, or + # - `func` is any of the C-level callables that can't be + # profiled # otherwise, wrapper objects are always returned. self.add_callable(func) return self.wrap_callable(func) - def add_callable(self, func): + def wrap_callable(self, func): + if is_c_level_callable(func): # Non-profilable + return func + return super().wrap_callable(func) + + def add_callable(self, func, guard=None, name=None): """ - Register a function, method, property, partial object, etc. with - the underlying Cython profiler. + Register a function, method, :py:class:`property`, + :py:func:`~functools.partial` object, etc. with the underlying + Cython profiler. + + Args: + func (...): + Function, class/static/bound method, property, etc. + guard (Optional[Callable[[types.FunctionType], bool]]) + Optional checker callable, which takes a function object + and returns true(-y) if it *should not* be passed to + :py:meth:`.add_function()`. Defaults to checking + whether the function is already a profiling wrapper. + name (Optional[str]) + Optional name for ``func``, to be used in log messages. Returns: - 1 if any function is added to the profiler, 0 otherwise + 1 if any function is added to the profiler, 0 otherwise. + + Note: + This method should in general be called instead of the more + low-level :py:meth:`.add_function()`. """ + if guard is None: + guard = self._already_a_wrapper + nadded = 0 - for impl in _get_underlying_functions(func): + func_repr = self._repr_for_log(func, name) + for impl in self.get_underlying_functions(func): info, wrapped_by_this_prof = self._get_wrapper_info(impl) - if wrapped_by_this_prof: + if wrapped_by_this_prof if guard is None else guard(impl): continue if info: # It's still a profiling wrapper, just wrapped by @@ -129,12 +130,42 @@ def add_callable(self, func): impl = info.func self.add_function(impl) nadded += 1 + if impl is func: + self._debug(f'added {func_repr}') + else: + self._debug(f'added {func_repr} -> {self._repr_for_log(impl)}') return 1 if nadded else 0 + @staticmethod + def _repr_for_log(obj, name=None): + try: + real_name = '{0.__module__}.{0.__qualname__}'.format(obj) + except AttributeError: + try: + real_name = obj.__name__ + except AttributeError: + real_name = '???' + return '{} `{}{}` {}@ {:#x}'.format( + type(obj).__name__, + real_name, + '()' if callable(obj) and not isinstance(obj, type) else '', + f'(=`{name}`) ' if name and name != real_name else '', + id(obj)) + + def _debug(self, msg): + self_repr = f'{type(self).__name__} @ {id(self):#x}' + logger = diagnostics.log + if logger.backend == 'print': + now = datetime.now().isoformat(sep=' ', timespec='seconds') + msg = f'[{self_repr} {now}] {msg}' + else: + msg = f'{self_repr}: {msg}' + logger.debug(msg) + def dump_stats(self, filename): - """ Dump a representation of the data to a file as a pickled LineStats - object from `get_stats()`. + """ Dump a representation of the data to a file as a pickled + :py:class:`~.LineStats` object from :py:meth:`~.get_stats()`. """ lstats = self.get_stats() with open(filename, 'wb') as f: @@ -149,23 +180,161 @@ def print_stats(self, stream=None, output_unit=None, stripzeros=False, stream=stream, stripzeros=stripzeros, details=details, summarize=summarize, sort=sort, rich=rich) - def add_module(self, mod): - """ Add all the functions in a module and its classes. + def _add_namespace( + self, namespace, *, + seen=None, + func_scoping_policy=ScopingPolicy.NONE, + class_scoping_policy=ScopingPolicy.NONE, + module_scoping_policy=ScopingPolicy.NONE, + wrap=False, + name=None): + def func_guard(func): + return self._already_a_wrapper(func) or not func_check(func) + + if seen is None: + seen = set() + count = 0 + add_namespace = functools.partial( + self._add_namespace, + seen=seen, + func_scoping_policy=func_scoping_policy, + class_scoping_policy=class_scoping_policy, + module_scoping_policy=module_scoping_policy, + wrap=wrap) + members_to_wrap = {} + func_check = func_scoping_policy.get_filter(namespace, 'func') + cls_check = class_scoping_policy.get_filter(namespace, 'class') + mod_check = module_scoping_policy.get_filter(namespace, 'module') + + # Logging stuff + if not name: + try: # Class + name = '{0.__module__}.{0.__qualname__}'.format(namespace) + except AttributeError: # Module + name = namespace.__name__ + + for attr, value in vars(namespace).items(): + if id(value) in seen: + continue + seen.add(id(value)) + if isinstance(value, type): + if not (cls_check(value) + and add_namespace(value, name=f'{name}.{attr}')): + continue + elif isinstance(value, types.ModuleType): + if not (mod_check(value) + and add_namespace(value, name=f'{name}.{attr}')): + continue + else: + try: + if not self.add_callable( + value, guard=func_guard, name=f'{name}.{attr}'): + continue + except TypeError: # Not a callable (wrapper) + continue + if wrap: + members_to_wrap[attr] = value + count += 1 + if wrap and members_to_wrap: + self._wrap_namespace_members(namespace, members_to_wrap, + warning_stack_level=3) + if count: + self._debug( + 'added {} member{} in {}'.format( + count, + '' if count == 1 else 's', + self._repr_for_log(namespace, name))) + return count + + def add_class(self, cls, *, scoping_policy=None, wrap=False): """ - from inspect import isclass + Add the members (callables (wrappers), methods, classes, ...) in + a class' local namespace and profile them. + + Args: + cls (type): + Class to be profiled. + scoping_policy (Union[str, ScopingPolicy, \ +ScopingPolicyDict, None]): + Whether (and how) to match the scope of members and + decide on whether to add them: + + :py:class:`str` (incl. :py:class:`~.ScopingPolicy`): + Strings are converted to :py:class:`~.ScopingPolicy` + instances in a case-insensitive manner, and the same + policy applies to all members. + + ``{'func': ..., 'class': ..., 'module': ...}`` + Mapping specifying individual policies to be enacted + for the corresponding member types. + + :py:const:`None` + The default, equivalent to + :py:data:\ +`~.scoping_policy.DEFAULT_SCOPING_POLICIES`. + + See :py:class:`~.ScopingPolicy` and + :py:meth:`.ScopingPolicy.to_policies` for details. + wrap (bool): + Whether to replace the wrapped members with wrappers + which automatically enable/disable the profiler when + called. - nfuncsadded = 0 - for item in mod.__dict__.values(): - if isclass(item): - for k, v in item.__dict__.items(): - if is_function(v): - self.add_function(v) - nfuncsadded += 1 - elif is_function(item): - self.add_function(item) - nfuncsadded += 1 + Returns: + n (int): + Number of members added to the profiler. + """ + policies = ScopingPolicy.to_policies(scoping_policy) + return self._add_namespace(cls, + func_scoping_policy=policies['func'], + class_scoping_policy=policies['class'], + module_scoping_policy=policies['module'], + wrap=wrap) + + def add_module(self, mod, *, scoping_policy=None, wrap=False): + """ + Add the members (callables (wrappers), methods, classes, ...) in + a module's local namespace and profile them. + + Args: + mod (ModuleType): + Module to be profiled. + scoping_policy (Union[str, ScopingPolicy, \ +ScopingPolicyDict, None]): + Whether (and how) to match the scope of members and + decide on whether to add them: + + :py:class:`str` (incl. :py:class:`~.ScopingPolicy`): + Strings are converted to :py:class:`~.ScopingPolicy` + instances in a case-insensitive manner, and the same + policy applies to all members. + + ``{'func': ..., 'class': ..., 'module': ...}`` + Mapping specifying individual policies to be enacted + for the corresponding member types. + + :py:const:`None` + The default, equivalent to + :py:data:\ +`~.scoping_policy.DEFAULT_SCOPING_POLICIES`. + + See :py:class:`~.ScopingPolicy` and + :py:meth:`.ScopingPolicy.to_policies` for details. + wrap (bool): + Whether to replace the wrapped members with wrappers + which automatically enable/disable the profiler when + called. - return nfuncsadded + Returns: + n (int): + Number of members added to the profiler. + """ + policies = ScopingPolicy.to_policies(scoping_policy) + return self._add_namespace(mod, + func_scoping_policy=policies['func'], + class_scoping_policy=policies['class'], + module_scoping_policy=policies['module'], + wrap=wrap) def _get_wrapper_info(self, func): info = getattr(func, self._profiler_wrapped_marker, None) @@ -487,8 +656,8 @@ def show_text(stats, unit, output_unit=None, stream=None, stripzeros=False, def load_stats(filename): - """ Utility function to load a pickled LineStats object from a given - filename. + """ Utility function to load a pickled :py:class:`~.LineStats` + object from a given filename. """ with open(filename, 'rb') as f: return pickle.load(f) @@ -496,7 +665,7 @@ def load_stats(filename): def main(): """ - The line profiler CLI to view output from ``kernprof -l``. + The line profiler CLI to view output from :command:`kernprof -l`. """ def positive_float(value): val = float(value) diff --git a/line_profiler/line_profiler.pyi b/line_profiler/line_profiler.pyi index edbf1bde..89a0fa3a 100644 --- a/line_profiler/line_profiler.pyi +++ b/line_profiler/line_profiler.pyi @@ -1,8 +1,17 @@ -from typing import Literal, List, Tuple import io -from ._line_profiler import LineProfiler as CLineProfiler -from .profiler_mixin import ByCountProfilerMixin +from functools import cached_property, partial, partialmethod +from types import FunctionType, MethodType, ModuleType +from typing import overload, Callable, List, Literal, Tuple, TypeVar from _typeshed import Incomplete +from ._line_profiler import LineProfiler as CLineProfiler +from .profiler_mixin import ByCountProfilerMixin, CLevelCallable +from .scoping_policy import ScopingPolicy, ScopingPolicyDict + + +CallableLike = TypeVar('CallableLike', + FunctionType, partial, property, cached_property, + MethodType, staticmethod, classmethod, partialmethod, + type) def load_ipython_extension(ip) -> None: @@ -10,7 +19,26 @@ def load_ipython_extension(ip) -> None: class LineProfiler(CLineProfiler, ByCountProfilerMixin): - def add_callable(self, func) -> Literal[0, 1]: + @overload + def __call__(self, # type: ignore[overload-overlap] + func: CLevelCallable) -> CLevelCallable: + ... + + @overload + def __call__(self, # type: ignore[overload-overlap] + func: CallableLike) -> CallableLike: + ... + + # Fallback: just wrap the `.__call__()` of a generic callable + + @overload + def __call__(self, func: Callable) -> FunctionType: + ... + + def add_callable( + self, func, + guard: Callable[[FunctionType], bool] | None = None, + name: str | None = None) -> Literal[0, 1]: ... def dump_stats(self, filename) -> None: @@ -26,7 +54,18 @@ class LineProfiler(CLineProfiler, ByCountProfilerMixin): rich: bool = ...) -> None: ... - def add_module(self, mod) -> int: + def add_module( + self, mod: ModuleType, *, + scoping_policy: ( + ScopingPolicy | str | ScopingPolicyDict | None) = None, + wrap: bool = False) -> int: + ... + + def add_class( + self, cls: type, *, + scoping_policy: ( + ScopingPolicy | str | ScopingPolicyDict | None) = None, + wrap: bool = False) -> int: ... diff --git a/line_profiler/line_profiler_utils.py b/line_profiler/line_profiler_utils.py new file mode 100644 index 00000000..0d903888 --- /dev/null +++ b/line_profiler/line_profiler_utils.py @@ -0,0 +1,73 @@ +""" +Miscellaneous utilities that :py:mod:`line_profiler` uses. +""" +import enum + + +class _StrEnumBase(str, enum.Enum): + """ + Base class mimicking :py:class:`enum.StrEnum` in Python 3.11+. + + Example + ------- + >>> import enum + >>> + >>> + >>> class MyEnum(_StrEnumBase): + ... foo = enum.auto() + ... BAR = enum.auto() + ... + >>> + >>> MyEnum.foo + + >>> MyEnum('bar') + + >>> MyEnum('baz') + Traceback (most recent call last): + ... + ValueError: 'baz' is not a valid MyEnum + """ + @staticmethod + def _generate_next_value_(name, *_, **__): + return name.lower() + + def __eq__(self, other): + return self.value == other + + def __str__(self): + return self.value + + +class StringEnum(getattr(enum, 'StrEnum', _StrEnumBase)): + """ + Convenience wrapper around :py:class:`enum.StrEnum`. + + Example + ------- + >>> import enum + >>> + >>> + >>> class MyEnum(StringEnum): + ... foo = enum.auto() + ... BAR = enum.auto() + ... + >>> + >>> MyEnum.foo + + >>> MyEnum('bar') + + >>> bar = MyEnum('BAR') # Case-insensitive + >>> bar + + >>> assert isinstance(bar, str) + >>> assert bar == 'bar' + >>> str(bar) + 'bar' + """ + @classmethod + def _missing_(cls, value): + if not isinstance(value, str): + return None + members = {name.casefold(): instance + for name, instance in cls.__members__.items()} + return members.get(value.casefold()) diff --git a/line_profiler/line_profiler_utils.pyi b/line_profiler/line_profiler_utils.pyi new file mode 100644 index 00000000..a510cf94 --- /dev/null +++ b/line_profiler/line_profiler_utils.pyi @@ -0,0 +1,26 @@ +import enum +try: + from typing import Self # type: ignore[attr-defined] # noqa: F401 +except ImportError: # Python < 3.11 + from typing_extensions import Self # noqa: F401 + + +# Note: `mypy` tries to read this class as a free-standing enum +# (instead of an `enum.Enum` subclass that string enums are to inherit +# from), and complains that it has no members -- so silence that + + +class StringEnum(str, enum.Enum): # type: ignore[misc] + @staticmethod + def _generate_next_value_(name: str, *_, **__) -> str: + ... + + def __eq__(self, other) -> bool: + ... + + def __str__(self) -> str: + ... + + @classmethod + def _missing_(cls, value) -> Self | None: + ... diff --git a/line_profiler/profiler_mixin.py b/line_profiler/profiler_mixin.py index 52980765..ab4cc59a 100644 --- a/line_profiler/profiler_mixin.py +++ b/line_profiler/profiler_mixin.py @@ -1,12 +1,45 @@ import functools import inspect import types +from warnings import warn +from .scoping_policy import ScopingPolicy is_coroutine = inspect.iscoroutinefunction +is_function = inspect.isfunction is_generator = inspect.isgeneratorfunction is_async_generator = inspect.isasyncgenfunction +# These objects are callables, but are defined in C(-ython) so we can't +# handle them anyway +C_LEVEL_CALLABLE_TYPES = (types.BuiltinFunctionType, + types.BuiltinMethodType, + types.ClassMethodDescriptorType, + types.MethodDescriptorType, + types.MethodWrapperType, + types.WrapperDescriptorType) + + +def is_c_level_callable(func): + """ + Returns: + func_is_c_level (bool): + Whether a callable is defined at the C(-ython) level (and is + thus non-profilable). + """ + return isinstance(func, C_LEVEL_CALLABLE_TYPES) or is_cython_callable(func) + + +def is_cython_callable(func): + if not callable(func): + return False + # Note: don't directly check against a Cython function type, since + # said type depends on the Cython version used for building the + # Cython code; + # just check for what is common between Cython versions + return (type(func).__name__ + in ('cython_function_or_method', 'fused_cython_function')) + def is_classmethod(f): return isinstance(f, classmethod) @@ -39,39 +72,111 @@ def is_cached_property(f): class ByCountProfilerMixin: """ Mixin class for profiler methods built around the - `.enable_by_count()` and `.disable_by_count()` methods, rather than - the `.enable()` and `.disable()` methods. + :py:meth:`!enable_by_count()` and :py:meth:`!disable_by_count()` + methods, rather than the :py:meth:`!enable()` and + :py:meth:`!disable()` methods. - Used by `line_profiler.line_profiler.LineProfiler` and - `kernprof.ContextualProfile`. + Used by :py:class:`line_profiler.line_profiler.LineProfiler` and + :py:class:`kernprof.ContextualProfile`. """ def wrap_callable(self, func): - """ Decorate a function to start the profiler on function entry and stop - it on function exit. + """ + Decorate a function to start the profiler on function entry and + stop it on function exit. """ if is_classmethod(func): - wrapper = self.wrap_classmethod(func) - elif is_staticmethod(func): - wrapper = self.wrap_staticmethod(func) - elif is_boundmethod(func): - wrapper = self.wrap_boundmethod(func) - elif is_partialmethod(func): - wrapper = self.wrap_partialmethod(func) - elif is_partial(func): - wrapper = self.wrap_partial(func) - elif is_property(func): - wrapper = self.wrap_property(func) - elif is_cached_property(func): - wrapper = self.wrap_cached_property(func) - elif is_async_generator(func): - wrapper = self.wrap_async_generator(func) - elif is_coroutine(func): - wrapper = self.wrap_coroutine(func) - elif is_generator(func): - wrapper = self.wrap_generator(func) - else: - wrapper = self.wrap_function(func) - return wrapper + return self.wrap_classmethod(func) + if is_staticmethod(func): + return self.wrap_staticmethod(func) + if is_boundmethod(func): + return self.wrap_boundmethod(func) + if is_partialmethod(func): + return self.wrap_partialmethod(func) + if is_partial(func): + return self.wrap_partial(func) + if is_property(func): + return self.wrap_property(func) + if is_cached_property(func): + return self.wrap_cached_property(func) + if is_async_generator(func): + return self.wrap_async_generator(func) + if is_coroutine(func): + return self.wrap_coroutine(func) + if is_generator(func): + return self.wrap_generator(func) + if isinstance(func, type): + return self.wrap_class(func) + if callable(func): + return self.wrap_function(func) + raise TypeError(f'func = {func!r}: does not look like a callable or ' + 'callable wrapper') + + @classmethod + def get_underlying_functions(cls, func): + """ + Get the underlying function objects of a callable or an adjacent + object. + + Returns: + funcs (list[Callable]) + """ + return cls._get_underlying_functions(func) + + @classmethod + def _get_underlying_functions(cls, func, seen=None, stop_at_classes=False): + if seen is None: + seen = set() + get_underlying = functools.partial( + cls._get_underlying_functions, + seen=seen, stop_at_classes=stop_at_classes) + if any(check(func) + for check in (is_boundmethod, is_classmethod, is_staticmethod)): + return get_underlying(func.__func__) + if any(check(func) + for check in (is_partial, is_partialmethod, is_cached_property)): + return get_underlying(func.func) + if is_property(func): + result = [] + for impl in func.fget, func.fset, func.fdel: + if impl is not None: + result.extend(get_underlying(impl)) + return result + if isinstance(func, type): + if stop_at_classes: + return [func] + result = [] + get_filter = cls._class_scoping_policy.get_filter + func_check = get_filter(func, 'func') + cls_check = get_filter(func, 'class') + for member in vars(func).values(): + try: + member_funcs = get_underlying(member, stop_at_classes=True) + except TypeError: + continue + for impl in member_funcs: + is_type = isinstance(impl, type) + check = cls_check if is_type else func_check + if not check(impl): + continue + if is_type: + result.extend(get_underlying(impl)) + else: + result.append(impl) + return result + if not callable(func): + raise TypeError(f'func = {func!r}: ' + f'cannot get functions from {type(func)} objects') + if id(func) in seen: + return [] + seen.add(id(func)) + if is_function(func): + return [func] + if is_c_level_callable(func): + return [] + func = type(func).__call__ + if is_c_level_callable(func): # Can happen with builtin types + return [] + return [func] def _wrap_callable_wrapper(self, wrapper, impl_attrs, *, args=None, kwargs=None, name_attr=None): @@ -81,12 +186,13 @@ def _wrap_callable_wrapper(self, wrapper, impl_attrs, *, Args: wrapper (W): - Wrapper object around regular callables, like - `property`, `staticmethod`, `functools.partial`, etc. + Wrapper object around other callables, like + :py:class:`property`, :py:func:`staticmethod`, + :py:func:`functools.partial`, etc. impl_attrs (Sequence[str]): Attribute names whence to retrieve the individual - callables to be wrapped and profiled, like `.fget`, - `.fset`, and `.fdel` for `property`; + callables to be wrapped and profiled, like ``.fget``, + ``.fset``, and ``.fdel`` for :py:class:`property`; the retrieved values are wrapped and passed as positional arguments to the wrapper constructor. args (Optional[str | Sequence[str]]): @@ -100,16 +206,18 @@ def _wrap_callable_wrapper(self, wrapper, impl_attrs, *, retrieve extra keyword arguments to pass to the wrapper constructor; if a single name, the retrieved values is unpacked; - else, the attribute of `wrapper` at the mapping value is - used to populate the keyword arg at the mapping key. + else, the attribute of ``wrapper`` at the mapping value + is used to populate the keyword arg at the mapping key. name_attr (Optional[str]): Optional attribute name whence to retrieve the name of - `wrapper` to be carried over in the new wrapper, like - `__name__` for `property` (Python 3.13+) and `attrname` - for `functools.cached_property`. + ``wrapper`` to be carried over in the new wrapper, like + ``.__name__`` for :py:class:`property` (Python 3.13+) + and ``.attrname`` for + :py:func:`functools.cached_property`. Returns: - (W): new wrapper of the type of `wrapper` + new_wrapper (W): + New wrapper of the type of ``wrapper`` """ # Wrap implementations impls = [getattr(wrapper, attr) for attr in impl_attrs] @@ -156,7 +264,8 @@ def _wrap_callable_wrapper(self, wrapper, impl_attrs, *, def _wrap_class_and_static_method(self, func): """ - Wrap a class/static method to profile it. + Wrap a :py:func:`classmethod` or :py:func:`staticmethod` to + profile it. """ return self._wrap_callable_wrapper(func, ('__func__',)) @@ -164,14 +273,15 @@ def _wrap_class_and_static_method(self, func): def wrap_boundmethod(self, func): """ - Wrap a bound method to profile it. + Wrap a :py:class:`types.MethodType` to profile it. """ return self._wrap_callable_wrapper(func, ('__func__',), args=('__self__',)) def _wrap_partial(self, func): """ - Wrap a `functools.partial[method]` to profile it. + Wrap a :py:func:`functools.partial` or + :py:class:`functools.partialmethod` to profile it. """ return self._wrap_callable_wrapper(func, ('func',), args='args', kwargs='keywords') @@ -180,7 +290,7 @@ def _wrap_partial(self, func): def wrap_property(self, func): """ - Wrap a property to profile it. + Wrap a :py:class:`property` to profile it. """ return self._wrap_callable_wrapper(func, ('fget', 'fset', 'fdel'), kwargs={'doc': '__doc__'}, @@ -188,7 +298,7 @@ def wrap_property(self, func): def wrap_cached_property(self, func): """ - Wrap a `functools.cached_property` to profile it. + Wrap a :py:func:`functools.cached_property` to profile it. """ return self._wrap_callable_wrapper(func, ('func',), name_attr='attrname') @@ -281,6 +391,63 @@ def wrapper(*args, **kwds): return self._mark_wrapper(wrapper) + def wrap_class(self, func): + """ + Wrap a class by wrapping all locally-defined callables and + callable wrappers. + + Returns: + func (type): + The class passed in, with its locally-defined + callables and wrappers wrapped. + + Warns: + UserWarning + If any of the locally-defined callables and wrappers + cannot be replaced with the appropriate wrapper returned + from :py:meth:`.wrap_callable()`. + """ + get_filter = self._class_scoping_policy.get_filter + func_check = get_filter(func, 'func') + cls_check = get_filter(func, 'class') + get_underlying = functools.partial( + self._get_underlying_functions, stop_at_classes=True) + members_to_wrap = {} + for name, member in vars(func).items(): + try: + impls = get_underlying(member) + except TypeError: # Not a callable (wrapper) + continue + if any((cls_check(impl) + if isinstance(impl, type) else + func_check(impl)) + for impl in impls): + members_to_wrap[name] = member + self._wrap_namespace_members(func, members_to_wrap, + warning_stack_level=2) + return func + + def _wrap_namespace_members( + self, namespace, members, *, warning_stack_level=2): + wrap_failures = {} + for name, member in members.items(): + wrapper = self.wrap_callable(member) + if wrapper is member: + continue + try: + setattr(namespace, name, wrapper) + except (TypeError, AttributeError): + # Corner case in case if a class/module don't allow + # setting attributes (could e.g. happen with some + # builtin/extension classes, but their method should be + # in C anyway, so `.add_callable()` should've returned 0 + # and we shouldn't be here) + wrap_failures[name] = member + if wrap_failures: + msg = (f'cannot wrap {len(wrap_failures)} attribute(s) of ' + f'{namespace!r} (`{{attr: value}}`): {wrap_failures!r}') + warn(msg, stacklevel=warning_stack_level) + def _already_a_wrapper(self, func): return getattr(func, self._profiler_wrapped_marker, None) == id(self) @@ -322,3 +489,4 @@ def __exit__(self, *_, **__): self.disable_by_count() _profiler_wrapped_marker = '__line_profiler_id__' + _class_scoping_policy = ScopingPolicy.CHILDREN diff --git a/line_profiler/profiler_mixin.pyi b/line_profiler/profiler_mixin.pyi index 0f751b06..166cc39f 100644 --- a/line_profiler/profiler_mixin.pyi +++ b/line_profiler/profiler_mixin.pyi @@ -1,89 +1,223 @@ -import inspect -import typing +from functools import cached_property, partial, partialmethod +from types import (CodeType, FunctionType, MethodType, + BuiltinFunctionType, BuiltinMethodType, + ClassMethodDescriptorType, MethodDescriptorType, + MethodWrapperType, WrapperDescriptorType) +from typing import (TYPE_CHECKING, + Any, Callable, Dict, List, Mapping, Protocol, TypeVar) +try: + from typing import ( # type: ignore[attr-defined] # noqa: F401 + ParamSpec) +except ImportError: # Python < 3.10 + from typing_extensions import ParamSpec # noqa: F401 +try: + from typing import ( # type: ignore[attr-defined] # noqa: F401 + Self) +except ImportError: # Python < 3.11 + from typing_extensions import Self # noqa: F401 +try: + from typing import ( # type: ignore[attr-defined] # noqa: F401 + TypeIs) +except ImportError: # Python < 3.13 + from typing_extensions import TypeIs # noqa: F401 +from ._line_profiler import label + + +T = TypeVar('T', bound=type) +T_co = TypeVar('T_co', covariant=True) +R = TypeVar('R') +PS = ParamSpec('PS') + +if TYPE_CHECKING: + class CythonCallable(Protocol[PS, T_co]): + def __call__(self, *args: PS.args, **kwargs: PS.kwargs) -> T_co: + ... + + @property + def __code__(self) -> CodeType: + ... + + @property + def func_code(self) -> CodeType: + ... + + @property + def __name__(self) -> str: + ... + + @property + def func_name(self) -> str: + ... + + @property + def __qualname__(self) -> str: + ... + + @property + def __doc__(self) -> str | None: + ... + + @__doc__.setter + def __doc__(self, doc: str | None) -> None: + ... + + @property + def func_doc(self) -> str | None: + ... + + @property + def __globals__(self) -> Dict[str, Any]: + ... + + @property + def func_globals(self) -> Dict[str, Any]: + ... + + @property + def __dict__(self) -> Dict[str, Any]: + ... + + @__dict__.setter + def __dict__(self, dict: Dict[str, Any]) -> None: + ... + + @property + def func_dict(self) -> Dict[str, Any]: + ... + + @property + def __annotations__(self) -> Dict[str, Any]: + ... + + @__annotations__.setter + def __annotations__(self, annotations: Dict[str, Any]) -> None: + ... + + @property + def __defaults__(self): + ... + + @property + def func_defaults(self): + ... + + @property + def __kwdefaults__(self): + ... + + @property + def __closure__(self): + ... + + @property + def func_closure(self): + ... -is_coroutine = inspect.iscoroutinefunction -is_generator = inspect.isgeneratorfunction -is_async_generator = inspect.isasyncgenfunction +else: + CythonCallable = type(label) +CLevelCallable = TypeVar('CLevelCallable', + BuiltinFunctionType, BuiltinMethodType, + ClassMethodDescriptorType, MethodDescriptorType, + MethodWrapperType, WrapperDescriptorType, + CythonCallable) -def is_classmethod(f) -> bool: + +def is_c_level_callable(func: Any) -> TypeIs[CLevelCallable]: + ... + + +def is_cython_callable(func: Any) -> TypeIs[CythonCallable]: + ... + + +def is_classmethod(f: Any) -> TypeIs[classmethod]: ... -def is_staticmethod(f) -> bool: +def is_staticmethod(f: Any) -> TypeIs[staticmethod]: ... -def is_boundmethod(f) -> bool: +def is_boundmethod(f: Any) -> TypeIs[MethodType]: ... -def is_partialmethod(f) -> bool: +def is_partialmethod(f: Any) -> TypeIs[partialmethod]: ... -def is_partial(f) -> bool: +def is_partial(f: Any) -> TypeIs[partial]: ... -def is_property(f) -> bool: +def is_property(f: Any) -> TypeIs[property]: ... -def is_cached_property(f) -> bool: +def is_cached_property(f: Any) -> TypeIs[cached_property]: ... class ByCountProfilerMixin: + def get_underlying_functions(self, func) -> List[FunctionType]: + ... def wrap_callable(self, func): ... - def wrap_classmethod(self, func): + def wrap_classmethod(self, func: classmethod) -> classmethod: + ... + + def wrap_staticmethod(self, func: staticmethod) -> staticmethod: ... - def wrap_staticmethod(self, func): + def wrap_boundmethod(self, func: MethodType) -> MethodType: ... - def wrap_boundmethod(self, func): + def wrap_partialmethod(self, func: partialmethod) -> partialmethod: ... - def wrap_partialmethod(self, func): + def wrap_partial(self, func: partial) -> partial: ... - def wrap_partial(self, func): + def wrap_property(self, func: property) -> property: ... - def wrap_property(self, func): + def wrap_cached_property(self, func: cached_property) -> cached_property: ... - def wrap_cached_property(self, func): + def wrap_async_generator(self, func: FunctionType) -> FunctionType: ... - def wrap_async_generator(self, func): + def wrap_coroutine(self, func: FunctionType) -> FunctionType: ... - def wrap_coroutine(self, func): + def wrap_generator(self, func: FunctionType) -> FunctionType: ... - def wrap_generator(self, func): + def wrap_function(self, func: Callable) -> FunctionType: ... - def wrap_function(self, func): + def wrap_class(self, func: T) -> T: ... - def run(self, cmd): + def run(self, cmd: str) -> Self: ... - def runctx(self, cmd, globals, locals): + def runctx(self, + cmd: str, + globals: Dict[str, Any] | None, + locals: Mapping[str, Any] | None) -> Self: ... - def runcall(self, func, /, *args, **kw): + def runcall(self, func: Callable[PS, R], /, + *args: PS.args, **kw: PS.kwargs) -> R: ... - def __enter__(self): + def __enter__(self) -> Self: ... - def __exit__(self, *_, **__): + def __exit__(self, *_, **__) -> None: ... diff --git a/line_profiler/scoping_policy.py b/line_profiler/scoping_policy.py new file mode 100644 index 00000000..cedf51e9 --- /dev/null +++ b/line_profiler/scoping_policy.py @@ -0,0 +1,311 @@ +from enum import auto +from types import MappingProxyType, ModuleType +from typing import Union, TypedDict +from .line_profiler_utils import StringEnum + + +#: Default scoping policies: +#: +#: * Profile sibling and descendant functions +#: (:py:attr:`ScopingPolicy.SIBLINGS`) +#: * Descend ingo sibling and descendant classes +#: (:py:attr:`ScopingPolicy.SIBLINGS`) +#: * Don't descend into modules (:py:attr:`ScopingPolicy.EXACT`) +DEFAULT_SCOPING_POLICIES = MappingProxyType( + {'func': 'siblings', 'class': 'siblings', 'module': 'exact'}) + + +class ScopingPolicy(StringEnum): + """ + :py:class:`StrEnum` for scoping policies, that is, how it is + decided whether to: + + * Profile a function found in a namespace (a class or a module), and + * Descend into nested namespaces so that their methods and functions + are profiled, + + when using :py:meth:`LineProfiler.add_class`, + :py:meth:`LineProfiler.add_module`, and + :py:func:`~.add_imported_function_or_module()`. + + Available policies are: + + :py:attr:`ScopingPolicy.EXACT` + Only profile *functions* found in the namespace fulfilling + :py:attr:`ScopingPolicy.CHILDREN` as defined below, without + descending into nested namespaces + + :py:attr:`ScopingPolicy.CHILDREN` + Only profile/descend into *child* objects, which are: + + * Classes and functions defined *locally* in the very + module, or in the very class as its "inner classes" and + methods + * Direct submodules, in case when the namespace is a module + object representing a package + + :py:attr:`ScopingPolicy.DESCENDANTS` + Only profile/descend into *descendant* objects, which are: + + * Child classes, functions, and modules, as defined above in + :py:attr:`ScopingPolicy.CHILDREN` + * Their child classes, functions, and modules, ... + * ... and so on + + Note: + Since imported submodule module objects are by default + placed into the namespace of their parent-package module + objects, this functions largely identical to + :py:attr:`ScopingPolicy.CHILDREN` for descent from module + objects into other modules objects. + + :py:attr:`ScopingPolicy.SIBLINGS` + Only profile/descend into *sibling* and descendant objects, + which are: + + * Descendant classes, functions, and modules, as defined above + in :py:attr:`ScopingPolicy.DESCENDANTS` + * Classes and functions (and descendants thereof) defined in the + same parent namespace to this very class, or in modules (and + subpackages and their descendants) sharing a parent package + to this very module + * Modules (and subpackages and their descendants) sharing a + parent package, when the namespace is a module + + :py:attr:`ScopingPolicy.NONE` + Don't check scopes; profile all functions found in the local + namespace of the class/module, and descend into all nested + namespaces recursively + + Note: + This is probably a *very* bad idea for module scoping, + potentially resulting in accidentally recursing through a + significant portion of loaded modules; + proceed with care. + + Note: + Other than :py:class:`enum.Enum` methods starting and ending + with single underscores (e.g. :py:meth:`!_missing_`), all + methods prefixed with a single underscore are to be considered + implementation details. + """ + EXACT = auto() + CHILDREN = auto() + DESCENDANTS = auto() + SIBLINGS = auto() + NONE = auto() + + # Verification + + def __init_subclass__(cls, *args, **kwargs): + """ + Call :py:meth:`_check_class`. + """ + super().__init_subclass__(*args, **kwargs) + cls._check_class() + + @classmethod + def _check_class(cls): + """ + Verify that :py:meth:`.get_filter` return a callable for all + policy values and object types. + """ + mock_module = ModuleType('mock_module') + + class MockClass: + pass + + for member in cls.__members__.values(): + for obj_type in 'func', 'class', 'module': + for namespace in mock_module, MockClass: + assert callable(member.get_filter(namespace, obj_type)) + + # Filtering + + def get_filter(self, namespace, obj_type): + """ + Args: + namespace (Union[type, types.ModuleType]): + Class or module to be profiled. + obj_type (Literal['func', 'class', 'module']): + Type of object encountered in ``namespace``: + + ``'func'`` + Either a function, or a component function of a + callable-like object (e.g. :py:class:`property`) + + ``'class'`` (resp. ``'module'``) + A class (resp. a module) + + Returns: + func (Callable[..., bool]): + Filter callable returning whether the argument (as + specified by ``obj_type``) should be added + via :py:meth:`LineProfiler.add_class`, + :py:meth:`LineProfiler.add_module`, or + :py:meth:`LineProfiler.add_callable` + """ + is_class = isinstance(namespace, type) + if obj_type == 'module': + if is_class: + return self._return_const(False) + return self._get_module_filter_in_module(namespace) + if is_class: + method = self._get_callable_filter_in_class + else: + method = self._get_callable_filter_in_module + return method(namespace, is_class=(obj_type == 'class')) + + @classmethod + def to_policies(cls, policies=None): + """ + Normalize ``policies`` into a dictionary of policies for various + object types. + + Args: + policies (Union[str, ScopingPolicy, \ +ScopingPolicyDict, None]): + :py:class:`ScopingPolicy`, string convertible thereto + (case-insensitive), or a mapping containing such values + and the keys as outlined in the return value; + the default :py:const:`None` is equivalent to + :py:data:`DEFAULT_SCOPING_POLICIES`. + + Returns: + normalized_policies (dict[Literal['func', 'class', \ +'module'], ScopingPolicy]): + Dictionary with the following key-value pairs: + + ``'func'`` + :py:class:`ScopingPolicy` for profiling functions + and other callable-like objects composed thereof + (e.g. :py:class:`property`). + + ``'class'`` + :py:class:`ScopingPolicy` for descending into + classes. + + ``'module'`` + :py:class:`ScopingPolicy` for descending into + modules (if the namespace is itself a module). + + Note: + If ``policies`` is a mapping, it is required to contain all + three of the aforementioned keys. + + Example: + + >>> assert (ScopingPolicy.to_policies('children') + ... == dict.fromkeys(['func', 'class', 'module'], + ... ScopingPolicy.CHILDREN)) + >>> assert (ScopingPolicy.to_policies({ + ... 'func': 'NONE', + ... 'class': 'descendants', + ... 'module': 'exact', + ... 'unused key': 'unused value'}) + ... == {'func': ScopingPolicy.NONE, + ... 'class': ScopingPolicy.DESCENDANTS, + ... 'module': ScopingPolicy.EXACT}) + >>> ScopingPolicy.to_policies({}) + Traceback (most recent call last): + ... + KeyError: 'func' + """ + if policies is None: + policies = DEFAULT_SCOPING_POLICIES + if isinstance(policies, str): + policy = cls(policies) + return _ScopingPolicyDict( + dict.fromkeys(['func', 'class', 'module'], policy)) + return _ScopingPolicyDict({'func': cls(policies['func']), + 'class': cls(policies['class']), + 'module': cls(policies['module'])}) + + @staticmethod + def _return_const(value): + def return_const(*_, **__): + return value + + return return_const + + @staticmethod + def _match_prefix(s, prefix, sep='.'): + return s == prefix or s.startswith(prefix + sep) + + def _get_callable_filter_in_class(self, cls, is_class): + def func_is_child(other): + if not modules_are_equal(other): + return False + return other.__qualname__ == f'{cls.__qualname__}.{other.__name__}' + + def modules_are_equal(other): # = sibling check + return cls.__module__ == other.__module__ + + def func_is_descdendant(other): + if not modules_are_equal(other): + return False + return other.__qualname__.startswith(cls.__qualname__ + '.') + + return {'exact': (self._return_const(False) + if is_class else + func_is_child), + 'children': func_is_child, + 'descendants': func_is_descdendant, + 'siblings': modules_are_equal, + 'none': self._return_const(True)}[self.value] + + def _get_callable_filter_in_module(self, mod, is_class): + def func_is_child(other): + return other.__module__ == mod.__name__ + + def func_is_descdendant(other): + return self._match_prefix(other.__module__, mod.__name__) + + def func_is_cousin(other): + if func_is_descdendant(other): + return True + return self._match_prefix(other.__module__, parent) + + parent, _, basename = mod.__name__.rpartition('.') + return {'exact': (self._return_const(False) + if is_class else + func_is_child), + 'children': func_is_child, + 'descendants': func_is_descdendant, + 'siblings': (func_is_cousin # Only if a pkg + if basename else + func_is_descdendant), + 'none': self._return_const(True)}[self.value] + + def _get_module_filter_in_module(self, mod): + def module_is_descendant(other): + return other.__name__.startswith(mod.__name__ + '.') + + def module_is_child(other): + return other.__name__.rpartition('.')[0] == mod.__name__ + + def module_is_sibling(other): + return other.__name__.startswith(parent + '.') + + parent, _, basename = mod.__name__.rpartition('.') + return {'exact': self._return_const(False), + 'children': module_is_child, + 'descendants': module_is_descendant, + 'siblings': (module_is_sibling # Only if a pkg + if basename else + self._return_const(False)), + 'none': self._return_const(True)}[self.value] + + +# Sanity check in case we extended `ScopingPolicy` and forgot to update +# the corresponding methods +ScopingPolicy._check_class() + +ScopingPolicyDict = TypedDict('ScopingPolicyDict', + {'func': Union[str, ScopingPolicy], + 'class': Union[str, ScopingPolicy], + 'module': Union[str, ScopingPolicy]}) +_ScopingPolicyDict = TypedDict('_ScopingPolicyDict', + {'func': ScopingPolicy, + 'class': ScopingPolicy, + 'module': ScopingPolicy}) diff --git a/line_profiler/scoping_policy.pyi b/line_profiler/scoping_policy.pyi new file mode 100644 index 00000000..0a45a09b --- /dev/null +++ b/line_profiler/scoping_policy.pyi @@ -0,0 +1,49 @@ +from enum import auto +from types import FunctionType, ModuleType +from typing import overload, Literal, Callable, TypedDict +from .line_profiler_utils import StringEnum + + +class ScopingPolicy(StringEnum): + CHILDREN = auto() + DESCENDANTS = auto() + SIBLINGS = auto() + NONE = auto() + + @overload + def get_filter( + self, + namespace: type | ModuleType, + obj_type: Literal['func']) -> Callable[[FunctionType], bool]: + ... + + @overload + def get_filter( + self, + namespace: type | ModuleType, + obj_type: Literal['class']) -> Callable[[type], bool]: + ... + + @overload + def get_filter( + self, + namespace: type | ModuleType, + obj_type: Literal['module']) -> Callable[[ModuleType], bool]: + ... + + @classmethod + def to_policies( + cls, + policies: (str | 'ScopingPolicy' | 'ScopingPolicyDict' + | None) = None) -> '_ScopingPolicyDict': + ... + + +ScopingPolicyDict = TypedDict('ScopingPolicyDict', + {'func': str | ScopingPolicy, + 'class': str | ScopingPolicy, + 'module': str | ScopingPolicy}) +_ScopingPolicyDict = TypedDict('_ScopingPolicyDict', + {'func': str | ScopingPolicy, + 'class': str | ScopingPolicy, + 'module': str | ScopingPolicy}) diff --git a/tests/test_autoprofile.py b/tests/test_autoprofile.py index 839038a8..040ec83d 100644 --- a/tests/test_autoprofile.py +++ b/tests/test_autoprofile.py @@ -1,6 +1,8 @@ import os +import re import subprocess import sys +import shlex import tempfile import pytest @@ -198,7 +200,10 @@ def _write_demo_module(temp_dpath): (temp_dpath / 'test_mod/subpkg').ensuredir() (temp_dpath / 'test_mod/__init__.py').touch() - (temp_dpath / 'test_mod/subpkg/__init__.py').touch() + (temp_dpath / 'test_mod/subpkg/__init__.py').write_text(ub.codeblock( + ''' + from .submod3 import add_three + ''')) (temp_dpath / 'test_mod/__main__.py').write_text(ub.codeblock( ''' @@ -432,37 +437,41 @@ def test_autoprofile_script_with_prof_imports(): @pytest.mark.parametrize( - ['use_kernprof_exec', 'prof_mod', 'prof_imports', - 'add_one', 'add_two', 'add_operator', 'main'], - [(False, 'test_mod.submod1', False, True, False, False, False), - (False, 'test_mod.submod2', True, False, True, True, False), - (False, 'test_mod', True, True, True, True, True), + ('use_kernprof_exec', 'prof_mod', 'flags', 'profiled_funcs'), + [(False, ['test_mod.submod1'], '', {'add_one', 'add_operator'}), + # By not using `--no-preimports`, the entirety of `.submod1` is + # passed to `add_imported_function_or_module()` + (False, ['test_mod.submod1'], '--no-preimports', {'add_one'}), + (False, ['test_mod.submod2'], + '--prof-imports', {'add_two', 'add_operator'}), + (False, ['test_mod'], + '--prof-imports', {'add_one', 'add_two', 'add_operator', '_main'}), # Explicitly add all the modules via multiple `-p` flags, without # using the `--prof-imports` flag - (False, ['test_mod', 'test_mod.submod1,test_mod.submod2'], False, - True, True, True, True), - (False, None, True, False, False, False, False), - (True, None, True, False, False, False, False)]) -def test_autoprofile_exec_package( - use_kernprof_exec, prof_mod, prof_imports, - add_one, add_two, add_operator, main): + (False, ['test_mod', 'test_mod.submod1,test_mod.submod2'], + '', {'add_one', 'add_two', 'add_operator', '_main'}), + (False, [], '--prof-imports', set()), + (True, [], '--prof-imports', set())]) +def test_autoprofile_exec_package(use_kernprof_exec, prof_mod, + flags, profiled_funcs): """ Test the execution of a package. """ temp_dpath = ub.Path(tempfile.mkdtemp()) _write_demo_module(temp_dpath) + # Sanity check + all_checked_funcs = {'add_one', 'add_two', 'add_operator', '_main'} + profiled_funcs = set(profiled_funcs) + assert not profiled_funcs - all_checked_funcs + if use_kernprof_exec: args = ['kernprof'] else: args = [sys.executable, '-m', 'kernprof'] - if prof_mod is not None: - if isinstance(prof_mod, str): - prof_mod = [prof_mod] - for pm in prof_mod: - args.extend(['-p', pm]) - if prof_imports: - args.append('--prof-imports') + for pm in prof_mod: + args.extend(['-p', pm]) + args.extend(shlex.split(flags)) args.extend(['-l', '-m', 'test_mod', '1', '2', '3']) proc = ub.cmd(args, cwd=temp_dpath, verbose=2) print(proc.stdout) @@ -477,37 +486,55 @@ def test_autoprofile_exec_package( print(raw_output) proc.check_returncode() - assert ('Function: add_one' in raw_output) == add_one - assert ('Function: add_two' in raw_output) == add_two - assert ('Function: add_operator' in raw_output) == add_operator - assert ('Function: _main' in raw_output) == main + for func in all_checked_funcs: + assert (f'Function: {func}' in raw_output) == (func in profiled_funcs) @pytest.mark.parametrize( - ['use_kernprof_exec', 'prof_mod', 'prof_imports', - 'add_one', 'add_two', 'add_four', 'add_operator', 'main'], - [(False, 'test_mod.submod2', False, False, True, False, False, False), - (False, 'test_mod.submod1', False, True, False, False, True, False), - (False, 'test_mod.subpkg.submod4', True, True, True, True, True, True), - (False, None, True, False, False, False, False, False), - (True, None, True, False, False, False, False, False)]) -def test_autoprofile_exec_module( - use_kernprof_exec, prof_mod, prof_imports, - add_one, add_two, add_four, add_operator, main): + ('use_kernprof_exec', 'prof_mod', 'flags', 'profiled_funcs'), + [(False, 'test_mod.submod2,test_mod.subpkg.submod3.add_three', + '--no-preimports', {'add_two'}), + # By not using `--no-preimports`: + # - The entirety of `.submod2` is passed to + # `add_imported_function_or_module()` + # - Despite not having been imported anywhere, `add_three()` is + # still profiled + (False, 'test_mod.submod2,test_mod.subpkg.submod3.add_three', + '', {'add_two', 'add_three', 'add_operator'}), + (False, 'test_mod.submod1', '', {'add_one', 'add_operator'}), + (False, 'test_mod.subpkg.submod4', + '--prof-imports', + {'add_one', 'add_two', 'add_four', 'add_operator', '_main'}), + (False, None, '--prof-imports', {}), + (True, None, '--prof-imports', {}), + # Packages are descended into by default, unless they are specified + # with `.__init__` + (False, 'test_mod', '', + {'add_one', 'add_two', 'add_three', 'add_four', 'add_operator', + '_main'}), + (False, 'test_mod.subpkg', '', {'add_three', 'add_four', '_main'}), + (False, 'test_mod.subpkg.__init__', '', {'add_three'})]) +def test_autoprofile_exec_module(use_kernprof_exec, prof_mod, + flags, profiled_funcs): """ Test the execution of a module. """ temp_dpath = ub.Path(tempfile.mkdtemp()) _write_demo_module(temp_dpath) + # Sanity check + all_checked_funcs = {'add_one', 'add_two', 'add_three', 'add_four', + 'add_operator', '_main'} + profiled_funcs = set(profiled_funcs) + assert not profiled_funcs - all_checked_funcs + if use_kernprof_exec: args = ['kernprof'] else: args = [sys.executable, '-m', 'kernprof'] if prof_mod is not None: args.extend(['-p', prof_mod]) - if prof_imports: - args.append('--prof-imports') + args.extend(shlex.split(flags)) args.extend(['-l', '-m', 'test_mod.subpkg.submod4', '1', '2', '3']) proc = ub.cmd(args, cwd=temp_dpath, verbose=2) print(proc.stdout) @@ -522,11 +549,8 @@ def test_autoprofile_exec_module( print(raw_output) proc.check_returncode() - assert ('Function: add_one' in raw_output) == add_one - assert ('Function: add_two' in raw_output) == add_two - assert ('Function: add_four' in raw_output) == add_four - assert ('Function: add_operator' in raw_output) == add_operator - assert ('Function: _main' in raw_output) == main + for func in all_checked_funcs: + assert (f'Function: {func}' in raw_output) == (func in profiled_funcs) @pytest.mark.parametrize('view', [True, False]) @@ -562,14 +586,14 @@ def test_autoprofile_from_stdin( proc.check_returncode() outfile, = temp_dpath.glob(expected_outfile) + lp_cmd = [sys.executable, '-m', 'line_profiler', str(outfile)] + lp_proc = ub.cmd(lp_cmd) + lp_proc.check_returncode() if view: raw_output = proc.stdout else: - lp_cmd = [sys.executable, '-m', 'line_profiler', str(outfile)] - proc = ub.cmd(lp_cmd) - raw_output = proc.stdout + raw_output = lp_proc.stdout print(raw_output) - proc.check_returncode() assert ('Function: add_one' in raw_output) == prof_mod assert 'Function: add_two' not in raw_output @@ -577,6 +601,9 @@ def test_autoprofile_from_stdin( # If we're calling a separate process to view the results, the # script file will already have been deleted assert ('Function: main' in raw_output) == view + # Check that `main()` is scrubbed from the written file and doesn't + # result in spurious error messages + assert 'Could not find file' not in lp_proc.stdout @pytest.mark.parametrize( @@ -612,7 +639,6 @@ def test_autoprofile_from_inlined_script(outfile, expected_outfile) -> None: print(proc.stdout) print(proc.stderr) proc.check_returncode() - outfile, = temp_dpath.glob(expected_outfile) lp_cmd = [sys.executable, '-m', 'line_profiler', str(outfile)] proc = ub.cmd(lp_cmd) @@ -623,3 +649,97 @@ def test_autoprofile_from_inlined_script(outfile, expected_outfile) -> None: assert 'Function: add_one' in raw_output assert 'Function: add_two' not in raw_output assert 'Function: add_three' in raw_output + + +@pytest.mark.parametrize( + ('prof_mod', 'profiled_funcs'), + [('my_module', + {'function', 'method', 'class_method', 'static_method', 'descriptor'}), + # `function()` included in profiling via `Class.partial_method()` + ('my_module.Class', + {'function', 'method', 'class_method', 'static_method', 'descriptor'}), + ('my_module.Class.descriptor', {'descriptor'})]) +def test_autoprofile_callable_wrapper_objects(prof_mod, profiled_funcs): + """ + Test that on-import profiling catches various callable-wrapper + object types: + - properties + - staticmethod + - classmethod + - partialmethod + Like it does regular methods and functions. + """ + # Sanity check + all_checked_funcs = {'function', 'method', + 'partial_method', 'class_method', 'static_method', + 'descriptor'} + profiled_funcs = set(profiled_funcs) + assert not profiled_funcs - all_checked_funcs + # Note: `partial_method()` not to be included as its own item + # because it's a wrapper around `function()` + assert 'partial_method' not in profiled_funcs + + with tempfile.TemporaryDirectory() as tmpdir: + temp_dpath = ub.Path(tmpdir) + path = temp_dpath / 'path' + path.mkdir() + (path / 'my_module.py').write_text(ub.codeblock(""" + import functools + + + def function(x): + return + + + class Class: + def method(self): + return + + @classmethod + def class_method(cls): + return + + @staticmethod + def static_method(): + return + + partial_method = functools.partial(function) + + @property + def descriptor(self): + return + """)) + (temp_dpath / 'script.py').write_text(ub.codeblock(""" + import my_module + + + if __name__ == '__main__': + pass + """)) + + with ub.ChDir(temp_dpath): + args = [sys.executable, '-m', 'kernprof', + '-p', prof_mod, '-lv', 'script.py'] + python_path = os.environ.get('PYTHONPATH') + if python_path: + python_path = '{}:{}'.format(path, python_path) + else: + python_path = str(path) + proc = ub.cmd(args, + env={**os.environ, 'PYTHONPATH': python_path}, + verbose=2) + raw_output = proc.stdout + print(raw_output) + print(proc.stderr) + proc.check_returncode() + + for func in all_checked_funcs: + if sys.version_info[:2] >= (3, 11) and func != 'function': + # Match qualnames, see PR #345 + prefix = r'.*\.' + else: + prefix = '' + in_output = re.search(f'^Function: {prefix}{func}', + raw_output, + re.MULTILINE) + assert bool(in_output) == (func in profiled_funcs) diff --git a/tests/test_eager_preimports.py b/tests/test_eager_preimports.py new file mode 100644 index 00000000..ba5d344d --- /dev/null +++ b/tests/test_eager_preimports.py @@ -0,0 +1,230 @@ +""" +Tests for :py:mod:`line_profiler.autoprofile.eager_preimports`. + +Notes +----- +Most of the features are already covered by the doctests. +""" +import subprocess +import sys +from contextlib import ExitStack +from functools import partial +from pathlib import Path +from operator import methodcaller +from runpy import run_path +from tempfile import TemporaryDirectory +from textwrap import dedent +from types import SimpleNamespace +from typing import Collection, Generator, Sequence, Type, Optional, Union +from uuid import uuid4 +from warnings import catch_warnings + +import pytest +try: + import flake8 # noqa: F401 +except ImportError: + HAS_FLAKE8 = False +else: + HAS_FLAKE8 = True + +from line_profiler.autoprofile.eager_preimports import ( + split_dotted_path, resolve_profiling_targets, write_eager_import_module) + + +def write(path: Path, content: Optional[str] = None) -> None: + path.parent.mkdir(parents=True, exist_ok=True) + if content is None: + path.touch() + else: + path.write_text(dedent(content).strip('\n')) + + +def gen_names(name) -> Generator[str, None, None]: + while True: + yield '_'.join([name, *str(uuid4()).split('-')]) + + +@pytest.fixture +def preserve_sys_state() -> None: + old_path = sys.path.copy() + old_modules = sys.modules.copy() + try: + yield + finally: + sys.path.clear() + sys.path[:] = old_path + sys.modules.clear() + sys.modules.update(old_modules) + + +@pytest.fixture +def sample_package(preserve_sys_state: None, tmp_path: Path) -> str: + """ + Write a normal package and put it in :py:data:`sys.path`. When + we're done, reset :py:data:`sys.path` and `sys.modules`. + """ + module_name = next(name for name in gen_names('my_sample_pkg') + if name not in sys.modules) + new_path = tmp_path / '_modules' + write(new_path / module_name / '__init__.py') + write(new_path / module_name / 'foo' / '__init__.py') + write(new_path / module_name / 'foo' / 'bar.py') + write(new_path / module_name / 'foo' / 'baz.py', + """ + ''' + This is a bad module. + ''' + raise AssertionError + """) + write(new_path / module_name / 'foobar.py') + # Cleanup managed with `preserve_sys_state()` + sys.path.insert(0, str(new_path)) + yield module_name + + +@pytest.fixture +def sample_namespace_package( + preserve_sys_state: None, + tmp_path_factory: pytest.TempPathFactory) -> str: + """ + Write a namespace package and put it in :py:data:`sys.path`. When + we're done, reset :py:data:`sys.path` and `sys.modules`. + """ + module_name = next(name for name in gen_names('my_sample_namespace_pkg') + if name not in sys.modules) + new_paths = [tmp_path_factory.mktemp('_modules-', numbered=True) + for _ in range(3)] + for submod, new_path in zip(['one', 'two', 'three'], new_paths): + write(new_path / module_name / (submod + '.py')) + # Cleanup managed with `preserve_sys_state()` + sys.path.insert(0, str(new_path)) + yield module_name + + +@pytest.mark.parametrize( + ('adder', 'xc'), + [('foo; bar', ValueError), (1, TypeError), ('(foo\n .bar)', ValueError)]) +def test_write_eager_import_module_wrong_adder( + adder: str, xc: Type[Exception]) -> None: + """ + Test passing an erroneous ``adder`` to + :py:meth:`~.write_eager_import_module()`. + """ + with pytest.raises(xc): + write_eager_import_module(['foo'], adder=adder) + + +@pytest.mark.skipif(not HAS_FLAKE8, reason='no `flake8`') +def test_written_module_pep8_compliance(sample_package: str): + """ + Test that the module written by + :py:meth:`~.write_eager_import_module()` passes linting by + :py:mod:`flake8`. + """ + with TemporaryDirectory() as tmpdir: + module = Path(tmpdir) / 'module.py' + with module.open(mode='w') as fobj: + write_eager_import_module( + [sample_package + '.foobar'], + recurse=[sample_package + '.foo'], stream=fobj) + print(module.read_text()) + (subprocess + .run([sys.executable, '-m', 'flake8', + '--extend-ignore=E501', # Allow long lines + module]) + .check_returncode()) + + +@pytest.mark.parametrize( + ('dotted_paths', 'recurse', 'warnings', 'error'), + [(['__MODULE__.foobar'], ['__MODULE__.foo'], + # `foo.baz` is indirectly included, so its raising an error + # shouldn't cause the script to error out + [{'target cannot', '__MODULE__.foo.baz'}], + None), + # We don't recurse down `__MODULE__.foo`, so that doesn't give a + # warning; but `__MODULE__.baz` cannot be imported because it + # doesn't exist + (['__MODULE__.foo', '__MODULE__.baz'], False, + [{'target cannot', '__MODULE__.baz'}], None), + # If we do recurse however, `__MODULE__.foo.baz` also ends up in + # the warning + # (also there's a `__MODULE___foo` which doesn't exist, about which + # the warning is issued during module generation) + (['__MODULE__' + '_foo', '__MODULE__', '__MODULE__.baz'], True, + [{'target cannot', '__MODULE__' + '_foo'}, # Fails at write + {'targets cannot', # Fails at import + '__MODULE__.foo.baz', '__MODULE__.baz'}], + None), + # And if the problematic module is an explicit target, raise the + # error + (['__MODULE__', '__MODULE__.foo.baz'], False, [], AssertionError)]) +def test_written_module_error_handling( + sample_package: str, + dotted_paths: Collection[str], + recurse: Union[Collection[str], bool], + warnings: Sequence[Collection[str]], + error: Union[Type[Exception], None]): + """ + Test that the module written by + :py:meth:`~.write_eager_import_module()` gracefully handles errors + for implicitly included modules. + """ + replace = methodcaller('replace', '__MODULE__', sample_package) + dotted_paths = [replace(target) for target in dotted_paths] + if recurse not in (True, False): + recurse = [replace(target) for target in recurse] + warnings = [{replace(fragment) for fragment in fragments} + for fragments in warnings] + with TemporaryDirectory() as tmpdir: + module = Path(tmpdir) / 'module.py' + with ExitStack() as stack: + enter = stack.enter_context + # Set up the warning capturing early so that we catch both + # warnings at module-generation time and execution time + captured_warnings = enter(catch_warnings(record=True)) + with module.open(mode='w') as fobj: + write_eager_import_module( + dotted_paths, recurse=recurse, stream=fobj) + print(module.read_text()) + if error is not None: + enter(pytest.raises(error)) + # Just use a dummy object, no need to instantiate a profiler + prof = SimpleNamespace( + add_imported_function_or_module=lambda *_, **__: 0) + run_path(str(module), {'profile': prof}, 'module') + assert len(captured_warnings) == len(warnings) + for warning, fragments in zip(captured_warnings, warnings): + for fragment in fragments: + assert fragment in str(warning.message) + + +def test_split_dotted_path_staticity() -> None: + """ + Test `split_dotted_path()` with different values for `static`. + """ + split = partial(split_dotted_path, 'os.path.abspath') + # Static analysis has no idea of `os.path` members since `os.path` + # is dynamically imported from e.g. `posixpath` or `ntpath` + assert split(static=True) == ('os', 'path.abspath') + # The import system knows of the already-imported module `os.path` + assert split(static=False) == ('os.path', 'abspath') + + +def test_resolve_profiling_targets_staticity( + sample_namespace_package: str) -> None: + """ + Test subpackage/-module discovery with `resolve_profiling_targets()` + with different values for `static`. + """ + all_targets = ({f'{sample_namespace_package}.{submod}' + for submod in ['one', 'two', 'three']} + | {sample_namespace_package}) + # Static analysis can't handle namespace packages + resolve = partial( + resolve_profiling_targets, [sample_namespace_package], recurse=True) + static_result = resolve(static=True) + assert set(static_result.targets) < all_targets, static_result + # The import system successfully retrieves all submodules + dyn_result = resolve(static=False) + assert set(dyn_result.targets) == all_targets, dyn_result diff --git a/tests/test_explicit_profile.py b/tests/test_explicit_profile.py index 7108a5d6..acedc8f1 100644 --- a/tests/test_explicit_profile.py +++ b/tests/test_explicit_profile.py @@ -2,11 +2,62 @@ import re import sys import tempfile +from contextlib import ExitStack import pytest import ubelt as ub +class enter_tmpdir: + """ + Set up a temporary directory and :cmd:`chdir` into it. + """ + def __init__(self): + self.stack = ExitStack() + + def __enter__(self): + """ + Returns: + curdir (ubelt.Path) + Temporary directory :cmd:`chdir`-ed into. + + Side effects: + ``curdir`` created and :cmd:`chdir`-ed into. + """ + enter = self.stack.enter_context + tmpdir = os.path.abspath(enter(tempfile.TemporaryDirectory())) + enter(ub.ChDir(tmpdir)) + return ub.Path(tmpdir) + + def __exit__(self, *_, **__): + """ + Side effects: + * Original working directory restored. + * Temporary directory created deleted. + """ + self.stack.close() + + +class restore_sys_modules: + """ + Restore :py:attr:`sys.modules` after exiting the context. + """ + def __enter__(self): + self.old = sys.modules.copy() + + def __exit__(self, *_, **__): + sys.modules.clear() + sys.modules.update(self.old) + + +def write(path, code=None): + path.parent.mkdir(exist_ok=True, parents=True) + if code is None: + path.touch() + else: + path.write_text(ub.codeblock(code)) + + def test_simple_explicit_nonglobal_usage(): """ python -c "from test_explicit_profile import *; test_simple_explicit_nonglobal_usage()" @@ -407,6 +458,454 @@ def func4(a): temp_dpath.delete() +@pytest.mark.parametrize('reset_enable_count', [True, False]) +@pytest.mark.parametrize('wrap_class, wrap_module', + [(None, None), (False, True), + (True, False), (True, True)]) +def test_profiler_add_methods(wrap_class, wrap_module, reset_enable_count): + """ + Test the `wrap` argument for the + `LineProfiler.add_class()`, `.add_module()`, and + `.add_imported_function_or_module()` (added via + `line_profiler.autoprofile.autoprofile. + _extend_line_profiler_for_profiling_imports()`) methods. + """ + script = ub.codeblock(''' + from line_profiler import LineProfiler + from line_profiler.autoprofile.autoprofile import ( + _extend_line_profiler_for_profiling_imports as upgrade_profiler) + + import my_module_1 + from my_module_2 import Class + from my_module_3 import func3 + + + profiler = LineProfiler() + upgrade_profiler(profiler) + # This dispatches to `.add_module()` + profiler.add_imported_function_or_module(my_module_1{}) + # This dispatches to `.add_class()` + profiler.add_imported_function_or_module(Class{}) + profiler.add_imported_function_or_module(func3) + + if {}: + for _ in range(profiler.enable_count): + profiler.disable_by_count() + + # `func1()` should only have timing info if `wrap_module` + my_module_1.func1() + # `method2()` should only have timing info if `wrap_class` + Class.method2() + # `func3()` is profiled but don't see any timing info because it + # isn't wrapped and doesn't auto-`.enable()` before being called + func3() + profiler.print_stats(details=True, summarize=True) + '''.format( + '' if wrap_module is None else f', wrap={wrap_module}', + '' if wrap_class is None else f', wrap={wrap_class}', + reset_enable_count)) + + with enter_tmpdir() as curdir: + write(curdir / 'script.py', script) + write(curdir / 'my_module_1.py', + ''' + def func1(): + pass # Marker: func1 + ''') + write(curdir / 'my_module_2.py', + ''' + class Class: + @classmethod + def method2(cls): + pass # Marker: method2 + ''') + write(curdir / 'my_module_3.py', + ''' + def func3(): + pass # Marker: func3 + ''') + proc = ub.cmd([sys.executable, str(curdir / 'script.py')]) + + # Check that the profiler has seen each of the methods + raw_output = proc.stdout + print(script) + print(raw_output) + print(proc.stderr) + proc.check_returncode() + assert '# Marker: func1' in raw_output + assert '# Marker: method2' in raw_output + assert '# Marker: func3' in raw_output + + # Check that the timing info (of the lack thereof) are correct + for func, has_timing in [('func1', wrap_module), ('method2', wrap_class), + ('func3', False)]: + line, = (line for line in raw_output.splitlines() + if line.endswith('Marker: ' + func)) + has_timing = has_timing or not reset_enable_count + assert line.split()[1] == ('1' if has_timing else 'pass') + + +def test_profiler_add_class_recursion_guard(): + """ + Test that if we were to add a pair of classes which each of them + has a reference to the other in its namespace, we don't end up in + infinite recursion. + """ + from line_profiler import LineProfiler + + class Class1: + def method1(self): + pass + + class ChildClass1: + def child_method_1(self): + pass + + class Class2: + def method2(self): + pass + + class ChildClass2: + def child_method_2(self): + pass + + OtherClass = Class1 + # A duplicate reference shouldn't affect profiling either + YetAnotherClass = Class1 + + # Add self/mutual references + Class1.ThisClass = Class1 + Class1.OtherClass = Class2 + + profile = LineProfiler() + profile.add_class(Class1) + assert len(profile.functions) == 4 + assert Class1.method1 in profile.functions + assert Class2.method2 in profile.functions + assert Class1.ChildClass1.child_method_1 in profile.functions + assert Class2.ChildClass2.child_method_2 in profile.functions + + +def test_profiler_warn_unwrappable(): + """ + Test for warnings when using `LineProfiler.add_*(wrap=True)` with a + namespace which doesn't allow attribute assignment. + """ + from line_profiler import LineProfiler + + class ProblamticMeta(type): + def __init__(cls, *args, **kwargs): + super(ProblamticMeta, cls).__init__(*args, **kwargs) + cls._initialized = True + + def __setattr__(cls, attr, value): + if not getattr(cls, '_initialized', None): + return super(ProblamticMeta, cls).__setattr__(attr, value) + raise AttributeError( + f'cannot set attribute on {type(cls)} instance') + + class ProblematicClass(metaclass=ProblamticMeta): + def method(self): + pass + + profile = LineProfiler() + vanilla_method = ProblematicClass.method + + with pytest.warns(match=r"cannot wrap 1 attribute\(s\) of " + r" \(`\{attr: value\}`\): " + r"\{'method': \}"): + # The method is added to the profiler, but we can't assign its + # wrapper back into the class namespace + assert profile.add_class(ProblematicClass, wrap=True) == 1 + + assert ProblematicClass.method is vanilla_method + + +@pytest.mark.parametrize( + ('scoping_policy', 'add_module_targets', 'add_class_targets'), + [('exact', {}, {'class3_method'}), + ('children', + {'class2_method', 'child_class2_method'}, + {'class3_method', 'child_class3_method'}), + ('descendants', + {'class2_method', 'child_class2_method', + 'class3_method', 'child_class3_method'}, + {'class3_method', 'child_class3_method'}), + ('siblings', + {'class1_method', 'child_class1_method', + 'class2_method', 'child_class2_method', + 'class3_method', 'child_class3_method', 'other_class3_method'}, + {'class3_method', 'child_class3_method', 'other_class3_method'}), + ('none', + {'class1_method', 'child_class1_method', + 'class2_method', 'child_class2_method', + 'class3_method', 'child_class3_method', 'other_class3_method'}, + {'child_class1_method', + 'class3_method', 'child_class3_method', 'other_class3_method'})]) +def test_profiler_class_scope_matching(monkeypatch, + scoping_policy, + add_module_targets, + add_class_targets): + """ + Test for the class-scope-matching strategies of the + `LineProfiler.add_*()` methods. + """ + with ExitStack() as stack: + stack.enter_context(restore_sys_modules()) + curdir = stack.enter_context(enter_tmpdir()) + + pkg_dir = curdir / 'packages' / 'my_pkg' + write(pkg_dir / '__init__.py') + write(pkg_dir / 'submod1.py', + """ + class Class1: + def class1_method(self): + pass + + class ChildClass1: + def child_class1_method(self): + pass + """) + write(pkg_dir / 'subpkg2' / '__init__.py', + """ + from ..submod1 import Class1 # Import from a sibling + from .submod3 import Class3 # Import descendant from a child + + + class Class2: + def class2_method(self): + pass + + class ChildClass2: + def child_class2_method(self): + pass + + BorrowedChildClass = Class1.ChildClass1 # Non-sibling class + """) + write(pkg_dir / 'subpkg2' / 'submod3.py', + """ + from ..submod1 import Class1 + + + class Class3: + def class3_method(self): + pass + + class OtherChildClass3: + def child_class3_method(self): + pass + + # Unrelated class + BorrowedChildClass1 = Class1.ChildClass1 + + class OtherClass3: + def other_class3_method(self): + pass + + # Sibling class + Class3.BorrowedChildClass3 = OtherClass3 + """) + monkeypatch.syspath_prepend(pkg_dir.parent) + + from my_pkg import subpkg2 + from line_profiler import LineProfiler + + policies = {'func': 'none', 'class': scoping_policy, + 'module': 'exact'} # Don't descend into submodules + # Add a module + profile = LineProfiler() + profile.add_module(subpkg2, scoping_policy=policies) + assert len(profile.functions) == len(add_module_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_module_targets) + # Add a class + profile = LineProfiler() + profile.add_class(subpkg2.Class3, scoping_policy=policies) + assert len(profile.functions) == len(add_class_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_class_targets) + + +@pytest.mark.parametrize( + ('scoping_policy', 'add_module_targets', 'add_subpackage_targets'), + [('exact', {'func4'}, {'class_method'}), + ('children', {'func4'}, {'class_method', 'func2'}), + ('descendants', {'func4'}, {'class_method', 'func2'}), + ('siblings', {'func4'}, {'class_method', 'func2', 'func3'}), + ('none', + {'func4', 'func5'}, + {'class_method', 'func2', 'func3', 'func4', 'func5'})]) +def test_profiler_module_scope_matching(monkeypatch, + scoping_policy, + add_module_targets, + add_subpackage_targets): + """ + Test for the module-scope-matching strategies of the + `LineProfiler.add_*()` methods. + """ + with ExitStack() as stack: + stack.enter_context(restore_sys_modules()) + curdir = stack.enter_context(enter_tmpdir()) + + pkg_dir = curdir / 'packages' / 'my_pkg' + write(pkg_dir / '__init__.py') + write(pkg_dir / 'subpkg1' / '__init__.py', + """ + import my_mod4 # Unrelated + from .. import submod3 # Sibling + from . import submod2 # Child + + + class Class: + @classmethod + def class_method(cls): + pass + + # We shouldn't descend into this no matter what + import my_mod5 as module + """) + write(pkg_dir / 'subpkg1' / 'submod2.py', + """ + def func2(): + pass + """) + write(pkg_dir / 'submod3.py', + """ + def func3(): + pass + """) + write(curdir / 'packages' / 'my_mod4.py', + """ + import my_mod5 # Unrelated + + + def func4(): + pass + """) + write(curdir / 'packages' / 'my_mod5.py', + """ + def func5(): + pass + """) + monkeypatch.syspath_prepend(pkg_dir.parent) + + import my_mod4 + from my_pkg import subpkg1 + from line_profiler import LineProfiler + + policies = {'func': 'none', 'class': 'children', + 'module': scoping_policy} + # Add a module + profile = LineProfiler() + profile.add_module(my_mod4, scoping_policy=policies) + assert len(profile.functions) == len(add_module_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_module_targets) + # Add a subpackage + profile = LineProfiler() + profile.add_module(subpkg1, scoping_policy=policies) + assert len(profile.functions) == len(add_subpackage_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_subpackage_targets) + # Add a class + profile = LineProfiler() + profile.add_class(subpkg1.Class, scoping_policy=policies) + assert [func.__name__ for func in profile.functions] == ['class_method'] + + +@pytest.mark.parametrize( + ('scoping_policy', 'add_module_targets', 'add_class_targets'), + [('exact', {'func1'}, {'method'}), + ('children', {'func1'}, {'method'}), + ('descendants', {'func1', 'func2'}, {'method', 'child_class_method'}), + ('siblings', + {'func1', 'func2', 'func3'}, + {'method', 'child_class_method', 'func1'}), + ('none', + {'func1', 'func2', 'func3', 'func4'}, + {'method', 'child_class_method', 'func1', 'another_func4'})]) +def test_profiler_func_scope_matching(monkeypatch, + scoping_policy, + add_module_targets, + add_class_targets): + """ + Test for the class-scope-matching strategies of the + `LineProfiler.add_*()` methods. + """ + with ExitStack() as stack: + stack.enter_context(restore_sys_modules()) + curdir = stack.enter_context(enter_tmpdir()) + + pkg_dir = curdir / 'packages' / 'my_pkg' + write(pkg_dir / '__init__.py') + write(pkg_dir / 'subpkg1' / '__init__.py', + """ + from ..submod3 import func3 # Sibling + from .submod2 import func2 # Descendant + from my_mod4 import func4 # Unrelated + + def func1(): + pass + + class Class: + def method(self): + pass + + class ChildClass: + @classmethod + def child_class_method(cls): + pass + + # Descendant + descdent_method = ChildClass.child_class_method + + # Sibling + sibling_method = staticmethod(func1) + + # Unrelated + from my_mod4 import another_func4 as imported_method + """) + write(pkg_dir / 'subpkg1' / 'submod2.py', + """ + def func2(): + pass + """) + write(pkg_dir / 'submod3.py', + """ + def func3(): + pass + """) + write(curdir / 'packages' / 'my_mod4.py', + """ + def func4(): + pass + + + def another_func4(_): + pass + """) + monkeypatch.syspath_prepend(pkg_dir.parent) + + from my_pkg import subpkg1 + from line_profiler import LineProfiler + + policies = {'func': scoping_policy, + # No descensions + 'class': 'exact', 'module': 'exact'} + # Add a module + profile = LineProfiler() + profile.add_module(subpkg1, scoping_policy=policies) + assert len(profile.functions) == len(add_module_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_module_targets) + # Add a class + profile = LineProfiler() + profile.add_module(subpkg1.Class, scoping_policy=policies) + assert len(profile.functions) == len(add_class_targets) + added = {func.__name__ for func in profile.functions} + assert added == set(add_class_targets) + + if __name__ == '__main__': ... test_simple_explicit_nonglobal_usage() diff --git a/tests/test_kernprof.py b/tests/test_kernprof.py index c56dd215..de9bb871 100644 --- a/tests/test_kernprof.py +++ b/tests/test_kernprof.py @@ -2,6 +2,7 @@ import os import re import shlex +import subprocess import sys import tempfile import unittest @@ -177,6 +178,168 @@ def main(): assert sys.modules.get('__main__') is old_main +@pytest.mark.parametrize( + ('flags', 'expected_stdout', 'expected_stderr'), + [('', # Neutral verbosity level + {'^Output to stdout': True, + r"^Wrote .* '.*script\.py\.lprof'": True, + r'Parser output:''(?:\n)+'r'.*namespace\((?:.+,\n)*.*\)': False, + r'^Inspect results with:''\n' + r'python -m line_profiler .*script\.py\.lprof': True, + '^ *[0-9]+ *import zipfile': False, + r'line_profiler\.autoprofile\.autoprofile' + r'\.run\(\n(?:.+,\n)*.*\)': False, + r'^\[kernprof .*\]': False, + r'^Function: main': False}, + {'^Output to stderr': True}), + ('--view', # Verbosity level 1 = `--view` + {'^Output to stdout': True, + r"^Wrote .* '.*script\.py\.lprof'": True, + r'^Inspect results with:''\n' + r'python -m line_profiler .*script\.py\.lprof': False, + r'line_profiler\.autoprofile\.autoprofile' + r'\.run\(\n(?:.+,\n)*.*\)': False, + r'^\[kernprof .*\]': False, + r'^Function: main': True}, + {'^Output to stderr': True}), + ('-vv', # Verbosity level 2, show diagnostics + {'^Output to stdout': True, + r"^\[kernprof .*\] Wrote .* '.*script\.py\.lprof'": True, + r'Inspect results with:''\n' + r'python -m line_profiler .*script\.py\.lprof': False, + r'line_profiler\.autoprofile\.autoprofile' + r'\.run\(\n(?:.+,\n)*.*\)': True, + r'^Function: main': True}, + {'^Output to stderr': True}), + # Verbosity level -1, suppress `kernprof` output + ('--quiet', + {'^Output to stdout': True, 'Wrote': False}, + {'^Output to stderr': True}), + # Verbosity level -2, suppress script stdout + # (also test verbosity arithmatics) + ('--quiet --quiet --verbose -q', None, {'^Output to stderr': True}), + # Verbosity level -3, suppress script stderr + ('-qq --quiet', None, + # This should have been `None`, but there's something weird with + # `coverage` in CI which causes a spurious warning... + {'^Output to stderr': False})]) +def test_kernprof_verbosity(flags, expected_stdout, expected_stderr): + """ + Test the various verbosity levels of `kernprof`. + """ + with contextlib.ExitStack() as stack: + enter = stack.enter_context + tmpdir = enter(tempfile.TemporaryDirectory()) + temp_dpath = ub.Path(tmpdir) + (temp_dpath / 'script.py').write_text(ub.codeblock( + ''' + import sys + + + def main(): + print('Output to stdout', file=sys.stdout) + print('Output to stderr', file=sys.stderr) + + + if __name__ == '__main__': + main() + ''')) + enter(ub.ChDir(tmpdir)) + proc = ub.cmd(['kernprof', '-l', + # Add an eager pre-import target + '-p', 'script.py', '-p', 'zipfile', '-z', + *shlex.split(flags), 'script.py']) + proc.check_returncode() + print(proc.stdout) + for expected_outputs, stream in [(expected_stdout, proc.stdout), + (expected_stderr, proc.stderr)]: + if expected_outputs is None: + assert not stream + continue + for pattern, expect_match in expected_outputs.items(): + found = re.search(pattern, stream, flags=re.MULTILINE) + if not bool(found) == expect_match: + msg = ub.paragraph( + f''' + Searching for pattern: {pattern!r} in output. + Did we expect a match? {expect_match!r}. + Did we get a match? {bool(found)!r}. + ''') + raise AssertionError(msg) + + +def test_kernprof_eager_preimport_bad_module(): + """ + Test for the preservation of the full traceback when an error occurs + in an auto-generated pre-import module. + """ + bad_module = '''raise Exception('Boo')''' + with contextlib.ExitStack() as stack: + enter = stack.enter_context + tmpdir = enter(tempfile.TemporaryDirectory()) + temp_dpath = ub.Path(tmpdir) + (temp_dpath / 'my_bad_module.py').write_text(bad_module) + enter(ub.ChDir(tmpdir)) + python_path = os.environ.get('PYTHONPATH', '') + if python_path: + python_path = f'{python_path}:{tmpdir}' + else: + python_path = tmpdir + proc = ub.cmd(['kernprof', '-l', + # Add an eager pre-import target + '-pmy_bad_module', '-c', 'print(1)'], + env={**os.environ, 'PYTHONPATH': python_path}) + # Check that the traceback is preserved + print(proc.stdout) + print(proc.stderr, file=sys.stderr) + assert proc.returncode + assert 'import my_bad_module' in proc.stderr + assert bad_module in proc.stderr + # Check that the generated tempfiles are wiped + reverse_iter_lines = iter(reversed(proc.stderr.splitlines())) + next(line for line in reverse_iter_lines if 'import my_bad_module' in line) + tb_header = next(reverse_iter_lines).strip() + match = re.match('File ([\'"])(.+)\\1, line [0-9]+, in .*', tb_header) + assert match + tmp_mod = match.group(2) + assert not os.path.exists(tmp_mod) + assert not os.path.exists(os.path.dirname(tmp_mod)) + + +@pytest.mark.parametrize('stdin', [True, False]) +def test_kernprof_bad_temp_script(stdin): + """ + Test for the preservation of the full traceback when an error occurs + in a temporary script supplied via `kernprof -c` or `kernprof -`. + """ + bad_script = '''1 / 0''' + with contextlib.ExitStack() as stack: + enter = stack.enter_context + enter(ub.ChDir(enter(tempfile.TemporaryDirectory()))) + if stdin: + proc = subprocess.run( + ['kernprof', '-'], + input=bad_script, capture_output=True, text=True) + else: + proc = subprocess.run(['kernprof', '-c', bad_script], + capture_output=True, text=True) + # Check that the traceback is preserved + print(proc.stdout) + print(proc.stderr, file=sys.stderr) + assert proc.returncode + assert '1 / 0' in proc.stderr + assert 'ZeroDivisionError' in proc.stderr + # Check that the generated tempfiles are wiped + reverse_iter_lines = iter(reversed(proc.stderr.splitlines())) + next(line for line in reverse_iter_lines if '1 / 0' in line) + tb_header = next(reverse_iter_lines).strip() + match = re.match('File ([\'"])(.+)\\1, line [0-9]+, in .*', tb_header) + assert match + tmp_script = match.group(2) + assert not os.path.exists(tmp_script) + assert not os.path.exists(os.path.dirname(tmp_script)) + + class TestKernprof(unittest.TestCase): def test_enable_disable(self): diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index c922109a..e7df7b21 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -470,7 +470,7 @@ def foo(self, foo) -> None: def test_cached_property_decorator(): """ - Test for `LineProfiler.wrap_cached_property()` + Test for `LineProfiler.wrap_cached_property()`. Notes ----- @@ -506,6 +506,111 @@ def foo(self) -> int: assert profile.enable_count == 0 +def test_class_decorator(): + """ + Test for `LineProfiler.wrap_class()`. + """ + profile = LineProfiler() + + def unrelated(x): + return str(x) + + @profile + class Object: + def __init__(self, x): + self.x = self.convert(x) + + @property + def id(self): + return id(self) + + @classmethod + def class_method(cls, n): + return cls.__name__ * n + + # This is unrelated to `Object` and shouldn't be profiled + convert = staticmethod(unrelated) + + # Are we keeping tabs on the correct entities? + assert len(profile.functions) == 3 + assert set(profile.functions) == { + Object.__init__.__wrapped__, + Object.id.fget.__wrapped__, + vars(Object)['class_method'].__func__.__wrapped__} + # Make some calls + assert not profile.enable_count + obj = Object(1) + assert obj.x == '1' + assert id(obj) == obj.id + assert obj.class_method(3) == 'ObjectObjectObject' + assert not profile.enable_count + # Check the profiling results + all_entries = sorted(sum(profile.get_stats().timings.values(), [])) + assert len(all_entries) == 3 + assert all(nhits == 1 for (_, nhits, _) in all_entries) + + +def test_add_class_wrapper(): + """ + Test adding a callable-wrapper object wrapping a class. + """ + profile = LineProfiler() + + class Object: + @classmethod + class method: + def __init__(self, cls, x): + self.cls = cls + self.x = x + + def __repr__(self): + fmt = '{.__name__}.{.__name__}({!r})'.format + return fmt(self.cls, type(self), self.x) + + # Bookkeeping + profile.add_class(Object) + method_cls = vars(Object)['method'].__func__ + assert profile.functions == [method_cls.__init__, method_cls.__repr__] + # Actual profiling + with profile: + obj = Object.method(1) + assert obj.cls == Object + assert obj.x == 1 + assert repr(obj) == 'Object.method(1)' + # Check data + all_nhits = { + func_name.rpartition('.')[-1]: sum(nhits for (_, nhits, _) in entries) + for (*_, func_name), entries in profile.get_stats().timings.items()} + assert all_nhits['__init__'] == all_nhits['__repr__'] == 2 + + +@pytest.mark.parametrize('decorate', [True, False]) +def test_profiler_c_callable_no_op(decorate): + """ + Test that the following are no-ops on C(-ython)-level callables: + - Decoration (`.__call__()`): the callable is returned as-is. + - `.add_callable()`: it returns 0. + """ + CythonCallable = type(LineProfiler.enable) + assert not isinstance(LineProfiler.enable, types.FunctionType) + profile = LineProfiler() + + for (func, Type) in [ + (len, types.BuiltinFunctionType), + ('string'.split, types.BuiltinMethodType), + (vars(int)['from_bytes'], types.ClassMethodDescriptorType), + (str.split, types.MethodDescriptorType), + ((1).__str__, types.MethodWrapperType), + (int.__repr__, types.WrapperDescriptorType), + (LineProfiler.enable, CythonCallable)]: + assert isinstance(func, Type) + if decorate: # Decoration is no-op + assert profile(func) is func + else: # Add is no-op + assert not profile.add_callable(func) + assert not profile.functions + + def test_show_func_column_formatting(): from line_profiler.line_profiler import show_func import line_profiler