From e543ffe0a413a0f5ef3362af152d6a195b3bf251 Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Wed, 21 May 2025 16:43:04 +0200 Subject: [PATCH 1/6] WIP: support for multiple profilers line_profiler/line_profiler.py[i]::LineProfiler No longer a `line_profiler._line_profiler.LineProfiler` subclass, but instead wrapping around a global instance thereof add_function(), {en,dis}able[_by_count](), get_stats() New methods (wrappers around the corresponding methods of the underlying profiler code_hash_map, dupes_map, [c_]{code_map, last_time} enable_count, timer_unit New properties (wrappers around the corresponding attributes of the underlying profiler) wrap_{async_generator,coroutine,generator,function}() Overrode superclass methods so as to distinguish between cases where the function has been seen by the underlying C-level profiler (but not this `LineProfiler` instance), and where it hasn't line_profiler/profiler_mixin.py wrap_{async_generator,coroutine,generator,function}() Refactored implementations so subclasses are allowed to supply the appropriate bookkeeping callbacks to be called before and after the profiled section other than `.enable_by_count()` and `.disable_by_count()` TODO: tests --- line_profiler/line_profiler.py | 299 +++++++++++++++++++++++++++++++- line_profiler/line_profiler.pyi | 78 ++++++++- line_profiler/profiler_mixin.py | 31 +++- 3 files changed, 389 insertions(+), 19 deletions(-) diff --git a/line_profiler/line_profiler.py b/line_profiler/line_profiler.py index c5f430c9..28ab93d4 100755 --- a/line_profiler/line_profiler.py +++ b/line_profiler/line_profiler.py @@ -4,16 +4,21 @@ inspect its output. This depends on the :py:mod:`line_profiler._line_profiler` Cython backend. """ -import pickle import inspect import linecache -import tempfile import os +import pickle import sys +import tempfile +import threading from argparse import ArgumentError, ArgumentParser +from copy import deepcopy +from weakref import WeakValueDictionary try: - from ._line_profiler import LineProfiler as CLineProfiler + from ._line_profiler import (NOP_BYTES as _NOP_BYTES, + LineProfiler as CLineProfiler, LineStats, + label as _get_stats_timing_label) except ImportError as ex: raise ImportError( 'The line_profiler._line_profiler c-extension is not importable. ' @@ -66,7 +71,39 @@ def _get_underlying_functions(func): return [type(func).__call__] -class LineProfiler(CLineProfiler, ByCountProfilerMixin): +def _get_code(func_like): + try: + return func_like.__code__ + except AttributeError: + return func_like.__func__.__code__ + + +class _WrappedTracker: + """ + Helper object for holding the state of a wrapper function. + + Attributes: + func (types.FunctionType): + The function it wraps. + c_profiler (int) + ID of the underlying Cython profiler. + profilers (set[int]) + IDs of the `LineProfiler` objects "listening" to the + function. + """ + def __init__(self, func, c_profiler, profilers=None): + self.func = func + self.c_profiler = c_profiler + self.profilers = set(profilers or ()) + + def __eq__(self, other): + if not isinstance(other, _WrappedTracker): + return False + return ((self.func, self.c_profiler, self.profilers) + == (other.func, other.c_profiler, other.profilers)) + + +class LineProfiler(ByCountProfilerMixin): """ A profiler that records the execution times of individual lines. @@ -83,6 +120,17 @@ class LineProfiler(CLineProfiler, ByCountProfilerMixin): >>> func() >>> profile.print_stats() """ + def __init__(self, *functions): + self.functions = [] + self.threaddata = threading.local() + for func in functions: + self.add_callable(func) + # Register the instance + try: + instances = type(self)._instances + except AttributeError: + instances = type(self)._instances = WeakValueDictionary() + instances[id(self)] = self def __call__(self, func): """ @@ -91,7 +139,8 @@ def __call__(self, func): exit. """ # Note: if `func` is a `types.FunctionType` which is already - # decorated by the profiler, the same object is returned; + # decorated by the (underlying C-level) profiler, the same + # object is returned; # otherwise, wrapper objects are always returned. self.add_callable(func) return self.wrap_callable(func) @@ -150,6 +199,246 @@ def add_module(self, mod): return nfuncsadded + # Helper methods and descriptors + + def _call_func_wrapper(self, super_impl, func): + if self._is_wrapper_around_seen(func): + tracker = getattr(func, self._profiler_wrapped_marker) + tracker.profilers.add(id(self)) + return func + return super_impl(func) + + def _filter_code_mapping(self, name): + mapping = getattr(self._get_c_profiler(), name) + codes = self._code_objs + return {code: deepcopy(item) for code, item in mapping.items() + if code in codes} + + @classmethod + def _is_wrapper_around_seen(cls, func): + """ + Returns: + seem (bool): + Whether the ``func`` is a wrapper function around an + underlying function which has been by the C-level + profiler. + """ + try: + tracker = getattr(func, cls._profiler_wrapped_marker) + except AttributeError: + return False + else: + return (isinstance(tracker, _WrappedTracker) + and tracker.c_profiler == id(cls._get_c_profiler())) + + @classmethod + def _get_c_profiler(cls): + """ + Get the :py:class:`line_profiler._line_profiler.LineProfiler` + (C-level profiler) instance for the Python process; as opposed + to :py:class:`line_profiler.LineProfiler` (this class), there + should only be one (active) instance thereof. + """ + try: + return cls._c_profiler + except AttributeError: + prof = cls._c_profiler = CLineProfiler() + return prof + + @property + def _code_objs(self): + # Note: this has to be calculated live from the function objects + # since the C-level profiler replaces a function's code object + # whenever its `.add_function()` is called on it + return {_get_code(func) for func in self.functions} + + # Override these `CLineProfiler` methods and attributes + # Note: `.__enter__()` and `.__exit__()` are already implemented in + # `ByCountProfilerMixin` + + def add_function(self, func): + """ + Register a function object with the underlying Cython profiler. + + Note: + This is a low-level function which strictly works with + :py:type:`types.FunctionType`; users should in general use + higher-level APIs like :py:meth:`.__call__()`, + :py:meth:`.add_callable()`, and :py:meth:`.wrap_callable()`. + """ + if self._is_wrapper_around_seen(func): + # If `func` is already a profiling wrapper and the wrapped + # function is known to the C-level profiler, just mark that + # we also have a finger in the pie + tracker = getattr(func, self._profiler_wrapped_marker) + tracker.profilers.add(id(self)) + self.functions.append(tracker.func) + else: + # Else, just pass it on to the C-level profiler + self._get_c_profiler().add_function(func) + self.functions.append(func) + + def enable_by_count(self): + self.enable_count += 1 + self._get_c_profiler().enable_by_count() + + def disable_by_count(self): + if self.enable_count <= 0: + return + self.enable_count -= 1 + self._get_c_profiler().disable_by_count() + + def enable(self): + pass # No-op, leave it to the underlying C-level profiler + + def disable(self): + pass # Ditto + + def get_stats(self): + all_timings = self._get_c_profiler().get_stats().timings + tracked_keys = {_get_stats_timing_label(code) + for code in self._code_objs} + timings = {key: entries for key, entries in all_timings.items() + if key in tracked_keys} + return LineStats(timings, self.timer_unit) + + @property + def code_hash_map(self): + return self._filter_code_mapping('code_hash_map') + + @property + def dupes_map(self): + # Note: in general, `func.__code__` for the `func` in + # `.functions` do not line up with + # `._get_c_profiler().dupes_map`, because `func.__code__` is + # padded by `CLineProfiler.add_function()` while entries (both + # the `CodeType.co_code` keys and the `list[CodeType]` values) + # aren't + def strip_suffix(byte_code, suffix): + n = len(suffix) + while byte_code.endswith(suffix) and byte_code != suffix: + byte_code = byte_code[:-n] + return byte_code + + assert _NOP_BYTES + stripped_codes = { + code.replace(co_code=strip_suffix(code.co_code, _NOP_BYTES)) + for code in self._code_objs + } + dupes = {byte_code: [code for code in codes if code in stripped_codes] + for byte_code, codes + in self._get_c_profiler().dupes_map.items()} + return {byte_code: list(codes) for byte_code, codes in dupes.items() + if codes} + + @property + def c_code_map(self): + hashes = {line_hash for hash_list in self.code_hash_map.values() + for line_hash in hash_list} + return {line_hash: deepcopy(line_time) + for line_hash, line_time + in self._get_c_profiler().c_code_map.items() + if line_hash in hashes} + + @property + def c_last_time(self): + # This should effectively be empty most of the time (and + # probably isn't meant for the end-user API), but do the + # filtering nonetheless + hashes = {hash(code.co_code) for code in self._code_objs} + return {block_hash: deepcopy(last_time) + for block_hash, last_time + in self._get_c_profiler().c_last_time.items() + if block_hash in hashes} + + @property + def code_map(self): + return self._filter_code_mapping('code_map') + + @property + def last_time(self): + return self._filter_code_mapping('last_time') + + @property + def enable_count(self): + try: + return self.threaddata.enable_count + except AttributeError: + self.threaddata.enable_count = 0 + return 0 + + @enable_count.setter + def enable_count(self, value): + self.threaddata.enable_count = value + + @property + def timer_unit(self): + return self._get_c_profiler().timer_unit + + # Override these mixed-in bookkeeping methods to take care of + # potential multiple profiler sequences + + def wrap_async_generator(self, func): + return self._call_func_wrapper(super().wrap_async_generator, func) + + def wrap_coroutine(self, func): + return self._call_func_wrapper(super().wrap_coroutine, func) + + def wrap_generator(self, func): + return self._call_func_wrapper(super().wrap_generator, func) + + def wrap_function(self, func): + return self._call_func_wrapper(super().wrap_function, func) + + def _already_wrapped(self, func): + if not self._is_wrapper_around_seen(func): + return False + tracker = getattr(func, self._profiler_wrapped_marker) + return id(self) in tracker.profilers + + def _mark_wrapped(self, func): + if self._is_wrapper_around_seen(func): + tracker = getattr(func, self._profiler_wrapped_marker) + else: + tracker = _WrappedTracker(func.__wrapped__, + id(self._get_c_profiler())) + setattr(func, self._profiler_wrapped_marker, tracker) + tracker.profilers.add(id(self)) + return func + + def _get_toggle_callbacks(self, wrapper): + # Notes: + # - The callbacks cannot be just `self.enable_by_count()` + # and `self.disable_by_count()`, since we want all the + # instances "listening" to the profiled function (plus the + # C-level profiler) to be enabled and disabled accordingly + # - And we can't just call those methods on each instance + # either, because they also call the corresponding methods + # on the C-level profiler... + + def enable(): + for prof in get_listeners(): + prof.enable_count += 1 + cprof.enable_by_count() + + def disable(): + for prof in get_listeners(): + if prof.enable_count <= 0: + continue + prof.enable_count -= 1 + cprof.disable_by_count() + + def get_listeners(): + tracker = getattr(wrapper, self._profiler_wrapped_marker) + return { + instances[prof_id] for prof_id in tracker.profilers + if prof_id in instances + } + + cprof = self._get_c_profiler() + instances = type(self)._instances + return enable, disable + # This could be in the ipython_extension submodule, # but it doesn't depend on the IPython module so it's easier to just let it stay here. diff --git a/line_profiler/line_profiler.pyi b/line_profiler/line_profiler.pyi index 1d476f95..26b496b1 100644 --- a/line_profiler/line_profiler.pyi +++ b/line_profiler/line_profiler.pyi @@ -1,7 +1,7 @@ -from typing import List -from typing import Tuple +from types import CodeType, ModuleType, FunctionType +from typing import Literal, Dict, List, Tuple import io -from ._line_profiler import LineProfiler as CLineProfiler +from ._line_profiler import LineStats from .profiler_mixin import ByCountProfilerMixin from _typeshed import Incomplete @@ -10,9 +10,14 @@ def load_ipython_extension(ip) -> None: ... -class LineProfiler(CLineProfiler, ByCountProfilerMixin): +class LineProfiler(ByCountProfilerMixin): + def __init__(self, *functions: FunctionType): + ... + + def __call__(self, func): + ... - def add_callable(self, func) -> None: + def add_callable(self, func) -> Literal[0, 1]: ... def dump_stats(self, filename) -> None: @@ -28,7 +33,68 @@ class LineProfiler(CLineProfiler, ByCountProfilerMixin): rich: bool = ...) -> None: ... - def add_module(self, mod): + def add_module(self, mod: ModuleType) -> int: + ... + + # `line_profiler._line_profiler.LineProfiler` methods and attributes + # (note: some of them are properties because they wrap around the + # corresponding C-level profiler attribute, but are bare attributes + # on the C-level profiler) + + functions: List[FunctionType] + + def add_function(self, func: FunctionType) -> None: + ... + + def enable_by_count(self) -> None: + ... + + def disable_by_count(self) -> None: + ... + + def enable(self) -> None: + ... + + def disable(self) -> None: + ... + + def get_stats(self) -> LineStats: + ... + + @property + def code_hash_map(self) -> Dict[CodeType, List[int]]: + ... + + @property + def dupes_map(self) -> Dict[bytes, List[CodeType]]: + ... + + @property + def c_code_map(self) -> Dict[int, dict]: + ... + + @property + def c_last_time(self) -> Dict[int, dict]: + ... + + @property + def code_map(self) -> Dict[CodeType, Dict[int, dict]]: + ... + + @property + def last_time(self) -> Dict[CodeType, dict]: + ... + + @property + def enable_count(self) -> int: + ... + + @enable_count.setter + def enable_count(self, value: int) -> None: + ... + + @property + def timer_unit(self) -> float: ... diff --git a/line_profiler/profiler_mixin.py b/line_profiler/profiler_mixin.py index 94653976..5f662981 100644 --- a/line_profiler/profiler_mixin.py +++ b/line_profiler/profiler_mixin.py @@ -207,15 +207,16 @@ async def wrapper(*args, **kwds): # Async generators are started by `.asend(None)` input_ = None while True: - self.enable_by_count() + enable() try: item = (await g.asend(input_)) except StopAsyncIteration: return finally: - self.disable_by_count() + disable() input_ = (yield item) + enable, disable = self._get_toggle_callbacks(wrapper) return self._mark_wrapped(wrapper) def wrap_coroutine(self, func): @@ -228,13 +229,14 @@ def wrap_coroutine(self, func): @functools.wraps(func) async def wrapper(*args, **kwds): - self.enable_by_count() + enable() try: result = await func(*args, **kwds) finally: - self.disable_by_count() + disable() return result + enable, disable = self._get_toggle_callbacks(wrapper) return self._mark_wrapped(wrapper) def wrap_generator(self, func): @@ -251,15 +253,16 @@ def wrapper(*args, **kwds): # Generators are started by `.send(None)` input_ = None while True: - self.enable_by_count() + enable() try: item = g.send(input_) except StopIteration: return finally: - self.disable_by_count() + disable() input_ = (yield item) + enable, disable = self._get_toggle_callbacks(wrapper) return self._mark_wrapped(wrapper) def wrap_function(self, func): @@ -272,13 +275,14 @@ def wrap_function(self, func): @functools.wraps(func) def wrapper(*args, **kwds): - self.enable_by_count() + enable() try: result = func(*args, **kwds) finally: - self.disable_by_count() + disable() return result + enable, disable = self._get_toggle_callbacks(wrapper) return self._mark_wrapped(wrapper) def _already_wrapped(self, func): @@ -288,6 +292,17 @@ def _mark_wrapped(self, func): setattr(func, self._profiler_wrapped_marker, id(self)) return func + def _get_toggle_callbacks(self, wrapper): + """ + Get the callbacks that should be called (1) before a profiled + function is used, and (2) when it returns, yields, or raises. + + Arguments: + wrapper (types.FunctionType): + Wrapper function around the profiled function + """ + return self.enable_by_count, self.disable_by_count + def run(self, cmd): """ Profile a single executable statment in the main namespace. """ From c97d2f3a5ba95941efa8e795aaf10977116d734c Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 02:23:07 +0200 Subject: [PATCH 2/6] Added tests tests/test_line_profiler.py test_multiple_profilers_metadata() Test that the metadata wrappers on `line_profiler.LineProfiler` correctly wraps around the corresponding attributes/descriptors on `line_profiler._line_profiler.LineProfiler` (the Cython-level object) test_multiple_profilers_usage() Test that multiple instances of `line_profiler.LineProfiler` can function simultaneously and separately --- tests/test_line_profiler.py | 155 ++++++++++++++++++++++++++++++++++++ 1 file changed, 155 insertions(+) diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index 3075189a..eb8ffe98 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -622,3 +622,158 @@ def test_profile_generated_code(): # .. as well as the generated code name assert generated_code_name in output + + +def test_multiple_profilers_metadata(): + """ + Test the curation of profiler metadata (e.g. `.code_hash_map`, + `.dupes_map`, `.code_map`) from the underlying C-level profiler. + """ + from copy import deepcopy + from operator import attrgetter + from warnings import warn + + prof1 = LineProfiler() + prof2 = LineProfiler() + cprof = prof1._get_c_profiler() + assert prof2._get_c_profiler() is cprof + + @prof1 + @prof2 + def f(c=False): + get_time = attrgetter('c_last_time' if c else 'last_time') + t1 = get_time(prof1) + t2 = get_time(prof2) + return [t1, t2, get_time(cprof)] + + @prof1 + def g(): + return [prof1.enable_count, prof2.enable_count] + + @prof2 + def h(): # Same bytecode as `g()` + return [prof1.enable_count, prof2.enable_count] + + get_code = attrgetter('__wrapped__.__code__') + + # `.functions` + assert prof1.functions == [f.__wrapped__, g.__wrapped__] + assert prof2.functions == [f.__wrapped__, h.__wrapped__] + # `.enable_count` + # (Note: `.enable_count` is automatically in-/de-cremented in + # decorated functions, so we need to access it within a called + # function) + assert g() == [1, 0] + assert h() == [0, 1] + assert prof1.enable_count == prof2.enable_count == cprof.enable_count == 0 + # `.timer_unit` + assert prof1.timer_unit == prof2.timer_unit == cprof.timer_unit + # `.code_hash_map` + assert set(prof1.code_hash_map) == {get_code(f), get_code(g)} + assert set(prof2.code_hash_map) == {get_code(f), get_code(h)} + + # `.c_code_map` + prof1_line_hashes = {h for hashes in prof1.code_hash_map.values() + for h in hashes} + assert set(prof1.c_code_map) == prof1_line_hashes + prof2_line_hashes = {h for hashes in prof2.code_hash_map.values() + for h in hashes} + assert set(prof2.c_code_map) == prof2_line_hashes + # `.code_map` + assert set(prof1.code_map) == {get_code(f), get_code(g)} + assert len(prof1.code_map[get_code(f)]) == 0 + assert len(prof1.code_map[get_code(g)]) == 1 + assert set(prof2.code_map) == {get_code(f), get_code(h)} + assert len(prof2.code_map[get_code(f)]) == 0 + assert len(prof2.code_map[get_code(h)]) == 1 + t1, t2, _ = f() # Timing info gathered after calling the function + assert len(prof1.code_map[get_code(f)]) == 4 # 4 real lines + assert len(prof2.code_map[get_code(f)]) == 4 + + # `.c_last_time` + # (Note: `.c_last_time` is transient, so we need to access it within + # a called function) + ct1, ct2, _ = f(c=True) + assert set(ct1) == set(ct2) == {hash(get_code(f).co_code)} + # `.last_time` + # (Note: `.last_time` is currently bugged; since `.c_last_time` + # stores code-block hashes and `.code_hash_map` line hashes, + # `line_profiler._line_profiler.LineProfiler.last_time` never gets a + # hash match and is thus always empty) + t1, t2, tc = f(c=False) + if tc: + expected = {get_code(f)} + else: + msg = ('`line_profiler/_line_profiler.pyx::LineProfiler.last_time` ' + 'is always empty because `.c_last_time` and `.code_hash_map` ' + 'use different types of hashes (see PR #344)') + warn(msg, DeprecationWarning) + expected = set() + assert set(t1) == set(t2) == set(tc) == expected + + # `.dupes_map` (introduce a dupe for this) + # Note: `h.__wrapped__.__code__` is padded but the `.dupes_map` + # entries are not + assert prof1.dupes_map == {get_code(f).co_code: [get_code(f)], + get_code(g).co_code: [get_code(g)]} + h = prof1(h) + dupes = deepcopy(prof1.dupes_map) + h_code = dupes[get_code(g).co_code][-1] + assert get_code(h).co_code.startswith(h_code.co_code) + dupes[get_code(g).co_code][-1] = (h_code + .replace(co_code=get_code(h).co_code)) + assert dupes == {get_code(f).co_code: [get_code(f)], + get_code(g).co_code: [get_code(g), get_code(h)]} + + +def test_multiple_profilers_usage(): + """ + Test using more than one profilers simultaneously. + """ + prof1 = LineProfiler() + prof2 = LineProfiler() + + def sum_n(n): + x = 0 + for n in range(1, n + 1): + x += n + return x + + @prof1 + def sum_n_sq(n): + x = 0 + for n in range(1, n + 1): + x += n ** 2 + return x + + @prof2 + def sum_n_cb(n): + x = 0 + for n in range(1, n + 1): + x += n ** 3 + return x + + # If we decorate a wrapper, just "register" the profiler with the + # existing wrapper and add the wrapped function + sum_n_wrapper = prof1(sum_n) + assert prof1.functions == [sum_n_sq.__wrapped__, sum_n] + sum_n_wrapper_2 = prof2(sum_n_wrapper) + assert prof2.functions == [sum_n_cb.__wrapped__, sum_n] + assert sum_n_wrapper_2 is sum_n_wrapper + + # Call the functions + n = 400 + assert sum_n_wrapper(n) == .5 * n * (n + 1) + assert 6 * sum_n_sq(n) == n * (n + 1) * (2 * n + 1) + assert sum_n_cb(n) == .25 * (n * (n + 1)) ** 2 + + # Inspect the timings + t1 = {fname: entries + for (*_, fname), entries in prof1.get_stats().timings.items()} + t2 = {fname: entries + for (*_, fname), entries in prof2.get_stats().timings.items()} + assert set(t1) == {'sum_n_sq', 'sum_n'} + assert set(t2) == {'sum_n_cb', 'sum_n'} + assert t1['sum_n'][2][1] == t2['sum_n'][2][1] == n + assert t1['sum_n_sq'][2][1] == n + assert t2['sum_n_cb'][2][1] == n From 97739db6d74b2e24ee93b857895a676a13acd72b Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 07:43:53 +0200 Subject: [PATCH 3/6] Rolled back changes, moved code to Cython level line_profiler/_line_profiler.pyx LineProfiler - Added: - Private class attribute `._active_instances_getter` - Private property `._active_instances` - Refactored `.enable()` and `.disable()` so that multiple instances of `LineProfiler` are supported python_trace_callback() - Updated call signature; instead of taking a `LineProfiler` `PyObject`, now it takes an iterable thereof - Refactored implementation to work with all profiler instances in said iterable line_profiler/line_profiler.py[i] Rolled back most of the code changes (e.g. now a `line_profiler._line_profiler.LineProfiler` subclass again) LineProfiler.add_callable() - Added check for if the callable is a wrapper created by another profiler, in which case the wrapped function's `add_callable()` should be called instead - Fixed erroneous stub-file return annotation (`None` -> `Literal[0, 1]`) LineProfiler._already_a_wrapper(), ._mark_wrapper() Renamed and updated implementations line_profiler/profiler_mixin.py::ByCountProfilerMixin Rolled back most of the code changes (e.g. removed the new private `._get_toggle_callbacks()` method) _already_a_wrapper() (<- `_already_wrapped()`) _mark_wrapper() (<- `_mark_wrapped()`) Renamed methods for clarity tests/test_line_profiler.py test_multiple_profilers_metadata() Removed test because `line_profiler.LineProfiler` no longer wraps around `line_profiler._line_profiler.LineProfiler` test_multiple_profilers_usage() Updated to reflect the new, improved implementation: profiler instances and created wrappers are now separate, so profiling is granular and only happens e.g. when the appropriate wrapper is called --- line_profiler/_line_profiler.pyx | 61 +++--- line_profiler/line_profiler.py | 309 +++---------------------------- line_profiler/line_profiler.pyi | 76 +------- line_profiler/profiler_mixin.py | 55 ++---- tests/test_line_profiler.py | 116 +----------- 5 files changed, 100 insertions(+), 517 deletions(-) diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 13ac480b..0e9ada10 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -253,6 +253,9 @@ cdef class LineProfiler: cdef public double timer_unit cdef public object threaddata + # This is shared between instances and threads + _active_instances_getter = {}.setdefault + def __init__(self, *functions): self.functions = [] self.code_hash_map = {} @@ -319,6 +322,11 @@ cdef class LineProfiler: def __set__(self, value): self.threaddata.enable_count = value + # This is shared between instances, but thread-local + property _active_instances: + def __get__(self): + return self._active_instances_getter(threading.get_ident(), set()) + def enable_by_count(self): """ Enable the profiler if it hasn't been enabled before. """ @@ -345,8 +353,11 @@ cdef class LineProfiler: # Register `line_profiler` with `sys.monitoring` in Python 3.12 # and above; # see: https://docs.python.org/3/library/sys.monitoring.html - _sys_monitoring_register() - PyEval_SetTrace(python_trace_callback, self) + instances = self._active_instances + if not instances: + _sys_monitoring_register() + PyEval_SetTrace(python_trace_callback, instances) + instances.add(self) @property def c_code_map(self): @@ -397,12 +408,15 @@ cdef class LineProfiler: cpdef disable(self): + instances = self._active_instances self._c_last_time[threading.get_ident()].clear() - unset_trace() - # Deregister `line_profiler` with `sys.monitoring` in Python - # 3.12 and above; - # see: https://docs.python.org/3/library/sys.monitoring.html - _sys_monitoring_deregister() + instances.discard(self) + if not instances: + unset_trace() + # Deregister `line_profiler` with `sys.monitoring` in Python + # 3.12 and above; + # see: https://docs.python.org/3/library/sys.monitoring.html + _sys_monitoring_deregister() def get_stats(self): """ @@ -443,7 +457,8 @@ cdef class LineProfiler: @cython.boundscheck(False) @cython.wraparound(False) -cdef extern int python_trace_callback(object self_, PyFrameObject *py_frame, +cdef extern int python_trace_callback(object instances, + PyFrameObject *py_frame, int what, PyObject *arg): """ The PyEval_SetTrace() callback. @@ -451,7 +466,8 @@ cdef extern int python_trace_callback(object self_, PyFrameObject *py_frame, References: https://github.com/python/cpython/blob/de2a4036/Include/cpython/pystate.h#L16 """ - cdef LineProfiler self + cdef object prof_ + cdef LineProfiler prof cdef object code cdef LineTime entry cdef LastTime old @@ -462,8 +478,6 @@ cdef extern int python_trace_callback(object self_, PyFrameObject *py_frame, cdef unordered_map[int64, LineTime] line_entries cdef uint64 linenum - self = self_ - if what == PyTrace_LINE or what == PyTrace_RETURN: # Normally we'd need to DECREF the return from get_frame_code, but Cython does that for us block_hash = hash(get_frame_code(py_frame)) @@ -471,25 +485,28 @@ cdef extern int python_trace_callback(object self_, PyFrameObject *py_frame, linenum = PyFrame_GetLineNumber(py_frame) code_hash = compute_line_hash(block_hash, linenum) - if self._c_code_map.count(code_hash): - time = hpTimer() + time = hpTimer() + for prof_ in instances: + prof = prof_ + if not prof._c_code_map.count(code_hash): + continue ident = threading.get_ident() - if self._c_last_time[ident].count(block_hash): - old = self._c_last_time[ident][block_hash] - line_entries = self._c_code_map[code_hash] + if prof._c_last_time[ident].count(block_hash): + old = prof._c_last_time[ident][block_hash] + line_entries = prof._c_code_map[code_hash] key = old.f_lineno if not line_entries.count(key): - self._c_code_map[code_hash][key] = LineTime(code_hash, key, 0, 0) - self._c_code_map[code_hash][key].nhits += 1 - self._c_code_map[code_hash][key].total_time += time - old.time + prof._c_code_map[code_hash][key] = LineTime(code_hash, key, 0, 0) + prof._c_code_map[code_hash][key].nhits += 1 + prof._c_code_map[code_hash][key].total_time += time - old.time if what == PyTrace_LINE: # Get the time again. This way, we don't record much time wasted # in this function. - self._c_last_time[ident][block_hash] = LastTime(linenum, hpTimer()) - elif self._c_last_time[ident].count(block_hash): + prof._c_last_time[ident][block_hash] = LastTime(linenum, hpTimer()) + elif prof._c_last_time[ident].count(block_hash): # We are returning from a function, not executing a line. Delete # the last_time record. It may have already been deleted if we # are profiling a generator that is being pumped past its end. - self._c_last_time[ident].erase(self._c_last_time[ident].find(block_hash)) + prof._c_last_time[ident].erase(prof._c_last_time[ident].find(block_hash)) return 0 diff --git a/line_profiler/line_profiler.py b/line_profiler/line_profiler.py index 28ab93d4..4ee0f7dc 100755 --- a/line_profiler/line_profiler.py +++ b/line_profiler/line_profiler.py @@ -10,15 +10,10 @@ import pickle import sys import tempfile -import threading from argparse import ArgumentError, ArgumentParser -from copy import deepcopy -from weakref import WeakValueDictionary try: - from ._line_profiler import (NOP_BYTES as _NOP_BYTES, - LineProfiler as CLineProfiler, LineStats, - label as _get_stats_timing_label) + from ._line_profiler import LineProfiler as CLineProfiler except ImportError as ex: raise ImportError( 'The line_profiler._line_profiler c-extension is not importable. ' @@ -71,39 +66,22 @@ def _get_underlying_functions(func): return [type(func).__call__] -def _get_code(func_like): - try: - return func_like.__code__ - except AttributeError: - return func_like.__func__.__code__ - - -class _WrappedTracker: +class _WrapperInfo: """ Helper object for holding the state of a wrapper function. Attributes: func (types.FunctionType): The function it wraps. - c_profiler (int) - ID of the underlying Cython profiler. - profilers (set[int]) - IDs of the `LineProfiler` objects "listening" to the - function. + profiler (int) + ID of the `LineProfiler`. """ - def __init__(self, func, c_profiler, profilers=None): + def __init__(self, func, profiler): self.func = func - self.c_profiler = c_profiler - self.profilers = set(profilers or ()) + self.profiler = profiler - def __eq__(self, other): - if not isinstance(other, _WrappedTracker): - return False - return ((self.func, self.c_profiler, self.profilers) - == (other.func, other.c_profiler, other.profilers)) - -class LineProfiler(ByCountProfilerMixin): +class LineProfiler(CLineProfiler, ByCountProfilerMixin): """ A profiler that records the execution times of individual lines. @@ -120,18 +98,6 @@ class LineProfiler(ByCountProfilerMixin): >>> func() >>> profile.print_stats() """ - def __init__(self, *functions): - self.functions = [] - self.threaddata = threading.local() - for func in functions: - self.add_callable(func) - # Register the instance - try: - instances = type(self)._instances - except AttributeError: - instances = type(self)._instances = WeakValueDictionary() - instances[id(self)] = self - def __call__(self, func): """ Decorate a function, method, property, partial object etc. to @@ -139,8 +105,7 @@ def __call__(self, func): exit. """ # Note: if `func` is a `types.FunctionType` which is already - # decorated by the (underlying C-level) profiler, the same - # object is returned; + # decorated by the profiler, the same object is returned; # otherwise, wrapper objects are always returned. self.add_callable(func) return self.wrap_callable(func) @@ -153,12 +118,15 @@ def add_callable(self, func): Returns: 1 if any function is added to the profiler, 0 otherwise """ - guard = self._already_wrapped - nadded = 0 for impl in _get_underlying_functions(func): - if guard(impl): + info, wrapped_by_this_prof = self._get_wrapper_info(impl) + if wrapped_by_this_prof: continue + if info: + # It's still a profiling wrapper, just wrapped by + # someone else -> extract the inner function + impl = info.func self.add_function(impl) nadded += 1 @@ -199,245 +167,24 @@ def add_module(self, mod): return nfuncsadded - # Helper methods and descriptors - - def _call_func_wrapper(self, super_impl, func): - if self._is_wrapper_around_seen(func): - tracker = getattr(func, self._profiler_wrapped_marker) - tracker.profilers.add(id(self)) - return func - return super_impl(func) - - def _filter_code_mapping(self, name): - mapping = getattr(self._get_c_profiler(), name) - codes = self._code_objs - return {code: deepcopy(item) for code, item in mapping.items() - if code in codes} - - @classmethod - def _is_wrapper_around_seen(cls, func): - """ - Returns: - seem (bool): - Whether the ``func`` is a wrapper function around an - underlying function which has been by the C-level - profiler. - """ - try: - tracker = getattr(func, cls._profiler_wrapped_marker) - except AttributeError: - return False - else: - return (isinstance(tracker, _WrappedTracker) - and tracker.c_profiler == id(cls._get_c_profiler())) - - @classmethod - def _get_c_profiler(cls): - """ - Get the :py:class:`line_profiler._line_profiler.LineProfiler` - (C-level profiler) instance for the Python process; as opposed - to :py:class:`line_profiler.LineProfiler` (this class), there - should only be one (active) instance thereof. - """ - try: - return cls._c_profiler - except AttributeError: - prof = cls._c_profiler = CLineProfiler() - return prof - - @property - def _code_objs(self): - # Note: this has to be calculated live from the function objects - # since the C-level profiler replaces a function's code object - # whenever its `.add_function()` is called on it - return {_get_code(func) for func in self.functions} - - # Override these `CLineProfiler` methods and attributes - # Note: `.__enter__()` and `.__exit__()` are already implemented in - # `ByCountProfilerMixin` - - def add_function(self, func): - """ - Register a function object with the underlying Cython profiler. - - Note: - This is a low-level function which strictly works with - :py:type:`types.FunctionType`; users should in general use - higher-level APIs like :py:meth:`.__call__()`, - :py:meth:`.add_callable()`, and :py:meth:`.wrap_callable()`. - """ - if self._is_wrapper_around_seen(func): - # If `func` is already a profiling wrapper and the wrapped - # function is known to the C-level profiler, just mark that - # we also have a finger in the pie - tracker = getattr(func, self._profiler_wrapped_marker) - tracker.profilers.add(id(self)) - self.functions.append(tracker.func) - else: - # Else, just pass it on to the C-level profiler - self._get_c_profiler().add_function(func) - self.functions.append(func) - - def enable_by_count(self): - self.enable_count += 1 - self._get_c_profiler().enable_by_count() - - def disable_by_count(self): - if self.enable_count <= 0: - return - self.enable_count -= 1 - self._get_c_profiler().disable_by_count() - - def enable(self): - pass # No-op, leave it to the underlying C-level profiler - - def disable(self): - pass # Ditto - - def get_stats(self): - all_timings = self._get_c_profiler().get_stats().timings - tracked_keys = {_get_stats_timing_label(code) - for code in self._code_objs} - timings = {key: entries for key, entries in all_timings.items() - if key in tracked_keys} - return LineStats(timings, self.timer_unit) - - @property - def code_hash_map(self): - return self._filter_code_mapping('code_hash_map') - - @property - def dupes_map(self): - # Note: in general, `func.__code__` for the `func` in - # `.functions` do not line up with - # `._get_c_profiler().dupes_map`, because `func.__code__` is - # padded by `CLineProfiler.add_function()` while entries (both - # the `CodeType.co_code` keys and the `list[CodeType]` values) - # aren't - def strip_suffix(byte_code, suffix): - n = len(suffix) - while byte_code.endswith(suffix) and byte_code != suffix: - byte_code = byte_code[:-n] - return byte_code - - assert _NOP_BYTES - stripped_codes = { - code.replace(co_code=strip_suffix(code.co_code, _NOP_BYTES)) - for code in self._code_objs - } - dupes = {byte_code: [code for code in codes if code in stripped_codes] - for byte_code, codes - in self._get_c_profiler().dupes_map.items()} - return {byte_code: list(codes) for byte_code, codes in dupes.items() - if codes} - - @property - def c_code_map(self): - hashes = {line_hash for hash_list in self.code_hash_map.values() - for line_hash in hash_list} - return {line_hash: deepcopy(line_time) - for line_hash, line_time - in self._get_c_profiler().c_code_map.items() - if line_hash in hashes} - - @property - def c_last_time(self): - # This should effectively be empty most of the time (and - # probably isn't meant for the end-user API), but do the - # filtering nonetheless - hashes = {hash(code.co_code) for code in self._code_objs} - return {block_hash: deepcopy(last_time) - for block_hash, last_time - in self._get_c_profiler().c_last_time.items() - if block_hash in hashes} - - @property - def code_map(self): - return self._filter_code_mapping('code_map') - - @property - def last_time(self): - return self._filter_code_mapping('last_time') - - @property - def enable_count(self): - try: - return self.threaddata.enable_count - except AttributeError: - self.threaddata.enable_count = 0 - return 0 - - @enable_count.setter - def enable_count(self, value): - self.threaddata.enable_count = value - - @property - def timer_unit(self): - return self._get_c_profiler().timer_unit + def _get_wrapper_info(self, func): + info = getattr(func, self._profiler_wrapped_marker, None) + return info, bool(info and id(self) == info.profiler) # Override these mixed-in bookkeeping methods to take care of # potential multiple profiler sequences - def wrap_async_generator(self, func): - return self._call_func_wrapper(super().wrap_async_generator, func) - - def wrap_coroutine(self, func): - return self._call_func_wrapper(super().wrap_coroutine, func) - - def wrap_generator(self, func): - return self._call_func_wrapper(super().wrap_generator, func) - - def wrap_function(self, func): - return self._call_func_wrapper(super().wrap_function, func) - - def _already_wrapped(self, func): - if not self._is_wrapper_around_seen(func): - return False - tracker = getattr(func, self._profiler_wrapped_marker) - return id(self) in tracker.profilers - - def _mark_wrapped(self, func): - if self._is_wrapper_around_seen(func): - tracker = getattr(func, self._profiler_wrapped_marker) - else: - tracker = _WrappedTracker(func.__wrapped__, - id(self._get_c_profiler())) - setattr(func, self._profiler_wrapped_marker, tracker) - tracker.profilers.add(id(self)) - return func - - def _get_toggle_callbacks(self, wrapper): - # Notes: - # - The callbacks cannot be just `self.enable_by_count()` - # and `self.disable_by_count()`, since we want all the - # instances "listening" to the profiled function (plus the - # C-level profiler) to be enabled and disabled accordingly - # - And we can't just call those methods on each instance - # either, because they also call the corresponding methods - # on the C-level profiler... - - def enable(): - for prof in get_listeners(): - prof.enable_count += 1 - cprof.enable_by_count() - - def disable(): - for prof in get_listeners(): - if prof.enable_count <= 0: - continue - prof.enable_count -= 1 - cprof.disable_by_count() - - def get_listeners(): - tracker = getattr(wrapper, self._profiler_wrapped_marker) - return { - instances[prof_id] for prof_id in tracker.profilers - if prof_id in instances - } - - cprof = self._get_c_profiler() - instances = type(self)._instances - return enable, disable + def _already_a_wrapper(self, func): + return self._get_wrapper_info(func)[1] + + def _mark_wrapper(self, wrapper): + # Are re-wrapping an existing wrapper (e.g. created by another + # profiler?) + wrapped = wrapper.__wrapped__ + info = getattr(wrapped, self._profiler_wrapped_marker, None) + new_info = _WrapperInfo(info.func if info else wrapped, id(self)) + setattr(wrapper, self._profiler_wrapped_marker, new_info) + return wrapper # This could be in the ipython_extension submodule, diff --git a/line_profiler/line_profiler.pyi b/line_profiler/line_profiler.pyi index 26b496b1..edbf1bde 100644 --- a/line_profiler/line_profiler.pyi +++ b/line_profiler/line_profiler.pyi @@ -1,7 +1,6 @@ -from types import CodeType, ModuleType, FunctionType -from typing import Literal, Dict, List, Tuple +from typing import Literal, List, Tuple import io -from ._line_profiler import LineStats +from ._line_profiler import LineProfiler as CLineProfiler from .profiler_mixin import ByCountProfilerMixin from _typeshed import Incomplete @@ -10,13 +9,7 @@ def load_ipython_extension(ip) -> None: ... -class LineProfiler(ByCountProfilerMixin): - def __init__(self, *functions: FunctionType): - ... - - def __call__(self, func): - ... - +class LineProfiler(CLineProfiler, ByCountProfilerMixin): def add_callable(self, func) -> Literal[0, 1]: ... @@ -33,68 +26,7 @@ class LineProfiler(ByCountProfilerMixin): rich: bool = ...) -> None: ... - def add_module(self, mod: ModuleType) -> int: - ... - - # `line_profiler._line_profiler.LineProfiler` methods and attributes - # (note: some of them are properties because they wrap around the - # corresponding C-level profiler attribute, but are bare attributes - # on the C-level profiler) - - functions: List[FunctionType] - - def add_function(self, func: FunctionType) -> None: - ... - - def enable_by_count(self) -> None: - ... - - def disable_by_count(self) -> None: - ... - - def enable(self) -> None: - ... - - def disable(self) -> None: - ... - - def get_stats(self) -> LineStats: - ... - - @property - def code_hash_map(self) -> Dict[CodeType, List[int]]: - ... - - @property - def dupes_map(self) -> Dict[bytes, List[CodeType]]: - ... - - @property - def c_code_map(self) -> Dict[int, dict]: - ... - - @property - def c_last_time(self) -> Dict[int, dict]: - ... - - @property - def code_map(self) -> Dict[CodeType, Dict[int, dict]]: - ... - - @property - def last_time(self) -> Dict[CodeType, dict]: - ... - - @property - def enable_count(self) -> int: - ... - - @enable_count.setter - def enable_count(self, value: int) -> None: - ... - - @property - def timer_unit(self) -> float: + def add_module(self, mod) -> int: ... diff --git a/line_profiler/profiler_mixin.py b/line_profiler/profiler_mixin.py index 5f662981..52980765 100644 --- a/line_profiler/profiler_mixin.py +++ b/line_profiler/profiler_mixin.py @@ -198,7 +198,7 @@ def wrap_async_generator(self, func): Wrap an async generator function to profile it. """ # Prevent double-wrap - if self._already_wrapped(func): + if self._already_a_wrapper(func): return func @functools.wraps(func) @@ -207,44 +207,42 @@ async def wrapper(*args, **kwds): # Async generators are started by `.asend(None)` input_ = None while True: - enable() + self.enable_by_count() try: item = (await g.asend(input_)) except StopAsyncIteration: return finally: - disable() + self.disable_by_count() input_ = (yield item) - enable, disable = self._get_toggle_callbacks(wrapper) - return self._mark_wrapped(wrapper) + return self._mark_wrapper(wrapper) def wrap_coroutine(self, func): """ Wrap a coroutine function to profile it. """ # Prevent double-wrap - if self._already_wrapped(func): + if self._already_a_wrapper(func): return func @functools.wraps(func) async def wrapper(*args, **kwds): - enable() + self.enable_by_count() try: result = await func(*args, **kwds) finally: - disable() + self.disable_by_count() return result - enable, disable = self._get_toggle_callbacks(wrapper) - return self._mark_wrapped(wrapper) + return self._mark_wrapper(wrapper) def wrap_generator(self, func): """ Wrap a generator function to profile it. """ # Prevent double-wrap - if self._already_wrapped(func): + if self._already_a_wrapper(func): return func @functools.wraps(func) @@ -253,55 +251,42 @@ def wrapper(*args, **kwds): # Generators are started by `.send(None)` input_ = None while True: - enable() + self.enable_by_count() try: item = g.send(input_) except StopIteration: return finally: - disable() + self.disable_by_count() input_ = (yield item) - enable, disable = self._get_toggle_callbacks(wrapper) - return self._mark_wrapped(wrapper) + return self._mark_wrapper(wrapper) def wrap_function(self, func): """ Wrap a function to profile it. """ # Prevent double-wrap - if self._already_wrapped(func): + if self._already_a_wrapper(func): return func @functools.wraps(func) def wrapper(*args, **kwds): - enable() + self.enable_by_count() try: result = func(*args, **kwds) finally: - disable() + self.disable_by_count() return result - enable, disable = self._get_toggle_callbacks(wrapper) - return self._mark_wrapped(wrapper) + return self._mark_wrapper(wrapper) - def _already_wrapped(self, func): + def _already_a_wrapper(self, func): return getattr(func, self._profiler_wrapped_marker, None) == id(self) - def _mark_wrapped(self, func): - setattr(func, self._profiler_wrapped_marker, id(self)) - return func - - def _get_toggle_callbacks(self, wrapper): - """ - Get the callbacks that should be called (1) before a profiled - function is used, and (2) when it returns, yields, or raises. - - Arguments: - wrapper (types.FunctionType): - Wrapper function around the profiled function - """ - return self.enable_by_count, self.disable_by_count + def _mark_wrapper(self, wrapper): + setattr(wrapper, self._profiler_wrapped_marker, id(self)) + return wrapper def run(self, cmd): """ Profile a single executable statment in the main namespace. diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index eb8ffe98..ae5c929c 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -624,108 +624,6 @@ def test_profile_generated_code(): assert generated_code_name in output -def test_multiple_profilers_metadata(): - """ - Test the curation of profiler metadata (e.g. `.code_hash_map`, - `.dupes_map`, `.code_map`) from the underlying C-level profiler. - """ - from copy import deepcopy - from operator import attrgetter - from warnings import warn - - prof1 = LineProfiler() - prof2 = LineProfiler() - cprof = prof1._get_c_profiler() - assert prof2._get_c_profiler() is cprof - - @prof1 - @prof2 - def f(c=False): - get_time = attrgetter('c_last_time' if c else 'last_time') - t1 = get_time(prof1) - t2 = get_time(prof2) - return [t1, t2, get_time(cprof)] - - @prof1 - def g(): - return [prof1.enable_count, prof2.enable_count] - - @prof2 - def h(): # Same bytecode as `g()` - return [prof1.enable_count, prof2.enable_count] - - get_code = attrgetter('__wrapped__.__code__') - - # `.functions` - assert prof1.functions == [f.__wrapped__, g.__wrapped__] - assert prof2.functions == [f.__wrapped__, h.__wrapped__] - # `.enable_count` - # (Note: `.enable_count` is automatically in-/de-cremented in - # decorated functions, so we need to access it within a called - # function) - assert g() == [1, 0] - assert h() == [0, 1] - assert prof1.enable_count == prof2.enable_count == cprof.enable_count == 0 - # `.timer_unit` - assert prof1.timer_unit == prof2.timer_unit == cprof.timer_unit - # `.code_hash_map` - assert set(prof1.code_hash_map) == {get_code(f), get_code(g)} - assert set(prof2.code_hash_map) == {get_code(f), get_code(h)} - - # `.c_code_map` - prof1_line_hashes = {h for hashes in prof1.code_hash_map.values() - for h in hashes} - assert set(prof1.c_code_map) == prof1_line_hashes - prof2_line_hashes = {h for hashes in prof2.code_hash_map.values() - for h in hashes} - assert set(prof2.c_code_map) == prof2_line_hashes - # `.code_map` - assert set(prof1.code_map) == {get_code(f), get_code(g)} - assert len(prof1.code_map[get_code(f)]) == 0 - assert len(prof1.code_map[get_code(g)]) == 1 - assert set(prof2.code_map) == {get_code(f), get_code(h)} - assert len(prof2.code_map[get_code(f)]) == 0 - assert len(prof2.code_map[get_code(h)]) == 1 - t1, t2, _ = f() # Timing info gathered after calling the function - assert len(prof1.code_map[get_code(f)]) == 4 # 4 real lines - assert len(prof2.code_map[get_code(f)]) == 4 - - # `.c_last_time` - # (Note: `.c_last_time` is transient, so we need to access it within - # a called function) - ct1, ct2, _ = f(c=True) - assert set(ct1) == set(ct2) == {hash(get_code(f).co_code)} - # `.last_time` - # (Note: `.last_time` is currently bugged; since `.c_last_time` - # stores code-block hashes and `.code_hash_map` line hashes, - # `line_profiler._line_profiler.LineProfiler.last_time` never gets a - # hash match and is thus always empty) - t1, t2, tc = f(c=False) - if tc: - expected = {get_code(f)} - else: - msg = ('`line_profiler/_line_profiler.pyx::LineProfiler.last_time` ' - 'is always empty because `.c_last_time` and `.code_hash_map` ' - 'use different types of hashes (see PR #344)') - warn(msg, DeprecationWarning) - expected = set() - assert set(t1) == set(t2) == set(tc) == expected - - # `.dupes_map` (introduce a dupe for this) - # Note: `h.__wrapped__.__code__` is padded but the `.dupes_map` - # entries are not - assert prof1.dupes_map == {get_code(f).co_code: [get_code(f)], - get_code(g).co_code: [get_code(g)]} - h = prof1(h) - dupes = deepcopy(prof1.dupes_map) - h_code = dupes[get_code(g).co_code][-1] - assert get_code(h).co_code.startswith(h_code.co_code) - dupes[get_code(g).co_code][-1] = (h_code - .replace(co_code=get_code(h).co_code)) - assert dupes == {get_code(f).co_code: [get_code(f)], - get_code(g).co_code: [get_code(g), get_code(h)]} - - def test_multiple_profilers_usage(): """ Test using more than one profilers simultaneously. @@ -755,15 +653,16 @@ def sum_n_cb(n): # If we decorate a wrapper, just "register" the profiler with the # existing wrapper and add the wrapped function - sum_n_wrapper = prof1(sum_n) + sum_n_wrapper_1 = prof1(sum_n) assert prof1.functions == [sum_n_sq.__wrapped__, sum_n] - sum_n_wrapper_2 = prof2(sum_n_wrapper) + sum_n_wrapper_2 = prof2(sum_n_wrapper_1) + assert sum_n_wrapper_2 is not sum_n_wrapper_1 assert prof2.functions == [sum_n_cb.__wrapped__, sum_n] - assert sum_n_wrapper_2 is sum_n_wrapper # Call the functions n = 400 - assert sum_n_wrapper(n) == .5 * n * (n + 1) + assert sum_n_wrapper_1(n) == .5 * n * (n + 1) + assert sum_n_wrapper_2(n) == .5 * n * (n + 1) assert 6 * sum_n_sq(n) == n * (n + 1) * (2 * n + 1) assert sum_n_cb(n) == .25 * (n * (n + 1)) ** 2 @@ -774,6 +673,9 @@ def sum_n_cb(n): for (*_, fname), entries in prof2.get_stats().timings.items()} assert set(t1) == {'sum_n_sq', 'sum_n'} assert set(t2) == {'sum_n_cb', 'sum_n'} - assert t1['sum_n'][2][1] == t2['sum_n'][2][1] == n + # Note: `prof1` active when both wrapper is called, but `prof2` only + # when `sum_n_wrapper_2()` is + assert t1['sum_n'][2][1] == 2 * n + assert t2['sum_n'][2][1] == n assert t1['sum_n_sq'][2][1] == n assert t2['sum_n_cb'][2][1] == n From 592b7fbc9b5e8bc1f2c3f69344881b21d76cfb1d Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 17:51:20 +0200 Subject: [PATCH 4/6] Added CHANGELOG entry --- CHANGELOG.rst | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index 2b6c7acf..0ca0cd22 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -14,6 +14,7 @@ Changes * ENH: Added CLI arguments ``-c`` to ``kernprof`` for (auto-)profiling module/package/inline-script execution instead of that of script files; passing ``'-'`` as the script-file name now also reads from and profiles ``stdin`` * ENH: In Python >=3.11, profiled objects are reported using their qualified name. * ENH: Highlight final summary using rich if enabled +* ENH: Made it possible to use multiple profiler instances simultaneously 4.2.0 ~~~~~ From dd11e59d570bcee268d0b093db1237455a7f9d0e Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 21:16:25 +0200 Subject: [PATCH 5/6] Cleanup and refactoring line_profiler/_line_profiler.pyx LineProfiler - Replaced private class attribute `._active_instances_getter` with `._all_active_instances` - Refactored private property `._active_instances` to use try-except instead of `.setdefault()` for performance python_trace_callback() Now no longer calls `line_profiler/timers.c::hpTimer()` for all line events line_profiler/line_profiler.py::_WrapperInfo Renamed attribute `.profiler` to `.profiler_id` --- line_profiler/_line_profiler.pyx | 14 +++++++++++--- line_profiler/line_profiler.py | 8 ++++---- 2 files changed, 15 insertions(+), 7 deletions(-) diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 0e9ada10..622dbf84 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -254,7 +254,7 @@ cdef class LineProfiler: cdef public object threaddata # This is shared between instances and threads - _active_instances_getter = {}.setdefault + _all_active_instances = {} def __init__(self, *functions): self.functions = [] @@ -325,7 +325,12 @@ cdef class LineProfiler: # This is shared between instances, but thread-local property _active_instances: def __get__(self): - return self._active_instances_getter(threading.get_ident(), set()) + thread_id = threading.get_ident() + try: + return self._all_active_instances[thread_id] + except KeyError: + insts = self._all_active_instances[thread_id] = set() + return insts def enable_by_count(self): """ Enable the profiler if it hasn't been enabled before. @@ -473,6 +478,7 @@ cdef extern int python_trace_callback(object instances, cdef LastTime old cdef int key cdef PY_LONG_LONG time + cdef int has_time = 0 cdef int64 code_hash cdef int64 block_hash cdef unordered_map[int64, LineTime] line_entries @@ -485,11 +491,13 @@ cdef extern int python_trace_callback(object instances, linenum = PyFrame_GetLineNumber(py_frame) code_hash = compute_line_hash(block_hash, linenum) - time = hpTimer() for prof_ in instances: prof = prof_ if not prof._c_code_map.count(code_hash): continue + if not has_time: + time = hpTimer() + has_time = 1 ident = threading.get_ident() if prof._c_last_time[ident].count(block_hash): old = prof._c_last_time[ident][block_hash] diff --git a/line_profiler/line_profiler.py b/line_profiler/line_profiler.py index 4ee0f7dc..0e0fd74c 100755 --- a/line_profiler/line_profiler.py +++ b/line_profiler/line_profiler.py @@ -73,12 +73,12 @@ class _WrapperInfo: Attributes: func (types.FunctionType): The function it wraps. - profiler (int) + profiler_id (int) ID of the `LineProfiler`. """ - def __init__(self, func, profiler): + def __init__(self, func, profiler_id): self.func = func - self.profiler = profiler + self.profiler_id = profiler_id class LineProfiler(CLineProfiler, ByCountProfilerMixin): @@ -169,7 +169,7 @@ def add_module(self, mod): def _get_wrapper_info(self, func): info = getattr(func, self._profiler_wrapped_marker, None) - return info, bool(info and id(self) == info.profiler) + return info, bool(info and id(self) == info.profiler_id) # Override these mixed-in bookkeeping methods to take care of # potential multiple profiler sequences From 6889534e296ba5806e0167fea2977397a42eaf7a Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 21:24:44 +0200 Subject: [PATCH 6/6] Test fix after merging #345 --- tests/test_line_profiler.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index ae5c929c..c922109a 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -667,9 +667,9 @@ def sum_n_cb(n): assert sum_n_cb(n) == .25 * (n * (n + 1)) ** 2 # Inspect the timings - t1 = {fname: entries + t1 = {fname.rpartition('.')[-1]: entries for (*_, fname), entries in prof1.get_stats().timings.items()} - t2 = {fname: entries + t2 = {fname.rpartition('.')[-1]: entries for (*_, fname), entries in prof2.get_stats().timings.items()} assert set(t1) == {'sum_n_sq', 'sum_n'} assert set(t2) == {'sum_n_cb', 'sum_n'}