[cmaloney]

• Look up file.write once per print() call, instead of once for each argument, separator and line ending.
• Pass the cached ' ' and '\n' strings for the default sep and end directly, instead of converting them from C strings with PyFile_WriteString(), which runs strlen() and the UTF-8 decoder on every call to get back the same cached string.

write() receives the same calls as before. Benchmarks are in the issue: 1.20x faster geometric mean across 8 cases, 5 faster (1.12x to 1.66x) and 3 not significant.

Developed with the help of AI: Claude Opus 5.5.

• Issue: Speed up print() by looking up file.write once per call #160725

[python-cla-bot]

All commit authors signed the Contributor License Agreement.

[cmaloney]

(force pushed to fixup author line and make cla bot happy)

[methane]

How about concatenating everything and making a single write() call instead of calling file.write() repeatedly? This would likely improve performance significantly. It would also prevent standard output from getting garbled when multiple threads call print(a, b), since another thread could otherwise call print() between the file.write(a) and file.write(b) calls.

[cmaloney]

I started with that but then found it didn't produce uniform speedup: Copying strings of various sizes into a PyUnicodeWriter instead of doing the "pending" list that TextIOWrapper does would slowdown for some string sizes. It also very significantly changes behavior if a __str__ implementation causes a fault / SIGSEGV. I then profiled and found the repeated method binding was actually most of the runtime so built this PR.

In the longer term I'm hoping to add what I call a "Coherent" print; everything in one print statement gets write() to the underlying device not interleaved with any other print statement. That is a couple versions away though: need to support list of buffers through a lot more of the stack.

[methane]

I then profiled and found the repeated method binding was actually most of the runtime so built this PR.

I was surprised to find that print() creates a bound method. How about avoiding the creation of a bound method with the following patch?

diff --git a/Objects/fileobject.c b/Objects/fileobject.c
index 79aa8889c1a..deaff193457 100644
--- a/Objects/fileobject.c
+++ b/Objects/fileobject.c
@@ -106,27 +106,21 @@ PyFile_GetLine(PyObject *f, int n)
 int
 PyFile_WriteObject(PyObject *v, PyObject *f, int flags)
 {
-    PyObject *writer, *value, *result;
-
     if (f == NULL) {
         PyErr_SetString(PyExc_TypeError, "writeobject with NULL file");
         return -1;
     }
-    writer = PyObject_GetAttr(f, &_Py_ID(write));
-    if (writer == NULL)
-        return -1;
-    if (flags & Py_PRINT_RAW) {
-        value = PyObject_Str(v);
-    }
-    else
-        value = PyObject_Repr(v);
+
+    /* str()/repr() may remove the last external reference to the stream. */
+    Py_INCREF(f);
+    PyObject *value = (flags & Py_PRINT_RAW) ? PyObject_Str(v) : PyObject_Repr(v);
     if (value == NULL) {
-        Py_DECREF(writer);
+        Py_DECREF(f);
         return -1;
     }
-    result = PyObject_CallOneArg(writer, value);
+    PyObject *result = PyObject_CallMethodOneArg(f, &_Py_ID(write), value);
     Py_DECREF(value);
-    Py_DECREF(writer);
+    Py_DECREF(f);
     if (result == NULL)
         return -1;
     Py_DECREF(result);

[cmaloney]

I tried the PyObject_CallMethodOneArg approach in PyFile_WriteObject (your patch, plus the cached ' '/'\n' for the default sep/end) and compared it with this PR and main. print() with no args is faster in your code but all other cases are equal or slightly slower patching PyFile_WriteObject.

Benchmark script

import pyperf

SETUP = """
import io, os, tempfile
devnull = open(os.devnull, 'w')
sio = io.StringIO()
disk = tempfile.TemporaryFile('w')
ten_ints = tuple(range(10))
big = 'x' * 2**20
big_list = list(range(1000))
"""

CASES = {
    "one_str[devnull]": "print('hello world', file=devnull)",
    "one_str[sio]": "print('hello world', file=sio)",
    "three_args[devnull]": "print('a', 1, 2.5, file=devnull)",
    "ten_ints[devnull]": "print(*ten_ints, file=devnull)",
    "empty[devnull]": "print(file=devnull)",
    "str_1mib[devnull]": "print(big, file=devnull)",
    "list_1000[devnull]": "print(big_list, file=devnull)",
    "flush[disk]": "print('hello world', file=disk, flush=True)",
}

runner = pyperf.Runner()
for name, stmt in CASES.items():
    runner.timeit(name, stmt, SETUP)

./python-main bench_print.py -p 10 -o main.json
./python-pr bench_print.py -p 10 -o pr.json
./python-callmethod bench_print.py -p 10 -o callmethod.json
python -m pyperf compare_to main.json pr.json callmethod.json --table

Benchmark	main	this PR (look up write once)	PyObject_CallMethodOneArg
print('hello world'), /dev/null	88.0 ns	73.1 ns: 1.20x faster	77.0 ns: 1.14x faster
print('hello world'), StringIO	78.1 ns	61.6 ns: 1.27x faster	61.1 ns: 1.28x faster
print('a', 1, 2.5), /dev/null	319 ns	232 ns: 1.37x faster	267 ns: 1.19x faster
print(*range(10)), /dev/null	855 ns	568 ns: 1.51x faster	750 ns: 1.14x faster
print(), /dev/null	56.8 ns	53.2 ns: 1.07x faster	48.0 ns: 1.18x faster
print('x' * 2**20), /dev/null	16.8 µs	17.1 µs: 1.02x slower	17.1 µs: 1.02x slower
print(list(range(1000))), /dev/null		n.s.	n.s.
print('hello world', flush=True), disk file	904 ns	859 ns: 1.05x faster	868 ns: 1.04x faster
Geometric mean	(ref)	1.17x faster	1.11x faster

(pyperf, -p 10, PGO+LTO builds (clang, tail-call interpreter), Linux x86_64, run one at a time. n.s. = not significant.)

I think it's worthwhile to optimize the PyFile APIs, they have many callers across the codebase but that is a separate github issue. There looks to be > 10% available there.

Part of what I like for this particular refactoring is that it simplifies the amount of conditional code inside print. It eliminates branching around NULL vs. provided sep and end in the main implementation as well as needing to tracing through the Py_File internal branches for Py_PRINT_RAW.

[methane]

Part of what I like for this particular refactoring is that it simplifies the amount of conditional code inside print. It eliminates branching around NULL vs. provided sep and end in the main implementation

Wouldn't combining that improvement with an optimization of PyFile_WriteString() achieve the same performance as this PR?

as well as needing to tracing through the Py_File internal branches for Py_PRINT_RAW.

I don't think the benefits are significant enough to justify the additional complexity.

[cmaloney]

Wouldn't combining that improvement with an optimization of PyFile_WriteString() achieve the same performance as this PR?

A single PyObject_CallMethodOneArg is cheaper than PyObject_GetAttr + PyObject_CallOneArg. For every object printed there is an additional call, and that's where the the gap opens up between the two. Calling the bound object in print_write takes less time and instructions than calling PyFile_WriteObject(obj, file, Py_PRINT_RAW) with PyObject_CallMethodOneArg inside.

I wanted to validate that so built a microbenchmark just focused on doing more and more arguments. Each argument gets a separator printed as well which doubles the difference.

Timing benchmark

import pyperf

runner = pyperf.Runner()
for n in range(1, 21):
    runner.timeit(
        f"print_{n:02d}_args",
        f"print({"'x', " * n}file=devnull)",
        "import os; devnull = open(os.devnull, 'w')",
    )

./python-pr bench_print_nargs.py -p 10 -o pr.json
./python-callmethod bench_print_nargs.py -p 10 -o callmethod.json
python -m pyperf compare_to pr.json callmethod.json --table

args	bind once (this PR)	PyObject_CallMethodOneArg	difference
1	83.6 ns	74.9 ns	-9 ns
2	98.7 ns	125 ns: 1.27x slower	+27 ns
5	188 ns	264 ns: 1.40x slower	+76 ns
10	347 ns	534 ns: 1.54x slower	+187 ns
15	510 ns	773 ns: 1.52x slower	+263 ns
20	661 ns	1.01 µs: 1.54x slower	+354 ns
per write (slope, n=10→20)	15.7 ns	24.0 ns	+8.3 ns

pyperf, -p 10, PGO+LTO builds (clang, tail-call interpreter), Linux x86_64, run one at a time on an idle machine. n.s. = not significant.

[cmaloney]

Updated with #160803 and re-measured. This is still slightly slower for zero args, faster for one or more.

Call	main	this PR	write() calls	Change per write()
print()	49.1 ns	55.6 ns: 1.13x slower	1	+6.5 ns
print('hello world')	81.1 ns	72.1 ns: 1.12x faster	2	-4.5 ns
print('a', 1, 2.5)	279 ns	229 ns: 1.22x faster	6	-8.3 ns
print(*range(10))	776 ns	584 ns: 1.33x faster	20	-9.6 ns

Benchmark script

import pyperf

runner = pyperf.Runner()
for name, stmt in {
    "0_args": "print(file=devnull)",
    "1_arg": "print('hello world', file=devnull)",
    "3_args": "print('a', 1, 2.5, file=devnull)",
    "10_args": "print(*ten_ints, file=devnull)",
}.items():
    runner.timeit(
        name, stmt,
        "import os; devnull = open(os.devnull, 'w'); ten_ints = tuple(range(10))",
    )

./python-main bench_print.py -p 10 -o main.json
./python-pr bench_print.py -p 10 -o pr.json
python -m pyperf compare_to main.json pr.json --table