PyO3 bindings slower than pure rust execution

[kraleva]

Hi community,

I am having a project, where I provide a service in rust, both via an HTTP server and via PyO3 bindings.

Let's call this function/service test_service. Within the function, I measure the duration of specific operations during the execution and return it in the endpoint's response. Meaning, I do not have anything dependent on the server or the bindings, which is taken into consideration, when doing the measurement.

However, when I do try to get a response from the service via the HTTP server, I get durations of these operations of something like 20 microseconds, whereas, if I do call exactly the same function via the pyo3 bindings, I get something like 400 microseconds per operation (normalized), which is quite a significant difference in performance. The operations are not by any way dependent on external services.

I wanted to ask, if you are aware of some reason, which could be the cause of this discrepancy in the performance. Thanks ! :)

[adamreichold]

I wanted to ask, if you are aware of some reason, which could be the cause of this discrepancy in the performance. Thanks ! :)

This might sound unlikely, but a somewhat common issue is not using release build when large unexpected performance changes are measured.

The one other thing that comes to mind is if any multi-threading and hence contention of the GIL might be involved?

[kraleva]

Hey, thanks for the response. I did use release builds in both cases, also with maturin.

Regarding multithreading – yes, it is indeed happening, but only in the scope of the server handling concurrent requests. From that point onwards, no further multithreading is implemented, and even that would be somehow a reason for the server to be slower than the pyo3 binding. The python interpreter and GIL shouldn't be affected at all, as the test_service function is not asynchronous at all. :)

[adamreichold]

In that case, I fear it will be hard to diagnose without looking at the code.

If tasked with this problem, I would probably try to gather a flame graph of the slower execution to determine where the time is spent and figure out if something sticks out.

Other than that, I think the most likely culprit still is some difference in the parameters (or in some global state if applicable) that you do not expect but which is still present.

[davidhewitt]

Have you attempted any profiling? There is a brief example of how to do this in pydantic-core - https://github.com/pydantic/pydantic-core#profiling

[richecr]

The same thing happened to me, I have created this simple function:

use pyo3::prelude::*;
use std::time::{Instant};

#[pyfunction]
fn rust_sleep() -> i32 {
    let start = Instant::now();
    let num = 1 + 1;
    let duration = start.elapsed();
    println!("{:?}", duration);
    num
}

#[pymodule]
fn pythonicsqlrust(_py: Python, m: &PyModule) -> PyResult<()> {
    m.add_function(wrap_pyfunction!(rust_sleep, m)?)?;
    Ok(())
}

import time
import pythonicsqlrust

def main():
    s = time.time_ns()
    print(pythonicsqlrust.rust_sleep())
    e = time.time_ns()
    print(e - s)

main()

In pure rust it takes ~60ns and when called in python ~22350ns. Can you help understand why this happens? (is slower than running in pure python)

[davidhewitt]

@richecr I'll reply to you in #3787