diff --git a/CHANGELOG.rst b/CHANGELOG.rst index 53640815..a36503c8 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -3,6 +3,11 @@ Changes 5.0.3 ----- +* FIX: misc. fixes and refactoring (#442): + + * Continuity of profiling in multithreaded environments + * Fix for frame-local trace-function wrapper reference leaks + * Context-manager-based setup and teardown * FIX: Make sure that the profiled code is run in the ``sys.modules['__main__']`` namespace to avoid issues w/e.g. pickling (#423) diff --git a/kernprof.py b/kernprof.py index 590fd48c..ead4d353 100755 --- a/kernprof.py +++ b/kernprof.py @@ -187,7 +187,6 @@ def main(): """ # noqa: E501 import atexit -import builtins import functools import os import sys @@ -198,10 +197,7 @@ def main(): import shutil import tempfile import time -import warnings from argparse import ArgumentParser -from io import StringIO -from operator import methodcaller from runpy import run_module from pathlib import Path from pprint import pformat @@ -228,7 +224,7 @@ def main(): positive_float, short_string_path, ) -from line_profiler.line_profiler_utils import restore +from line_profiler.line_profiler_utils import restore, make_tempfile from line_profiler.profiler_mixin import ByCountProfilerMixin from line_profiler._logger import Logger from line_profiler import _diagnostics as diagnostics @@ -331,6 +327,7 @@ def resolve_module_path(mod_name): # type: (str) -> str | None fname = mod_spec.origin # type: str | None if fname and os.path.exists(fname): return fname + return None get_module_path = modname_to_modpath if static else resolve_module_path @@ -692,8 +689,8 @@ def _build_parsers(args=None): # We've already consumed the `-m `, so we need a dummy # parser for generating the help text; # 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 + # positional arg, and if it got the `--help` option, it should + # hand off to the dummy parser real_parser = ArgumentParser(add_help=False, **parser_kwargs) real_parser.add_argument('-h', '--help', action='store_true') help_parser = ArgumentParser(**parser_kwargs) @@ -823,6 +820,15 @@ def main(args=None, *, exit_on_error=True): files created during execution may be deferred to when the interpreter exits. """ + def rmdir_with_pid_guard(pid, dir, *, defer=False, **kwargs): + if os.getpid() != pid: + return # Leave cleanup to the main process in case of forks + callback = functools.partial(_remove, dir, **kwargs) + if defer: + atexit.register(callback) + else: + callback() + real_parser, help_parser, special_info = _build_parsers(args=args) args = special_info['args'] module = special_info['module'] @@ -857,7 +863,8 @@ def main(args=None, *, exit_on_error=True): cleanup = no_op else: cleanup = functools.partial( - _remove, + rmdir_with_pid_guard, + os.getpid(), tmpdir, recursive=True, missing_ok=True, @@ -874,30 +881,12 @@ def main(args=None, *, exit_on_error=True): 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() + cleanup(defer=bool(os.path.isdir(tmpdir) and os.listdir(tmpdir))) 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 @@ -924,7 +913,7 @@ def _write_tempfile(source, content, options): # filename clash) if not options.outfile: extension = 'lprof' if options.line_by_line else 'prof' - options.outfile = _touch_tempfile( + options.outfile = make_tempfile( dir=os.curdir, prefix=file_prefix + '-', suffix='.' + extension ) diagnostics.log.debug( @@ -932,104 +921,34 @@ def _write_tempfile(source, content, options): ) -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.warning(msg) - - return filtered_targets, recurse_targets - - -def _write_preimports(prof, options, exclude): +def _write_preimports(prof, options, exclude, keep=False): """ 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, - ) + from line_profiler.curated_profiling import ClassifiedPreimportTargets - 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( + temp_mod_path = make_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 to ' - f'{short_string_path(temp_mod_path)!r}' + with open(temp_mod_path, mode='w') as fobj: + preimports = ClassifiedPreimportTargets.from_targets( + options.prof_mod, exclude, ) - else: - with temp_file as fobj: - write_eager_import_module(stream=fobj, **write_module_kwargs) - if not options.dryrun: + preimports.write_preimport_module( + fobj, debug=options.debug, static=options.static, + ) + if preimports and 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) + if keep or diagnostics.KEEP_TEMPDIRS: + return temp_mod_path + _remove(temp_mod_path) + return None def _remove(path, *, recursive=False, missing_ok=False): @@ -1043,9 +962,20 @@ def _remove(path, *, recursive=False, missing_ok=False): path.unlink(missing_ok=missing_ok) -def _dump_filtered_stats(tmpdir, prof, filename): +def _dump_filtered_stats(tmpdir, prof, filename, extra_line_stats=None): import os - import pickle + + if isinstance(prof, ContextualProfile): + # - Not using `line_profiler` + # -> doesn't matter if the source lines can't be retrieved + # -> no need to filter anything + prof.dump_stats(filename) + return + + # Remember to incorporate extra stats where available + line_stats = prof.get_stats() + if extra_line_stats is not None: + line_stats += extra_line_stats # Build list of known temp file paths tempfile_paths = [ @@ -1053,31 +983,28 @@ def _dump_filtered_stats(tmpdir, prof, filename): for dirpath, _, fnames in os.walk(tmpdir) for fname in fnames ] - - if not tempfile_paths or isinstance(prof, ContextualProfile): + if not tempfile_paths: # - No tempfiles written -> no function lives in tempfiles # -> no need to filter anything - # - Not using `line_profiler` - # -> doesn't matter if the source lines can't be retrieved - # -> no need to filter anything - prof.dump_stats(filename) + line_stats.to_file(filename) return + _dump_filtered_line_stats(line_stats, tempfile_paths, filename) + + +def _dump_filtered_line_stats(stats, exclude, filename): # 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): + if any(os.path.samefile(fname, tmp) for tmp in exclude): del timings[key] except OSError: del timings[key] - - with open(filename, 'wb') as f: - pickle.dump(stats, f, protocol=pickle.HIGHEST_PROTOCOL) + stats.to_file(filename) def _format_call_message(func, *args, **kwargs): @@ -1120,13 +1047,62 @@ def _call_with_diagnostics(options, func, *args, **kwargs): return func(*args, **kwargs) -def _pre_profile(options, module, exit_on_error): +class _manage_profiler: """ Prepare the environment to execute profiling with requested options. Note: modifies ``options`` with extra attributes. """ + def __init__(self, options, module, exit_on_error): + self.options = options + self.module = module + self.exit_on_error = exit_on_error + self._pid = os.getpid() + + def __enter__(self): + from line_profiler.curated_profiling import CuratedProfilerContext + + self.prof = _prepare_profiler( + self.options, self.module, self.exit_on_error, + ) + self._ctx = CuratedProfilerContext( + self.prof, insert_builtin=self.options.builtin, + ) + self._ctx.install() + # Note: the `_` is for the pre-imports file (removed); when we + # refactor further profile child processes (TODO), it is to be + # preserved (`keep_preimports_file`) and used by them + try: + script_file, _ = _prepare_exec_script( + self.options, self.module, self.prof, + exit_on_error=self.exit_on_error, + keep_preimports_file=False, + ) + return self.prof, script_file + except BaseException: + # Make sure that we don't leak the changes made by `._ctx` + # before we've gotten out of `.__enter__()` + self._ctx.uninstall() + raise + + def __exit__(self, *_, **__): + # Notes: + # - After we've refactored (TODO) to manage profiling in child + # processes, we'll need to add a PID guard here in case that + # the profiled code has forked. + # - The stats gathered from child processes can be integrated + # via the currently unused `extra_line_stats`. + try: + _post_profile(self.options, self.prof, extra_line_stats=None) + finally: + self._ctx.uninstall() + + +def _prepare_profiler(options, module, exit_on_error): + """ + Set up the appropriate profiler instance. + """ if not options.outfile: extension = 'lprof' if options.line_by_line else 'prof' options.outfile = f'{os.path.basename(options.script)}.{extension}' @@ -1134,7 +1110,10 @@ def _pre_profile(options, module, exit_on_error): f'Using default output destination {short_string_path(options.outfile)!r}' ) - sys.argv = [options.script] + options.args + # Note: we'll restore the content of `sys.argv` with the decorator + # on `main()`, so it's simpler to just `setitem()` instead of + # replacing the whole list object + sys.argv[:] = [options.script] + options.args if module: # Make sure the current directory is on `sys.path` to emulate # `python -m` @@ -1156,24 +1135,26 @@ def _pre_profile(options, module, exit_on_error): execfile(setup_file, ns, ns) if options.line_by_line: - prof = line_profiler.LineProfiler() options.builtin = True + return line_profiler.LineProfiler() elif Profile.__module__ == 'profile': raise RuntimeError( 'non-line-by-line profiling depends on cProfile, ' 'which is not available on this platform' ) else: - prof = ContextualProfile() + return ContextualProfile() - # Overwrite the explicit decorator - global_profiler = line_profiler.profile - install_profiler = global_profiler._kernprof_overwrite - install_profiler(prof) - - if options.builtin: - builtins.__dict__['profile'] = prof +def _prepare_exec_script( + options, module, prof, + *, + exit_on_error=False, + keep_preimports_file=False, +): + """ + Set up the script to be executed among other things. + """ if module: script_file = find_module_script( options.script, static=options.static, exit_on_error=exit_on_error @@ -1193,6 +1174,8 @@ def _pre_profile(options, module, exit_on_error): options.prof_mod = _normalize_profiling_targets(options.prof_mod) if not options.prof_mod: options.preimports = False + + preimports_file = None if options.line_by_line and options.preimports: # We assume most items in `.prof_mod` to be import-able without # significant side effects, but the same cannot be said if it @@ -1200,10 +1183,10 @@ def _pre_profile(options, module, exit_on_error): # 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) + preimports_file = _write_preimports( + prof, options, exclude, keep=keep_preimports_file, + ) - 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 @@ -1211,7 +1194,7 @@ def _pre_profile(options, module, exit_on_error): else: options.rt = None options.original_stdout = sys.stdout - return script_file, prof + return script_file, preimports_file def _main_profile(options, module=False, exit_on_error=True): @@ -1219,9 +1202,10 @@ def _main_profile(options, module=False, exit_on_error=True): 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, exit_on_error) call = functools.partial(_call_with_diagnostics, options) - try: + with _manage_profiler( + options, module, exit_on_error, + ) as (prof, script_file): rmod = functools.partial( run_module, run_name='__main__', alter_sys=True ) @@ -1272,18 +1256,18 @@ def _main_profile(options, module=False, exit_on_error=True): module_ns, module_ns, ) - finally: - _post_profile(options, prof) -def _post_profile(options, prof): +def _post_profile(options, prof, extra_line_stats=None): """ - Cleanup setup after executing a main profile + Cleanup setup after executing :py:func:`_main_profile` """ if options.rt is not None: options.rt.stop() if not options.dryrun: - _dump_filtered_stats(options.tmpdir, prof, options.outfile) + _dump_filtered_stats( + options.tmpdir, prof, options.outfile, extra_line_stats, + ) short_outfile = short_string_path(options.outfile) diagnostics.log.info( ( @@ -1294,9 +1278,15 @@ def _post_profile(options, prof): + f'to {short_outfile!r}' ) if options.verbose > 0 and not options.dryrun: - kwargs = {} - if not isinstance(prof, ContextualProfile): - kwargs.update( + if isinstance(prof, ContextualProfile): + _call_with_diagnostics(options, prof.print_stats) + else: + stats = prof.get_stats() + if extra_line_stats is not None: + stats += extra_line_stats + _call_with_diagnostics( + options, + stats.print, output_unit=options.unit, stripzeros=options.skip_zero, summarize=options.summarize, @@ -1304,7 +1294,6 @@ def _post_profile(options, prof): stream=options.original_stdout, config=options.config, ) - _call_with_diagnostics(options, prof.print_stats, **kwargs) else: py_exe = _python_command() if isinstance(prof, ContextualProfile): @@ -1316,12 +1305,6 @@ def _post_profile(options, prof): f'{quote(py_exe)} -m {show_mod} ' f'{quote(short_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/_line_profiler.pyi b/line_profiler/_line_profiler.pyi index 5598ffbe..d295c57f 100644 --- a/line_profiler/_line_profiler.pyi +++ b/line_profiler/_line_profiler.pyi @@ -1,6 +1,7 @@ from __future__ import annotations -from typing import Any, Mapping +from collections.abc import Callable, Mapping +from typing import Any class LineStats: timings: Mapping[tuple[str, int, str], list[tuple[int, int, int]]] @@ -13,6 +14,20 @@ class LineStats: ) -> None: ... class LineProfiler: + def __init__( + self, + # Note: realistically these should be `types.FunctionType` or + # `MethodType`, but type-annotating this as those results in + # type checkers balking against even the most simple of usecases + # because bare functions are resolved to `Callable`s with the + # appropriate signatures, and are no longer recognized as + # `FunctionType`s. + *functions: Callable[..., Any], + wrap_trace: bool | None = None, + set_frame_local_trace: bool | None = None, + ) -> None: + ... + def enable_by_count(self) -> None: ... def disable_by_count(self) -> None: ... def add_function(self, func: Any) -> None: ... diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 042f23c6..3c0e0071 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -356,22 +356,69 @@ list[tuple[int, int, int]]]): cdef class _SysMonitoringState: """ - Another helper object for managing the thread-local state. + Helper object for managing the :py:mod:`sys.monitoring` state. + + Methods of interest: + + :py:meth:`~.handle_line_event` + Callback for |LINE|_ events + :py:meth:`~.handle_return_event` + Callback for |PY_RETURN|_ events + :py:meth:`~.handle_yield_event` + Callback for |PY_YIELD|_ events + :py:meth:`~.handle_raise_event` + Callback for |RAISE|_ events + :py:meth:`~.handle_reraise_event` + Callback for |RERAISE|_ events Note: - Documentations are for reference only, and all APIs are to be - considered private and subject to change. + - Documentations are for reference only, and all APIs are to be + considered private and subject to change. + + - In contrast to the legacy trace system (which is set up + per-thread), :py:mod:`sys.monitoring` registration is + process-global; a single instance (per tool ID) is therefore + shared between the per-thread :py:class:`_LineProfilerManager` + objects (see :py:func:`_get_shared_mon_state`), while its + :py:attr:`~.active_instances` set remains thread-local. This + way, the global callbacks/events are only torn down when the + last profiler anywhere is disabled, instead of whenever any + one thread's manager runs out of active profilers (which used + to kill profiling on the other threads and make their + subsequent :py:meth:`LineProfiler.disable` calls raise). + + .. |LINE| replace:: :py:attr:`!sys.monitoring.events.LINE` + .. |PY_RETURN| replace:: :py:attr:`!sys.monitoring.events.PY_RETURN` + .. |PY_YIELD| replace:: :py:attr:`!sys.monitoring.events.PY_YIELD` + .. |RAISE| replace:: :py:attr:`!sys.monitoring.events.RAISE` + .. |RERAISE| replace:: :py:attr:`!sys.monitoring.events.RERAISE` + .. _LINE: https://docs.python.org/3/library/\ +sys.monitoring.html#monitoring-event-LINE + .. _PY_RETURN: https://docs.python.org/3/library/\ +sys.monitoring.html#monitoring-event-PY_RETURN + .. _PY_YIELD: https://docs.python.org/3/library/\ +sys.monitoring.html#monitoring-event-PY_YIELD + .. _RAISE: https://docs.python.org/3/library/\ +sys.monitoring.html#monitoring-event-RAISE + .. _RERAISE: https://docs.python.org/3/library/\ +sys.monitoring.html#monitoring-event-RERAISE """ cdef int tool_id - cdef object name # type: str | None - # type: dict[int, Callable | None], int = event id - cdef dict callbacks + # type: dict[int, set[LineProfiler]], int = thread id + cdef dict _active_inst_sets # type: dict[int, set[tuple[code, Unpack[tuple]]]], # int = event id, tuple = cdef dict disabled - cdef int events + cdef int _wrap_trace cdef Py_uintptr_t restart_version + # These attributes pertain to the stored pre-`.register()` states, + # to be restored upon `.deregister()` + cdef object name # type: str | None + # type: dict[int, Callable | None], int = event id + cdef dict callbacks + cdef int events + if _CAN_USE_SYS_MONITORING: line_tracing_event_set = ( # type: ClassVar[FrozenSet[int]] frozenset({sys.monitoring.events.LINE, @@ -388,17 +435,26 @@ cdef class _SysMonitoringState: line_tracing_event_set = frozenset({}) line_tracing_events = 0 - def __init__(self, tool_id: int): + def __init__(self, tool_id: int, wrap_trace: bool): self.tool_id = tool_id self.name = None self.callbacks = {} self.disabled = {} + self._active_inst_sets = {} + self.wrap_trace = wrap_trace self.events = 0 # NO_EVENTS self.restart_version = monitoring_restart_version() - cpdef register(self, object handle_line, - object handle_return, object handle_yield, - object handle_raise, object handle_reraise): + property active_instances: # type: set[LineProfiler] + def __get__(self): + thread_id = PyThread_get_thread_ident() + try: + return self._active_inst_sets[thread_id] + except KeyError: + self._active_inst_sets[thread_id] = instances = set() + return instances + + cpdef register(self): # Note: only activating `sys.monitoring` line events for the # profiled code objects in `LineProfiler.add_function()` may # seem like an obvious optimization, but: @@ -425,11 +481,20 @@ cdef class _SysMonitoringState: mon.set_events(self.tool_id, self.events | self.line_tracing_events) # Register tracebacks and remember the existing ones - for event_id, callback in [(mon.events.LINE, handle_line), - (mon.events.PY_RETURN, handle_return), - (mon.events.PY_YIELD, handle_yield), - (mon.events.RAISE, handle_raise), - (mon.events.RERAISE, handle_reraise)]: + # Note: we need to declare `cpdef`-ed methods explicitly as + # `object`s, otherwise Cython will assume that we meant the + # C++-level functions (see Cython issue #8001) + cdef object handle_line_event = self.handle_line_event + cdef object handle_return_event = self.handle_return_event + cdef object handle_yield_event = self.handle_yield_event + cdef object handle_raise_event = self.handle_raise_event + cdef object handle_reraise_event = self.handle_reraise_event + for event_id, callback in [ + (mon.events.LINE, handle_line_event), + (mon.events.PY_RETURN, handle_return_event), + (mon.events.PY_YIELD, handle_yield_event), + (mon.events.RAISE, handle_raise_event), + (mon.events.RERAISE, handle_reraise_event)]: self.callbacks[event_id] = mon.register_callback( self.tool_id, event_id, callback) @@ -437,17 +502,120 @@ cdef class _SysMonitoringState: mon = sys.monitoring cdef dict wrapped_callbacks = self.callbacks - # Restore prior state - mon.set_events(self.tool_id, self.events) - if self.name is None: + # No-op unless `.register()` has been called (makes repeated or + # spurious `.deregister()` calls harmless) + if not wrapped_callbacks: + return + + # Restore prior state; be tolerant of external interference + # (e.g. other code having freed the tool ID from under us), + # which shouldn't prevent the teardown from completing + try: + mon.set_events(self.tool_id, self.events) + except ValueError: + pass + if self.name is None and mon.get_tool(self.tool_id) is not None: mon.free_tool_id(self.tool_id) self.name = None self.events = mon.events.NO_EVENTS + self.disabled.clear() # Reset tracebacks while wrapped_callbacks: mon.register_callback(self.tool_id, *wrapped_callbacks.popitem()) + cdef int _has_active_instances(self): + if any(self._active_inst_sets.values()): + return 1 + return 0 + + # If we allowed these `sys.monitoring` callbacks to be profiled + # (i.e. to emit line events), we may fall into an infinite recusion; + # so disable profiling for them pre-emptively + + @cython.profile(False) + cpdef handle_line_event(self, object code, int lineno): + """ + Line-event callback for :py:attr:`!sys.monitoring.events.LINE`, + passed to :py:func:`sys.monitoring.register_callback`. + """ + self._base_callback( + 1, sys.monitoring.events.LINE, code, lineno, (lineno,), ()) + + @cython.profile(False) + cpdef handle_return_event( + self, object code, int instruction_offset, object retval): + """ + Return-event callback for + :py:attr:`!sys.monitoring.events.PY_RETURN`, passed to + :py:func:`sys.monitoring.register_callback`. + """ + self._handle_exit_event( + sys.monitoring.events.PY_RETURN, code, instruction_offset, retval) + + @cython.profile(False) + cpdef handle_yield_event( + self, object code, int instruction_offset, object retval): + """ + Yield-event callback for + :py:attr:`!sys.monitoring.events.PY_YIELD`, passed to + :py:func:`sys.monitoring.register_callback`. + """ + self._handle_exit_event( + sys.monitoring.events.PY_YIELD, code, instruction_offset, retval) + + @cython.profile(False) + cpdef handle_raise_event( + self, object code, int instruction_offset, object exception): + """ + Raise-event callback for + :py:attr:`!sys.monitoring.events.RAISE`, passed to + :py:func:`sys.monitoring.register_callback`. + """ + self._handle_exit_event( + sys.monitoring.events.RAISE, code, instruction_offset, exception) + + @cython.profile(False) + cpdef handle_reraise_event( + self, object code, int instruction_offset, object exception): + """ + Re-raise-event callback for + :py:attr:`!sys.monitoring.events.RERAISE`, passed to + :py:func:`sys.monitoring.register_callback`. + """ + self._handle_exit_event( + sys.monitoring.events.RERAISE, code, instruction_offset, exception) + + cdef void _handle_exit_event( + self, int event_id, object code, int offset, object obj) noexcept: + """ + Base for the frame-exit-event (e.g. via returning or yielding) + callbacks passed to :py:func:`sys.monitoring.register_callback`. + + Note: + This is deliberately made a non-traceable C method so that + we don't fall info infinite recursion. + """ + cdef int lineno = PyCode_Addr2Line(code, offset) + self._base_callback(0, event_id, code, lineno, (offset,), (obj,)) + + cdef void _base_callback( + self, int is_line_event, int event_id, object code, int lineno, + object loc_args, object other_args) noexcept: + """ + Base for the various callbacks passed to + :py:func:`sys.monitoring.register_callback`. + + Note: + * This is deliberately made a non-traceable C method so that + we don't fall info infinite recursion. + * ``loc_args`` and ``other_args`` should be tuples. + """ + inner_trace_callback( + is_line_event, self.active_instances, code, lineno) + if self._wrap_trace: + self.call_callback(event_id, code, loc_args, other_args) + cdef void call_callback(self, int event_id, object code, object loc_args, object other_args) noexcept: """ @@ -523,6 +691,33 @@ cdef class _SysMonitoringState: mon.set_events(self.tool_id, self.events | self.line_tracing_events) + property wrap_trace: + def __get__(self): + return bool(self._wrap_trace) + def __set__(self, wrap_trace): + self._wrap_trace = 1 if wrap_trace else 0 + + +# type: dict[int, _SysMonitoringState], int = tool id +_shared_mon_states = {} + + +cdef _SysMonitoringState _get_shared_mon_state( + int tool_id, object wrap_trace = None): + """ + Get the process-global :py:class:`_SysMonitoringState` for the + ``tool_id``, creating it if necessary; see the class docstring for + why the state is shared. + """ + try: + state = _shared_mon_states[tool_id] + except KeyError: + state = _shared_mon_states[tool_id] = _SysMonitoringState( + tool_id, wrap_trace) + if wrap_trace is not None: + state.wrap_trace = wrap_trace + return state + cdef class _LineProfilerManager: """ @@ -530,38 +725,9 @@ cdef class _LineProfilerManager: Supports being called with the same signature as a legacy trace function (see :py:func:`sys.settrace`). - Other methods of interest: - - :py:meth:`~.handle_line_event` - Callback for |LINE|_ events - :py:meth:`~.handle_return_event` - Callback for |PY_RETURN|_ events - :py:meth:`~.handle_yield_event` - Callback for |PY_YIELD|_ events - :py:meth:`~.handle_raise_event` - Callback for |RAISE|_ events - :py:meth:`~.handle_reraise_event` - Callback for |RERAISE|_ events - Note: Documentations are for reference only, and all APIs are to be considered private and subject to change. - - .. |LINE| replace:: :py:attr:`!sys.monitoring.events.LINE` - .. |PY_RETURN| replace:: :py:attr:`!sys.monitoring.events.PY_RETURN` - .. |PY_YIELD| replace:: :py:attr:`!sys.monitoring.events.PY_YIELD` - .. |RAISE| replace:: :py:attr:`!sys.monitoring.events.RAISE` - .. |RERAISE| replace:: :py:attr:`!sys.monitoring.events.RERAISE` - .. _LINE: https://docs.python.org/3/library/\ -sys.monitoring.html#monitoring-event-LINE - .. _PY_RETURN: https://docs.python.org/3/library/\ -sys.monitoring.html#monitoring-event-PY_RETURN - .. _PY_YIELD: https://docs.python.org/3/library/\ -sys.monitoring.html#monitoring-event-PY_YIELD - .. _RAISE: https://docs.python.org/3/library/\ -sys.monitoring.html#monitoring-event-RAISE - .. _RERAISE: https://docs.python.org/3/library/\ -sys.monitoring.html#monitoring-event-RERAISE """ cdef TraceCallback *legacy_callback cdef _SysMonitoringState mon_state @@ -588,9 +754,21 @@ sys.monitoring.html#monitoring-event-RERAISE :py:class:`~.LineProfiler` """ self.legacy_callback = NULL - self.mon_state = _SysMonitoringState(tool_id) + if USE_LEGACY_TRACE: + # The legacy trace system is per-thread, so each (per- + # thread) manager tracks its own state + self.mon_state = _SysMonitoringState(tool_id, wrap_trace) + self.active_instances = set() + else: + # `sys.monitoring` is process-global, so all managers share + # one monitoring state and one set of active profilers; + # the global callbacks are then only torn down when the + # last profiler anywhere is disabled, regardless of which + # thread registered or disables them + self.mon_state = _get_shared_mon_state(tool_id, wrap_trace) + # However, this set here is thread-local + self.active_instances = self.mon_state.active_instances - self.active_instances = set() self.wrap_trace = wrap_trace self.set_frame_local_trace = set_frame_local_trace self.recursion_guard = 0 @@ -671,114 +849,29 @@ line_profiler/blob/main/line_profiler/_line_profiler.pyx pass return wrapper - # If we allowed these `sys.monitoring` callbacks to be profiled - # (i.e. to emit line events), we may fall into an infinite recusion; - # so disable profiling for them pre-emptively - - @cython.profile(False) - cpdef handle_line_event(self, object code, int lineno): - """ - Line-event callback for :py:attr:`!sys.monitoring.events.LINE`, - passed to :py:func:`sys.monitoring.register_callback`. - """ - self._base_callback( - 1, sys.monitoring.events.LINE, code, lineno, (lineno,), ()) - - @cython.profile(False) - cpdef handle_return_event( - self, object code, int instruction_offset, object retval): - """ - Return-event callback for :py:attr:`!sys.monitoring.events.PY_RETURN`, - passed to :py:func:`sys.monitoring.register_callback`. - """ - self._handle_exit_event( - sys.monitoring.events.PY_RETURN, code, instruction_offset, retval) - - @cython.profile(False) - cpdef handle_yield_event( - self, object code, int instruction_offset, object retval): - """ - Yield-event callback for :py:attr:`!sys.monitoring.events.PY_YIELD`, - passed to :py:func:`sys.monitoring.register_callback`. - """ - self._handle_exit_event( - sys.monitoring.events.PY_YIELD, code, instruction_offset, retval) - - @cython.profile(False) - cpdef handle_raise_event( - self, object code, int instruction_offset, object exception): - """ - Raise-event callback for :py:attr:`!sys.monitoring.events.RAISE`, - passed to :py:func:`sys.monitoring.register_callback`. - """ - self._handle_exit_event( - sys.monitoring.events.RAISE, code, instruction_offset, exception) - - @cython.profile(False) - cpdef handle_reraise_event( - self, object code, int instruction_offset, object exception): - """ - Re-raise-event callback for :py:attr:`!sys.monitoring.events.RERAISE`, - passed to :py:func:`sys.monitoring.register_callback`. - """ - self._handle_exit_event( - sys.monitoring.events.RERAISE, code, instruction_offset, exception) - - cdef void _handle_exit_event( - self, int event_id, object code, int offset, object obj) noexcept: - """ - Base for the frame-exit-event (e.g. via returning or yielding) - callbacks passed to :py:func:`sys.monitoring.register_callback`. - - Note: - This is deliberately made a non-traceable C method so that - we don't fall info infinite recursion. - """ - cdef int lineno = PyCode_Addr2Line(code, offset) - self._base_callback(0, event_id, code, lineno, (offset,), (obj,)) - - cdef void _base_callback( - self, int is_line_event, int event_id, object code, int lineno, - object loc_args, object other_args) noexcept: - """ - Base for the various callbacks passed to - :py:func:`sys.monitoring.register_callback`. - - Note: - * This is deliberately made a non-traceable C method so that - we don't fall info infinite recursion. - * ``loc_args`` and ``other_args`` should be tuples. - """ - inner_trace_callback( - is_line_event, self.active_instances, code, lineno) - if self._wrap_trace: - self.mon_state.call_callback(event_id, code, loc_args, other_args) - cpdef _handle_enable_event(self, prof): cdef TraceCallback* legacy_callback - instances = self.active_instances - already_active = bool(instances) - instances.add(prof) + cdef int already_active = self._has_active_instances() + + self.active_instances.add(prof) if already_active: return + if USE_LEGACY_TRACE: legacy_callback = alloc_callback() populate_callback(legacy_callback) self.legacy_callback = legacy_callback PyEval_SetTrace(legacy_trace_callback, self) else: - self.mon_state.register(self.handle_line_event, - self.handle_return_event, - self.handle_yield_event, - self.handle_raise_event, - self.handle_reraise_event) + self.mon_state.register() cpdef _handle_disable_event(self, prof): cdef TraceCallback* legacy_callback - instances = self.active_instances - instances.discard(prof) - if instances: + self.active_instances.discard(prof) + + if self._has_active_instances(): # Still active return + # Only use the legacy trace-callback system if Python < 3.12 or # if explicitly requested with `LINE_PROFILER_CORE=legacy`; # otherwise, use `sys.monitoring` @@ -791,11 +884,18 @@ line_profiler/blob/main/line_profiler/_line_profiler.pyx else: self.mon_state.deregister() + cdef int _has_active_instances(self): + if USE_LEGACY_TRACE: + return 1 if self.active_instances else 0 + return self.mon_state._has_active_instances() + property wrap_trace: def __get__(self): return bool(self._wrap_trace) def __set__(self, wrap_trace): - self._wrap_trace = 1 if wrap_trace else 0 + self.mon_state._wrap_trace = self._wrap_trace = ( + 1 if wrap_trace else 0 + ) property set_frame_local_trace: def __get__(self): @@ -911,7 +1011,7 @@ cdef class LineProfiler: :py:mod:`sys.monitoring` tool ID it acquired. * When setting :py:attr:`.wrap_trace` and :py:attr:`.set_frame_local_trace`, they are set process-wide - for all instances. + for all instances across all threads. .. _note-backends: @@ -1334,6 +1434,8 @@ datamodel.html#user-defined-functions return py_last_time cpdef disable(self): + # Note: `operator[]` (re-)creates an empty entry for the + # calling thread, which `.c_last_time` expects to find self._c_last_time[PyThread_get_thread_ident()].clear() self._manager._handle_disable_event(self) diff --git a/line_profiler/_threading_patches.py b/line_profiler/_threading_patches.py new file mode 100644 index 00000000..75281753 --- /dev/null +++ b/line_profiler/_threading_patches.py @@ -0,0 +1,421 @@ +""" +Patch :py:mod:`threading` so that profiling extends consistenly into +processes it creates. +""" +from __future__ import annotations + +import threading +from collections.abc import Callable, Collection, Mapping +from functools import wraps +from types import MethodType, ModuleType +from typing import TYPE_CHECKING, Any, TypeVar, cast, overload +from typing_extensions import ParamSpec, Concatenate + +from .line_profiler import LineProfiler +from .cleanup import Cleanup + + +__all__ = ('apply',) + + +T = TypeVar('T') +PS = ParamSpec('PS') + +_PATCHED_MARKER = '__line_profiler_patched_threading__' + + +@overload +def make_syncing_wrapper( + func: Callable[PS, T], prof_enable_counts: Mapping[LineProfiler, int], +) -> Callable[PS, T]: + ... + + +@overload +def make_syncing_wrapper( + func: MethodType, prof_enable_counts: Mapping[LineProfiler, int], +) -> MethodType: + ... + + +def make_syncing_wrapper( + func: Callable[PS, T] | MethodType, + prof_enable_counts: Mapping[LineProfiler, int], +) -> Callable[PS, T] | MethodType: + """ + Wrap the callable ``func`` so that when we spin up a new thread, we + sync the + :py:attr:`line_profiler.line_profiler.LineProfiler.enable_count`s of + the profilers as specified by ``prof_enable_counts``. + + Example: + >>> class Cls: + ... @classmethod + ... def method(cls) -> int: + ... print(cls.__name__, prof.enable_count) + + >>> prof = LineProfiler(Cls.method) + >>> Cls.method() + Cls 0 + >>> assert not any( + ... (stats := prof.get_stats()).timings.values() + ... ), stats + + >>> func_wrapper = make_syncing_wrapper(Cls.method, {prof: 2}) + >>> prof.enable_count + 0 + >>> func_wrapper() + Cls 2 + >>> prof.enable_count + 0 + >>> assert any( + ... (stats := prof.get_stats()).timings.values() + ... ), stats + """ + # Note: the above doctest is mainly here for coverage purposes, + # since this function is otherwise only called on a thread in a part + # inaccessible to `coverage`. + if isinstance(func, MethodType): + impl = make_syncing_wrapper(func.__func__, prof_enable_counts) + return MethodType(impl, func.__self__) + + @wraps(func) + def wrapper(*args: PS.args, **kwargs: PS.kwargs) -> T: + for prof, enable_count in prof_enable_counts.items(): + _sync_enable_count(prof, enable_count) + try: + return func(*args, **kwargs) + finally: + # Reset enable counts to avoid problems if the "physical" + # thread id is ever reused + for prof in prof_enable_counts: + try: + _sync_enable_count(prof, 0) + except Exception: + pass + + return wrapper + + +def _sync_enable_count(prof: LineProfiler, count: int) -> None: + """ + Example: + (Use a dummy class to avoid the side effects of having live + :py:class:`LineProfiler` objects at test teardown and/or process + termination.) + + >>> from collections import Counter + >>> from typing import cast + >>> from line_profiler import LineProfiler + + >>> class MockProfiler: + ... def __init__(self) -> None: + ... self.enable_count = 0 + ... self._events = Counter() + ... + ... def enable(self) -> None: + ... self._events['enable'] += 1 + ... + ... def disable(self) -> None: + ... self._events['disable'] += 1 + ... + ... def enable_by_count(self) -> None: + ... if not self.enable_count: + ... self.enable() + ... self.enable_count += 1 + ... + ... def disable_by_count(self) -> None: + ... if self.enable_count <= 0: + ... return + ... if self.enable_count == 1: + ... self.disable() + ... self.enable_count -= 1 + + >>> def test_sync(prof: MockProfiler, count: int) -> None: + ... print(f'{prof.enable_count} -> {count}') + ... _sync_enable_count(cast(LineProfiler, prof), count) + ... assert ( + ... prof.enable_count == count + ... ), f'{prof.enable_count=!r}, {count=!r}' + + >>> prof = MockProfiler() + >>> test_sync(prof, 4) # Enabled + 0 -> 4 + >>> test_sync(prof, 6) + 4 -> 6 + >>> test_sync(prof, 1) + 6 -> 1 + >>> test_sync(prof, 3) + 1 -> 3 + >>> test_sync(prof, 0) # Disabled + 3 -> 0 + >>> test_sync(prof, 5) # Enabled + 0 -> 5 + >>> assert ( + ... prof._events == {'enable': 2, 'disable': 1} + ... ), f'{prof._events=!r}' + """ + if TYPE_CHECKING: + assert hasattr(prof, 'enable_count') + assert isinstance(prof.enable_count, int) + delta = count - prof.enable_count + if delta > 0: + bump_count: Callable[[], None] = prof.enable_by_count + else: + bump_count, delta = prof.disable_by_count, -delta + for _ in range(delta): + bump_count() + + +def wrap_thread_start( + profs: Collection[LineProfiler], + vanilla_impl: Callable[Concatenate[threading.Thread, PS], None], +) -> Callable[Concatenate[threading.Thread, PS], None]: + """ + Wrap :py:meth:`threading.Thread.start` so that the profilers' + :py:attr:`LineProfiler.enable_count`s are synced up on newly spun-up + threads. + """ + @wraps(vanilla_impl) + def wrapper( + self: threading.Thread, *args: PS.args, **kwargs: PS.kwargs + ) -> None: + if TYPE_CHECKING: + assert hasattr(self, '_bootstrap') + prof_enable_counts: dict[LineProfiler, int] = {} + for prof in profs: + count: int = getattr(prof, 'enable_count', 0) + if count: + prof_enable_counts[prof] = count + if prof_enable_counts: + bst: Callable[..., Any] | MethodType = cast(Any, self._bootstrap) + # `.start()` passes `._bootstrap()` to some lower-level + # function to spin up the new thread. + bst = wrap_thread_bootstrap(prof_enable_counts, bst) + # This is a private method; we don't care about restoring it + self._bootstrap = bst # type: ignore + vanilla_impl(self, *args, **kwargs) + + return wrapper + + +@overload +def wrap_thread_bootstrap( + prof_enable_counts: Mapping[LineProfiler, int], + vanilla_impl: Callable[Concatenate[threading.Thread, PS], None], +) -> Callable[Concatenate[threading.Thread, PS], None]: + ... + + +@overload +def wrap_thread_bootstrap( + prof_enable_counts: Mapping[LineProfiler, int], vanilla_impl: MethodType, +) -> MethodType: + ... + + +def wrap_thread_bootstrap( + prof_enable_counts: Mapping[LineProfiler, int], + vanilla_impl: Callable[ + Concatenate[threading.Thread, PS], None + ] | MethodType, +) -> Callable[Concatenate[threading.Thread, PS], None] | MethodType: + """ + Wrap :py:meth:`threading.Thread._bootstrap` so that the profilers' + :py:attr:`LineProfiler.enable_count` is synced up on newly spun-up + threads. + + Notes: + This is separate from :py:func:`wrap_thread_start` because: + + - :py:func:`wrap_thread_start` is responsible for + capturing ``prof.enable_count`` at startup on the parent + thread. + + - However, if :py:func:`threading.settrace` is used, the + supplied callable will override the legacy trace callback mid + ``._bootstrap()`` (inside + :py:meth:`threading.Thread._bootstrap_inner`, before calling + :py:meth:`threading.Thread.run`), thus interfering with + profiling (when the "legacy" core is used). + + - To circumvent that, we use a wrapper to reversibly + monkey-patch :py:meth:`threading.Thread.run`, so that profiler + activation happens after the call to :py:func:`sys.settrace` + and can thus "wrap" the callable. + """ + if isinstance(vanilla_impl, MethodType): + impl = wrap_thread_bootstrap(prof_enable_counts, vanilla_impl.__func__) + return MethodType(impl, vanilla_impl.__self__) + + @wraps(vanilla_impl) + def wrapper( + self: threading.Thread, *args: PS.args, **kwargs: PS.kwargs + ) -> None: # nocover + # Note: this CANNOT be covered because `coverage` uses + # `threading.settrace()` to set up shop on the new thread, but + # that is only called INSIDE `._bootstrap_inner()` + with Cleanup() as cleanup: + run = make_syncing_wrapper(self.run, prof_enable_counts) + cleanup.patch(self, 'run', run) + vanilla_impl(self, *args, **kwargs) + + return wrapper + + +def apply( + cleanup: Cleanup, + profs: LineProfiler | Collection[LineProfiler], + threading: ModuleType | None = None, +) -> None: + """ + Set up profiling in threads started by :py:mod:`threading` by + applying patches to the module. + + Args: + cleanup (Cleanup): + :py:class:`Cleanup` instance managing the profiling session. + + profs (LineProfiler | Collection[LineProfiler]): + :py:class:`LineProfiler` instance(s) used in the session. + + threading (ModuleType | None): + Optional :py:mod:`threading` module or a copy thereof; + default is the global module. + + Side effects: + - :py:mod:`threading` marked as having been set up. + + - The following methods and functions patched: + + - :py:meth:`threading.Thread.start`. + + - Cleanup callbacks registered via ``cleanup.add_cleanup()``. + + Examples: + >>> from contextlib import ExitStack + >>> from threading import Thread + + >>> from line_profiler import LineProfiler + >>> from line_profiler.cleanup import Cleanup + + >>> prof1 = LineProfiler() + >>> prof2 = LineProfiler() + + >>> def print_enable_counts(header: str | None = None) -> None: + ... ''' + ... Note that these counts are thread-local. + ... ''' + ... if header is None: + ... header = '' + ... else: + ... header = f'{header}: ' + ... print(f'{header}{prof1.enable_count = !r}') + ... print(f'{header}{prof2.enable_count = !r}') + + >>> def print_enable_counts_in_another_thread() -> None: + ... thread = Thread( + ... target=print_enable_counts, args=('In new thread',), + ... ) + ... thread.start() + ... thread.join() + + >>> class enable_profilers: + ... ''' + ... Manage the :py:attr:`LineProfiler.enable_count`s inside + ... the context. NON-REENTRANT. + ... ''' + ... def __init__( + ... self, prof1: int = 0, prof2: int = 0, + ... ) -> None: + ... self.prof1 = prof1 + ... self.prof2 = prof2 + ... self._stack: ExitStack | None = None + ... + ... def __enter__(self) -> None: + ... pc = [(prof1, self.prof1), (prof2, self.prof2)] + ... assert self._stack is None + ... stack = self._stack = ExitStack() + ... for prof, count in pc: + ... for _ in range(count): + ... stack.enter_context(prof) + ... + ... def __exit__(self, *_, **__) -> None: + ... assert self._stack is not None + ... self._stack.close() + ... self._stack = None + + No patches: + + >>> with enable_profilers(1, 2): + ... print_enable_counts('In context') + ... print_enable_counts_in_another_thread() + In context: prof1.enable_count = 1 + In context: prof2.enable_count = 2 + In new thread: prof1.enable_count = 0 + In new thread: prof2.enable_count = 0 + + >>> print_enable_counts() + prof1.enable_count = 0 + prof2.enable_count = 0 + + Syncing a single profiler instance: + + >>> with ExitStack() as stack: + ... stack.enter_context(enable_profilers(1, 2)) + ... cleanup = stack.enter_context(Cleanup()) + ... apply(cleanup, prof1) + ... print_enable_counts('In context') + ... print_enable_counts_in_another_thread() + In context: prof1.enable_count = 1 + In context: prof2.enable_count = 2 + In new thread: prof1.enable_count = 1 + In new thread: prof2.enable_count = 0 + + >>> print_enable_counts() + prof1.enable_count = 0 + prof2.enable_count = 0 + + Syncing multiple profiler instances: + + >>> with ExitStack() as stack: + ... stack.enter_context(enable_profilers(1, 2)) + ... cleanup = stack.enter_context(Cleanup()) + ... apply(cleanup, [prof1, prof2]) + ... print_enable_counts('In context') + ... print_enable_counts_in_another_thread() + In context: prof1.enable_count = 1 + In context: prof2.enable_count = 2 + In new thread: prof1.enable_count = 1 + In new thread: prof2.enable_count = 2 + + >>> print_enable_counts() + prof1.enable_count = 0 + prof2.enable_count = 0 + + Note: + Trying to re-apply the patches while existing ones are not + undone will result in a :py:class:`RuntimeError`: + + >>> with Cleanup( + ... ) as cleanup: # doctest: +ELLIPSIS, +NORMALIZE_WHITESPACE + ... apply(cleanup, prof1) + ... apply(cleanup, prof2) + Traceback (most recent call last): + ... + RuntimeError: threading=: + already patched + """ + if threading is None: + threading = cast(ModuleType, globals()['threading']) + if getattr(threading, _PATCHED_MARKER, False): + raise RuntimeError(f'{threading=!r}: already patched') + + # Wrap in a `set()` to deduplicate + if isinstance(profs, Collection): + profs = set(cast(Collection[LineProfiler], profs)) + else: + profs = {profs} + start_wrapper = wrap_thread_start(profs, threading.Thread.start) + cleanup.patch(threading.Thread, 'start', start_wrapper) + cleanup.patch(threading, _PATCHED_MARKER, True) diff --git a/line_profiler/autoprofile/autoprofile.py b/line_profiler/autoprofile/autoprofile.py index 4471a778..0f8209c9 100644 --- a/line_profiler/autoprofile/autoprofile.py +++ b/line_profiler/autoprofile/autoprofile.py @@ -46,36 +46,120 @@ def main(): """ from __future__ import annotations + import importlib.util import sys import types -from collections.abc import MutableMapping -from typing import Any, cast, Dict, Mapping -from typing import ContextManager +from collections.abc import Callable, Mapping, MutableMapping +from functools import partial +from typing import Any, cast + +from ..cleanup import Cleanup from ..line_profiler_utils import restore from .ast_tree_profiler import AstTreeProfiler from .run_module import AstTreeModuleProfiler from .line_profiler_utils import add_imported_function_or_module from .util_static import modpath_to_modname + PROFILER_LOCALS_NAME = 'prof' +_EXTENSION_METHODS: dict[str, Callable[..., Any]] = { + 'add_imported_function_or_module': add_imported_function_or_module, +} -def _extend_line_profiler_for_profiling_imports(prof: Any) -> None: - """Allow profiler to handle functions/methods, classes & modules with a single call. - Add a method to LineProfiler that can identify whether the object is a - function/method, class or module and handle it's profiling accordingly. - Mainly used for profiling objects that are imported. - (Workaround to keep changes needed by autoprofile separate from base LineProfiler) +def _extend_line_profiler_for_profiling_imports( + prof: Any, + cleanup: Cleanup | None = None, + methods: Mapping[str, Callable[..., Any]] | None = None, + **kwargs +) -> None: + """ + Extend ``prof`` to handle functions/methods, classes & modules with + a single call. + + Equip the :py:class:`LineProfiler` instance with pseudo-methods that + can identify whether the object is a function/method, class or + module and handle it's profiling accordingly. Mainly used for + profiling objects that are imported in a + :py:mod:`line_profiler.curated_profiling` context. Args: prof (LineProfiler): - instance of LineProfiler. + Profiler instance. + cleanup (Cleanup | None): + Optional :py:class:`Cleanup` object used for managing the + equipping of the methods; if not provided, they are just + bolted on with :py:func:`setattr`. + methods (Mapping[str, Callable[..., Any]] | None): + Optional mapping from pseudo-method names to the + instance-method implementation callables; if not provided, + default to the tools defined in + :py:mod:`line_profiler.autoprofile.line_profiler_utils`. + **kwargs: + Passed to :py:meth:`Cleanup.patch`. + + Notes: + This is a workaround to keep changes needed by autoprofile + separate from the base :py:class:`LineProfiler`. + + Example: + >>> from functools import partial + >>> from typing import cast + + >>> from line_profiler import LineProfiler + >>> from line_profiler.cleanup import Cleanup + + >>> class MockProfiler: + ... pass + + >>> def test(prof: MockProfiler, *args, **kwargs) -> None: + ... lprof = cast(LineProfiler, prof) + ... assert not hasattr( + ... lprof, 'get_id', + ... ), f'{lprof.get_id=!r}' + ... assert not hasattr( + ... lprof, 'double', + ... ), f'{lprof.double=!r}' + ... + ... extend(lprof, *args, **kwargs) + ... assert (res := lprof.get_id()) == id(lprof), f'{res=!r}' + ... assert (res := lprof.double(5)) == 10, f'{res=!r}' + + >>> extensions = { + ... 'get_id': lambda self: id(self), + ... 'double': lambda _, x: 2 * x + ... } + >>> extend = partial( + ... _extend_line_profiler_for_profiling_imports, + ... methods=extensions, + ... ) + + Normal use: + + >>> test(MockProfiler()) + + Managed use (w/``cleanup``): + + >>> prof = MockProfiler() + >>> with Cleanup() as cleanup: + ... test(prof, cleanup=cleanup) + ... assert hasattr(prof, 'get_id') + ... assert hasattr(prof, 'double') + >>> # The equipped methods should be restored outside the + >>> # context + >>> assert not hasattr(prof, 'get_id'), f'{prof.get_id=!r}' + >>> assert not hasattr(prof, 'double'), f'{prof.double=!r}' """ - prof.add_imported_function_or_module = types.MethodType( - add_imported_function_or_module, prof - ) + if cleanup is None: + set_attr: Callable[[Any, str, Any], None] = setattr + else: + set_attr = partial(cleanup.patch, **kwargs) + if methods is None: + methods = _EXTENSION_METHODS + for name, impl in methods.items(): + set_attr(prof, name, types.MethodType(impl, prof)) def run( @@ -87,26 +171,28 @@ def run( ) -> None: """Automatically profile a script and run it. - Profile functions, classes & modules specified in prof_mod without needing to add - @profile decorators. + Profile functions, classes & modules specified in ``prof_mod`` + without needing to add ``@profile`` decorators. Args: script_file (str): path to script being profiled. - ns (dict): + ns (MutableMapping[str, Any]): "locals" from kernprof scope. - prof_mod (List[str]): + prof_mod (list[str]): list of imports to profile in script. passing the path to script will profile the whole script. - the objects can be specified using its dotted path or full path (if applicable). + the objects can be specified using its dotted path or full + path (if applicable). profile_imports (bool): - if True, when auto-profiling whole script, profile all imports aswell. + if :py:const:`True`, when auto-profiling whole script, + profile all imports aswell. as_module (bool): - Whether we're running script_file as a module + Whether we're running ``script_file`` as a module """ Profiler: type[AstTreeModuleProfiler] | type[AstTreeProfiler] @@ -115,7 +201,8 @@ def run( module_name = modpath_to_modname(script_file) if not module_name: raise ModuleNotFoundError( - f'script_file = {script_file!r}: cannot find corresponding module' + f'script_file = {script_file!r}: ' + 'cannot find corresponding module', ) module_obj = types.ModuleType(module_name) @@ -138,4 +225,4 @@ def run( # then restore it via the context manager, so that the executed # code is run as `__main__` sys.modules['__main__'] = module_obj - exec(code_obj, cast(Dict[str, Any], namespace), namespace) # type: ignore[redundant-cast] + exec(code_obj, cast('dict[str, Any]', namespace), namespace) diff --git a/line_profiler/c_trace_callbacks.c b/line_profiler/c_trace_callbacks.c index 764b6003..36cf73df 100644 --- a/line_profiler/c_trace_callbacks.c +++ b/line_profiler/c_trace_callbacks.c @@ -182,7 +182,7 @@ int call_callback( * `python_trace_callback()`. */ TraceCallback before, after; - PyObject *mod = NULL, *dle = NULL, *f_trace = NULL; + PyObject *f_trace = NULL; char f_trace_lines; int result; @@ -211,8 +211,6 @@ int call_callback( py_frame->f_trace_lines = f_trace_lines; if (py_frame->f_trace != NULL && py_frame->f_trace != Py_None) { - // Note: DON'T `Py_[X]DECREF()` the pointer! Nothing else is - // holding a reference to it. f_trace = PyObject_CallOneArg(disabler, py_frame->f_trace); if (f_trace == NULL) { @@ -221,8 +219,11 @@ int call_callback( result = -1; goto cleanup; } - // No need to raise another exception, it's already - // raised in the call + // Note: the frame's `f_trace` setter takes its own + // reference to the wrapper, so ours is released in the + // cleanup block. + // (No need to raise another exception on failure, it's + // already raised in the call) if (PyObject_SetAttrString( (PyObject *)py_frame, "f_trace", f_trace)) { @@ -231,8 +232,7 @@ int call_callback( } } cleanup: - Py_XDECREF(mod); - Py_XDECREF(dle); + Py_XDECREF(f_trace); return result; } @@ -244,30 +244,44 @@ void set_local_trace(PyObject *manager, PyFrameObject *py_frame) * where appropriate, setting the frame-local trace callable. * * Notes: - * This function is necessary for side-stepping Cython's auto - * memory management, which causes the return value of - * `wrap_local_f_trace()` to trigger the "Casting temporary - * Python object to non-numeric non-Python type" error. + * - This function is necessary for side-stepping Cython's auto + * memory management, which causes the return value of + * `wrap_local_f_trace()` to trigger the "Casting temporary + * Python object to non-numeric non-Python type" error. + * - This runs inside a trace callback, from which an exception + * cannot cleanly propagate (the caller declares the C + * signature `void` without exception checks), so failures + * are reported via `PyErr_WriteUnraisable()` instead of + * being left set. */ - PyObject *method = NULL; - if (manager == NULL || py_frame == NULL) goto cleanup; + PyObject *method = NULL, *wrapped = NULL; + if (manager == NULL || py_frame == NULL) return; // No-op - if (py_frame->f_trace == manager) goto cleanup; + if (py_frame->f_trace == manager) return; // No local trace function to wrap, just assign `manager` + // (releasing a possible `Py_None` currently in the slot) if (py_frame->f_trace == NULL || py_frame->f_trace == Py_None) { Py_INCREF(manager); - py_frame->f_trace = manager; - goto cleanup; + Py_XSETREF(py_frame->f_trace, manager); + return; } - // Wrap the trace function - // (No need to raise another exception in case the call or the - // `setattr()` failed, it's already raised in the call) + // Wrap the trace function; the frame's `f_trace` setter takes its + // own reference to the wrapper, so ours is released in the cleanup + // block method = PyUnicode_FromString("wrap_local_f_trace"); - PyObject_SetAttrString( - (PyObject *)py_frame, "f_trace", - PyObject_CallMethodOneArg(manager, method, py_frame->f_trace)); + if (method == NULL) goto error; + wrapped = PyObject_CallMethodOneArg(manager, method, py_frame->f_trace); + if (wrapped == NULL) goto error; + if (PyObject_SetAttrString((PyObject *)py_frame, "f_trace", wrapped)) + { + goto error; + } + goto cleanup; +error: + PyErr_WriteUnraisable(manager); cleanup: + Py_XDECREF(wrapped); Py_XDECREF(method); return; } diff --git a/line_profiler/cleanup.py b/line_profiler/cleanup.py new file mode 100644 index 00000000..ca36c7f4 --- /dev/null +++ b/line_profiler/cleanup.py @@ -0,0 +1,576 @@ +""" +Utilities for cleaning up after ourselves. +""" +from __future__ import annotations + +from collections.abc import ( + Callable, Generator, Iterable, Mapping, MutableMapping, +) +from functools import partial +from inspect import getattr_static +from operator import setitem +from pathlib import Path +from typing import Any, Literal, TypeVar, cast +from typing_extensions import Concatenate, ParamSpec, Self + +from .line_profiler_utils import CallbackRepr, make_tempfile +from . import _diagnostics as diagnostics + + +__all__ = ('Cleanup',) + +PS = ParamSpec('PS') +K = TypeVar('K') +V = TypeVar('V') +_Stacks = dict[float, list[Callable[[], Any]]] +_StackContexts = list[_Stacks] +LogLevel = Literal['debug', 'info', 'warning', 'error', 'critical'] + + +_CALLBACK_REPR_HELPER = CallbackRepr(maxother=cast(int, float('inf'))) +_CALLBACK_REPR = _CALLBACK_REPR_HELPER.repr + + +class Cleanup: + """ + Object which holds cleanup callbacks. Also provides convenience + methods for creating tempfiles, updating mappings, and setting + attributes on objects. + """ + def __init__(self, *_, **__) -> None: + self._contexts: _StackContexts = [] + + def __enter__(self) -> Self: + """ + Returns: + The instance + + Note: + This context manager is reentrant; entering the context + create a new set of cleanup stacks, which is then cleaned up + on :py:meth:`~.__exit__`. + + Example: + >>> strings = [] + >>> add = strings.append + >>> with Cleanup() as cleanup: + ... cleanup.add_cleanup(add, 'one') + ... # Increased priority + ... cleanup.add_cleanup_with_priority(add, 1, 'two') + ... add('three') + ... with cleanup: + ... # Decreased priority + ... cleanup.add_cleanup_with_priority( + ... add, -1, 'four', + ... ) + ... cleanup.add_cleanup(add, 'five') + ... add('six') + ... add('seven') + ... # Increased priority + ... cleanup.add_cleanup_with_priority(add, 1, 'eight') + ... + >>> strings # doctest: +NORMALIZE_WHITESPACE + ['three', 'six', 'five', 'four', 'seven', 'eight', 'two', + 'one'] + """ + self._contexts.append({}) + return self + + def __exit__(self, *_, **__) -> Any: + """ + Call ``~.cleanup(1)``, clearing the level of cleanup stacks we + previously :py:meth:`~.__enter__`-ed into. + """ + self.cleanup(1, reason='context exit') + + # Cleanup methods + + def cleanup( + self, levels: int | None = None, *, reason: str | None = None, + ) -> None: + """ + Pop cleanup callbacks from the internal stacks added via + :py:meth:`~.add_cleanup` etc. and call them in order. + + Args: + levels (int | None): + Number of stack levels to clear; passing :py:const`None` + clears the entire stack of callback stacks + reason (str | None): + Optional description of the reason for cleaning up + """ + def pop_all_contexts( + contexts: _StackContexts, + ) -> Generator[_Stacks, None, None]: + while contexts: + yield contexts.pop() + + def pop_n_levels_of_contexts( + contexts: _StackContexts, n: int, + ) -> Generator[_Stacks, None, None]: + for _ in range(n): + try: + yield contexts.pop() + except IndexError: # Ran out of levels + return + + pop_contexts: Iterable[_Stacks] + if levels is None: + pop_contexts = pop_all_contexts(self._contexts) + else: + pop_contexts = pop_n_levels_of_contexts(self._contexts, levels) + for stacks in pop_contexts: + self._cleanup(stacks, reason) + + def _cleanup(self, stacks: _Stacks, reason: str | None) -> None: + r""" + Example: + >>> import re + >>> from collections.abc import Callable + >>> from dataclasses import dataclass + >>> from typing import Any + >>> from typing_extensions import Self + + >>> @dataclass + ... class LogEntry: + ... level: str + ... msg: str + ... + ... def compare( + ... self, + ... *, + ... level: str | None = None, + ... msg: str | None = None, + ... regex: bool = False, + ... ) -> bool: + ... for field, pat in [ + ... ('level', level), ('msg', msg), + ... ]: + ... if pat is None: + ... continue + ... value = getattr(self, field) + ... if regex: + ... if not re.search(pat, value): + ... return False + ... elif value != pat: + ... return False + ... return True + + >>> class MyCleanup(Cleanup): + ... def __init__(self, *args, **kwargs) -> None: + ... super().__init__(*args, **kwargs) + ... self.debug_log: list[LogEntry] = [] + ... + ... def _debug_output( + ... self, msg: str, level: str = 'debug', + ... ) -> None: + ... self.debug_log.append(LogEntry(level, msg)) + + >>> def good_callback(msg: Any) -> None: + ... print(msg) + + >>> def bad_callback(msg: Any) -> None: + ... raise RuntimeError(msg) + + >>> with MyCleanup() as cleanup: + ... cleanup.add_cleanup(good_callback, 1) + ... cleanup.add_cleanup(bad_callback, 2) + ... cleanup.add_cleanup(good_callback, 3) + 3 + 1 + + >>> log = cleanup.debug_log + >>> assert len(log) >= 5, f'{log=!r}; {len(log)=!r}' + + >>> assert log[-5].compare( + ... level='debug', + ... msg='Starting cleanup ' + ... '(context exit; 3 callback(s))...', + ... ), f'{log[-5]=!r}' + >>> assert log[-4].compare( + ... level='debug', + ... msg=r'- Cleanup succeeded \(1/3\): ' + ... '.*good_callback.*3', + ... regex=True, + ... ), f'{log[-4]=!r}' + >>> assert log[-3].compare( + ... level='warning', + ... msg=r'- Cleanup failed \(2/3\): ' + ... '.*bad_callback.*2.*: RuntimeError: 2', + ... regex=True, + ... ), f'{log[-3]=!r}' + >>> assert log[-2].compare( + ... level='debug', + ... msg=r'- Cleanup succeeded \(3/3\): ' + ... '.*good_callback.*1.*', + ... regex=True, + ... ), f'{log[-2]=!r}' + >>> assert log[-1].compare( + ... level='debug', + ... msg='... cleanup completed ' + ... '(context exit; 3 callback(s))', + ... ), f'{log[-1]=!r}' + + >>> with MyCleanup() as cleanup: + ... pass + >>> log = cleanup.debug_log + >>> assert len(log) == 1, f'{log=!r}; {len(log)=!r}' + >>> assert log[-1].compare( + ... msg='Cleanup aborted (context exit; 0 callback(s))', + ... ), f'{log[-1]=!r}' + """ + log = self._debug_output + # Note: the doctest is mainly here for coverage purposes. + ncallbacks_total = sum(len(stack) for stack in stacks.values()) + note = f'{ncallbacks_total} callback(s)' + if reason: + note = f'{reason}; {note}' + if not ncallbacks_total: + log(f'Cleanup aborted ({note})') + return + # Bookend the cleanup loop with log messages to help detect if + # child processes are prematurely terminated + log(f'Starting cleanup ({note})...') + ncallbacks_run = 0 + for priority in sorted(stacks, reverse=True): + callbacks = stacks.pop(priority) + while callbacks: + callback = callbacks.pop() + callback_repr = _CALLBACK_REPR(callback) + ncallbacks_run += 1 + try: + callback() + except Exception as e: + success, state = False, 'failed' + msg = f'{callback_repr}: {type(e).__name__}: {e}' + else: + success, state, msg = True, 'succeeded', f'{callback_repr}' + msg = ( + f'- Cleanup {state} ' + f'({ncallbacks_run}/{ncallbacks_total}): {msg}' + ) + log(msg, 'debug' if success else 'warning') + log(f'... cleanup completed ({note})') + + def add_cleanup( + self, callback: Callable[PS, Any], *args: PS.args, **kwargs: PS.kwargs, + ) -> None: + """ + Shorthand for calling :py:meth:`~.add_cleanup_with_priority` + with ``priority=0``, which should be considered the default. + """ + self.add_cleanup_with_priority(callback, 0, *args, **kwargs) + + def add_cleanup_with_priority( + self, callback: Callable[PS, Any], priority: float, /, + *args: PS.args, **kwargs: PS.kwargs, + ) -> None: + """ + Add a cleanup callback to the internal stacks. + + Args: + callback (Callable[..., Any]): + Callback to be called at cleanup + priority (float): + Numeric priority value; callbacks with a HIGHER value + are invoked BEFORE those with lower values + *args, **kwargs: + Arguments ``callback`` should be called with + + Example: + >>> strings = [] + >>> cleanup = Cleanup() + >>> # Default priority + >>> cleanup.add_cleanup(strings.append, 'first') + >>> # Decreased priority + >>> cleanup.add_cleanup_with_priority( + ... strings.append, -1, 'second', + ... ) + >>> # Increased priority + >>> cleanup.add_cleanup_with_priority( + ... strings.append, 1, 'third', + ... ) + >>> cleanup.add_cleanup(strings.append, 'fourth') + >>> assert not strings + >>> cleanup.cleanup() + >>> strings + ['third', 'fourth', 'first', 'second'] + """ + if args or kwargs: + callback = partial(callback, *args, **kwargs) + self._current_context.setdefault(priority, []).append(callback) + header = 'Cleanup callback added' + if priority: + header = f'{header} (priority: {priority})' + self._debug_output(f'{header}: {_CALLBACK_REPR(callback)}') + + # Convenience methods + + def update_mapping( + self, mapping: MutableMapping[K, V], updates: Mapping[K, V], + ) -> None: + """ + Update a mapping with another and add cleanup callbacks to + reverse them. + + Args: + mapping (MutableMapping[K, V]): + Mapping to be updated + updates (Mapping[K, V]): + Mapping containing the updates + + Example: + >>> d1 = {1: 2, 3: 4} + >>> d2 = d1.copy() + >>> updates = {0: -1, 3: 5} + >>> with Cleanup() as cleanup: + ... cleanup.update_mapping(d1, updates) + ... for key, value in updates.items(): + ... assert d1[key] == value + ... + >>> assert d1 == d2 + """ + for key, value in updates.items(): + try: + old = mapping[key] + except KeyError: + self.add_cleanup(mapping.pop, key, None) + change = f'{value!r} (new)' + else: + self.add_cleanup(setitem, mapping, key, old) + change = f'{old!r} -> {value!r}' + msg = self._format_mapping_update_message(mapping, key, change) + self._debug_output(msg) + mapping[key] = value + + def make_tempfile( + self, *, delete: bool = True, priority: float = 0, **kwargs + ) -> Path: + """ + Create a fresh tempfile with :py:func:`tempfile.mkstemp`. + + Args: + delete (bool): + Whether to remove the file on cleanup + priority (float): + Cleanup priority (see + :py:meth:`~.add_cleanup_with_priority`) + **kwargs: + Passed to :py:func:`tempfile.mkstemp` + + Returns: + path (Path): + Path to the created file. + + Example: + >>> prefix, suffix = 'my_file_', '.txt' + >>> with Cleanup() as cleanup: + ... path = cleanup.make_tempfile( + ... prefix=prefix, suffix=suffix, + ... ) + ... assert path.exists() + ... assert path.name.startswith(prefix) + ... assert path.name.endswith(suffix) + ... + >>> assert not path.exists() + """ + path = make_tempfile(**kwargs) + self._debug_output(self._format_tempfile_creation_message(path)) + if delete: + self.add_cleanup_with_priority( + path.unlink, priority, missing_ok=True, + ) + return path + + def patch( + self, obj: Any, attr: str, value: Any, *, + name: str | None = None, + static: bool = True, + cleanup: bool = True, + priority: float = 0, + ) -> None: + """ + Patch an attribute on an object. + + Args: + obj (Any): + Object to be patched + attr (str): + Name of the attribute + value (Any): + Value to be assigned to said attribute of ``obj`` + name (str | None): + Optional name for ``obj`` to be used in debug messages + static (bool): + Whether to use :py:func:`inspect.getattr_static` to + get the current value of the attribute + cleanup (bool): + Whether to reverse the patch (by resetting or deleting + the attribute) on cleanup + priority (float): + Cleanup priority (see + :py:meth:`~.add_cleanup_with_priority`) + + Example: + >>> class Object: + ... pass # Allow setting arbitrary attributes + ... + >>> + >>> obj = Object() + >>> obj.foo = 1 + >>> with Cleanup() as cleanup: + ... cleanup.patch(obj, 'foo', 2) + ... cleanup.patch(obj, 'bar', 3) + ... cleanup.patch(obj, 'baz', 4, cleanup=False) + ... assert obj.foo == 2 + ... assert obj.bar == 3 + ... assert obj.baz == 4 # Not restored + ... + >>> assert obj.foo == 1 + >>> assert not hasattr(obj, 'bar') + >>> assert obj.baz == 4 + """ + if cleanup: + add_cleanup: Callable[ + Concatenate[Callable[..., Any], float, ...], Any + ] = self.add_cleanup_with_priority + else: + # ... yeah gotta disagree with flake8, a lambda makes + # perfect sense here + add_cleanup = lambda *_, **__: None # noqa: E731 + _, should_be_restored, old_value = self._get_attribute_info(obj, attr) + if should_be_restored: + add_cleanup(setattr, priority, obj, attr, old_value) + else: + add_cleanup(delattr, priority, obj, attr) + setattr(obj, attr, value) + if name is None: + name = self._get_name(obj) + msg = 'Patched `{}.{}` -> `{}`'.format(name, attr, value) + self._debug_output(msg) + + # Helper methods + + @staticmethod + def _get_attribute_info(obj: Any, attr: str) -> tuple[bool, bool, Any]: + """ + Returns: + result (tuple[bool, bool, Any]): + 3-tuple of the following: + + - Whether the object has the attribute + + - Whether the present attribute value (if any) should be + restored if changed + + - The attribute that should be restored (if any) + """ + try: + value = getattr(obj, attr) + except AttributeError: + return False, False, None + + try: + static_value = getattr_static(obj, attr) + except AttributeError: + has_static = False + else: + has_static = True + + if isinstance(obj, type) and has_static: + # Special-case classes: only restore if value not inherited + # from a base class + return True, (attr in vars(obj)), static_value + + try: + inherited_value = getattr(type(obj), attr) + except AttributeError: + # Two cases: + # - `has_static=True`: `value` is instance-bound (e.g. in + # `vars()`) + # -> Should be restored + # - `has_static=False`: `value` is calculated dynamically + # (via `.__getattr[ibute]__()`) + return True, has_static, value + + # If it is a settable data descriptor, reset it; else, leave it + # alone (i.e. delete the instance-bound override we assign to) + InheritedDescriptorType = type(inherited_value) + if not callable(getattr(InheritedDescriptorType, '__set__', None)): + is_settable = False + elif issubclass(InheritedDescriptorType, property): + # Special-case properties + is_settable = inherited_value.fset is not None + else: + is_settable = True + return True, is_settable, value + + @staticmethod + def _get_name(obj: Any, /) -> str: + """ + Get an appropriate name for an arbitrary object. + + Example: + >>> import textwrap + >>> + >>> + >>> Cleanup._get_name(textwrap) + 'textwrap' + >>> Cleanup._get_name(textwrap.dedent) + 'textwrap.dedent' + >>> Cleanup._get_name(str) + 'str' + >>> Cleanup._get_name(print) + 'print' + >>> Cleanup._get_name(object()) # doctest: +ELLIPSIS + '' + """ + if hasattr(obj, '__qualname__'): + name = obj.__qualname__ + elif hasattr(obj, '__name__'): + name = obj.__name__ + else: + return repr(obj) + if hasattr(obj, '__module__'): + if obj.__module__ not in ('builtins', '__builtins__'): + name = f'{obj.__module__}.{name}' + return str(name) + + def _debug_output(self, msg: str, /, level: LogLevel = 'debug') -> None: + """ + Write debugging output. + + Note: + This default implementation just writes to the logger at the + specified level. + """ + log_func = getattr(diagnostics.log, level) + log_func(msg) + + @staticmethod + def _format_mapping_update_message( + mapping: Mapping[K, Any], key: K, change: str, /, + ) -> str: + """ + Helper method used by :py:meth:`.update_mapping` to format debug + messages. + """ + mapping_repr = object.__repr__(mapping) + return f'Update {mapping_repr}[{key!r}]: {change}' + + @staticmethod + def _format_tempfile_creation_message(path: Path) -> str: + """ + Helper method used by :py:meth:`.make_tempfile` to format debug + messages. + """ + return f'Created tempfile: {path}' + + @property + def _current_context(self) -> _Stacks: + try: + return self._contexts[-1] + except IndexError: + ctx: _Stacks = {} + self._contexts.append(ctx) + return ctx diff --git a/line_profiler/curated_profiling.py b/line_profiler/curated_profiling.py new file mode 100644 index 00000000..c72f4b66 --- /dev/null +++ b/line_profiler/curated_profiling.py @@ -0,0 +1,473 @@ +""" +Tools for setting up profiling in a curated environment (e.g. with +the use of :py:mod:`kernprof`). + +The class :py:class:`ClassifiedPreimportTargets` is responsible for +classifying profiling targets (like those supplied by +:option:`!--prof-mod`). and feeding them onwards to the machineries of +:py:mod:`line_profiler.autoprofile.eager_preimports` (see documentation +therefor), writing a script which ensures that the profiling targets are +all presented to the session's **main profiler**. + +The class :py:class:`CuratedProfilerContext` is used for setting up a +profiling session, with a single associated +:py:class:`line_profiler.LineProfiler` instance as the +**main profiler**. Said profiler is installed to various global states +as appropriate, and will be the sole instance in the process for the +collection of profiling data directly associated with the session. The +installation will be torn worn as the session ends. + +Notes: + The intention is for there to be **at most one** profiling session, + **one** curated context, and **one** "main profiler" at any given + time in a single process. Using multiple instances may result in + undefined behavior. +""" +from __future__ import annotations + +import builtins +import dataclasses +import os +import warnings +from collections.abc import Collection +from io import StringIO +from textwrap import indent +from typing import Any, TextIO +from typing_extensions import Self + +from . import _diagnostics as diagnostics, profile as _GLOBAL_PROFILER +from ._threading_patches import apply as apply_threading_patches +from .autoprofile.autoprofile import ( + _extend_line_profiler_for_profiling_imports as upgrade_profiler, +) +from .autoprofile.util_static import modpath_to_modname +from .autoprofile.eager_preimports import ( + is_dotted_path, write_eager_import_module, +) +from .cleanup import Cleanup +from .cli_utils import short_string_path +from .explicit_profiler import GlobalProfiler +from .line_profiler import LineProfiler +from .profiler_mixin import ByCountProfilerMixin + + +__all__ = ('ClassifiedPreimportTargets', 'CuratedProfilerContext') + + +@dataclasses.dataclass +class ClassifiedPreimportTargets: + """ + Pre-import targets classified into three bins: :py:attr:`.regular` + targets, targets to :py:attr:`.recurse` into, and + :py:attr:`.invalid` targets. + """ + regular: list[str] = dataclasses.field(default_factory=list) + recurse: list[str] = dataclasses.field(default_factory=list) + invalid: list[str] = dataclasses.field(default_factory=list) + + def __bool__(self) -> bool: + return bool(self.regular or self.recurse) + + def write_preimport_module( + self, fobj: TextIO, *, debug: bool | None = None, **kwargs + ) -> None: + r""" + Convenience interface with + :py:func:`~.write_eager_import_module`, writing a module which + when imported sets up profiling of the targets. + + Args: + fobj (TextIO): + File object to write said module to. + debug (bool | None): + Whether to generate debugging outputs. + kwargs: + Passed to :py:func:`~.write_eager_import_module`. + + Example: + >>> from pathlib import Path + >>> from contextlib import ExitStack, redirect_stdout + >>> from os import devnull + >>> from tempfile import TemporaryDirectory + + >>> import pytest + + >>> with TemporaryDirectory() as tmpdir_: + ... tmpdir = Path(tmpdir_) + ... file = tmpdir / 'preimports.py' + ... targets = ClassifiedPreimportTargets.from_targets([ + ... 'inspect.getdoc', + ... str(tmpdir / 'nonexistent.py'), + ... ]) + ... with ExitStack() as stack: + ... enter = stack.enter_context + ... _ = enter(pytest.warns( + ... match='1 .* target cannot be converted .*' + ... r'nonexistent\.py', + ... )) + ... fobj = enter(file.open('w')) + ... _ = enter( + ... redirect_stdout(enter(open(devnull, 'a'))), + ... ) + ... targets.write_preimport_module(fobj) + ... line_matcher = pytest.LineMatcher( + ... file.read_text().splitlines(), + ... ) + + >>> line_matcher.re_match_lines([ + ... r'\s*import inspect', r'\s*add\(.*\bgetdoc\)', + ... ]) + """ + if debug is None: + debug = diagnostics.DEBUG + if self.invalid: + invalid_targets = sorted(set(self.invalid)) + 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, + ) + ) + # Log before warn in case the warning is raised + diagnostics.log.warning(msg) + warnings.warn(msg, stacklevel=2) + + if not self: + return None + # Note: `ty` (but not `mypy`) keeps complaining about our + # splatting this dict; explicitly use `Any` to tell it to shut + # up. + write_module_kwargs: dict[str, Any] = { + 'dotted_paths': self.regular, + 'recurse': self.recurse, + **kwargs, + } + if debug: # nocover + with StringIO() as sio: + write_eager_import_module(stream=sio, **write_module_kwargs) + code = sio.getvalue() + print(code, end='', file=fobj) + if hasattr(fobj, 'name'): + fobj_repr = repr(short_string_path(str(fobj.name))) + else: + fobj_repr = repr(fobj) # Fall back + diagnostics.log.debug( + f'Wrote temporary module for pre-imports to {fobj_repr}:\n' + + indent(code, ' ') + ) + else: + write_eager_import_module(stream=fobj, **write_module_kwargs) + + @classmethod + def from_targets( + cls, + targets: Collection[str], + exclude: Collection[os.PathLike[str] | str] = (), + ) -> Self: + """ + Create an instance based on a collection of targets + (like what is supplied to ``kernprof --prof-mod=...``). + + Args: + targets (Collection[str]): + Collection of dotted paths and filenames to profile. + exclude (Collection[str | os.PathLike[str]]): + Collections of filenames which are explicitly excluded + from being profiled. + + Return: + New instance. + + Example: + >>> import multiprocessing + >>> import os.path + >>> import textwrap + >>> import xml + >>> from importlib.util import find_spec + >>> from tempfile import TemporaryDirectory + + >>> get_targets = ClassifiedPreimportTargets.from_targets + >>> invalid_module = 'textwrapppppp' + >>> assert find_spec(invalid_module) is None + >>> nonexistent_target = textwrap.__file__.replace( + ... 'textwrap', invalid_module, + ... ) + + >>> with TemporaryDirectory() as tmpdir: + ... malformed_target = os.path.join(tmpdir, 'b-a-r.py') + ... with open(malformed_target, mode='w'): + ... pass # touch + ... excluded_target = os.path.join(tmpdir, 'excl.py') + ... with open(excluded_target, mode='w'): + ... pass # touch + ... + ... raw_targets = [ + ... 'sys', + ... # Could be invalid, but we don't know ATP + ... 'foo', + ... # Resolved to `'textwrap'` + ... textwrap.__file__, + ... # Invalid targets + ... nonexistent_target, malformed_target, + ... # This is valid, but will be excluded + ... excluded_target, + ... # Resolved to `'xml'` (non-recursed) + ... xml.__file__, + ... # Resolved to `'multiprocessing'` (recursed) + ... os.path.dirname(multiprocessing.__file__), + ... ] + ... tar = get_targets( + ... raw_targets, exclude=[excluded_target], + ... ) + + >>> all_targets = set().union(tar.regular, tar.recurse) + >>> assert { + ... 'sys', 'foo', 'textwrap', 'multiprocessing', + ... } <= all_targets, f'{all_targets=!r}' + >>> assert 'xml' in tar.regular, f'{tar.regular=!r}' + >>> assert 'excl' not in all_targets + >>> assert { + ... nonexistent_target, malformed_target, + ... } == set(tar.invalid), f'{tar=!r}; {tar.invalid=!r}' + + Notes: + The distinction between :py:attr:`.regular` and + :py:attr:`.recurse` is that packages in the former are + guaranteed to NOT be recursed into, while those in the + latter can be recursed into where appropriate (see + :py:func:`line_profiler.autoprofile.eager_preimports.\ +resolve_profiling_targets`). + Hence, modules and packages are classified into + :py:attr:`.recurse` by default; recursion into packages is + stopped (i.e. target classified into :py:attr:`.regular`) by + supplying a dotted path suffixed with ``.__init__`` or a + file path to the package's ``__init__.py``. + """ + filtered_targets = [] + recurse_targets = [] + invalid_targets = [] + for target in targets: + 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 not is_dotted_path(modname): + invalid_targets.append(target) + continue + if modname.endswith('.__init__'): + modname = modname.rpartition('.')[0] + filtered_targets.append(modname) + else: + recurse_targets.append(modname) + return cls(filtered_targets, recurse_targets, invalid_targets) + + +class CuratedProfilerContext: + """ + Context manager for handling various bookkeeping tasks when setting + up and tearing down profiling: + + - Slipping ``prof`` into the builtin namespace (if + ``insert_builtin`` is true) and the ``global_profiler`` instance + (default: :py:deco:`line_profiler.profile`) + + - Patch :py:class:`threading.Thread` so that line-profiling is + enabled on new threads if it is on the spawning threads + + - At exit, clearing the ``enable_count`` of ``prof``, properly + disabling it + + Notes: + + - The attributes on this object are to be considered + implementation details, but not its methods and their + signatures. + + - This is meant to be a functional singleton; NOT MORE THAN ONE + INSTANCE should be used in the process at any single given + moment. (See the module docstring.) + + - Entering the context more than once is undefined behavior. + """ + def __init__( + self, + prof: ByCountProfilerMixin, + *, + insert_builtin: bool = False, + builtin_loc: str = 'profile', + global_profiler: GlobalProfiler | None = None, + ) -> None: + if global_profiler is None: + global_profiler = _GLOBAL_PROFILER + self.prof = prof + self.insert_builtin = insert_builtin + self.builtin_loc = builtin_loc + self.global_profiler = global_profiler + self._cleanup = Cleanup() + self._installed = False + + def _global_install(self, prof: ByCountProfilerMixin | None) -> None: + """ + Overwrite the :py:class:`line_profiler.LineProfiler` instance + backing the :py:attr:`.global_profiler` and mark it as being + :py:attr:`GlobalProfiler.enabled`. + + Example: + >>> from operator import attrgetter + >>> from line_profiler import LineProfiler + >>> from line_profiler.explicit_profiler import ( + ... GlobalProfiler, + ... ) + + >>> get_prof_state = attrgetter('_profile', 'enabled') + >>> gp = GlobalProfiler() + >>> lp = LineProfiler() + >>> old_state = get_prof_state(gp) + + >>> with CuratedProfilerContext(lp, global_profiler=gp): + ... new_state = get_prof_state(gp) + ... assert ( + ... old_state != new_state == (lp, True) + ... ), f'{new_state=!r}, {old_state=!r}' + >>> assert ( + ... (new_state := get_prof_state(gp)) + ... == old_state + ... ), f'{new_state=!r}, {old_state=!r}' + + Notes: + Since we directly set :py:attr:`GlobalProfiler.enabled` + instead of calling :py:meth:`GlobalProfiler.enable`, this + doesn't register an :py:mod:`atexit` hook. This is what we + want because :py:mod:`kernprof` either instructs to use + another program to read its output file or calls + :py:meth:`line_profiler.LineStats.show` directly. + """ + # Note: refactored from the old + # `.GlobalProfiler._kernprof_overwrite()`. + self._cleanup.patch(self.global_profiler, '_profile', prof) + self._cleanup.patch(self.global_profiler, 'enabled', True) + + @staticmethod + def _disable_profiler(prof: ByCountProfilerMixin) -> None: + for _ in range(getattr(prof, 'enable_count', 0)): + prof.disable_by_count() + + def _install(self) -> None: + """ + Example: + >>> from pytest import raises + + >>> from line_profiler import LineProfiler + + >>> class BuggedContext(CuratedProfilerContext): + ... ''' + ... This class bugs out at the end of + ... :py:meth:`.install`, because it attempts to change + ... the value of :py:attr:`._installed`. + ... ''' + ... @property + ... def _installed(self) -> bool: + ... return self.__installed + ... + ... @_installed.setter + ... def _installed(self, installed: bool) -> None: + ... try: + ... self.__installed + ... except AttributeError: + ... self.__installed = installed + ... return + ... raise AttributeError('_installed') + + >>> prof = LineProfiler() + + Normal execution: + + >>> with CuratedProfilerContext( + ... prof, insert_builtin=True, builtin_loc='foo', + ... ): + ... assert foo is prof # `foo` inserted above + >>> with raises(NameError): + ... assert foo is not prof # `foo` reverted + + Botched installation: + + >>> # Context managed + >>> with raises(AttributeError, match='_installed'): + ... with BuggedContext( + ... prof, insert_builtin=True, builtin_loc='foo', + ... ): + ... raise RuntimeError # Unreachable (setup failed) + ... with raises(NameError): + ... assert foo is not prof # `foo` reverted + + >>> # Explicit invocation + >>> ctx = BuggedContext( + ... prof, insert_builtin=True, builtin_loc='foo', + ... ) + >>> with raises(AttributeError, match='_installed'): + ... ctx.install() + >>> with raises(NameError): + ... assert foo is not prof # `foo` reverted + """ + if self._installed: + return + cleanup = self._cleanup + # Equip the profiler instance with the + # `.add_imported_function_or_module()` pseudo-method + upgrade_profiler(self.prof, cleanup=cleanup) + # Overwrite the explicit profiler (`@line_profiler.profile`) + self._global_install(self.prof) + # Patch `threading` + if isinstance(self.prof, LineProfiler): + apply_threading_patches(cleanup, self.prof) + # Set up hooks to deal with inserting `.prof` as a builtin name + if self.insert_builtin: + cleanup.patch(builtins, self.builtin_loc, self.prof) + # Disable the profiler at session exit + cleanup.add_cleanup(self._disable_profiler, self.prof) + # Indicate that we shouldn't redo the installation as a failsafe + cleanup.patch(self, '_installed', True) + + def install(self) -> None: + """ + Perform setup (see the class docstring). + """ + try: + self._install() + except BaseException as e: + # If anything goes south, immediately roll back all the + # installed changes + xc = type(e).__name__ + if (detail := str(xc)): + xc = f'{xc}: {detail}' + try: # This shouldn't raise, but just in case... + self._cleanup.cleanup(reason=f'installation failed ({xc})') + finally: + raise e + + def uninstall(self) -> None: + """ + Tear down all the setup. + """ + self._cleanup.cleanup(reason='uninstalling profiling context') + + def __enter__(self) -> Self: + self.install() + return self + + def __exit__(self, *_, **__) -> None: + self.uninstall() diff --git a/line_profiler/explicit_profiler.py b/line_profiler/explicit_profiler.py index 88c3fc9f..3884ba25 100644 --- a/line_profiler/explicit_profiler.py +++ b/line_profiler/explicit_profiler.py @@ -311,16 +311,6 @@ def __init__(self, config: ConfigArg = None) -> None: # supplied `config`) self.show_config.pop('column_widths') - def _kernprof_overwrite(self, profile: LineProfiler) -> None: - """ - Kernprof will call this when it runs, so we can use its profile object - instead of our own. Note: when kernprof overwrites us we wont register - an atexit hook. This is what we want because kernprof wants us to use - another program to read its output file. - """ - self._profile = profile - self.enabled = True - def _implicit_setup(self) -> None: """ Called once the first time the user decorates a function with diff --git a/line_profiler/line_profiler.py b/line_profiler/line_profiler.py index 1be5ea8c..7dfdf41d 100755 --- a/line_profiler/line_profiler.py +++ b/line_profiler/line_profiler.py @@ -1,15 +1,14 @@ #!/usr/bin/env python """ -This module defines the core :class:`LineProfiler` class as well as methods to -inspect its output. This depends on the :py:mod:`line_profiler._line_profiler` -Cython backend. +This module defines the core :py:class:`LineProfiler` class as well as +methods to inspect its output. This depends on the +:py:mod:`line_profiler._line_profiler` Cython backend. """ from __future__ import annotations import functools import io -import inspect import linecache import operator import os @@ -18,32 +17,23 @@ import tempfile import types import tokenize +import warnings from argparse import ArgumentParser +from collections.abc import Callable, Collection, Mapping, Sequence from datetime import datetime from os import PathLike -from typing import ( - TYPE_CHECKING, - IO, - Callable, - Literal, - Mapping, - Protocol, - Sequence, - TypeVar, - cast, - Tuple, -) +from typing import TYPE_CHECKING, IO, Any, Literal, Protocol, TypeVar, cast try: from ._line_profiler import ( LineProfiler as CLineProfiler, LineStats as CLineStats, ) -except ImportError as ex: +except ImportError as ex: # nocover raise ImportError( 'The line_profiler._line_profiler c-extension is not importable. ' f'Has it been compiled? Underlying error is ex={ex!r}' - ) + ) from ex from . import _diagnostics as diagnostics from .cli_utils import ( add_argument, @@ -51,20 +41,24 @@ positive_float, short_string_path, ) +from .line_profiler_utils import clone_single_module from .profiler_mixin import ByCountProfilerMixin, is_c_level_callable from .scoping_policy import ScopingPolicy, ScopingPolicyDict from .toml_config import ConfigSource if TYPE_CHECKING: # pragma: no cover + import inspect as _inspect_patched from typing_extensions import ParamSpec, Self class _IPythonLike(Protocol): def register_magics(self, magics: type) -> None: ... PS = ParamSpec('PS') - _TimingsMap = Mapping[Tuple[str, int, str], list[Tuple[int, int, int]]] + _TimingsMap = Mapping[tuple[str, int, str], list[tuple[int, int, int]]] T = TypeVar('T') T_co = TypeVar('T_co', covariant=True) +else: + _inspect_patched = clone_single_module('inspect') ColumnLiterals = Literal['line', 'hits', 'time', 'perhit', 'percent'] @@ -81,7 +75,6 @@ def get_column_widths( Args: config (bool | str | None): Passed to :py:meth:`.ConfigSource.from_config`. - Note: * Results are cached. * The default value (:py:data:`False`) loads the config from the @@ -132,13 +125,11 @@ def get_code_block(filename: os.PathLike[str] | str, lineno: int) -> list[str]: >>> from os.path import join >>> from tempfile import TemporaryDirectory >>> from textwrap import dedent - >>> - >>> + >>> def get_last_line(*args, **kwargs): ... lines = get_code_block(*args, **kwargs) ... return lines[-1].rstrip('\\n') - ... - >>> + >>> with TemporaryDirectory() as tmpdir: ... fname = join(tmpdir, 'cython_source.pyx') ... with open(fname, mode='w') as fobj: @@ -186,18 +177,12 @@ def get_code_block(filename: os.PathLike[str] | str, lineno: int) -> list[str]: ... # - `cython_function()` ... assert get_last_line(fname, 22).endswith('# 24') """ - BlockFinder = inspect.BlockFinder - namespace = inspect.getblock.__globals__ - namespace['BlockFinder'] = _CythonBlockFinder - try: - return inspect.getblock( - linecache.getlines(os.fspath(filename))[lineno - 1 :] - ) - finally: - namespace['BlockFinder'] = BlockFinder + return _inspect_patched.getblock( + linecache.getlines(os.fspath(filename))[lineno - 1:], + ) -class _CythonBlockFinder(inspect.BlockFinder): +class _CythonBlockFinder(_inspect_patched.BlockFinder): """ Compatibility layer turning Cython-specific code blocks (``cdef``, ``cpdef``, and legacy ``property`` declaration) into something that @@ -208,7 +193,6 @@ class _CythonBlockFinder(inspect.BlockFinder): is public but undocumented API. See similar caveat in :py:func:`~.get_code_block`. """ - def tokeneater( self, type: int, @@ -227,6 +211,21 @@ def tokeneater( return super().tokeneater(type, token, srowcol, erowcol, line) +# We only need our copy of `inspect` for `get_code_block()`, so just +# directly overwrite the `BlockFinder` class there instaed of using +# the monkey-patching facilities +_inspect_patched.BlockFinder = _CythonBlockFinder # type: ignore + + +class _EmptyFileError(OSError): + """ + Error raised when trying to read profiling data from an empty file. + """ + def __init__(self, file: PathLike[str] | str) -> None: + super().__init__(str(file)) + self.file = file + + class _WrapperInfo: """ Helper object for holding the state of a wrapper function. @@ -265,8 +264,8 @@ def __eq__(self, other: object) -> bool: Example: >>> from copy import deepcopy >>> stats1 = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 2, 1000), (12, 1, 500)]}, ... 1E-6) >>> stats2 = deepcopy(stats1) @@ -275,7 +274,7 @@ def __eq__(self, other: object) -> bool: >>> assert stats2 != stats1 >>> stats3 = deepcopy(stats1) >>> assert stats1 == stats3 is not stats1 - >>> stats3.timings['foo', 1, 'spam.py'][:] = [(2, 11, 330)] + >>> stats3.timings['spam.py', 1, 'foo'][:] = [(2, 11, 330)] >>> assert stats3 != stats1 """ for attr in 'timings', 'unit': @@ -291,20 +290,20 @@ def __add__(self, other: _StatsLike) -> Self: """ Example: >>> stats1 = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 2, 1000), (12, 1, 500)]}, ... 1E-6) >>> stats2 = LineStats( - ... {('bar', 10, 'spam.py'): + ... {('spam.py', 10, 'bar'): ... [(11, 10, 20000), (12, 5, 1000)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 5000)]}, + ... ('eggs.py', 5, 'baz'): [(5, 2, 5000)]}, ... 1E-7) >>> stats_sum = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 12, 3000), (12, 6, 600)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 500)]}, + ... ('eggs.py', 5, 'baz'): [(5, 2, 500)]}, ... 1E-6) >>> assert stats1 + stats2 == stats2 + stats1 == stats_sum """ @@ -315,20 +314,20 @@ def __iadd__(self, other: _StatsLike) -> Self: """ Example: >>> stats1 = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 2, 1000), (12, 1, 500)]}, ... 1E-6) >>> stats2 = LineStats( - ... {('bar', 10, 'spam.py'): + ... {('spam.py', 10, 'bar'): ... [(11, 10, 20000), (12, 5, 1000)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 5000)]}, + ... ('eggs.py', 5, 'baz'): [(5, 2, 5000)]}, ... 1E-7) >>> stats_sum = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 12, 3000), (12, 6, 600)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 500)]}, + ... ('eggs.py', 5, 'baz'): [(5, 2, 500)]}, ... 1E-6) >>> address = id(stats2) >>> stats2 += stats1 @@ -338,6 +337,114 @@ def __iadd__(self, other: _StatsLike) -> Self: self.timings, self.unit = self._get_aggregated_timings([self, other]) return self + def __sub__(self, other: _StatsLike) -> Self: + """ + Subtract a "baseline" from this instance; the inverse of + :py:meth:`~.__add__`. Entries which reach zero hits and zero + time are dropped. The result is expressed in ``self``'s + :py:attr:`~.unit`. + + Raises: + ValueError: + If ``other`` contains an entry absent from (or larger + than the corresponding entry in) ``self``; + a valid baseline must ``self``. + + Example: + >>> baseline = LineStats( + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): + ... [(11, 2, 1000), (12, 1, 500)]}, + ... 1E-6) + >>> new = LineStats( + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): + ... [(11, 12, 3000), (12, 6, 600)], + ... ('eggs.py', 5, 'baz'): [(5, 2, 500)]}, + ... 1E-6) + >>> new - baseline + LineStats({('spam.py', 10, 'bar'): [(11, 10, 2000), \ +(12, 5, 100)], ('eggs.py', 5, 'baz'): [(5, 2, 500)]}, 1E-06) + >>> assert (new - baseline) + baseline == new + >>> new - new + LineStats({}, 1E-06) + >>> baseline - new + Traceback (most recent call last): + ... + ValueError: ...cannot be a baseline... + """ + timings, unit = self._get_subtracted_timings(self, other) + return type(self)(timings, unit) + + def __isub__(self, other: _StatsLike) -> Self: + """ + In-place version of :py:meth:`~.__sub__`. + + Example: + >>> baseline = LineStats( + ... {('spam.py', 1, 'foo'): [(2, 10, 300)]}, 1E-6) + >>> stats = LineStats( + ... {('spam.py', 1, 'foo'): [(2, 15, 450)]}, 1E-6) + >>> address = id(stats) + >>> stats -= baseline + >>> assert id(stats) == address + >>> stats + LineStats({('spam.py', 1, 'foo'): [(2, 5, 150)]}, 1E-06) + """ + self.timings, self.unit = self._get_subtracted_timings(self, other) + return self + + @staticmethod + def _get_subtracted_timings(minuend, subtrahend): + """ + Compute ``minuend - subtrahend`` timings, expressed in + ``minuend.unit``; see :py:meth:`~.__sub__`. + """ + def prefix_error(reason): + return ValueError( + 'subtrahend cannot be a baseline of the minuend: ' + f'{reason}' + ) + + unit = minuend.unit + factor = subtrahend.unit / unit + timings = { + key: {lineno: (nhits, time) for lineno, nhits, time in entries} + for key, entries in minuend.timings.items() + } + for key, entries in subtrahend.timings.items(): + try: + min_entries = timings[key] + except KeyError: + raise prefix_error(f'{key!r} not in the minuend') from None + for lineno, nhits, time in entries: + try: + prev_nhits, prev_time = min_entries[lineno] + except KeyError: + raise prefix_error( + f'line {lineno} of {key!r} not in the minuend' + ) from None + new_nhits = prev_nhits - nhits + new_time = int(round(prev_time - factor * time, 0)) + if new_nhits < 0 or new_time < 0: + raise prefix_error( + f'line {lineno} of {key!r}: ' + f'({prev_nhits}, {prev_time}) - ({nhits}, {time})' + + ('' if factor == 1 else f' * {factor}') + + f' = ({new_nhits}, {new_time})' + ) + if new_nhits or new_time: + min_entries[lineno] = new_nhits, new_time + else: + del min_entries[lineno] + return { + key: [ + (lineno, nhits, time) + for lineno, (nhits, time) in sorted(entries.items()) + ] + for key, entries in timings.items() if entries + }, unit + def print( self, stream: io.TextIOBase | None = None, @@ -368,17 +475,105 @@ def to_file(self, filename: PathLike[str] | str) -> None: with open(filename, 'wb') as f: pickle.dump(self, f, pickle.HIGHEST_PROTOCOL) + @classmethod + def get_empty_instance(cls) -> Self: + """ + Returns: + instance (LineStats): + New instance without any profiling data. + """ + prof = LineProfiler() + if TYPE_CHECKING: + assert hasattr(prof, 'timer_unit') + return cls({}, cast(float, prof.timer_unit)) + @classmethod def from_files( - cls, file: PathLike[str] | str, /, *files: PathLike[str] | str + cls, + file: PathLike[str] | str, + /, + *files: PathLike[str] | str, + on_empty: Literal['ignore', 'warn', 'error'] = 'warn', + on_defective: Literal['ignore', 'warn', 'error'] = 'error', + _note_on_empty: str | None = None, + _note_on_defective: str | None = None, ) -> Self: """ Utility function to load an instance from the given filenames. + + Args: + file (PathLike[str] | str): + File to load profiling data from + *files (PathLike[str] | str): + Ditto above + on_empty, on_defective (Literal['ignore', 'warn', 'error']): + What to do if some files are empty (resp. otherwise fail + to load): ``'ignore'`` those files, skip them but with a + ``'warn'``-ing, or raise the ``'error'`` as soon as one + is encountered + + Returns: + instance (LineStats): + New instance """ stats_objs = [] - for file in [file, *files]: - with open(file, 'rb') as f: - stats_objs.append(pickle.load(f)) + failures: dict[str, str] = {} + empty_files: set[str] = set() + all_files = [file, *files] + + for file in all_files: + try: + if not os.stat(file).st_size: + raise _EmptyFileError(file) + with open(file, 'rb') as f: + maybe_statlike = cast(_StatsLike, pickle.load(f)) + # Pass it through `.from_stats_objects()` for a basic + # structural check + stats_objs.append(cls.from_stats_objects(maybe_statlike)) + except _EmptyFileError as e: + if on_empty == 'error': + raise + empty_files.add(str(e.file)) + except Exception as e: + if on_defective == 'error': + raise + failure = type(e).__name__ + if str(e): + failure = f'{failure}: {e}' + failures[str(file)] = failure + + problems: Collection[Any] + for problems, description, behavior, note in [ + ( + list(empty_files), + 'is/are empty and thus skipped', + on_empty, + _note_on_empty, + ), + ( + failures, + 'cannot be loaded and thus is/are skipped', + on_defective, + _note_on_defective, + ), + ]: + if not problems: + continue + msg = '{} file(s) out of {} {}: {!r}'.format( + len(problems), len(all_files), description, problems, + ) + if note: + msg = f'{msg}; {note}' + if behavior == 'warn': + # Log before warning because warnings may be promoted to + # errors + diagnostics.log.warning(msg) + warnings.warn(msg, stacklevel=2) + else: # 'ignore' + diagnostics.log.debug(msg) + + if not stats_objs: + return cls.get_empty_instance() return cls.from_stats_objects(*stats_objs) @classmethod @@ -388,23 +583,23 @@ def from_stats_objects( """ Example: >>> stats1 = LineStats( - ... {('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... {('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 2, 1000), (12, 1, 500)]}, ... 1E-6) >>> stats2 = LineStats( - ... {('bar', 10, 'spam.py'): + ... {('spam.py', 10, 'bar'): ... [(11, 10, 20000), (12, 5, 1000)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 5000)]}, + ... ('eggs.py', 5, 'baz'): [(5, 2, 5000)]}, ... 1E-7) >>> stats_combined = LineStats.from_stats_objects( ... stats1, stats2) >>> assert stats_combined.unit == 1E-6 >>> assert stats_combined.timings == { - ... ('foo', 1, 'spam.py'): [(2, 10, 300)], - ... ('bar', 10, 'spam.py'): + ... ('spam.py', 1, 'foo'): [(2, 10, 300)], + ... ('spam.py', 10, 'bar'): ... [(11, 12, 3000), (12, 6, 600)], - ... ('baz', 5, 'eggs.py'): [(5, 2, 500)]} + ... ('eggs.py', 5, 'baz'): [(5, 2, 500)]} """ timings, unit = cls._get_aggregated_timings([stats, *more_stats]) return cls(timings, unit) @@ -841,7 +1036,7 @@ def show_func( func_name (str): name of profiled function - timings (List[Tuple[int, int, float]]): + timings (list[tuple[int, int, float]]): Measurements for each line (lineno, nhits, time). unit (float): diff --git a/line_profiler/line_profiler_utils.py b/line_profiler/line_profiler_utils.py index 706df475..ab8d23f3 100644 --- a/line_profiler/line_profiler_utils.py +++ b/line_profiler/line_profiler_utils.py @@ -5,15 +5,30 @@ from __future__ import annotations import enum +import os +import sys from collections.abc import ( Callable, Collection, Mapping, MutableMapping, MutableSequence, Sequence, ) -from functools import wraps +from functools import partial, wraps +from importlib.util import find_spec from operator import methodcaller -from typing import TYPE_CHECKING, Any, Generic, TypeVar, final -from typing_extensions import Self, ParamSpec - +from pathlib import Path +from reprlib import Repr +from tempfile import mkstemp +from textwrap import indent +from types import MethodType, ModuleType +from typing import TYPE_CHECKING, Any, Generic, TypedDict, TypeVar, final +from typing_extensions import Self, ParamSpec, Unpack + + +__all__ = ( + 'StringEnum', 'restore', 'CallbackRepr', + 'block_indent', 'clone_single_module', 'make_tempfile', +) +# Note: `typing.AnyStr` deprecated since 3.13 +AnyStr = TypeVar('AnyStr', str, bytes) T = TypeVar('T') K = TypeVar('K') V = TypeVar('V') @@ -272,3 +287,304 @@ def instance_dict( False """ return cls.mapping(vars(obj), attrs) + + +class _ReprAttributes(TypedDict, total=False): + """ + Note: + We use this typed dict instead of directly supplying them in the + :py:meth:`CallbackRepr.__init__()` signature, because we don't + want to bother with the default values there. + """ + maxlevel: int + maxtuple: int + maxlist: int + maxarray: int + maxdict: int + maxset: int + maxfrozenset: int + maxdeque: int + maxstring: int + maxlog: int + maxother: int + fillvalue: str + indent: str | int | None + + +class CallbackRepr(Repr): + """ + :py:class:`reprlib.Repr` subclass to help with representing cleanup + callbacks, special-casing certain relevant object types (see + examples below). + + Example: + >>> from functools import partial + >>> from sys import version_info + + >>> class MyEnviron(dict): + ... def some_method(self) -> None: + ... ... + ... + >>> + >>> class MyRepr(CallbackRepr): + ... # Since we can't instantiate a new `os._Environ`, test + ... # the relevant method with a mock + ... repr_MyEnviron = CallbackRepr.repr__Environ + ... + >>> + >>> r = MyRepr(maxenv=3, maxargs=4, maxstring=15) + + Environ-dict formatting: + + >>> my_env = MyEnviron( + ... foo='1', + ... bar='2', + ... this_varname_is_long_but_isnt_truncated=( + ... "THIS VALUE IS TRUNCATED BECAUSE IT'S TOO LONG" + ... ), + ... baz='4', + ... ) + >>> print(r.repr(my_env)) + environ({'foo': '1', 'bar': '2', \ +'this_varname_is_long_but_isnt_truncated': 'THIS ... LONG', ...}) + + Partial-object formatting: + + >>> r.maxenv = 0 + >>> print(r.repr(my_env.some_method)) + + + Bound-method formatting: + + >>> r.maxargs = 0 + >>> callback_1 = partial(int, base=8) + >>> print(r.repr(callback_1)) + functools.partial(, ...) + + Indentation (Python 3.12+): + + >>> if version_info < (3, 12): + ... from pytest import skip + ... + ... skip( + ... '`Repr.indent` not available on {}.{},{}' + ... .format(*sys.version_info) + ... ) + + >>> r = MyRepr(maxenv=2, maxargs=4) + >>> r.indent = 2 + >>> callback_1 = partial(int, base=8) + >>> print(r.repr(callback_1)) + functools.partial( + , + base=8, + ) + + >>> callback_2 = partial(min, 5, 4, 3, 2, 1) + >>> r.indent = '----' + >>> print(r.repr(callback_2)) + functools.partial( + ----, + ----5, + ----4, + ----3, + ----2, + ----..., + ) + + >>> r.indent = ' ' + >>> r.maxenv = 2 + >>> print(r.repr(my_env.some_method)) + + """ + def __init__( + self, + *, + maxargs: int = 5, + maxenv: int = 3, + **kwargs: Unpack[_ReprAttributes] + ) -> None: + super().__init__() # kwargs are 3.12+ + valid_kwargs = ( + _ReprAttributes.__optional_keys__ + | _ReprAttributes.__required_keys__ + ) + for k, v in kwargs.items(): + if k in valid_kwargs: + setattr(self, k, v) + self.maxargs = maxargs + self.maxenv = maxenv + + def repr__Environ(self, env: os._Environ[AnyStr], level: int) -> str: + """ + Format :py:data:`os.environ` or :py:data:`os.environb`. + """ + get: Callable[[AnyStr], str] = partial(self.repr1, level=level-1) + # Truncate envvar values, but not their names + envvars = ['{!r}: {}'.format(k, get(v)) for k, v in env.items()] + return self._format_items(envvars, ('environ({', '})'), self.maxenv) + + def repr_method(self, method: MethodType, level: int) -> str: + """ + Format a :py:class:`types.MethodType`. + """ + instance = self.repr1(method.__self__, level-1) + func = getattr(method.__func__, '__qualname__', '?') + prefix, suffix = f'' + # Take care of possible multi-line reprs + return block_indent(instance, prefix) + suffix + + def repr_partial(self, ptl: partial, level: int) -> str: + """ + Format a :py:func:`functools.partial`. + """ + name = '{0.__module__}.{0.__qualname__}'.format(type(ptl)) + # The +1 is to account for `ptl.func` + return self._format_call( + level, (name + '(', ')'), self.maxargs + 1, + [ptl.func, *ptl.args], ptl.keywords, + ) + + def format_call(self, /, *args, **kwargs) -> str: + """ + Convenience method for Formatting a call a la + :py:meth:`inspect.BoundArguments.__str__`. + + Example: + >>> r = CallbackRepr(maxargs=3, maxlist=3) + >>> print(r.format_call( + ... [1, 2, 3, 4, 5], 'foo', spam=1, ham=2, + ... )) + ([1, 2, 3, ...], 'foo', spam=1, ...) + """ + return self._format_call( + self.maxlevel, ('(', ')'), self.maxargs, args, kwargs, + ) + + def _format_call( + self, + level: int, + delims: tuple[str, str], + maxargs: int, + args: Sequence[Any], + kwargs: Mapping[str, Any], + ) -> str: + get: Callable[[Any], str] = partial(self.repr1, level=level-1) + args = [get(arg) for arg in args] + args.extend('{}={}'.format(k, get(v)) for k, v in kwargs.items()) + return self._format_items(args, delims, maxargs) + + def _format_items( + self, + items: Collection[str], + delims: tuple[str, str], + maxlen: int | None = None, + ) -> str: + start, end = delims + if maxlen is not None and len(items) > maxlen: + items = list(items)[:maxlen] + ['...'] + indent_prefix: str | None = self._get_indent() + if indent_prefix is None or not items: + return '{}{}{}'.format(start, ', '.join(items), end) + return '\n'.join([ + start, *(indent(item + ',', indent_prefix) for item in items), end, + ]) + + if sys.version_info >= (3, 12): + # Note: `.indent` only available since 3.12 + def _get_indent(self) -> str | None: + indent = self.indent + if indent is None or isinstance(indent, str): + return indent + return ' ' * indent + else: + @staticmethod + def _get_indent() -> None: + return None + + +def block_indent(string: str, prefix: str, fill_char: str = ' ') -> str: + r""" + Example: + >>> string = 'foo\nbar\nbaz' + >>> print(string) + foo + bar + baz + >>> print(block_indent(string, '++++', '-')) + ++++foo + ----bar + ----baz + """ + width = len(prefix) + return prefix + indent(string, fill_char * width)[width:] + + +def clone_single_module(module: str | ModuleType) -> ModuleType: + r""" + Returns: + module_clone (ModuleType): + Module object, which is a fresh copy of the module (named) + ``module`` + + Example: + >>> import sys + >>> import textwrap + + >>> textwrap_clone = clone_single_module(textwrap) + >>> assert ( + ... sys.modules['textwrap'] + ... is textwrap + ... is not textwrap_clone + ... ) + >>> assert textwrap.indent is not textwrap_clone.indent + >>> assert ( + ... textwrap.indent('x\n\ny', ' ') + ... == textwrap_clone.indent('x\n\ny', ' ') + ... == ' x\n\n y' + ... ) + """ + if isinstance(module, ModuleType): + module = module.__name__ + spec = find_spec(module) + if spec is None: + raise ModuleNotFoundError(module) + assert spec.loader + assert callable(getattr(spec.loader, 'exec_module', None)) + + module = ModuleType(spec.name) + for attr, value in { + '__spec__': spec, + '__name__': spec.name, + '__file__': spec.origin, + '__path__': spec.submodule_search_locations, + }.items(): + if value is not None: + setattr(module, attr, value) + + spec.loader.exec_module(module) + return module + + +def make_tempfile(**kwargs) -> Path: + """ + Convenience wrapper around :py:func:`tempfile.mkstemp`, discarding + and closing the integer handle (which if left unattended causes + problems on some platforms). + + Note: + If for whatever reason the handle cannot be closed, the function + errors out and the tempfile is deleted. + """ + handle, fname = mkstemp(**kwargs) + path = Path(fname) + try: + os.close(handle) + return path + except Exception: + path.unlink() + raise diff --git a/line_profiler/toml_config.py b/line_profiler/toml_config.py index 781dc60d..67ee07ab 100644 --- a/line_profiler/toml_config.py +++ b/line_profiler/toml_config.py @@ -100,13 +100,23 @@ def get_subconfig( ... == default.subtable + ['show', 'column_widths']) >>> assert (display_widths.conf_dict ... is default.conf_dict['show']['column_widths']) + >>> display_widths_copy = default.get_subconfig( + ... 'show', 'column_widths', copy=True) + >>> assert ( + ... display_widths.conf_dict + ... == display_widths_copy.conf_dict + ... is not display_widths.conf_dict + ... ) """ new_dict = cast( Dict[str, Any], get_subtable(self.conf_dict, headers, allow_absence=allow_absence), ) new_subtable = [*self.subtable, *headers] - return type(self)(new_dict, self.path, new_subtable) + new_instance = type(self)(new_dict, self.path, new_subtable) + if copy: + new_instance = new_instance.copy() + return new_instance @classmethod def from_default(cls, *, copy: bool = True) -> ConfigSource: @@ -355,7 +365,8 @@ def iter_configs(dir_path): def get_subtable( - table: Mapping[K, Mapping], keys: Sequence[K], *, allow_absence: bool = True + table: Mapping[K, Mapping], keys: Sequence[K], *, + allow_absence: bool = True, ) -> Mapping: """ Arguments: diff --git a/tests/test_cleanup.py b/tests/test_cleanup.py new file mode 100644 index 00000000..1424bbc2 --- /dev/null +++ b/tests/test_cleanup.py @@ -0,0 +1,397 @@ +""" +Misc. tests for :py:mod:`line_profiler.cleanup`. +""" +from __future__ import annotations + +from collections.abc import Callable +from functools import partial +from inspect import getattr_static +from types import MethodType +from typing import Any, ClassVar, cast +from typing_extensions import Self + +import pytest + +from line_profiler.cleanup import Cleanup + + +class _Cases: + def __init__(self) -> None: + self.cases: dict[str, Callable[..., None]] = {} + + def add_case( + self, name: str, func: Callable[..., Any], /, *args, **kwargs + ) -> Self: + if args or kwargs: + func = partial(func, *args, **kwargs) + self.cases[name] = func + return self + + def run_case(self, name: str, /, *args, **kwargs) -> Self: + self.cases[name](*args, **kwargs) + return self + + +class Object: + _dd: int + + def __init__(self, dd: int | None = None) -> None: + if dd is not None: + self.data_descriptor = dd + + def __dir__(self) -> list[str]: + return [*object.__dir__(self), 'id'] + + def __getattr__(self, attr: str) -> Any: + if attr == 'dynamic_attr': + return 0 + raise AttributeError(attr) + + def instance_method(self) -> tuple[Self, int]: + return self, 1 + + @classmethod + def class_method(cls) -> tuple[type[Self], int]: + return cls, 2 + + @staticmethod + def static_method() -> int: + return 3 + + @property + def data_descriptor(self) -> int: + try: + return self._dd + except AttributeError: + self._dd = 4 + return self._dd + + @data_descriptor.setter + def data_descriptor(self, dd: int) -> None: + self._dd = dd + + attr_on_class: ClassVar[int] = 5 + + +class InheritedObject(Object): + pass + + +def _test_instance_method( + obj: Object, expected_old: int, expected_new: int, +) -> None: + assert expected_old != expected_new + + Class = type(obj) + old_inst_method_impl = Class.instance_method + impl_is_local = 'instance_method' in vars(Class) + + # ---------------------- Patch on class level ---------------------- + + # Before patch + assert obj.instance_method() == (obj, expected_old) + + with Cleanup() as cleanup: + cleanup.patch( + Class, 'instance_method', lambda self: (self, expected_new), + ) + # Post patch + assert 'instance_method' in vars(Class) + assert obj.instance_method() == (obj, expected_new) + # Patch reversal + # - Instance level (dynamic) + assert obj.instance_method() == (obj, expected_old) + assert obj.instance_method == MethodType(old_inst_method_impl, obj) + # - Class level + assert ('instance_method' in vars(Class)) == impl_is_local + assert Class.instance_method == old_inst_method_impl + + # ---------------------- Patch on inst. level ---------------------- + + with Cleanup() as cleanup: + cleanup.patch( + obj, 'instance_method', + MethodType(lambda self: (self, expected_new), obj), + ) + # Post patch + assert 'instance_method' in vars(obj) + assert obj.instance_method() == (obj, expected_new) + # Patch reversal + # - Instance level (dynamic) + assert obj.instance_method() == (obj, expected_old) + assert obj.instance_method == MethodType(old_inst_method_impl, obj) + # - Instance level (static) + assert 'instance_method' not in vars(obj) + assert getattr_static(obj, 'instance_method') == old_inst_method_impl + + +def _test_class_method( + obj: Object, expected_old: int, expected_new: int, +) -> None: + assert expected_old != expected_new + + Class = type(obj) + old_cls_method_obj = cast( + 'classmethod[Object, ..., tuple[type[Object], int]]', + getattr_static(Class, 'class_method'), + ) + impl_is_local = 'class_method' in vars(Class) + + # ---------------------- Patch on class level ---------------------- + + # Before patch + assert obj.class_method() == (Class, expected_old) + assert Class.class_method() == (Class, expected_old) + with Cleanup() as cleanup: + cleanup.patch( + Class, 'class_method', + classmethod(lambda Class: (Class, expected_new)), + ) + # Post patch + assert 'class_method' in vars(Class) + assert Class.class_method() == (Class, expected_new) + assert obj.class_method() == (Class, expected_new) + # Patch reversal + # - Instance level (dynamic) + assert obj.class_method() == (Class, expected_old) + assert obj.class_method == MethodType(old_cls_method_obj.__func__, Class) + # - Class level + assert ('class_method' in vars(Class)) == impl_is_local + assert Class.class_method() == (Class, expected_old) + assert Class.class_method == MethodType(old_cls_method_obj.__func__, Class) + assert getattr_static(Class, 'class_method') is old_cls_method_obj + + # ---------------------- Patch on inst. level ---------------------- + + with Cleanup() as cleanup: + cleanup.patch( + obj, 'class_method', + MethodType(lambda Class: (Class, expected_new), Class), + ) + # Post patch + assert 'class_method' in vars(obj) + assert obj.class_method() == (Class, expected_new) + # Patch reversal + # - Instance level (dynamic) + assert obj.class_method() == (Class, expected_old) + assert obj.class_method == MethodType(old_cls_method_obj.__func__, Class) + # - Instance level (static) + assert 'class_method' not in vars(obj) + assert getattr_static(obj, 'class_method') == old_cls_method_obj + + +def _test_static_method( + obj: Object, expected_old: int, expected_new: int, +) -> None: + assert expected_old != expected_new + + Class = type(obj) + old_st_method_obj = cast( + 'staticmethod[..., int]', getattr_static(Class, 'static_method'), + ) + impl_is_local = 'static_method' in vars(Class) + + # ---------------------- Patch on class level ---------------------- + + # Before patch + assert obj.static_method() == expected_old + assert Class.static_method() == expected_old + with Cleanup() as cleanup: + cleanup.patch( + Class, 'static_method', staticmethod(lambda: expected_new), + ) + # Post patch + assert 'static_method' in vars(Class) + assert Class.static_method() == expected_new + assert obj.static_method() == expected_new + # Patch reversal + # - Instance level (dynamic) + assert obj.static_method() == expected_old + assert obj.static_method == old_st_method_obj.__func__ + # - Class level + assert ('static_method' in vars(Class)) == impl_is_local + assert Class.static_method() == expected_old + assert Class.static_method == old_st_method_obj.__func__ + assert getattr_static(Class, 'static_method') is old_st_method_obj + + # ---------------------- Patch on inst. level ---------------------- + + with Cleanup() as cleanup: + cleanup.patch(obj, 'static_method', lambda: expected_new) + # Post patch + assert 'static_method' in vars(obj) + assert obj.static_method() == expected_new + # Patch reversal + # - Instance level (dynamic) + assert obj.static_method() == expected_old + assert obj.static_method == old_st_method_obj.__func__ + # - Instance level (static) + assert 'static_method' not in vars(obj) + assert getattr_static(obj, 'static_method') == old_st_method_obj + + +def _test_property(obj: Object, expected: int) -> None: + ncalls_wrapped_fget = 0 + + def wrap_fget(self) -> int: + nonlocal ncalls_wrapped_fget + ncalls_wrapped_fget += 1 + return cast(Callable[[Object], int], old_prop.fget)(self) + + Class = type(obj) + old_prop = cast(property, Class.data_descriptor) + new_prop = old_prop.getter(wrap_fget) + impl_is_local = 'data_descriptor' in vars(Class) + # ---------------------- Patch on class level ---------------------- + + # Before patch + assert obj.data_descriptor == expected + assert ncalls_wrapped_fget == 0 + with Cleanup() as cleanup: + cleanup.patch(Class, 'data_descriptor', new_prop) + # Post patch + assert 'data_descriptor' in vars(Class) + assert obj.data_descriptor == expected + assert ncalls_wrapped_fget == 1 # Wrapped `.__get__()` + assert obj.data_descriptor == expected + assert ncalls_wrapped_fget == 2 # Wrapped `.__get__()` + # Patch reversal + # - Instance level (dynamic) + assert obj.data_descriptor == expected + assert ncalls_wrapped_fget == 2 + assert obj.data_descriptor == expected + assert ncalls_wrapped_fget == 2 + # - Class level + assert ('data_descriptor' in vars(Class)) == impl_is_local + + # ---------------------- Patch on inst. level ---------------------- + + with Cleanup() as cleanup: + cleanup.patch(obj, 'data_descriptor', expected + 2) + # Post patch + assert obj.data_descriptor == expected + 2 + # Patch reversal (same as normal instance attributes, as tested in + # the doctest) + assert obj.data_descriptor == expected + + +def _test_nonlocal_attr( + obj: Object, + expected_old: int, + expected_new: int, + name: str, + dynamic: bool, +) -> None: + assert expected_old != expected_new + + Class = type(obj) + attr_is_on_class = name in vars(Class) + + # ---------------------- Patch on class level ---------------------- + + # Before patch + assert getattr(obj, name) == expected_old + if not dynamic: + assert getattr(Class, name) == expected_old + with Cleanup() as cleanup: + cleanup.patch(Class, name, expected_new) + # Poast patch + assert name in vars(Class) + assert getattr(obj, name) == expected_new + assert getattr(Class, name) == expected_new + # Patch reversal + # - Instance level (dynamic) + assert getattr(obj, name) == expected_old + # - Instance level (static) + if dynamic: + with pytest.raises(AttributeError): + getattr_static(obj, name) + else: + assert getattr_static(obj, name) == expected_old + # - Class level + assert (name in vars(Class)) == attr_is_on_class + if dynamic: + assert not hasattr(Class, name) + else: + getattr(Class, name) == expected_old + + # ---------------------- Patch on inst. level ---------------------- + + with Cleanup() as cleanup: + cleanup.patch(obj, name, expected_new) + # Post patch + assert name in vars(obj) + assert getattr(obj, name) == expected_new + # Patch reversal + # - Instance level (dynamic) + assert name not in vars(obj) + assert getattr(obj, name) == expected_old + # - Instance level (static) + if dynamic: + with pytest.raises(AttributeError): + getattr_static(obj, name) + else: + assert getattr_static(obj, name) == expected_old + + +_test_overridden_class_attr = partial( + _test_nonlocal_attr, name='attr_on_class', dynamic=False, +) +_test_dynamic_attr = partial( + _test_nonlocal_attr, name='dynamic_attr', dynamic=True, +) + +_PATCHING_TEST_CASES = ( + _Cases() + .add_case( + 'instance-method', _test_instance_method, + expected_old=1, expected_new=2, + ) + .add_case( + 'class-method', _test_class_method, + expected_old=2, expected_new=3, + ) + .add_case( + 'static-method', _test_static_method, + expected_old=3, expected_new=4, + ) + .add_case('data-descriptor', _test_property, expected=4) + .add_case( + 'overridden-class-attr', _test_overridden_class_attr, + expected_old=5, expected_new=6, + ) + .add_case( + 'dynamic-attr', _test_dynamic_attr, + expected_old=0, expected_new=1, + ) +) + + +@pytest.mark.parametrize('case', _PATCHING_TEST_CASES.cases) +def test_base_class_attr_patching(case: str) -> None: + """ + Test :py:meth:`Cleanup.patch`-ing various attributes (descriptors, + class/dynamic attributes) on (1) the base class they are defined in + and (2) an instance thereof. + + Notes: + The most basic use-cases with normal instance attributes are + tested in the doctest of the method; this test is to test some + of the remaining edge cases. + """ + _PATCHING_TEST_CASES.run_case(case, Object()) + + +@pytest.mark.parametrize('case', _PATCHING_TEST_CASES.cases) +def test_child_class_attr_patching(case: str) -> None: + """ + Test :py:meth:`Cleanup.patch`-ing various attributes (descriptors, + class/dynamic attributes) on (1) a class inheriting from the base + class they are defined in and (2) an instance thereof. + + Notes: + The most basic use-cases with normal instance attributes are + tested in the doctest of the method; this test is to test some + of the remaining edge cases. + """ + _PATCHING_TEST_CASES.run_case(case, InheritedObject()) diff --git a/tests/test_docs_conf.py b/tests/test_docs_conf.py index 6f072b8a..41d1afc1 100644 --- a/tests/test_docs_conf.py +++ b/tests/test_docs_conf.py @@ -1,31 +1,43 @@ """Tests for helpers defined in the Sphinx configuration.""" +from __future__ import annotations + import ast -from os.path import dirname, exists, join +import os.path +from collections.abc import Callable +from pathlib import Path +from typing import Any import pytest -CONF_FPATH = join(dirname(dirname(__file__)), 'docs', 'source', 'conf.py') + +CONF_FPATH = Path(__file__).parent.parent / 'docs' / 'source' / 'conf.py' -def _load_parse_version(): - """Extract ``parse_version`` from ``conf.py`` without importing sphinx.""" - if not exists(CONF_FPATH): +@pytest.fixture(scope='module') +def parse_version() -> Callable[[str | os.PathLike[str]], Any]: + """ + Extract ``parse_version`` from ``conf.py`` without importing sphinx + """ + if not CONF_FPATH.exists(): pytest.skip('docs/source/conf.py is not available') - tree = ast.parse(open(CONF_FPATH, 'r').read()) + tree = ast.parse(CONF_FPATH.read_text()) for node in tree.body: if isinstance(node, ast.FunctionDef) and node.name == 'parse_version': - ns = {'exists': exists, 'join': join, 'dirname': dirname} + ns = dict(vars(os.path)) exec(compile(ast.Module([node], []), CONF_FPATH, 'exec'), ns) return ns['parse_version'] - pytest.skip('conf.py does not define parse_version') + pytest.skip('conf.py does not define `parse_version()`') -def test_parse_version(tmp_path): - """``parse_version`` works on Python 3.14, where ``ast.Constant.s`` is gone. +def test_parse_version( + parse_version: Callable[[str | os.PathLike[str]], Any], tmp_path: Path, +) -> None: + """ + Test that ``parse_version()`` works on Python 3.14, where + :py:attr:`ast.Constant.s` is gone. See https://github.com/pyutils/line_profiler/issues/429 """ - parse_version = _load_parse_version() fpath = tmp_path / 'mod.py' fpath.write_text("__version__ = '1.2.3'\n") - assert parse_version(str(fpath)) == '1.2.3' + assert parse_version(fpath) == '1.2.3' diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index b9cca990..cc699857 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -1,20 +1,26 @@ from __future__ import annotations + import asyncio -import contextlib import functools import gc import inspect -import io import os import pickle import subprocess import sys import textwrap import types +import warnings +from contextlib import ExitStack, nullcontext +from io import StringIO from pathlib import Path from tempfile import TemporaryDirectory +from typing import Any, Literal, cast + import pytest + from ubelt import ChDir + from line_profiler import _line_profiler, LineProfiler, LineStats @@ -50,7 +56,7 @@ def strip(s): def get_prof_stats(prof, name='prof', **kwargs): - with io.StringIO() as sio: + with StringIO() as sio: prof.print_stats(sio, **kwargs) output = sio.getvalue() print(f'@{name}:', textwrap.indent(output, ' '), sep='\n\n') @@ -149,6 +155,9 @@ def timings(self): return self.prof.get_stats().timings +# ------------------------ `LineProfiler` tests ------------------------ + + def test_init(): lp = LineProfiler() assert lp.functions == [] @@ -320,7 +329,7 @@ async def use_agen_complex(*args, delay=delay): with ( pytest.raises(StopAsyncIteration) if send is None - else contextlib.nullcontext() + else nullcontext() ): results.append(await agen.asend(send)) if send is None: @@ -366,7 +375,7 @@ def has_refcount_bug(): assert profile.enable_count == 0 assert asyncio.run(use_agen_simple(1, 2, 3)) == [0, 1, 3, 6] assert profile.enable_count == 0 - with contextlib.ExitStack() as stack: + with ExitStack() as stack: if xfail_refcount: excinfo = stack.enter_context( pytest.raises(AssertionError, match=r'ag\(\): ref count') @@ -747,7 +756,6 @@ def test_profiler_c_callable_no_op(decorate): def test_show_func_column_formatting(): from line_profiler.line_profiler import show_func import line_profiler - import io # Use a function in this module as an example func = line_profiler.line_profiler.show_text @@ -785,7 +793,7 @@ def get_func_linenos(func): (lineno, idx * 1e13, idx * (2e10 ** (idx % 3))) for idx, lineno in enumerate(line_numbers, start=1) ] - stream = io.StringIO() + stream = StringIO() show_func( filename, start_lineno, @@ -803,7 +811,7 @@ def get_func_linenos(func): (lineno, idx * 1e15, idx * 2e19) for idx, lineno in enumerate(line_numbers, start=1) ] - stream = io.StringIO() + stream = StringIO() show_func( filename, start_lineno, @@ -1352,9 +1360,12 @@ def func_try_except_finally(reraise): assert line.split()[1] == str(nhits) +# ------------------------- `LineStats` tests -------------------------- + + @pytest.mark.parametrize('n', [1, 2]) @pytest.mark.parametrize('legacy', [True, False]) -def test_load_stats_files(legacy, n): +def test_load_stats_files_backward_compatibility(legacy: bool, n: int) -> None: """ Test the loading of stats files. If ``legacy`` is true, the tempfiles are written from @@ -1363,7 +1374,6 @@ def test_load_stats_files(legacy, n): that we ensure that ``'.lprof'`` files written by old versions of :py:mod:`line_profiler` is still properly handled. """ - def write(stats, filename): if legacy: legacy_stats = type(stats).__base__(stats.timings, stats.unit) @@ -1394,3 +1404,97 @@ def write(stats, filename): stats_read = LineStats.from_files(*files) assert isinstance(stats_read, LineStats) assert stats_read == stats_combined + + +@pytest.mark.parametrize( + ('behavior', 'status', 'error'), + [('ignore', 'empty', None), ('ignore', 'nonexistent', None), + ('ignore', 'corrupted', None), ('ignore', 'incompatible', None), + ('warn', 'empty', + (UserWarning, r'.*1 file.* empty.* skipped: .*bad\.lprof')), + ('warn', 'nonexistent', + (UserWarning, + '.*1 file.* cannot be loaded.* skipped: ' + r'.*FileNotFoundError: .*bad\.lprof')), + ('warn', 'corrupted', + (UserWarning, + '.*1 file.* cannot be loaded.* skipped: .*UnpicklingError')), + ('warn', 'incompatible', + (UserWarning, '.*1 file.* cannot be loaded.* skipped')), + ('error', 'empty', (OSError, r'.*bad\.lprof')), + ('error', 'nonexistent', (FileNotFoundError, r'.*bad\.lprof')), + ('error', 'corrupted', (pickle.UnpicklingError, None)), + ('error', 'incompatible', ((TypeError, AttributeError), None))]) +def test_load_problematic_stats_file( + tmp_path_factory: pytest.TempPathFactory, + behavior: Literal['ignore', 'warn', 'error'], + status: Literal['empty', 'nonexistent', 'corrupted', 'incompatible'], + error: tuple[ + type[Exception] | tuple[type[Exception], ...], str | None, + ] | None, +) -> None: + """ + Test the behavior when trying to load a :py:class:`LineStats` object + from: + - An empty file + - A nonexistent file + - A corrupted pickle file + - A pickle file of an incompatible object + """ + tmpdir = tmp_path_factory.mktemp('mytmp') + kwargs: dict[str, Any] = {} + bad_file = tmpdir / 'bad.lprof' + + good_file = tmpdir / 'good.lprof' + good_stats = LineStats.get_empty_instance() + good_stats.timings = {('foo.py', 10, 'func'): [(12, 10, 300)]} + good_stats.to_file(good_file) + + if status == 'empty': + bad_file.touch() + kwargs['on_empty'] = behavior + elif status == 'nonexistent': + kwargs['on_defective'] = behavior + elif status == 'corrupted': + kwargs['on_defective'] = behavior + LineStats.get_empty_instance().to_file(bad_file) + with open(bad_file, mode='wb+') as fobj: + fobj.write(b'42') # Destroy the magic number in the start + elif status == 'incompatible': + kwargs['on_defective'] = behavior + with open(bad_file, mode='wb') as fobj: + pickle.dump([1, 2, 3], fobj) + else: + assert False, f'{status=}' + + with ExitStack() as stack: + if behavior == 'ignore': + stack.enter_context(warnings.catch_warnings()) + warnings.filterwarnings( + 'error', module='line_profiler.line_profiler', + ) + elif behavior == 'warn': + if error is None: + ErrorClass: type[Exception] | tuple[type[Exception], ...] + ErrorClass = UserWarning + error_msg: str | None = None + else: + ErrorClass, error_msg = error + stack.enter_context(pytest.warns( + cast(type[Warning] | tuple[type[Warning], ...], ErrorClass), + match=error_msg, + )) + elif behavior == 'error': + if error is None: + ErrorClass, error_msg = Exception, None + else: + ErrorClass, error_msg = error + stack.enter_context(pytest.raises(ErrorClass, match=error_msg)) + else: + assert False, f'{behavior=}' + stats = LineStats.from_files(bad_file, good_file, **kwargs) + + if behavior != 'error': + # As long as we don't error out, the data from the good file + # should remain + assert stats == good_stats diff --git a/tests/test_sys_trace.py b/tests/test_sys_trace.py index ad73d224..65ae8ede 100644 --- a/tests/test_sys_trace.py +++ b/tests/test_sys_trace.py @@ -1,22 +1,25 @@ """ -Test the interoperability between `LineProfiler` and other `sys` tracing -facilities (e.g. Python functions registered via `sys.settrace()`. - -Notes ------ -- By the very nature of the tests in this test module, they override - `sys` trace functions, and are thus largely opaque towards - `coverage.py`. -- However, there effects are isolated since each test is run in a - separate Python subprocess. -""" +Test the interoperability between :py:class:`LineProfiler` and other +:py:mod:`sys` tracing facilities (e.g. Python functions registered via +:py:func:`sys.settrace`. + +Notes: + - By the very nature of the tests in this test module, they override + :py:mod:`sys` trace functions, and are thus largely opaque towards + `coverage.py`. + - However, their effects are isolated since each test is run in a + separate Python subprocess. +""" from __future__ import annotations + import concurrent.futures import functools +import gc import inspect import linecache import os +import re import subprocess import shlex import sys @@ -24,46 +27,93 @@ import tempfile import textwrap import threading -import pytest +import weakref from ast import literal_eval -from contextlib import nullcontext +from contextlib import AbstractContextManager, ExitStack, nullcontext from io import StringIO -from types import FrameType, ModuleType -from typing import Any, Optional, Union, Callable, List, Literal -from line_profiler import LineProfiler +from pathlib import Path +from types import CodeType, FrameType, FunctionType, ModuleType +from typing import ( + TYPE_CHECKING, Any, Callable, Literal, ParamSpec, TextIO, cast, overload, +) + +import pytest + +from line_profiler import LineProfiler, LineStats +from line_profiler._diagnostics import USE_LEGACY_TRACE +from line_profiler._line_profiler import ( # type: ignore + _LineProfilerManager, label as get_line_stats_key, +) +from line_profiler.curated_profiling import CuratedProfilerContext # Common utilities DEBUG = False -USE_SYS_MONITORING = isinstance(getattr(sys, 'monitoring', None), ModuleType) +if TYPE_CHECKING: # Do it in a static-analysis-friendly way + USE_SYS_MONITORING = sys.version_info[:2] >= (3, 12) +else: + USE_SYS_MONITORING = isinstance( + getattr(sys, 'monitoring', None), ModuleType, + ) +PS = ParamSpec('PS') Event = Literal['call', 'line', 'return', 'exception', 'opcode'] -TracingFunc = Callable[[FrameType, Event, Any], Union['TracingFunc', None]] +if TYPE_CHECKING: + from typeshed import TraceFunction as TracingFunc +else: + TracingFunc = Callable[[FrameType, Event, Any], 'TracingFunc | None'] def strip(s: str) -> str: return textwrap.dedent(s).strip('\n') +@overload +def isolate_test_in_subproc( + func: Callable[PS, None], *, debug: bool = DEBUG, core: str | None = None, +) -> Callable[PS, None]: + ... + + +@overload +def isolate_test_in_subproc( + func: None = None, *, debug: bool = DEBUG, core: str | None = None, +) -> Callable[[Callable[PS, None]], Callable[PS, None]]: + ... + + def isolate_test_in_subproc( - func: Optional[Callable] = None, debug: bool = DEBUG -) -> Callable: + func: Callable[PS, None] | None = None, + *, + debug: bool = DEBUG, + core: str | None = None, +) -> Callable[[Callable[PS, None]], Callable[PS, None]] | Callable[PS, None]: """ Run the test function with the supplied arguments in a subprocess so that it doesn't pollute the state of the current interpretor. - If `debug` is true, run with `pytest` for more detailed traceback. - Notes - ----- - - Code is written to a tempfile and run in a subprocess. - - The test function should be import-able from the top-level - namespace of this file. - - All the arguments should be `ast.literal_eval()`-able. - - Beware of using fixtures for these tests. + Args: + debug (bool): + If true, run with ``pytest`` for more detailed traceback. + core (str | None): + If not :py:const:`None`, set ``${LINE_PROFILER_CORE}`` to + that value. + + Notes: + - Code is written to a tempfile and run in a subprocess. + + - The test function should be import-able from the top-level + namespace of this file. + + - All the arguments should be :py:func:`ast.literal_eval`-able. + + - Beware of using fixtures for these tests. """ if func is None: - return functools.partial(isolate_test_in_subproc, debug=debug) + return functools.partial( + isolate_test_in_subproc, debug=debug, core=core, + ) def message( msg: str, header: str, *, short: bool = False, **kwargs @@ -80,7 +130,7 @@ def message( @functools.wraps(func) def wrapper(*args, **kwargs): # Check if the function is importable - test_func = func.__name__ + test_func = cast(FunctionType, func).__name__ assert globals()[test_func].__subproc_test_inner__ is func # Check if the arguments are round-trippable @@ -112,7 +162,10 @@ def {test}(): test_module_name, dot_py = os.path.splitext(test_filename) assert dot_py == '.py' code = code_template.format( - path=test_dir, mod=test_module_name, test=test_func, args=args_repr + path=test_dir, + mod=test_module_name, + test=test_func, + args=args_repr, ) # Run the test script in a subprocess if debug: # Use `pytest` to get perks like assertion rewriting @@ -131,9 +184,12 @@ def {test}(): print(code, file=fobj) env = os.environ.copy() # Make sure that we're testing the "default behavior" - env.pop('LINE_PROFILER_CORE', '') + if core is None: + env.pop('LINE_PROFILER_CORE', '') + else: + env['LINE_PROFILER_CORE'] = core proc = subprocess.run( - cmd, capture_output=True, env=env, text=True + cmd, capture_output=True, env=env, text=True, ) finally: os.chdir(curdir) @@ -147,7 +203,7 @@ def {test}(): message('', 'Stderr', short=True) proc.check_returncode() - wrapper.__subproc_test_inner__ = func + wrapper.__subproc_test_inner__ = func # type: ignore return wrapper @@ -197,23 +253,23 @@ def __exit__(self, *_, **__): def get_incr_logger( - logs: List[str], - func: Literal[foo, bar, baz] = foo, + logs: list[str], + func: Callable[[int], int] = foo, *, bugged: bool = False, report_return: bool = False, ) -> TracingFunc: """ Append a ': spam = <...>' message whenever we hit the line in - `func()` containing the incrementation of `result`. - If it's made `bugged`, it sets the frame's `.f_trace_lines` to false - after writing the first log entry, disabling line events. - If `report_return` is true, a 'Returning from ()' log entry + ``func()`` containing the incrementation of ``result``. + If it's made ``bugged``, it sets :py:attr:`FrameType.f_trace_lines` + to false after writing the first log entry, disabling line events. + If ``report_return`` is true, a 'Returning from ()' log entry is written on return. """ - def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: - if DEBUG and callback.emit_debug: + def callback(frame: FrameType, event: Event, _) -> TracingFunc | None: + if DEBUG and callback.emit_debug: # type: ignore print( '{0.co_filename}:{1.f_lineno} - {0.co_name} ({2})'.format( frame.f_code, frame, event @@ -222,13 +278,13 @@ def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: if event == 'call': # Set up tracing for nested scopes return callback if event not in events: # Only trace the specified events - return + return None code = frame.f_code if code.co_filename != filename or code.co_name != func_name: - return + return None if event == 'return': # Write a return entry where appropriate logs.append(f'Returning from `{func_name}()`') - return + return None if frame.f_lineno == lineno: # Add log entry whenever the target line is hit counter_value = frame.f_locals.get(counter) @@ -239,10 +295,11 @@ def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: # Get data from `func()`: its (file-)name, the line number of the # incrementation, and the name of the counter variable - func_name = func.__name__ - filename = func.__code__.co_filename - lineno = func.__code__.co_firstlineno - block = inspect.getblock(linecache.getlines(__file__)[lineno - 1 :]) + func_ = cast(FunctionType, func) + func_name = func_.__name__ + filename = func_.__code__.co_filename + lineno = func_.__code__.co_firstlineno + block = inspect.getblock(linecache.getlines(__file__)[lineno - 1:]) ((offset, line),) = ( (i, line) for i, line in enumerate(block) if 'result +=' in line ) @@ -253,20 +310,20 @@ def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: if report_return: events.add('return') - callback.emit_debug = False + callback.emit_debug = False # type: ignore return callback -def get_return_logger(logs: List[str], *, bugged: bool = False) -> TracingFunc: +def get_return_logger(logs: list[str], *, bugged: bool = False) -> TracingFunc: """ Append a 'Returning from `()`' message whenever we hit return - from a function defined in this file. If it's made `bugged`, it - panics and errors out when returning from `bar`, thus unsetting the - `sys` trace. + from a function defined in this file. If it's made ``bugged``, it + panics and errors out when returning from ``bar``, thus unsetting the + :py:mod:`sys` trace. """ - def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: - if DEBUG and callback.emit_debug: + def callback(frame: FrameType, event: Event, _) -> TracingFunc | None: + if DEBUG and callback.emit_debug: # type: ignore print( '{0.co_filename}:{1.f_lineno} - {0.co_name} ({2})'.format( frame.f_code, frame, event @@ -276,17 +333,18 @@ def callback(frame: FrameType, event: Event, _) -> Union[TracingFunc, None]: # Set up tracing for nested scopes return callback if event != 'return': - return # Only trace return events + return None # Only trace return events code = frame.f_code if code.co_filename != __file__: - return # Only trace functions in this file + return None # Only trace functions in this file # Add log entry logs.append(f'Returning from `{code.co_name}()`') if bugged and code.co_name == 'bar': # Error out and cause `sys.settrace(None)` raise MyException + return None - callback.emit_debug = False + callback.emit_debug = False # type: ignore return callback @@ -300,14 +358,15 @@ class MyException(Exception): def _test_helper_callback_preservation( - callback: Union[TracingFunc, None], + callback: TracingFunc | None, ) -> None: sys.settrace(callback) assert sys.gettrace() is callback, f"can't set trace to {callback!r}" profile = LineProfiler(wrap_trace=False) profile.enable_by_count() if not USE_SYS_MONITORING: - assert profile in sys.gettrace().active_instances, ( + manager = cast(_LineProfilerManager, sys.gettrace()) + assert profile in manager.active_instances, ( "can't set trace to the profiler" ) profile.disable_by_count() @@ -318,8 +377,9 @@ def _test_helper_callback_preservation( @isolate_test_in_subproc def test_callback_preservation(): """ - Test in a subprocess that the profiler restores the active `sys` - trace callback (or the lack thereof) after it's `.disable()`-ed. + Test in a subprocess that the profiler restores the active + :py:mod:`sys` trace callback (or the lack thereof) after it's + :py:meth:`LineProfiler.disable`-ed. """ _test_helper_callback_preservation(None) _test_helper_callback_preservation(lambda frame, event, arg: None) @@ -346,7 +406,7 @@ def test_callback_wrapping( trace callback such that we both profile the code and do whatever the existing callback does. """ - logs = [] + logs: list[str] = [] my_callback = get_incr_logger(logs) sys.settrace(my_callback) @@ -365,9 +425,9 @@ def test_callback_wrapping( exp_logs = [] assert sys.gettrace() is my_callback, "can't set custom trace" - my_callback.emit_debug = True + my_callback.emit_debug = True # type: ignore x = foo_like(5) - my_callback.emit_debug = False + my_callback.emit_debug = False # type: ignore assert x == 15, f'expected `foo(5) = 15`, got {x!r}' assert sys.gettrace() is my_callback, 'trace not restored afterwards' @@ -404,23 +464,27 @@ def test_wrapping_throwing_callback( """ Test in a subprocess that if the profiler wraps around an existing trace callback that errors out: + - Profiling continues uninterrupted. + - The errored-out trace callback is no longer called from the profiling traceback. - - The `sys` traceback is set to `None` when the profiler is - `.disable()`-ed. + + - The :py:mod:`sys` traceback is set to :py:const:`None` when the + profiler is :py:meth:`LineProfiler.disable`-ed. Notes ----- - Extra `enable_count` means that the profiler stays enabled between + Extra ``enable_count`` means that the profiler stays enabled between the calls to the profiled functions, and we thereyby test against - these problematic behaviors after `my_callback()` bugs out: - - If the profiler stops profiling (because the `sys` trace callback - is unset), or - - If the profiler's callback keeps calling `my_callback()` + these problematic behaviors after ``my_callback()`` bugs out: + + - If the profiler stops profiling (because the :py:mod:`sys` trace + callback is unset), or + - If the profiler's callback keeps calling ``my_callback()`` afterwards. """ - logs = [] + logs: list[str] = [] my_callback = get_return_logger(logs, bugged=True) sys.settrace(my_callback) assert sys.gettrace() is my_callback, "can't set custom trace" @@ -434,7 +498,7 @@ def test_wrapping_throwing_callback( for _ in range(enable_count): profile.enable_by_count() - my_callback.emit_debug = True + my_callback.emit_debug = True # type: ignore x = foo_like(3) # This is logged try: _ = bar_like(4) # This is also logged, but... @@ -445,7 +509,7 @@ def test_wrapping_throwing_callback( else: assert False, "tracing function didn't error out" y = baz_like(5) # Not logged because trace disabled itself - my_callback.emit_debug = False + my_callback.emit_debug = False # type: ignore for _ in range(enable_count): profile.disable_by_count() @@ -492,12 +556,14 @@ def test_wrapping_line_event_disabling_callback( ) -> None: """ Test in a subprocess that if the profiler wraps around an existing - trace callback that disables `.f_trace_lines`: + trace callback that disables :py:mod:`FrameType.f_trace_lines`: + - Profiling continues uninterrupted. - - `.f_trace` is subsequently disabled, but only for line events in - that frame. + + - :py:mod:`FrameType.f_trace` is subsequently disabled, but only for + line events in that frame. """ - logs = [] + logs: list[str] = [] my_callback = get_incr_logger(logs, bugged=True, report_return=True) sys.settrace(my_callback) @@ -508,9 +574,9 @@ def test_wrapping_line_event_disabling_callback( foo_like = foo assert sys.gettrace() is my_callback, "can't set custom trace" - my_callback.emit_debug = True + my_callback.emit_debug = True # type: ignore x = foo_like(5) - my_callback.emit_debug = False + my_callback.emit_debug = False # type: ignore assert x == 15, f'expected `foo(5) = 15`, got {x!r}' assert sys.gettrace() is my_callback, 'trace not restored afterwards' @@ -534,9 +600,9 @@ def test_wrapping_line_event_disabling_callback( def _test_helper_wrapping_thread_local_callbacks( - profile: Union[LineProfiler, None], sleep: float = 0.0625 + profile: LineProfiler | None, sleep: float = 0.0625 ) -> str: - logs = [] + logs: list[str] = [] if threading.current_thread() == threading.main_thread(): thread_label = 'main' func = foo @@ -556,9 +622,9 @@ def _test_helper_wrapping_thread_local_callbacks( # Check result sys.settrace(my_callback) assert sys.gettrace() is my_callback, "can't set custom trace" - my_callback.emit_debug = True + my_callback.emit_debug = True # type: ignore x = func_like(5) - my_callback.emit_debug = False + my_callback.emit_debug = False # type: ignore assert x == 15, f'expected `{func.__name__}(5) = 15`, got {x!r}' assert sys.gettrace() is my_callback, 'trace not restored afterwards' @@ -578,7 +644,7 @@ def test_wrapping_thread_local_callbacks( ) -> None: """ Test in a subprocess that the profiler properly handles thread-local - `sys` trace callbacks. + :py:mod:`sys` trace callbacks. """ profile = LineProfiler(wrap_trace=True) if use_profiler else None expected_results = { @@ -600,7 +666,8 @@ def test_wrapping_thread_local_callbacks( # This is run on the main thread results.add(_test_helper_wrapping_thread_local_callbacks(profile)) results.update( - future.result() for future in concurrent.futures.as_completed(tasks) + future.result() + for future in concurrent.futures.as_completed(tasks) ) assert results == expected_results, ( f'expected {expected_results!r}, got {results!r}' @@ -654,15 +721,21 @@ def test_wrapping_thread_local_callbacks( ) @isolate_test_in_subproc def test_python_level_trace_manipulation( - stay_in_scope, set_frame_local_trace, n, nhits -): + stay_in_scope: bool, + set_frame_local_trace: bool, + n: int, + nhits: dict[int, int], +) -> None: """ Test that: - - When Python code retrieves the trace object set by `line_profiler` - with `sys.gettrace()` and later restores it via `sys.settrace()`, - it doesn't break anything, and + + - When Python code retrieves the trace object set by + :py:mod:`line_profiler` with :py:func:`sys.gettrace` and later + restores it via :py:func:`sys.settrace`, it doesn't break + anything, and + - Resumption of line profiling in the same frame thereafter happens - if and only if `set_frame_local_trace` is true. + if and only if ``set_frame_local_trace`` is true. """ prof = LineProfiler(set_frame_local_trace=set_frame_local_trace) @@ -686,6 +759,8 @@ def func_break_in_middle(n): prof.add_callable(func_no_break) expected = n * (n + 1) // 2 + outer_ctx: AbstractContextManager[Any] + inner_ctx: AbstractContextManager[Any] if stay_in_scope: # Do two calls, each with tracing suspended for half of the loop @@ -715,3 +790,352 @@ def func_break_in_middle(n): } all_nhits = {lineno: all_nhits.get(lineno, 0) for lineno in nhits} assert all_nhits == nhits, f'expected {nhits=}, got {all_nhits=}' + + +@pytest.mark.parametrize( + ('use_context', 'label1'), + [(True, 'use-context'), (False, 'no-context')]) +@pytest.mark.parametrize( + ('enable_during_thread_start', 'label2'), + [(True, 'start-enabled'), (False, 'start-disabled')]) +@pytest.mark.parametrize('profile_foo', ['no-foo', 'add-foo', 'wrap-foo']) +@pytest.mark.parametrize('profile_bar', ['no-bar', 'add-bar', 'wrap-bar']) +@isolate_test_in_subproc(core='legacy') +def test_wrapping_threading_trace( + use_context: bool, + enable_during_thread_start: bool, + profile_foo: Literal['no-foo', 'add-foo', 'wrap-foo'], + profile_bar: Literal['no-foo', 'add-foo', 'wrap-foo'], + label1: str, + label2: str, +) -> None: + """ + Test the interaction between :py:mod:`line_profiler` (esp. + :py:mod:`line_profiler.curated_profiling`) and thread-local trace + functions set via :py:func:`threading.settrace` when + ``wrap_trace=True``; the trace functions are wrapped and invoked by + ours. + """ + # All events should remain visible to `threading_trace()` + trace_events = [ + ('call', 'foo'), + ('call', 'bar'), + ('return', 'bar'), + ('return', 'foo'), + ] + + # 'no': not profiling the function + # 'add': only `.add_callable()` + # 'wrap': replace the function with a profiling wrapper + profile_map: dict[str, Literal[0, 1, 2]] = {'no': 0, 'add': 1, 'wrap': 2} + pf = profile_map[profile_foo.partition('-')[0]] + pb = profile_map[profile_bar.partition('-')[0]] + + if use_context and enable_during_thread_start: + # Using a `CuratedProfilerContext`, the enabled state of the + # profiler persists into the new thread, so profiling of any of + # the valid targets continues + foo_is_profiled = bool(pf) + bar_is_profiled = bool(pb) + else: + foo_is_profiled = pf > 1 + # `bar()` is called by `foo()`, so if the profiler is enabled + # when calling `foo()`, it will already be when calling `bar()` + # too + if foo_is_profiled: + bar_is_profiled = bool(pb) + else: + bar_is_profiled = pb > 1 + + _test_threading_trace_manipulation_helper( + wrap_trace=True, + use_context=use_context, + enable_during_thread_start=enable_during_thread_start, + profile_foo=pf, + profile_bar=pb, + foo_is_profiled=foo_is_profiled, + bar_is_profiled=bar_is_profiled, + trace_events=cast(Any, trace_events), + ) + + +@pytest.mark.parametrize('enable_timing', ['foo', 'bar', 'no']) +@isolate_test_in_subproc(core='legacy') +def test_replacing_threading_trace( + enable_timing: Literal['foo', 'bar', 'no'], +) -> None: + """ + Test the interaction between :py:mod:`line_profiler` (esp. + :py:mod:`line_profiler.curated_profiling`) and thread-local trace + functions set via :py:func:`threading.settrace` when + ``wrap_trace=False``; the trace functions are superseded by ours + when the profiler is enabled, and restored when it is disabled. + """ + profile_foo: Literal[0, 1, 2] + profile_bar: Literal[0, 1, 2] + trace_events: list[ + tuple[Literal['call', 'return'], Literal['foo', 'bar']] + ] = [] + + assert USE_LEGACY_TRACE + + if enable_timing == 'foo': + # Profiler enabled before calling `foo()` + # -> `threading_trace()` entirely circumvented + pre_enable = True + profile_foo = profile_bar = 1 + foo_is_profiled = bar_is_profiled = True + elif enable_timing == 'bar': + # Profiler enabled when calling `bar()` + # -> `threading_trace()` only captures the `foo()` events + pre_enable = False + profile_foo = 1 + profile_bar = 2 # The wrapper enables the profiler + foo_is_profiled = False + bar_is_profiled = True + trace_events.extend([('call', 'foo'), ('return', 'foo')]) + elif enable_timing == 'no': + # Profiler never enabled + # -> `threading_trace()` captures all events + pre_enable = False + profile_foo = profile_bar = 1 + foo_is_profiled = False + bar_is_profiled = False + trace_events.extend([ + ('call', 'foo'), + ('call', 'bar'), + ('return', 'bar'), + ('return', 'foo'), + ]) + else: + assert False, f'{enable_timing=!r}' + + _test_threading_trace_manipulation_helper( + wrap_trace=False, + use_context=pre_enable, + enable_during_thread_start=pre_enable, + profile_foo=profile_foo, + profile_bar=profile_bar, + foo_is_profiled=foo_is_profiled, + bar_is_profiled=bar_is_profiled, + trace_events=trace_events, + ) + + +def _test_threading_trace_manipulation_helper( + # Setup params + wrap_trace: bool, + use_context: bool, + enable_during_thread_start: bool, + profile_foo: Literal[0, 1, 2], + profile_bar: Literal[0, 1, 2], + # Result params + foo_is_profiled: bool, + bar_is_profiled: bool, + trace_events: list[ + tuple[Literal['call', 'return'], Literal['foo', 'bar']] + ], + # Misc. params + n_foo: int = 7, + n_bar: int = 42, +) -> None: + def threading_trace(frame: FrameType, event: str, _) -> TracingFunc | None: + code = frame.f_code + if code not in traced_codes: + return None + if event in ('call', 'return'): + # Trace local events in the funcs + actual_events.append(( + cast(Literal['call', 'return'], event), + get_normalized_name(code), + )) + return threading_trace + + def foo_(fobj: TextIO | None = None) -> None: + bar(fobj) + for i in range(n_foo): + print('foo:', i, file=fobj) # LOOP + + def bar_(fobj: TextIO | None = None) -> None: + for i in range(n_bar): + print('bar:', i, file=fobj) # LOOP + + def find_pattern_lineno(func: FunctionType, pattern: str) -> int: + lines, offset = inspect.getsourcelines(func) + source = ''.join(lines) + match = re.search(pattern, source, flags=re.MULTILINE) + if not match: + return 0 + return offset + source[:match.start()].count('\n') + + def get_nhits( + stats: LineStats, func: Callable[..., Any], + ) -> dict[int, int]: + code = cast(FunctionType, inspect.unwrap(func)).__code__ + try: + entries = stats.timings[get_line_stats_key(code)] + except KeyError: + return {} + return {lineno: nhits for lineno, nhits, _ in entries} + + def get_normalized_name(code: CodeType) -> str: + return code.co_name.strip('_') + + foo: Callable[[TextIO | None], None] = foo_ + bar: Callable[[TextIO | None], None] = bar_ + + actual_events: list[tuple[Literal['call', 'return'], str]] = [] + lineno_loops = { + get_normalized_name(cast(FunctionType, func).__code__): + find_pattern_lineno(cast(FunctionType, func), '# LOOP$') + for func in [foo, bar] + } + + # Set up the profiler + prof = LineProfiler(wrap_trace=wrap_trace) + if profile_foo > 1: + foo = prof(foo) + elif profile_foo: + prof.add_callable(foo) + if profile_bar > 1: + bar = prof(bar) + elif profile_bar: + prof.add_callable(bar) + + # Note: passing functions to the profiler may have (1) wrapped them + # and/or (2) altered their `.__code__`; so we only assign to + # `traced_codes` now, and retrieve the innermost function objects. + traced_codes: set[CodeType] = { + inspect.unwrap(foo).__code__, + inspect.unwrap(bar).__code__, + } + + # Run profiling + try: + old_threading_trace = threading.gettrace() + threading.settrace(threading_trace) + with ExitStack() as stack: + tmpdir = Path(stack.enter_context(tempfile.TemporaryDirectory())) + if use_context: + stack.enter_context(CuratedProfilerContext(prof)) + if enable_during_thread_start: + stack.enter_context(prof) + tmp = tmpdir / 'out.txt' + with tmp.open(mode='w') as fobj: + thread = threading.Thread(target=foo, args=(fobj,)) + thread.start() + thread.join() + output = tmp.read_text() + finally: + threading.settrace(old_threading_trace) + stats = prof.get_stats() + + # Check the captured results + expected_output = [ + *(f'bar: {n}' for n in range(n_bar)), + *(f'foo: {n}' for n in range(n_foo)), + ] + assert ( + output.splitlines() == expected_output + ), f'{output=!r}, {expected_output=!r}' + assert ( + actual_events == trace_events + ), f'{actual_events=!r}, {trace_events=!r}' + foo_nhits = get_nhits(stats, foo) + assert ( + foo_nhits.get(lineno_loops['foo'], 0) == (foo_is_profiled and n_foo) + ), f'{stats=!r}, {foo_is_profiled=!r}, {n_foo=!r}' + bar_nhits = get_nhits(stats, bar) + assert ( + bar_nhits.get(lineno_loops['bar'], 0) == (bar_is_profiled and n_bar) + ), f'{stats=!r}, {bar_is_profiled=!r}, {n_bar=!r}' + + +@pytest.mark.parametrize('disable_line_events', [True, False]) +@isolate_test_in_subproc(core='legacy') +def test_trace_wrappers_are_not_leaked(disable_line_events: bool) -> None: + """ + Regression test: the C helpers in ``c_trace_callbacks.c`` must not + leak the wrapper objects they create. + + :c:func:`call_callback` wraps a foreign frame-local trace function + with :py:func:`line_profiler._line_profiler.disable_line_events()`` + when that function turns off :py:attr:`FrameType.f_trace_lines`, and + :c:func:`set_local_trace` wraps foreign local trace functions with + :py:meth:`line_profiler._line_profiler.\ +_LineProfilerManager.wrap_local_f_trace`. + Both store the wrapper on :py:attr:`FrameType.f_trace`, whose setter + takes its own reference; holding on to the creation reference + therefore leaked one wrapper per event, which adds up on long + profiled runs under a debugger/coverage tool. + + The wrappers masquerade as the functions they wrap + (:py:func:`functools.wraps` copies ``__qualname__``), so the checks + capture :py:attr:`FrameType.f_trace` from inside the profiled + function and assert via weakref that the wrappers die with their + frames. The scenario only exists under the legacy trace core, so it + runs in a subprocess with ``LINE_PROFILER_CORE=legacy``. + + Note: + Relocated from the eponymous test in + ``tests/test_trace_callback_leaks.py`` + (see commit 2f36f08 in TTsangSC#5 by Erotemic). + """ + wrapper_refs = [] + + def capture_frame_trace() -> None: + # The frame-local trace of the *caller* of this function + f_trace = sys._getframe(1).f_trace + if f_trace is None or type(f_trace).__name__ == '_LineProfilerManager': + # Only interested in the wrapper objects created around + # foreign trace functions, not in the profiler itself + return + wrapper_refs.append(weakref.ref(f_trace)) + + def foo(n: int) -> int: + result = 0 + for spam in range(1, n + 1): + result += spam + capture_frame_trace() + return result + + def make_callback(bugged: bool) -> TracingFunc: + def callback(frame: FrameType, event: str, arg: Any) -> TracingFunc: + if ( + bugged + and event == 'line' + and frame.f_code.co_name == 'foo' + ): + # Turns off line events, triggering the + # `disable_line_events()` wrapping in `call_callback()` + frame.f_trace_lines = False + return callback + + return callback + + def scenario(bugged: bool, repeat: int = 5) -> None: + # Everything traced happens inside this function so that by the + # time the caller checks the weakrefs, every traced frame is + # dead and any live wrapper can only be held by a leaked + # reference. + sys.settrace(make_callback(bugged)) + try: + profile = LineProfiler( + wrap_trace=True, set_frame_local_trace=True, + ) + foo_prof = profile(foo) + for _ in range(repeat): + assert foo_prof(5) == 15 + finally: + sys.settrace(None) + + wrapper_refs.clear() + scenario(disable_line_events) + gc.collect() + alive = [ref for ref in wrapper_refs if ref() is not None] + assert wrapper_refs, 'scenario failed to produce trace wrappers' + assert not alive, ( + f'{len(alive)}/{len(wrapper_refs)} trace wrapper(s) still ' + f'alive after all traced frames died ({disable_line_events=!r}): ' + f'{[ref() for ref in alive]!r}' + ) diff --git a/tests/test_threading.py b/tests/test_threading.py new file mode 100644 index 00000000..b8c8efe3 --- /dev/null +++ b/tests/test_threading.py @@ -0,0 +1,487 @@ +""" +Test that our patch for :py:mod:`threading` is robust. +""" +from __future__ import annotations + +import importlib +import os +import re +import subprocess +import sys +from collections.abc import Callable, Collection, Generator +from contextlib import ExitStack +from functools import partial +from inspect import getsourcelines, unwrap +from pathlib import Path +from tempfile import TemporaryDirectory +from textwrap import dedent, indent +from threading import Condition, Event, Thread +from types import FunctionType, ModuleType +from typing import Any, ClassVar, Literal, cast +from uuid import uuid4 + +import pytest + +from line_profiler._line_profiler import label as code_to_timing_key +from line_profiler._threading_patches import apply as apply_patches +from line_profiler.line_profiler_utils import restore +from line_profiler.cleanup import Cleanup +from line_profiler.curated_profiling import CuratedProfilerContext +from line_profiler.line_profiler import LineProfiler, LineStats + + +LOOP_BODY_LINE: int = 0 # Placeholder to appease the linter +N = 2000 + + +@pytest.fixture(scope='module') +def _my_module() -> Generator[Path, None, None]: + module_text = dedent(""" + from __future__ import annotations + + from contextlib import nullcontext + from os import PathLike + + + def func(n: int, file: str | PathLike[str] | None = None) -> None: + with ( + nullcontext(None) if file is None else open(file, mode='w') + ) as fobj: + for i in range(1, n + 1): + print(i, file=fobj) + """).strip('\n') + + global LOOP_BODY_LINE + LOOP_BODY_LINE = len(module_text.splitlines()) + + with TemporaryDirectory() as tmpdir: + module = Path(tmpdir) / ( + next(propose_module_name('my_module')) + '.py' + ) + module.write_text(module_text) + yield module + + +@pytest.fixture +def my_module_path(_my_module: Path) -> Generator[Path, None, None]: + with pytest.MonkeyPatch.context() as mp: + tmpdir = _my_module.parent + mp.syspath_prepend(str(tmpdir)) + mp.setenv('PYTHONPATH', str(tmpdir), os.pathsep) + + yield _my_module + + +@pytest.fixture +def my_module_obj(my_module_path: Path) -> Generator[ModuleType, None, None]: + module = my_module_path.stem + with restore.mapping(sys.modules, [module]): + sys.modules.pop(module, None) + importlib.invalidate_caches() + + yield importlib.import_module(module) + + +@pytest.fixture +def prof() -> Generator[LineProfiler, None, None]: + try: + prof = LineProfiler() + yield prof + finally: + reset_enable_count(prof) + + +def propose_module_name( + base: str, existing: Collection[str] | None = None, +) -> Generator[str, None, None]: + if existing is None: + existing = sys.modules + if base not in existing: + yield base + while True: + uuid = str(uuid4()).replace('-', '_') + name = f'{base}_{uuid}' + if name not in existing: + yield name + + +def reset_enable_count(prof: LineProfiler, count: int = 0) -> None: + delta = count - cast(int, getattr(prof, 'enable_count', None)) + if delta > 0: + for _ in range(delta): + prof.enable_by_count() + elif delta < 0: + for _ in range(-delta): + prof.disable_by_count() + assert getattr(prof, 'enable_count', None) == count + + +def get_nhits(stats: LineStats, func: FunctionType, lineno: int) -> int: + timings: list[tuple[int, int, int]] + timings = stats.timings.get(code_to_timing_key(func.__code__), []) + return {lineno: nhits for lineno, nhits, _ in timings}.get(lineno, 0) + + +@pytest.mark.parametrize('count_at_creation', [0, 1, 2]) +@pytest.mark.parametrize('count_at_start', [0, 1, 2]) +@pytest.mark.parametrize('use_wrapper', [True, False]) +@pytest.mark.parametrize('use_curated_ctx', [True, False]) +def test_child_thread_profiling_toggle_by_count( + my_module_obj: ModuleType, + prof: LineProfiler, + count_at_creation: int, + count_at_start: int, + use_wrapper: bool, + use_curated_ctx: bool, +) -> None: + """ + Test the profiling of child threads when the + :py:attr:`LineProfiler.enable_count` has been manipulated in + different manners. + """ + n = 10 + target = my_module_obj.func + if use_wrapper: + target = prof(target) + is_profiling = True + else: + prof.add_callable(target) + is_profiling = count_at_start > 0 + + with ExitStack() as stack: + if use_curated_ctx: + stack.enter_context(CuratedProfilerContext(prof)) + else: # Basically the same, but more explicit + cleanup = stack.enter_context(Cleanup()) + apply_patches(cleanup, prof) + + reset_enable_count(prof, count_at_creation) + thread = Thread(target=target, args=(n,)) + + reset_enable_count(prof, count_at_start) + thread.start() + thread.join() + + nhits = get_nhits(prof.get_stats(), unwrap(target), LOOP_BODY_LINE) + assert nhits == (n if is_profiling else 0) + + +@pytest.mark.parametrize('use_wrapper', [True, False]) +def test_child_thread_profiling_subclassed( + my_module_obj: ModuleType, prof: LineProfiler, use_wrapper: bool, +) -> None: + """ + Test profiling the workload in a :py:class:`Thread` subclass which + directly overrides the :py:meth:`Thread.run` method. + """ + target: Callable[[int], None] = my_module_obj.func + + class MyThread(Thread): + def run(self) -> None: + self.worker(self.n) + + @staticmethod + def worker(n: int) -> None: + target(n) + + @classmethod + def use(cls) -> None: + thread = cls() + thread.start() + thread.join() + + n: ClassVar[int] = 10 + + prof.enable_by_count() + with CuratedProfilerContext(prof): + if use_wrapper: + target = prof(target) + else: + prof.add_callable(target) + + MyThread.use() + + nhits = get_nhits(prof.get_stats(), unwrap(target), LOOP_BODY_LINE) + assert nhits == MyThread.n + + +@pytest.mark.parametrize('use_wrapper', [True, False]) +def test_child_thread_profiling_separate_creation_and_consumption( + my_module_obj: ModuleType, prof: LineProfiler, use_wrapper: bool, +) -> None: + """ + Test profiling in a thread whose instantiation and use happened on + different threads. + """ + target: Callable[[int], None] = my_module_obj.func + + def construct_thread(cond: Condition, namespace: dict[str, Any]) -> None: + with cond: + namespace['thread'] = Thread(target=target, args=(n,)) + cond.notify_all() + + def use_constructed_thread( + cond: Condition, namespace: dict[str, Any], + ) -> None: + with cond: + cond.wait() + thread = namespace['thread'] + thread.start() + thread.join() + + n = 10 + + prof.enable_by_count() + with CuratedProfilerContext(prof): + if use_wrapper: + target = prof(target) + else: + prof.add_callable(target) + + namespace: dict[str, Any] = {} + new_thread = partial(Thread, args=(Condition(), namespace)) + constructor_thread = new_thread(target=construct_thread) + consumer_thread = new_thread(target=use_constructed_thread) + # Start the consumer first to ensure that the underlying + # "physical" thread id isn't reused between the two + consumer_thread.start() + constructor_thread.start() + assert ( + None + is not consumer_thread.ident + != constructor_thread.ident + is not None + ) + constructor_thread.join() + consumer_thread.join() + + nhits = get_nhits(prof.get_stats(), unwrap(target), LOOP_BODY_LINE) + assert nhits == n + + +@pytest.mark.parametrize('lp_core', ['old', 'new']) +def test_child_thread_profiling_in_kernprof( + tmp_path_factory: pytest.TempPathFactory, + my_module_obj: ModuleType, + lp_core: Literal['old', 'new'], +) -> None: + """ + End-to-end test for profiling multithreaded code with + :py:mod:`kernprof`. + """ + if (sys.version_info[:2]) < (3, 12) and lp_core == 'new': + pytest.skip( + f"Can't use `sys.monitoring` in Python " + f'{".".join(str(v) for v in sys.version_info[:3])}' + ) + tmpdir = tmp_path_factory.mktemp('mytemp') + module = my_module_obj.__name__ + + nfiles = 4 + test_code = dedent(f""" + from __future__ import annotations + + import os + from threading import Thread + from {module} import func + + + threads: list[Thread] = [] + + for i in range(1, {nfiles + 1}): + output = os.path.join({str(tmpdir)!r}, f'out-{{i}}.txt') + threads.append(Thread(target=func, args=(i, output))) + + for thread in threads: + thread.start() + + for thread in threads: + thread.join() + """).strip('\n') + stats_file = tmpdir / 'out.lprof' + + cmd = [ + 'kernprof', '-l', f'--prof-mod={module}', + f'--outfile={stats_file}', + '-c', test_code, + ] + env = dict(os.environ) + env['LINE_PROFILER_CORE'] = lp_core + + # Verify the code execution + subprocess.run(cmd, check=True, env=env) + for i in range(1, nfiles + 1): + out = tmpdir / f'out-{i}.txt' + assert out.exists() + assert out.read_text() == ''.join(f'{n}\n' for n in range(1, i + 1)) + + # Verify the profiling output + total_nhits = (nfiles + 1) * nfiles / 2 + assert total_nhits == get_nhits( + LineStats.from_files(stats_file), + my_module_obj.func, + LOOP_BODY_LINE, + ) + + +def _test_disable_on_one_thread_keeps_other_threads_profiling_scenario( + nprof: Literal[1, 2], outdir: str | os.PathLike[str] | None = None, +) -> None: + def work_a() -> int: + return len([None]) # grep: BODY (a) + + def work_b(n: int = N) -> int: + total = 0 + for i in range(n): + total += i # grep: LOOP (b) + return total + + if nprof == 1: + prof_a = prof_b = LineProfiler(work_a, work_b) + elif nprof == 2: + prof_a = LineProfiler(work_a) + prof_b = LineProfiler(work_b) + else: + assert False, f'{nprof=}' + + b_ready = Event() + a_disabled = Event() + errors = [] + + def thread_b() -> None: + try: + with prof_b: + work_b() + b_ready.set() + assert a_disabled.wait(timeout=30) + # Profiling of this thread must survive thread A's + # disable... + work_b() + # ... and exiting the ctx disables `prof_b`, which must + # not raise + except BaseException as e: + errors.append(e) + b_ready.set() + + # Thread A (the main thread) is the first to enable a profiler and + # thus the one holding the global registration (when the core is + # process-global); it bows out while thread B is still profiling. + with prof_a: + worker = Thread(target=thread_b) + worker.start() + assert b_ready.wait(timeout=30) + work_a() + a_disabled.set() + worker.join(timeout=30) + assert not worker.is_alive() + + assert not errors, f'thread B errored: {errors!r}' + + # Write the profiling results for the test function to analyze + if outdir is None: + path = Path.cwd() + else: + path = Path(outdir) + assert path.is_dir() + prof_a.dump_stats(path / 'stats_a.lprof') + prof_b.dump_stats(path / 'stats_b.lprof') + + +@pytest.mark.parametrize('core', ['sysmon', 'legacy']) +@pytest.mark.parametrize('nprof', [1, 2]) +def test_disable_on_one_thread_keeps_other_threads_profiling( + tmp_path_factory: pytest.TempPathFactory, + core: Literal['sysmon', 'legacy'], + nprof: Literal[1, 2], +) -> None: + """ + Regression tests: disabling a profiler on one thread must not affect + profilers still active on other threads, be it the same profiler or + a different one. + + Under the :py:mod:`sys.monitoring` core, registration is + process-global while the manager bookkeeping is per-thread; the + first thread's manager used to tear down the global events/tool ID + as soon as *its* profilers were disabled, silently ending data + collection for every other thread and making their later + :py:meth:`LineProfiler.disable` calls raise + ``ValueError: tool ... is not in use`` from inside user ``finally`` + blocks. + + The core is chosen at import time, so the scenarios run in + subprocesses (once per core). + """ + def _get_nhits( + stats: LineStats, funcname: str, line_pattern: str | re.Pattern, + ) -> int: + source, start = getsourcelines(scenario) + if not isinstance(line_pattern, re.Pattern): + line_pattern = re.compile(line_pattern) + try: + ln_match = start + next( + offset for offset, line in enumerate(source) + if line_pattern.search(line.rstrip('\n')) + ) + except StopIteration: + return 0 + + try: + (entries_match,) = [ + e for (*_, func), e in stats.timings.items() + if func == funcname or func.rpartition('.')[-1] == funcname + ] + except ValueError: # != 1 match + return 0 + + return sum( + nhits for lineno, nhits, _ in entries_match if lineno == ln_match + ) + + tmp = tmp_path_factory.mktemp('mytmp') + if core == 'sysmon' and sys.version_info[:2] < (3, 12): + pytest.skip( + 'Cannot use `sys.monitoring` on Python ' + f'{".".join(str(v) for v in sys.version_info[:3])}' + ) + scenario = ( + _test_disable_on_one_thread_keeps_other_threads_profiling_scenario + ) + + env = {**os.environ, 'LINE_PROFILER_CORE': core} + script = dedent(f""" + from runpy import run_path + + + func = run_path({__file__!r})[{scenario.__name__!r}] + func({nprof}, {str(tmp)!r}) + """) + try: + proc = subprocess.run( + [sys.executable, '-c', script], + capture_output=True, env=env, text=True, timeout=120, + ) + proc.check_returncode() + finally: + for stream in 'stdout', 'stderr': + fobj = getattr(sys, stream) + if (content := getattr(proc, stream)): + content = indent(content, ' ') + sep = '\n' + else: + content, sep = '', ' ' + print(f'{stream}:{sep}{content}', end='', file=fobj) + + errors: list[str] = [] + for thread, filename, funcname, pattern, expected in [ + ('Main thread', 'stats_a.lprof', 'work_a', r'# grep: BODY \(a\)$', 1), + ('Thread B', 'stats_b.lprof', 'work_b', r'# grep: LOOP \(b\)$', 2 * N), + ]: + stats = LineStats.from_files(tmp / filename) + actual = _get_nhits(stats, funcname, pattern) + if actual != expected: + errors.append( + f'{thread}: ' + f'expected {expected} hit(s) on the line {pattern}, ' + f'got {actual}', + ) + assert not errors