implement per-opcode cache in ceval

@gvanrossum

BPO	26219
Nosy	@gvanrossum, @brettcannon, @ncoghlan, @vstinner, @ned-deily, @methane, @markshannon, @ericsnowcurrently, @1st1, @jstasiak, @MojoVampire, @DimitrisJim, @dopplershift, @rowillia
PRs	bpo-26219: per opcode cache for LOAD_GLOBAL #12884 bpo-26219: remove unused code #13775 bpo-26219: Fix compiler warning #13809 bpo-26219: Fix compiler warning in _PyCode_InitOpcache() #13997 [3.8] bpo-26219: Fix compiler warning in _PyCode_InitOpcache() (GH-13997) #14000
Dependencies	bpo-26058: PEP 509: Add ma_version to PyDictObject bpo-26110: Speedup method calls 1.2x
Files	opcache1.patch opcache2.patch opcache3.patch

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = 'https://github.com/1st1'
closed_at = <Date 2019-06-04.15:15:23.302>
created_at = <Date 2016-01-27.17:11:27.004>
labels = ['interpreter-core', '3.8', 'performance']
title = 'implement per-opcode cache in ceval'
updated_at = <Date 2019-12-27.19:07:14.427>
user = 'https://github.com/1st1'

bugs.python.org fields:

activity = <Date 2019-12-27.19:07:14.427>
actor = 'eric.snow'
assignee = 'yselivanov'
closed = True
closed_date = <Date 2019-06-04.15:15:23.302>
closer = 'vstinner'
components = ['Interpreter Core']
creation = <Date 2016-01-27.17:11:27.004>
creator = 'yselivanov'
dependencies = ['26058', '26110']
files = ['41729', '41776', '42658']
hgrepos = ['333']
issue_num = 26219
keywords = ['patch']
message_count = 42.0
messages = ['259040', '259042', '259051', '259052', '259060', '259064', '259065', '259344', '259371', '259410', '259522', '259523', '262623', '264528', '264532', '264533', '264534', '264658', '264660', '264664', '264671', '264674', '264676', '310845', '310956', '310960', '310961', '310965', '311028', '344418', '344419', '344421', '344470', '344587', '344591', '345300', '345315', '354089', '354090', '354091', '354122', '354181']
nosy_count = 15.0
nosy_names = ['gvanrossum', 'brett.cannon', 'ncoghlan', 'vstinner', 'ned.deily', 'methane', 'Mark.Shannon', 'eric.snow', 'francismb', 'yselivanov', 'jstasiak', 'josh.r', 'Jim Fasarakis-Hilliard', 'Ryan May', 'Roy Williams']
pr_nums = ['12884', '13775', '13809', '13997', '14000']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'performance'
url = 'https://bugs.python.org/issue26219'
versions = ['Python 3.8']

I assume there's going to be a patch or more of a description of what your idea is? :)

Yeah, I needed a URL of the issue for my email to python-dev ;)

Here's a link to the email, that explains a lot about this patch: https://mail.python.org/pipermail/python-dev/2016-January/142945.html

The patch is also attached (opcache1.patch).

BTW, there are a couple of unit-tests that fail. Both can be easily fixed.

To really move this thing forward, we need to profile the memory usage. First, it would be interesting to see how much additional memory is consumed if we optimize every code object. That will give us an idea of the overhead, and if it is significant, we can experiment with various heuristics to minimize it.

If you run hg.python.org/benchmarks on Linux it has a flag to measure memory.

If you run hg.python.org/benchmarks on Linux it has a flag to measure memory.

Great. I'll re-run the benchmarks. BTW, the latest results are here: https://gist.github.com/1st1/aed69d63a2ff4de4c7be

If I understand correctly, this change requires to wait until the PEP-509 is accepted, right? Well, I'm not really suprised, since global cache is mentioned as an use case of the PEP-509, and other global cache patches are mentioned in Prior Art.

Yes, this patch depends on PEP-509.

Attaching a new version of the patch. Issues bpo-26058 and bpo-26110 need to be merged before we can start reviewing it.

I'm concerned by the test_descr failure.

======================================================================
ERROR: test_vicious_descriptor_nonsense (test.test_descr.ClassPropertiesAndMethods)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/haypo/prog/python/default/Lib/test/test_descr.py", line 4176, in test_vicious_descriptor_nonsense
    self.assertEqual(c.attr, 1)
AttributeError: 'C' object has no attribute 'attr'

----------------------------------------------------------------------

======================================================================
FAIL: test_objecttypes (test.test_sys.SizeofTest)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/haypo/prog/python/default/Lib/test/test_sys.py", line 895, in test_objecttypes
    check(get_cell().__code__, size('5i9Pi3P'))
  File "/home/haypo/prog/python/default/Lib/test/support/__init__.py", line 1475, in check_sizeof
    test.assertEqual(result, size, msg)
AssertionError: 192 != 160 : wrong size for <class 'code'>: got 192, expected 160

----------------------------------------------------------------------

======================================================================
FAIL: test_pycfunction (test.test_gdb.PyBtTests)
Verify that "py-bt" displays invocations of PyCFunction instances
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/haypo/prog/python/default/Lib/test/test_gdb.py", line 857, in test_pycfunction
    self.assertIn('#0 <built-in method gmtime', gdb_output)
AssertionError: '#0 <built-in method gmtime' not found in 'Breakpoint 1 at 0x6518e3: file ./Modules/timemodule.c, line 338.\n[Thread debugging using libthread_db enabled]\nUsing host libthread_db library "/lib64/libthread_db.so.1".\n\nBreakpoint 1, time_gmtime (self=<module at remote 0x7ffff7e6ff58>, args=(1,)) at ./Modules/timemodule.c:338\n338\t    if (!parse_time_t_args(args, "|O:gmtime", &when))\n#1 <built-in method gmtime of module object at remote 0x7ffff7e6ff58>\n#4 Frame 0x7ffff7fb27b8, for file <string>, line 3, in foo ()\n#7 Frame 0x7ffff7f423f8, for file <string>, line 5, in bar ()\n#10 Frame 0x7ffff7fb25e0, for file <string>, line 6, in <module> ()\n'

Victor,

Thanks for the initial review. I'll work on the patch sometime later next week.

As for test_vicious_descriptor_nonsense -- yeah, I saw that too. I know what's going on there and I know how to fix that. FWIW that test tests a very counter-intuitive and quirky CPython implementation detail.

From the two checks on Python/compile.c:

+ expr_ty meth = e->v.Call.func;
[...]
+ /* Check [...] that
+ the call doesn't have keyword parameters. */
[...]
+ /* Check that there are no *varargs types of arguments. */
[...]

I just wonder how many times those kind of checks/guards are done
on the whole Cpython code base (the second one seems expensive).

(Naive Idea):
Wouldn't be some kind of fast function description (e.g. bit flags
or 'e->v.Call.func.desc') generally helpful? The function description
could have: 'has_keywords' or 'has_varargs', ...

Thanks in advance!

From the two checks on Python/compile.c:

Stuff done in compile.c is cached in *.pyc files.

The for-loop you saw shouldn't take a lot of time - it iterates through function parameters, which an average function doesn't have more than 3-6.

New changeset 91234a1 by Inada Naoki in branch 'master':
bpo-26219: per opcode cache for LOAD_GLOBAL (GH-12884)
91234a1

I committed cache only for LOAD_GLOBAL, which is much simpler than
LOAD_ATTR or LOAD_METHOD.

Caches for other instructions will be implemented 3.9 or later.

New changeset 395420e by Inada Naoki in branch 'master':
bpo-26219: remove unused code (GH-13775)
395420e

The opcode cache introduced an issue in reference leak hunting: see bpo-37146.

New changeset ea9f168 by Victor Stinner in branch 'master':
bpo-26219: Fix compiler warning in _PyCode_InitOpcache() (GH-13809)
ea9f168

I understand that the initial issue (add an opcode cache) has been implemented. Well done Yury and INADA-san!

Please open new issues for follow-up like the new optimization ideas ;-)

New changeset 376ce98 by Victor Stinner in branch 'master':
bpo-26219: Fix compiler warning in _PyCode_InitOpcache() (GH-13997)
376ce98

New changeset 996e526 by Victor Stinner (Miss Islington (bot)) in branch '3.8':
bpo-26219: Fix compiler warning in _PyCode_InitOpcache() (GH-13997) (GH-14000)
996e526

"What's new in Python 3.8" says that this change speeds up the LOAD_GLOBAL opcode by 40%.
That seems meaningless as a program cannot have LOAD_GLOBAL in isolation so any test would have other bytecodes as well.

What's the evidence for the claimed speedup?
What's the speedup on the benchmark suite?

What's the evidence for the claimed speedup?
What's the speedup on the benchmark suite?

#12884 (comment)
points to:
https://github.com/methane/sandbox/tree/master/2019/opcache_load_global#opcache-for-load_global

== Microbenchmark ==

$ master/python -m perf timeit -s 'def foo(): int; str; bytes; float; int; str; bytes; float' -- 'foo()'
.....................
Mean +- std dev: 213 ns +- 5 ns

$ opcache/python -m perf timeit -s 'def foo(): int; str; bytes; float; int; str; bytes; float' -- 'foo()'
.....................
Mean +- std dev: 120 ns +- 2 ns

== pyperformance ==

$ ./cpython/python -m perf compare_to master.json opcache_load_global.json -G  --min-speed=2
Slower (2):
- pickle: 19.1 us +- 0.2 us -> 19.7 us +- 0.8 us: 1.03x slower (+3%)
- unpickle_list: 8.66 us +- 0.04 us -> 8.85 us +- 0.06 us: 1.02x slower (+2%)

Faster (23):

scimark_lu: 424 ms +- 22 ms -> 384 ms +- 4 ms: 1.10x faster (-9%)
regex_compile: 359 ms +- 4 ms -> 330 ms +- 1 ms: 1.09x faster (-8%)
django_template: 250 ms +- 3 ms -> 231 ms +- 2 ms: 1.08x faster (-8%)
unpickle_pure_python: 802 us +- 12 us -> 754 us +- 9 us: 1.06x faster (-6%)
pickle_pure_python: 1.04 ms +- 0.01 ms -> 991 us +- 15 us: 1.05x faster (-5%)
hexiom: 20.8 ms +- 0.2 ms -> 19.8 ms +- 0.1 ms: 1.05x faster (-5%)
logging_simple: 18.4 us +- 0.2 us -> 17.6 us +- 0.2 us: 1.05x faster (-4%)
sympy_expand: 774 ms +- 5 ms -> 741 ms +- 3 ms: 1.04x faster (-4%)
json_dumps: 28.1 ms +- 0.2 ms -> 27.0 ms +- 0.2 ms: 1.04x faster (-4%)
logging_format: 20.4 us +- 0.2 us -> 19.6 us +- 0.3 us: 1.04x faster (-4%)
richards: 147 ms +- 2 ms -> 141 ms +- 1 ms: 1.04x faster (-4%)
meteor_contest: 189 ms +- 1 ms -> 182 ms +- 1 ms: 1.04x faster (-4%)
xml_etree_iterparse: 226 ms +- 2 ms -> 217 ms +- 2 ms: 1.04x faster (-4%)
sympy_str: 358 ms +- 3 ms -> 345 ms +- 4 ms: 1.04x faster (-4%)
sqlalchemy_imperative: 44.0 ms +- 1.2 ms -> 42.4 ms +- 1.2 ms: 1.04x faster (-4%)
sympy_sum: 167 ms +- 1 ms -> 161 ms +- 1 ms: 1.04x faster (-4%)
nqueens: 217 ms +- 1 ms -> 211 ms +- 1 ms: 1.03x faster (-3%)
fannkuch: 1.09 sec +- 0.01 sec -> 1.07 sec +- 0.00 sec: 1.03x faster (-3%)
raytrace: 1.11 sec +- 0.02 sec -> 1.08 sec +- 0.01 sec: 1.03x faster (-3%)
dulwich_log: 122 ms +- 1 ms -> 119 ms +- 1 ms: 1.03x faster (-3%)
logging_silent: 419 ns +- 5 ns -> 410 ns +- 5 ns: 1.02x faster (-2%)
sympy_integrate: 33.5 ms +- 0.1 ms -> 32.8 ms +- 0.2 ms: 1.02x faster (-2%)
pathlib: 40.8 ms +- 0.4 ms -> 40.0 ms +- 0.5 ms: 1.02x faster (-2%)

Benchmark hidden because not significant (32): (...)

Given that
def foo(): int; str; bytes; float; int; str; bytes; float
can be trivially be rewritten as
def foo(): pass
I think that benchmark is meaningless.

I really don't think we should be making claims like "40% speedup" for such contrived examples.

It looks like the speedup is real, but only about 2% speedup overall.
The "what's new" should reflect that, IMO.

I personally think it would be fine to change the wording to say "measurable speed-up" and not attribute a specific number.

On Mon, Oct 7, 2019 at 9:41 PM Mark Shannon <report@bugs.python.org> wrote:

Mark Shannon <mark@hotpy.org> added the comment:

Given that
def foo(): int; str; bytes; float; int; str; bytes; float
can be trivially be rewritten as
def foo(): pass
I think that benchmark is meaningless.

Do you mean every microbenchmark measuring single feature is meaningless?

I think it is worth enough for readers who understand what
LOAD_GLOBAL instruction means.
(e.g. People who using techniques like int_ = int before a loop.)

Navigation Menu

Repository navigation

implement per-opcode cache in ceval #70407

18 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

implement per-opcode cache in ceval #70407

Description

Activity

brettcannon commented on Jan 27, 2016

1st1 commented on Jan 27, 2016

1st1 commented on Jan 27, 2016

brettcannon commented on Jan 27, 2016

1st1 commented on Jan 27, 2016

vstinner commented on Jan 27, 2016

1st1 commented on Jan 27, 2016

1st1 commented on Feb 1, 2016

vstinner commented on Feb 2, 2016

1st1 commented on Feb 2, 2016

francismb commented on Feb 3, 2016

1st1 commented on Feb 4, 2016

18 remaining items

methane commented on Jun 3, 2019

methane commented on Jun 3, 2019

methane commented on Jun 3, 2019

vstinner commented on Jun 3, 2019

vstinner commented on Jun 4, 2019

vstinner commented on Jun 4, 2019

vstinner commented on Jun 12, 2019

vstinner commented on Jun 12, 2019

markshannon commented on Oct 7, 2019

vstinner commented on Oct 7, 2019

markshannon commented on Oct 7, 2019

brettcannon commented on Oct 7, 2019

methane commented on Oct 8, 2019

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions