Cythonize the call loop #263

goodboy · 2020-06-04T13:05:13Z

Resolves #104 and is something I wrote a few years ago after a discussion with @RonnyPfannschmidt.

I haven't integrated the _c_multicall() into the benchmark tests yet (starting to think I shouldn't have removed the multiple loops from #147 🙄) but this is at least a draft that builds the faster function.

Update: Above is all complete.

Interested to see what peeps think!

TODO:

fix build
revert 72948af
integrate with benchmark tests
make linter tests pass
make cython an optional dependency?
test with pytest test suite -> deferring to @bluetech 😎

goodboy · 2020-06-04T13:15:21Z

Ahh yeah so there's an import cycle in this..

I need to break out the _Result into it's own module, any preferences on a name?
I was thinking _result.py ?

It's that or we move the _c_multicall() import further down the file?

RonnyPfannschmidt · 2020-06-04T13:18:00Z

sounds fair

goodboy · 2020-06-04T13:37:08Z

One other idea: given the .pyx code isn't yet truly written as native cython code we could just breakout _multicall() to a new module and then copy and cythonize it on build instead of having duplicate code in both files?

Might just make sense to actually play with writing properly tuned cython code to see if there's any benefit before jumping on that wagon tho.

bluetech · 2020-06-04T15:38:26Z

I need to break out the _Result into it's own module, any preferences on a name? I was thinking _result.py ?

I proposed this before in #227 so 👍 from me

goodboy · 2020-06-04T19:01:55Z

I proposed this before in #227 so +1 from me

@bluetech I might add it in in a new PR just so that it can come in before this one and because we're touching stuff for the 1.0 release that's importing it.

goodboy · 2020-06-04T19:05:43Z

Got the benchmarks running with both.
See the results from my terminal:

bluetech · 2020-06-04T19:06:05Z

I have been working a bit on pytest performance lately, so let me know once you believe that the implementation is semantically correct, and I'll do some profiling on pytest (when I get the chance).

goodboy · 2020-06-04T19:07:34Z

@bluetech sounds good!

I'm just gonna put up a PR to split out the _Result and friends and then this will basically be ready once I rebase on that.

goodboy · 2020-06-04T19:56:12Z

I rebased this onto #268 so once that's merged I'll rebase onto master again to factor out those commits.

RonnyPfannschmidt · 2020-06-05T15:12:35Z

src/pluggy/callers/cythonized.pyx

+    try:  # run impl and wrapper setup functions in a loop
+        teardowns = []
+        try:
+            for hook_impl in reversed(hook_impls):


i wonder if there is a way to line up implementations better so we cna do less work and less work on calls,

@RonnyPfannschmidt oh there definitely is. I actually have some ideas but it's going to require some rejigging of how implementations are stored/managed in the manger iirc and I think this may have something to do with the way we couple tracing to that management (see #262 and #217). I also think we should let @bluetech play with it in the context of pytest before we get too ahead of ourselves - micro-benchmarks shouldn't be our guiding light IMO.

I also thought about this a while back with ideas for the rework of internals.. let's see if I can find some notes.

@RonnyPfannschmidt another question I have is how to implement both of these implementations (cython and python) without too much duplicate work.

@goodboy as cython has a python mode, where a annotated file is next to the implementation file, i beleive we can do it better these days (by implementing it in python, and then cythonizing those files

So then it is as simple as running cython on the original code?
Haven't looked at cython in ages.

im going to sprint on this next week, i hope to get a sync with simon from datasette about async use of pluggy before so we can enable that as well

Cythonize `pluggy.callers._multicall` which gives around a 2x speedup according to the benchmark suite. Transform the `pluggy.callers` module in a new package and move utils and the legacy call loop into separate modules.

When cython is installed always rebuild the C sources, when not installed use whatever C sources were included in the sdist.

This reverts commit 72948af since we need this parametrization for testing the cythonized version of `_multicall` aka `pluggy.caller.cythonized._c_multicall()`.

bluetech · 2020-06-06T18:48:44Z

Running pytest's test suite against this branch (+ switching to _c_multicall) gives two failures:

Details

================================================================================== FAILURES ==================================================================================
________________________________________________________________ TestTracebackCutting.test_traceback_argsetup ________________________________________________________________

self = <collect.TestTracebackCutting object at 0x7f98a766a790>, testdir = <Testdir local('/tmp/pytest-of-ran/pytest-9/test_traceback_argsetup0')>

    def test_traceback_argsetup(self, testdir):
        testdir.makeconftest(
            """
            import pytest
    
            @pytest.fixture
            def hello(request):
                raise ValueError("xyz")
        """
        )
        p = testdir.makepyfile("def test(hello): pass")
        result = testdir.runpytest(p)
        assert result.ret != 0
        out = result.stdout.str()
        assert "xyz" in out
        assert "conftest.py:5: ValueError" in out
        numentries = out.count("_ _ _")  # separator for traceback entries
>       assert numentries == 0
E       assert 26 == 0

/home/ran/src/pytest/testing/python/collect.py:955: AssertionError
---------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------
============================= test session starts ==============================
platform linux -- Python 3.8.3, pytest-5.4.1.dev459+g10bfcf590.d20200606, py-1.8.1, pluggy-1.0.0.dev17+g05b57e7
rootdir: /tmp/pytest-of-ran/pytest-9/test_traceback_argsetup0
collected 1 item

test_traceback_argsetup.py E                                             [100%]

==================================== ERRORS ====================================
____________________________ ERROR at setup of test ____________________________

>   ???

src/pluggy/callers/cythonized.pyx:14: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:43: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:14: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:43: in pluggy.callers.cythonized._c_multicall
    ???
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

request = <SubRequest 'hello' for <Function test>>

    @pytest.fixture
    def hello(request):
>       raise ValueError("xyz")
E       ValueError: xyz

conftest.py:5: ValueError
=========================== short test summary info ============================
ERROR test_traceback_argsetup.py::test - ValueError: xyz
=============================== 1 error in 0.03s ===============================
______________________________________________________________________ test_yield_fixture_with_no_value ______________________________________________________________________

testdir = <Testdir local('/tmp/pytest-of-ran/pytest-9/test_yield_fixture_with_no_value0')>

    def test_yield_fixture_with_no_value(testdir):
        testdir.makepyfile(
            """
            import pytest
            @pytest.fixture(name='custom')
            def empty_yield():
                if False:
                    yield
    
            def test_fixt(custom):
                pass
            """
        )
        expected = "E               ValueError: custom did not yield a value"
        result = testdir.runpytest()
        result.assert_outcomes(error=1)
>       result.stdout.fnmatch_lines([expected])
E       Failed: nomatch: 'E               ValueError: custom did not yield a value'
E           and: '============================= test session starts =============================='
E           and: 'platform linux -- Python 3.8.3, pytest-5.4.1.dev459+g10bfcf590.d20200606, py-1.8.1, pluggy-1.0.0.dev17+g05b57e7'
E           and: 'rootdir: /tmp/pytest-of-ran/pytest-9/test_yield_fixture_with_no_value0'
E           and: 'collected 1 item'
E           and: ''
E           and: 'test_yield_fixture_with_no_value.py E                                    [100%]'
E           and: ''
E           and: '==================================== ERRORS ===================================='
E           and: '_________________________ ERROR at setup of test_fixt __________________________'
E           and: ''
E           and: '>   ???'
E           and: ''
E           and: 'src/pluggy/callers/cythonized.pyx:14: '
E           and: '_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ '
E           and: 'src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall'
E           and: '    ???'
E           and: 'src/pluggy/callers/cythonized.pyx:43: in pluggy.callers.cythonized._c_multicall'
E           and: '    ???'
E           and: 'src/pluggy/callers/cythonized.pyx:14: in pluggy.callers.cythonized._c_multicall'
E           and: '    ???'
E           and: 'src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall'
E           and: '    ???'
E           and: '_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ '
E           and: ''
E           and: '>   ???'
E           and: 'E   ValueError: custom did not yield a value'
E           and: ''
E           and: 'src/pluggy/callers/cythonized.pyx:43: ValueError'
E           and: '=========================== short test summary info ============================'
E           and: 'ERROR test_yield_fixture_with_no_value.py::test_fixt - ValueError: custom did...'
E           and: '=============================== 1 error in 0.02s ==============================='
E       remains unmatched: 'E               ValueError: custom did not yield a value'

/home/ran/src/pytest/testing/python/fixtures.py:4346: Failed
---------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------
============================= test session starts ==============================
platform linux -- Python 3.8.3, pytest-5.4.1.dev459+g10bfcf590.d20200606, py-1.8.1, pluggy-1.0.0.dev17+g05b57e7
rootdir: /tmp/pytest-of-ran/pytest-9/test_yield_fixture_with_no_value0
collected 1 item

test_yield_fixture_with_no_value.py E                                    [100%]

==================================== ERRORS ====================================
_________________________ ERROR at setup of test_fixt __________________________

>   ???

src/pluggy/callers/cythonized.pyx:14: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:43: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:14: in pluggy.callers.cythonized._c_multicall
    ???
src/pluggy/callers/cythonized.pyx:64: in pluggy.callers.cythonized._c_multicall
    ???
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

>   ???
E   ValueError: custom did not yield a value

src/pluggy/callers/cythonized.pyx:43: ValueError
=========================== short test summary info ============================
ERROR test_yield_fixture_with_no_value.py::test_fixt - ValueError: custom did...
=============================== 1 error in 0.02s ===============================

I haven't looked at them, might be just something on pytest's side.

And here is a small pytest benchmark that I've used recently, which is not egrigously micro-benchmarky:

import pytest
@pytest.mark.parametrize("x", range(5000))
def test_foo(x): pass

it fires 100,408 hooks (I think). I run it under cProfile (best of 5, output is trimmed at 1s cumtime):

Results

Before:

         10927116 function calls (10371875 primitive calls) in 9.935 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    365/1    0.007    0.000    9.947    9.947 {built-in method builtins.exec}
        1    0.000    0.000    9.947    9.947 __main__.py:1(<module>)
        1    0.000    0.000    9.841    9.841 __init__.py:146(console_main)
        1    0.000    0.000    9.841    9.841 __init__.py:101(main)
100221/56    0.068    0.000    9.795    0.175 manager.py:90(_hookexec)
100221/56    0.152    0.000    9.795    0.175 manager.py:84(<lambda>)
100221/56    0.826    0.000    9.795    0.175 callers.py:157(_multicall)
 100058/2    0.372    0.000    9.793    4.897 hooks.py:272(__call__)
        1    0.000    0.000    9.553    9.553 main.py:249(pytest_cmdline_main)
        1    0.000    0.000    9.553    9.553 main.py:188(wrap_session)
        1    0.000    0.000    9.366    9.366 main.py:253(_main)
        1    0.023    0.023    8.563    8.563 main.py:270(pytest_runtestloop)
     5000    0.040    0.000    7.552    0.002 runner.py:97(pytest_runtest_protocol)
     5000    0.039    0.000    6.668    0.001 runner.py:104(runtestprotocol)
    15000    0.090    0.000    6.610    0.000 runner.py:203(call_and_report)
    15002    0.110    0.000    4.980    0.000 runner.py:275(from_call)
    15000    0.057    0.000    4.606    0.000 runner.py:224(call_runtest_hook)
    15000    0.036    0.000    4.221    0.000 runner.py:239(<lambda>)
140057/120053 0.090   0.000    2.581    0.000 {built-in method builtins.next}
95050/95048  0.064    0.000    2.294    0.000 {method 'send' of 'generator' objects}
    30000    0.077    0.000    1.269    0.000 capture.py:707(item_capture)
    20003    0.029    0.000    1.122    0.000 contextlib.py:117(__exit__)

After:

         10287357 function calls (9752107 primitive calls) in 9.441 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    366/1    0.006    0.000    9.453    9.453 {built-in method builtins.exec}
        1    0.000    0.000    9.453    9.453 __main__.py:1(<module>)
        1    0.000    0.000    9.345    9.345 __init__.py:146(console_main)
        1    0.000    0.000    9.345    9.345 __init__.py:101(main)
100221/56    0.065    0.000    9.300    0.166 manager.py:90(_hookexec)
100221/56    0.079    0.000    9.300    0.166 manager.py:84(<lambda>)
100221/56    0.643    0.000    9.299    0.166 {built-in method pluggy.callers.cythonized._c_multicall}
 100058/2    0.310    0.000    9.297    4.649 hooks.py:268(__call__)
        1    0.000    0.000    9.056    9.056 main.py:249(pytest_cmdline_main)
        1    0.000    0.000    9.056    9.056 main.py:188(wrap_session)
        1    0.000    0.000    8.868    8.868 main.py:253(_main)
        1    0.023    0.023    8.073    8.073 main.py:270(pytest_runtestloop)
     5000    0.040    0.000    7.108    0.001 runner.py:97(pytest_runtest_protocol)
     5000    0.040    0.000    6.250    0.001 runner.py:104(runtestprotocol)
    15000    0.091    0.000    6.190    0.000 runner.py:203(call_and_report)
    15002    0.109    0.000    4.815    0.000 runner.py:275(from_call)
    15000    0.057    0.000    4.446    0.000 runner.py:224(call_runtest_hook)
    15000    0.035    0.000    4.056    0.000 runner.py:239(<lambda>)
    45007    0.033    0.000    1.901    0.000 {built-in method builtins.next}
    30000    0.076    0.000    1.268    0.000 capture.py:707(item_capture)
    20003    0.035    0.000    1.133    0.000 contextlib.py:117(__exit__)

So it's a 5% improvement. Note that cProfile slows down the total execution time but relatively it should be about right.

IMO, 5% is probably not enough to be worth it, given that Cython, C extensions, wheels etc. are a huge headache all around. But if the Cython implementation can be sped up further I'll be happy to check again.

goodboy · 2020-06-06T18:54:24Z

So it's a 5% improvement.

Yeah nothing to write home about.

IMO, 5% is probably not enough to be worth it, given that Cython, C extensions, wheels etc. are a huge headache all around.

Agreed, at least not as the default packaging. I think that if we want to include it as an optional dependency once we can get a better speedup that's something to consider.

RonnyPfannschmidt · 2020-06-06T19:54:29Z

What's the raw execution time on cryptography for example, or a test suite with 40k tests

goodboy · 2020-06-06T21:49:57Z

Check this out.

@oremanj just pointed to mypyc in the trio gitter which might be worth investigating as well for other modules in pytest and pluggy.

I know @bluetech is gonna luv the type hints :)

RonnyPfannschmidt · 2021-08-09T15:44:58Z

@goodboy mypyc cant do pluggy ^^ - i tried it before ^^

goodboy changed the title ~~Cythonize call loop~~ Cythonize the call loop Jun 4, 2020

goodboy requested review from bluetech and RonnyPfannschmidt June 4, 2020 13:15

goodboy self-assigned this Jun 4, 2020

goodboy added enhancement performance labels Jun 4, 2020

goodboy force-pushed the cythonize_call_loop branch from 4ad5d08 to d61800d Compare June 4, 2020 19:55

goodboy force-pushed the cythonize_call_loop branch from 888f975 to 7e3d794 Compare June 4, 2020 20:09

goodboy requested review from nicoddemus and asottile June 4, 2020 20:17

RonnyPfannschmidt reviewed Jun 5, 2020

View reviewed changes

Tyler Goodlet and others added 10 commits June 5, 2020 16:10

Turn callers module into package

995c1ba

Cythonize the call loop

e586fb5

Cythonize `pluggy.callers._multicall` which gives around a 2x speedup according to the benchmark suite. Transform the `pluggy.callers` module in a new package and move utils and the legacy call loop into separate modules.

Build cython extension in packaging

a0ffaa6

When cython is installed always rebuild the C sources, when not installed use whatever C sources were included in the sdist.

Include cython in tox benchmark tests

7bd1ec5

Install cython in travis env

08db646

Fix install to include cython

e003fc4

Move import to bottom of mod; rename c func.

323ce41

Revert "Drop callertype fixture from benchmark tests"

044aa54

This reverts commit 72948af since we need this parametrization for testing the cythonized version of `_multicall` aka `pluggy.caller.cythonized._c_multicall()`.

Include cythonized multicall in benchmarks

c17cfeb

Port callers to new _result.py module

b826f75

Appease black linter

f5d4eb4

goodboy force-pushed the cythonize_call_loop branch from 7e3d794 to f5d4eb4 Compare June 5, 2020 20:11

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Cythonize the call loop #263

Cythonize the call loop #263

goodboy commented Jun 4, 2020 •

edited

goodboy commented Jun 4, 2020 •

edited

RonnyPfannschmidt commented Jun 4, 2020

goodboy commented Jun 4, 2020

bluetech commented Jun 4, 2020

goodboy commented Jun 4, 2020

goodboy commented Jun 4, 2020

bluetech commented Jun 4, 2020

goodboy commented Jun 4, 2020

goodboy commented Jun 4, 2020

RonnyPfannschmidt Jun 5, 2020

goodboy Jun 5, 2020

RonnyPfannschmidt Aug 9, 2021

goodboy Aug 9, 2021 •

edited

RonnyPfannschmidt Aug 14, 2021

bluetech commented Jun 6, 2020

goodboy commented Jun 6, 2020

RonnyPfannschmidt commented Jun 6, 2020

goodboy commented Jun 6, 2020 •

edited

RonnyPfannschmidt commented Aug 9, 2021

Cythonize the call loop #263

Are you sure you want to change the base?

Cythonize the call loop #263

Conversation

goodboy commented Jun 4, 2020 • edited

goodboy commented Jun 4, 2020 • edited

RonnyPfannschmidt commented Jun 4, 2020

goodboy commented Jun 4, 2020

bluetech commented Jun 4, 2020

goodboy commented Jun 4, 2020

goodboy commented Jun 4, 2020

bluetech commented Jun 4, 2020

goodboy commented Jun 4, 2020

goodboy commented Jun 4, 2020

RonnyPfannschmidt Jun 5, 2020

Choose a reason for hiding this comment

goodboy Jun 5, 2020

Choose a reason for hiding this comment

RonnyPfannschmidt Aug 9, 2021

Choose a reason for hiding this comment

goodboy Aug 9, 2021 • edited

Choose a reason for hiding this comment

RonnyPfannschmidt Aug 14, 2021

Choose a reason for hiding this comment

bluetech commented Jun 6, 2020

goodboy commented Jun 6, 2020

RonnyPfannschmidt commented Jun 6, 2020

goodboy commented Jun 6, 2020 • edited

RonnyPfannschmidt commented Aug 9, 2021

goodboy commented Jun 4, 2020 •

edited

goodboy commented Jun 4, 2020 •

edited

goodboy Aug 9, 2021 •

edited

goodboy commented Jun 6, 2020 •

edited