From f97bfd51434290743ce876bf7713842468c25b95 Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 00:30:18 +0200 Subject: [PATCH 1/3] New test showing what's broken line_profiler/_line_profiler.pyx::LineProfiler c_last_time Now catching the `KeyError` when trying to access the attribute from a threading without prior profiling and returning an empty dict last_time Now using `.c_last_time` instead of `._c_last_time` directly test_last_time() New test showing the problematic behavior of `LineProfiler.last_time` (inconsistency w/`.c_last_time`) --- line_profiler/_line_profiler.pyx | 7 +++++-- tests/test_line_profiler.py | 24 ++++++++++++++++++++++++ 2 files changed, 29 insertions(+), 2 deletions(-) diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 15510317..64d80169 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -471,7 +471,10 @@ cdef class LineProfiler: @property def c_last_time(self): - return (self._c_last_time)[threading.get_ident()] + try: + return (self._c_last_time)[threading.get_ident()] + except KeyError: # We haven't actually profiled anything yet + return {} @property def code_map(self): @@ -500,7 +503,7 @@ cdef class LineProfiler: line_profiler 4.0 no longer directly maintains last_time, but this will construct something similar for backwards compatibility. """ - c_last_time = (self._c_last_time)[threading.get_ident()] + c_last_time = self.c_last_time code_hash_map = self.code_hash_map py_last_time = {} for code, code_hashes in code_hash_map.items(): diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index 954c77b1..fcfc63d7 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -80,6 +80,30 @@ def test_init(): } +def test_last_time(): + """ + Test that `LineProfiler.c_last_time` and `LineProfiler.last_time` + are consistent. + """ + prof = LineProfiler() + + @prof + def func(): + return prof.c_last_time.copy(), prof.last_time.copy() + + # These are always empty outside a profiling context + # (hence the need of the above function to capture the transient + # values) + assert not prof.c_last_time + assert not prof.last_time + # Inside `func()`, both should get an entry therefor + clt, lt = func() + assert not prof.c_last_time + assert not prof.last_time + assert set(clt) == {hash(func.__wrapped__.__code__.co_code)} + assert set(lt) == {func.__wrapped__.__code__} + + def test_enable_disable(): lp = LineProfiler() assert lp.enable_count == 0 From cf700842da4d6e30bb44de889b139e848c86387f Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Fri, 23 May 2025 00:43:38 +0200 Subject: [PATCH 2/3] Fixed the bug --- line_profiler/_line_profiler.pyx | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 64d80169..3e7f8c07 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -504,12 +504,11 @@ cdef class LineProfiler: construct something similar for backwards compatibility. """ c_last_time = self.c_last_time - code_hash_map = self.code_hash_map py_last_time = {} - for code, code_hashes in code_hash_map.items(): - for code_hash in code_hashes: - if code_hash in c_last_time: - py_last_time[code] = c_last_time[code_hash] + for code in self.code_hash_map: + block_hash = hash(code.co_code) + if block_hash in c_last_time: + py_last_time[code] = c_last_time[block_hash] return py_last_time From 1db643331eae30ce3eaf1c90639143f69bd82f83 Mon Sep 17 00:00:00 2001 From: "Terence S.-C. Tsang" Date: Thu, 29 May 2025 03:26:27 +0200 Subject: [PATCH 3/3] Rolled back suppression of `KeyError` line_profiler/_line_profiler.pyx::LineProfiler.c_last_time No longer suppressing the `KeyError` when accessed on a thread without profiling data; now wrapping the `KeyError` with a more helpful message tests/test_line_profiler.py::test_last_time() Updated to reflect the above change --- line_profiler/_line_profiler.pyx | 13 +++++++++++-- tests/test_line_profiler.py | 19 ++++++++++++++----- 2 files changed, 25 insertions(+), 7 deletions(-) diff --git a/line_profiler/_line_profiler.pyx b/line_profiler/_line_profiler.pyx index 3e7f8c07..a6bb5a20 100644 --- a/line_profiler/_line_profiler.pyx +++ b/line_profiler/_line_profiler.pyx @@ -471,10 +471,19 @@ cdef class LineProfiler: @property def c_last_time(self): + """ + Raises: + KeyError + If no profiling data is available on the current thread. + """ try: return (self._c_last_time)[threading.get_ident()] - except KeyError: # We haven't actually profiled anything yet - return {} + except KeyError as e: + # We haven't actually profiled anything yet + raise (KeyError('No profiling data on the current thread ' + '(`threading.get_ident()` = ' + f'{threading.get_ident()})') + .with_traceback(e.__traceback__)) from None @property def code_map(self): diff --git a/tests/test_line_profiler.py b/tests/test_line_profiler.py index fcfc63d7..8e15ff7b 100644 --- a/tests/test_line_profiler.py +++ b/tests/test_line_profiler.py @@ -86,20 +86,29 @@ def test_last_time(): are consistent. """ prof = LineProfiler() + with pytest.raises(KeyError, match='[Nn]o profiling data'): + prof.c_last_time + + def get_last_time(prof, *, c=False): + try: + return getattr(prof, 'c_last_time' if c else 'last_time') + except KeyError: + return {} @prof def func(): - return prof.c_last_time.copy(), prof.last_time.copy() + return (get_last_time(prof, c=True).copy(), + get_last_time(prof).copy()) # These are always empty outside a profiling context # (hence the need of the above function to capture the transient # values) - assert not prof.c_last_time - assert not prof.last_time + assert not get_last_time(prof, c=True) + assert not get_last_time(prof) # Inside `func()`, both should get an entry therefor clt, lt = func() - assert not prof.c_last_time - assert not prof.last_time + assert not get_last_time(prof, c=True) + assert not get_last_time(prof) assert set(clt) == {hash(func.__wrapped__.__code__.co_code)} assert set(lt) == {func.__wrapped__.__code__}