FIX: kernprof erroring out in non--l, non--b mode in Python 3.12+

[TTsangSC]

Synopsis

When writing #323, we noticed that the one of the new tests are failing in Python 3.12 and above, and accidentally discovered that the prof.runctx() code path is currently untested. Said code path is executed when kernprof is run with neither the -b/--builtin nor -l/--line-by-line options.

Further investigation revealed that the introduction of sys.monitoring and tooling registration is to blame, especially these lines in lsprof.c of the Python source code, corresponding to cProfile.Profile.enable() – which causes kernprof.ContextualProfile.enable_by_count() to fail when first called, because the profiling tool 'cProfile' has already been registered to sys.monitoring.use_tool_id().

This PR adds a check which frees the tool ID if registered, so that it can be re-registered by .enable() when .enable_by_count() is called.

EDIT 22 Mar: This PR refactors kernprof.ContextualProfile so that:

• Its .run(), .runctx(), and .runcall() methods no longer directly call .enable() and .disable(), but .enable_by_count() and .disable_by_count() instead;
• The methods shared between it and line_profiler.LineProfiler are moved into a separate mix-in class, which both now inherit from.
• .__init__() now raises an error when cProfile.Profile is unavailable and profile.Profile is loaded as a base class instead, because of API incompatibilities (see comment below).

EDIT 1 Apr: the error raised by ContextualProfile.__init__() has been migrated to kernprof.main().

Caveats

When messing around with the code, the following potential bug is noted; but since it may be a while before we can come up with a robust fix, I decided to let that be and maybe fix/write an issue later.

Specifically, profile.Profile may be imported as a substitute for cProfile.Profile. However, the former is not fully compatible with kernprof.ContextualProfile, because it cannot be .enable()-ed nor .disable()-ed. A "fix" seems easy – just don't call those methods if we don't have them – but IDK about the full ramifications of that.

EDIT 22 Mar: see above edit.

[TTsangSC]

Hi @Erotemic, just fixed the bug we went over the past few days; please review. Cheers

EDIT: weird, I assumed that the coverage would go up... anyway

EDIT 2: and do we need a CHANGELOG note for that?

EDIT 3: nvm just pushed the CHANGELOG entry. Should've done it before writing the PR so that CI isn't run twice – sorry about that.

EDIT 4: just realized that we aren't including kernprof.py in the coverage report, hence the unchanged coverage report. Also, line_profiler.LineProfiler.runctx() won't be called anyway because setting --line-by-line automatically sets --builtin, bypassing the code branch.

[codecov]

Codecov Report

Attention: Patch coverage is 40.69767% with 51 lines in your changes missing coverage. Please review.

Project coverage is 61.82%. Comparing base (b80e87d) to head (675b28f).
Report is 9 commits behind head on main.

Files with missing lines	Patch %	Lines
line_profiler/profiler_mixin.py	38.55%	46 Missing and 5 partials ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #326      +/-   ##
==========================================
+ Coverage   61.32%   61.82%   +0.50%     
==========================================
  Files          11       12       +1     
  Lines         848      854       +6     
  Branches      186      186              
==========================================
+ Hits          520      528       +8     
+ Misses        274      272       -2     
  Partials       54       54              

Files with missing lines	Coverage Δ
line_profiler/line_profiler.py	67.03% <100.00%> (+10.66%)	⬆️
line_profiler/profiler_mixin.py	38.55% <38.55%> (ø)

---

Continue to review full report in Codecov by Sentry.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update fc7c6b6...675b28f. Read the comment docs.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[Erotemic]

This line is never going to run, right? I'm trying to find when lsprof even existed under that namespace, but even as far back as 2.6 I only see _lsprof. Unless I'm missing something, maybe lets just remove this case to simplify the logic.

[TTsangSC]

Since the Python docs say

cProfile is recommended for most users; it’s a C extension with reasonable overhead that makes it suitable for profiling long-running programs. Based on lsprof, contributed by Brett Rosen and Ted Czotter.

I guess it's just a fallback for when lsprof used to be its own thing, before it was "vendor-ed into" cPython (and nowhere else to be found). But given we're on 3.9 anyways I guess it should be safe to drop it...

[Erotemic]

I'm trying to understand why cProfile has already been registered. Is it just because when we are running tests, multiple profilers get created?

Perhaps a better solution would be to ensure that we are cleaning up the profilers after we are done?

[TTsangSC]

Probably figured it out:

• We call prof.runctx() in the code.
• Since we haven't overriden .runctx(), it defers to cProfile.Profile.runctx(), which calls .enable() as the first thing it does.
• And cProfile.Profile.enable() is inherited from _lsprof.Profiler.enable(), which calls sys.monitoring.use_tool_id(2, 'cProfile').
• In fact, cProfile.Profile.runctx(), .runcall(), and .__enter__() all starts with an .enable() call.

So the solution is to override the aforementioned methods (.runctx() and .runcall(), but probably just the former because the latter isn't used anyway; and we're already supplying an .__enter__()) in ContextualProfile with their equivalents in line_profiler.line_profiler.LineProfiler, which uses the .enable_by_count() and .disable_by_count() idioms rather than the bare .enable() and .disable(). Looking at the class body of ContextualProfile, there are already several methods labelled with a decade-old comment to the effect of # FIXME: refactor so that both LineProfiler and ContextualProfile can use the same implementation, like .wrap_function(), .wrap_generator(), and .__call__(). So we can either:

• Add another to the pile, or
• Do as the comments suggested and refactor ContextualProfile completely, perhaps with a line_profiler.utils.ProfilerMixin for the common methods.

I'd also like to note that there's probably no extra cleanup needed on our (i.e. line_profiler's) end that we aren't already doing, because it uses a separate implementation of .enable() (see _line_profiler.pyx) which never registered itself with sys.monitoring. However, it may be worth considering actually doing so to comply with standards:

cdef class LineProfiler:
    def enable(self):
        try:
            sys.monitoring.use_tool_id(sys.PROFILER_ID, 'line_profiler')
        except AttributeError:  # Python < 3.12
            pass
        PyEval_SetTrace(python_trace_callback, self)
    cpdef disable(self):
        try:
            sys.monitoring.free_tool_id(sys.PROFILER_ID)
        except AttributeError:  # Python < 3.12
            pass
        self._c_last_time[threading.get_ident()].clear()
        unset_trace()

[TTsangSC]

If we were to go down the refactor route, maybe we should also consider dropping all those conditional and try-except imports of line_profiler in kernprof – since we've been distributing kernprof with line_profiler for ages, maybe it no longer makes sense to cater to imaginary use-cases where the one is available while the other isn't?

[Erotemic]

That would require a major version bump. It's niche, but still a code path you could envision a path to hit.

[Erotemic]

To the earlier comment: fantastic work. I agree that overloading runctx makes sense. I also think we should register ourselves to comply with standards.

If outdated constructs are getting in your way, we can major version bump if needed.

[TTsangSC]

That would require a major version bump. It's niche, but still a code path you could envision a path to hit.

Yikes, I missed your reply before pushing the new changes. Sorry about that.

Maybe I can move the module containing the mixin class to the top-level (where kernprof.py lives) and have both kernprof.ContextualProfile and line_profiler.line_profiler.LineProfiler inherit from that instead? That stops kernprof from becoming dependent on line_profiler, but then again whatever new module does become a new dependency, which may require the version bump anyway.

Or would it be acceptable w/o a major version bump if we put the mixin class in kernprof and have line_profiler.line_profiler.LineProfiler import and inherit from that instead?

[TTsangSC]

I also think we should register ourselves to comply with standards.

Did some more tests with the sys.monitoring thing, but it unexpectedly broke a test: specifically tests/test_complex_case.py::test_varied_complex_invocations(), which does something fancy with coroutines. It seems that with concurrency we have some consistency issues with LineProfiler.enable_count, causing double .enable(), which sys.monitoring.use_tool_id() now turns into an error.

That in itself is probably worth further investigation, but for the time being it's probably for the best that we keep the Cython code on this PR untouched, and spin that off into another PR (will write soon), since the fix seems nontrivial?

EDIT: just fixed that in #327.

[Erotemic]

Yikes, I missed your reply before pushing the new changes. Sorry about that.

I'm looking at the diff, and it seems like the code can be consolidated by quite a bit if we move kernprof into line_profiler itself.

The main thing that makes me hesitant to more tightly couple line_profiler and kernprof is that the README states:

kernprof is a single-file pure Python script and does not require a compiler

If kernprof has advertised itself like this for over a decade, it seems like someone might be using it like that. On the other hand: is anyone actually using it like that? And perhaps the single-file thing isn't important, but the pure-Python piece is. In that case we could integrate kernprof into line_profiler directly, and it will keep the same API via modifying entry_points.console_scripts.

Not sure if I can summon @rkern, but I'd be interested in an opinion.

[rkern]

Installation was more of a Wild West back then. I noted it as single-file, pure Python script in case folks wanted to download it by itself and use it as a driver for cProfile. Nowadays, people pip install everything, and the hassle of distributing code that needs compilation is significantly lessened. And there are likely other tools for driving cProfile.

Do whatever you think is best. The motivation behind that statement is a decade or so gone.

[TTsangSC]

Thanks both for the feedback.

In this case, is it advisable that I:

• Roll back the mixin refactoring on this PR and just patch kernprof.ContextualProfile.runctx() in the interest of small diffs – and leave the refactoring for later, or
• Push further with the refactoring, moving kernprof.py into line_profiler and providing it as an entry-point console script on installation?

One corner case though is exhibited by tests/test_kernprof.py::TestKernprof, where ContextualProfile is imported from kernprof. It's dubious whether it's a use-case that exists in the wild and that we want to cater to; but if it does and/or we do, we'll have to implement a shim that makes kernprof import-able, much like how setuptools shims a .pth file on install to make setuptools._distutils visible to the import system as distutils. Or maybe there's a simpler way via package discovery that I haven't thought of yet, since in setuptools' case they needed their vendored-in distutils to override the stdlib one, and thus the hack that they explicitly advised against using.

Another thing that I've been thinking about is the code consolidation. While LineProfiler and ContextualProfile share certain implementations, they are still separate classes – and thus it's probably better to have them pull the common methods from the mixin than to have one depend on the other, even if we do migrate kernprof...

[TTsangSC]

Just went ahead and went through with the refactoring.

• Code shared by ContextualProfile and LineProfiler has now been moved to the new line_profiler/line_profiler/profiler_mixin.py.
• Also rigged kernprof.ContextualProfile.__init__() to raise an error when inheriting from profile.Profile instead of cProfile.Profile, because the way it is implemented is fundamentally incompatible with the .{en,dis}able_by_count() business that we have, and users would've gotten an error when trying to use that via kernprof anyway (see Note).

EDIT: codecov is complaining because the code in line_profiler/line_profiler/profiler_mixin.py::ByCountProfilerMixin is apparently not covered. However, they are just extracted from line_profiler/line_profiler/line_profiler.py::LineProfiler, and put back in (and injected into kernprof.py::ContextualProfile) via the mix-in.

EDIT 2: formatting

EDIT 3: Just realized I forgot to inherit from ByCountProfilerMixin subclass in LineProfiler's stub file; probably that was why codecov complained.

EDIT 4: codecov still complaining; no idea why.

EDIT 5: The coverage report is somewhat suspicious. In #327 I didn't touch line_profiler/line_profiler.py, so all the LineWrapper.wrap_classmethod(), .wrap_generator(), etc. were still there. In principle they should've all (except .wrap_coroutine()) been covered by the corresponding tests/test_line_profiler.py::test_*_decorator() tests, but they still show as being un-covered in the htmlcov report (see attachment)...

Note

Specifically, cProfile.Profile and profile.Profile use different idioms for capturing code execution:

# cProfile.Profile


def do_stuff_cprofile(self: cProfile.Profile, ...):
    self.enable()
    try:
        ...
    finally:
        self.disable()


# profile.Profile


def do_stuff_profile(self: profile.Profile, ...):
    self.set_cmd(...)
    sys.setprofile(self.dispatcher)
    try:
        ...
    finally:
        sys.setprofile(None)

It's tempting to supply .enable() and .disable(), and just have them do the appropriate sys.setprofile() call. However, I did try that and it didn't work – the underlying profile.Profile.trace_dispatch_*() methods do some weird frame checks, which can't be reconciled with how we only indirectly and conditionally call .enable() through .enable_by_count().

[TTsangSC]

Since the previous comment is already getting too long, I'm breaking it off here.

Summary

• LineWrapper.wrap_generator() is somehow neglected in the coverage report despite actually being tested; and in the same process as pytest, so pytest-cov has no excuses.
• LineWrapper.wrap_classmethod() is not covered by tests and is erroneously implemented.

What happened

So pytest-cov is somewhat unexpectedly saying that line_profiler/line_profiler.py::LineProfiler.wrap_classmethod() and .wrap_generator() are not covered in tests. After taking a closer look I have good news and bad news.

wrap_classmethod()

Good news

I checked in PDB, and tests/test_line_profiler.py::test_gen_decorator() does go through the line_profiler/line_profiler.py::LineProfiler.wrap_generator() code path.

Bad news

Given what I said about .wrap_generator(), pytest-cov is definitely wrong in reporting that the branch is not taken, and we don't know why.

wrap_classmethod()

Good news

.wrap_classmethod() is indeed not tested, so pytest-cov hasn't gone completely insane. The typical use-cases are either:

• The user uses autoprofile:
  The AST of the module is rewritten, so that @profile is the innermost decorator on class methods. This means that it sees a regular function instead of a classmethod.
• The user uses explicit post-hoc profiling:
  (This is what tests/test_line_profiler.py::test_classmethod_decorator() does.) Since accessing a class method off the class returns a types.MethodType bound to the class, @profile only sees a MethodType object instead of a classmethod.

Bad news

The only case where @profile will see a classmethod is probably when someone does something like

class SomeClass:
    @profile
    @classmethod
    def some_method(cls, ...): ...

which admittedly is not the optimal way to profile a class method anyway.

However, since we already have this wrap_classmethod() method, we should probably make it right. Which it currently isn't, because it returns a regular function instead of a proper classmethod object, which will result in wrong argument binding if accessed on the instance:

(py3.13)  $ cat test_classmethod.py
from line_profiler import LineProfiler


class MyClass:
    @profile
    @classmethod
    def my_method(cls) -> str:
        return '{0.__module__}.{0.__qualname__}'.format(cls)


@profile
def main():
    obj = MyClass()
    MyClass.my_method()  # This is apparently OK, but...
    obj.my_method()  # ... this errors out

if __name__ == '__main__':
    main()
(py3.13)  $ kernprof -lv test_classmethod.py 
/Users/terence/python_env/line_profiler_dev/line_profiler/line_profiler/line_profiler.py:75: UserWarning: Adding a function with a __wrapped__ attribute. You may want to profile 
the wrapped function by adding my_method.__wrapped__ instead.
  self.add_function(func)
Wrote profile results to test_classmethod.py.lprof
Timer unit: 1e-06 s

Total time: 3e-06 s
File: test_classmethod.py
Function: my_method at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     5                                               @profile
     6                                               @classmethod
     7                                               def my_method(cls) -> str:
     8         1          3.0      3.0    100.0          return '{0.__module__}.{0.__qualname__}'.format(cls)

Total time: 1.2e-05 s
File: test_classmethod.py
Function: main at line 11

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    11                                           @profile
    12                                           def main():
    13         1          1.0      1.0      8.3      obj = MyClass()
    14         1          7.0      7.0     58.3      MyClass.my_method()  # This is apparently OK, but...
    15         1          4.0      4.0     33.3      obj.my_method()  # ... this errors out

Traceback (most recent call last):
  File "/Users/terence/python_env/line_profiler_dev/py3.13/bin/kernprof", line 8, in <module>
    sys.exit(main())
             ~~~~^^
  File "/Users/terence/python_env/line_profiler_dev/line_profiler/kernprof.py", line 381, in main
    execfile(script_file, ns, ns)
    ~~~~~~~~^^^^^^^^^^^^^^^^^^^^^
  File "/Users/terence/python_env/line_profiler_dev/line_profiler/kernprof.py", line 110, in execfile
    exec(compile(f.read(), filename, 'exec'), globals, locals)
    ~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "test_classmethod.py", line 18, in <module>
    main()
    ~~~~^^
  File "/Users/terence/python_env/line_profiler_dev/line_profiler/line_profiler/line_profiler.py", line 150, in wrapper
    result = func(*args, **kwds)
  File "test_classmethod.py", line 15, in main
    obj.my_method()  # ... this errors out
    ~~~~~~~~~~~~~^^
  File "/Users/terence/python_env/line_profiler_dev/line_profiler/line_profiler/line_profiler.py", line 94, in wrapper
    result = func.__func__(func.__class__, *args, **kwds)
TypeError: MyClass.my_method() takes 1 positional argument but 2 were given
(py3.13)  $ 

[Erotemic]

I've always had issues with test coverage in this module. The goal here is not to be 100%, it's to provide reasonable quality control. Sure it would be better if we had a bigger number, but if the tests are running, then any step further is a nice-to-have. If you do manage to figure out the cause for missing coverage or how to fix it I would be very interested, but the priority doesn't need to be high.

If this classmethod issue was a bug in previous versions, then we can mark it as a known issue.

What is important here is that there are no regressions and that new code is reasonably tested.

[TTsangSC]

By turning on dynamic contexts, it seems that only these tests are (reported as) actively contributing to coverage:

• tests/test_duplicate_functions.py::test_duplicate_function()
• tests/test_explicit_profile.py::test_simple_explicit_nonglobal_usage()

... which is absolutely preposterous. Many of the tests in tests/test_line_profiler.py are functionally identical to test_simple_explicit_nonglobal_usage() (e.g. test_function_decorator()), but they are somehow all neglected. Also, most other lines of the ~50% "coverage" that we have now are attributed to the (empty) context, i.e. not to any specific test, but simply as "code that Python ran".

Possible known issue?

And according to Issue #974 apparently this has been known behavior for years, that function and class definition are counted as "covered" once they are executed, i.e. at definition time – which reads like it renders the coverage percentage a useless metric, at least for any part of the code that isn't inside an if block. But that doesn't make sense either since we do see some method bodies being counted as covered, and some not so.

Why do only two tests have attributed lines?

The only tractable difference between the tests which contributed to coverage and the majority that did seems to be that those two tests define the entities they are profiling within the tests themselves...

... at least that was my theory until I took the function/class definitions outside of those tests, cleared all caches and reran everything, and the results stayed the same. I'm completely baffled.

Even more inconsistencies

Another weird behavior is how the coverage keeps flip-flopping between 57 and 63%, with the lower coverage being shown approximately 1/4-th of the time. Apparently it is the lines in the if summarize: ... block in line_profiler/line_profiler.py::show_text() that alternate between showing up as being covered or not, but I've yet to figure out why.

It is probably less of an issue in CI because the coverages are combined across runs, which makes it less probable that all runs "rolled low" and caused an apparent coverage drop. But I guess it can still happen if one is unlucky enough...

[Erotemic]

Finally got some time to review this in details. I think I've understood the problem and I see the reasoning for all of the changes.

After addressing the following comments we can merge and finally get to your main PR.

[TTsangSC]

Thanks for the review! Just pushed the suggested changes. Do we want to work on #323 next, or fix #328 first then?

[Erotemic]

I have a user case where I need auto-profiling, so as long as #328 isn't blocking any progress lets rebase #323 on main (after I merge this) and work on that.