Performance of tokio-postgres worse than postgres?

[bikeshedder]

I just started dipping my feet into actix water and wanted to go full async. After having a look at existing connection pools I tried both bb8 and the experimental l337 connection pool just to find that they both perform worse than r2d2 + postgres + web::block:

https://bitbucket.org/bikeshedder/actix_web_async_postgres/src/master/

I did not expect those results and wonder if I'm doing anything wrong? I surely did expect tokio-postgres to outperform postgres with ease. Am I doing anything wrong? Are the pools causing the performance drop or is tokio-postgres the culprit?

I have yet to create a benchmark between tokio-postgres and postgres without the use of connection pools. Just posting this here to document my progress in the hope someone can tell if I'm doing anything wrong.

[sfackler]

The current postgres crate is just a little wrapper over tokio-postgres. I guess there are a couple of places the throughput difference could be coming from:

1. The connection pools. You could try adding some simple timing around the connection checkout to see how the latency there compares between r2d2 and the other pools.
2. The postgres crate uses a separate multi-threaded Tokio runtime to run all of the tokio-postgres connections. It could be that for whatever reason having a separate runtime for the connections and the HTTP server is faster? You could try running your own separate runtime for the Connection objects when using tokio-postgres, or setting up the postgres Config to use actix's executor: https://docs.rs/postgres/0.16.0-rc.2/postgres/config/struct.Config.html#method.executor.

[bikeshedder]

After experiments I realized that I was essentially benchmarking tokio-postgres-0.4.0-rc.3 against tokio-postgres-0.3.0 which was indirectly referenced by r2d2_postgres-0.14.0. After switching to r2d2_postgres-0.15.0-rc.1 which depends on postgres-0.16.0-rc.2 the results are very different:

Running 2m test @ http://localhost:8000/v1.0/event_list_l337
Requests/sec:  20973.62

Running 2m test @ http://localhost:8000/v1.0/event_list_bb8
Requests/sec:  17913.07

Running 2m test @ http://localhost:8000/v1.0/event_list_r2d2
Requests/sec:  14948.59

When switching back to r2d2_postgres-0.14.0 which uses postgres-0.3.0/`tokio-postgres I get a much faster result:

Running 2m test @ http://localhost:8000/v1.0/event_list_r2d2
Requests/sec:  25807.48

I haven't tested bb8 and l337 with an older version of tokio-postgres due to them not being compatible with tokio-postgres-0.3.0.

Could all this be caused by a performance regression of tokio-postgres?

[bikeshedder]

I'm by no means an expert writing benchmarks and async code but after having invested so much time into this whole affair I decided to write a benchmark showing the performance regression of postgres and improvement of tokio-postgres:

https://github.com/bikeshedder/rust-postgres-benchmark

Results:

• postgres version 0.16-rc.2 is 2 times slower than version 0.15.2
• tokio-postgres version 0.4.0-rc.3 is 1.5 times faster than version 0.3.0
• tokio-postgres version 0.4.0-rc.3 is still 1.4 times slower than postgres version 0.15.2

Disclaimer

I had a hard time benchmarking the async code and for _ in 0..ITERATIONS { sys.block(fetch_async(...)) } is not ideal. I first tried to implement it using a recursion but since Rust has no support for tail recursions that was the only way I found to implement this without causing a stack overflow. The numbers match the results of theactix_web_async_postgres project quite nicely so I think they're not completely wrong.

[sfackler]

Thanks for those numbers! Is the first result ordered backwards, though?

• postgres version 0.15.2 is 2 times slower than version 0.16-rc.2

It's not super surprising to me that we'd be regressing a bit from postgres 0.15 to 0.16, since 0.15 was just doing inline blocking IO while there's now a background reactor we need to talk to. Definitely worth looking into where that time is going and what improvements can be made.

There have been some other performance reports about the RC releases, but they've dealt with large data volumes: #450 where the small constant costs don't really matter.

[bikeshedder]

Thanks for those numbers! Is the first result ordered backwards, though?

• postgres version 0.15.2 is 2 times slower than version 0.16-rc.2

Whops. I fixed the comment. That's indeed what I meant.

[sfackler]

I wrote up a quick criterion benchmark to get some more precise numbers: https://gist.github.com/sfackler/4188bf8789ac6eee50502f6331392711.

Here are the numbers, at least on my local Linux VM:

prepare/new             time:   [260.47 us 266.22 us 272.02 us]                        
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high severe
prepare/old             time:   [282.90 us 293.57 us 306.30 us]                        

query_prepared/new      time:   [252.40 us 258.39 us 264.29 us]                               
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high mild
query_prepared/old      time:   [197.38 us 199.81 us 202.27 us]                               
Found 2 outliers among 100 measurements (2.00%)
  1 (1.00%) low mild
  1 (1.00%) high severe

query/new               time:   [514.09 us 530.57 us 546.64 us]                      
Found 2 outliers among 100 measurements (2.00%)
  1 (1.00%) low mild
  1 (1.00%) high severe
query/old               time:   [420.15 us 422.89 us 425.17 us]                      
Found 20 outliers among 100 measurements (20.00%)
  5 (5.00%) low severe
  7 (7.00%) high mild
  8 (8.00%) high severe

Interestingly, query preparation is actually faster now, but we've lost some ground on making the query itself.

[sfackler]

I'm in the process of moving across the country, so I probably won't be able to spend too much time on this for the next week or two. However, given that prepare is now faster than it used to be, I'm hopeful we can make the same thing happen for query.

[Dowwie]

Hey @sfackler -- you're planning to address these query performance issues prior to v16, correct?

[sfackler]

I'm not sure - from profiling it appears that much of the time is being spent allocating and managing channels per request. There are more options to fix that with std::futures than old futures.

[sfackler]

I moved from a static multi-threaded runtime to per-connection runtimes for a 20% improvement: 09a63d6.

[bikeshedder]

I updated the benchmark repository and rerun it. I might be doing something wrong but it performance wise it doesn't look like 09a63d6 did have any effect:

https://github.com/bikeshedder/rust-postgres-benchmark

postgres-0.15.2

Elapsed time: 65057 ms
Performance: 15371 req/s

postgres-0.16-rc.2

Elapsed time: 134766 ms
Performance: 7420 req/s

tokio-postgres-0.3.0

Elapsed time: 141756 ms
Performance: 7054 req/s

tokio-postgres-0.4.0-rc.3

Elapsed time: 91957 ms
Performance: 10874 req/s

tokio-postgres-0.5.0-alpha.2

Elapsed time: 83041 ms
Performance: 12042 req/s

tokio-postgres-0.5.0-09a63d6

Elapsed time: 86778 ms
Performance: 11523 req/s

[sfackler]

That commit isn't in a published release.

[bikeshedder]

The benchmark tokio-postgres-0.5.0-09a63d6 uses the following dependency in its Cargo.toml:

tokio-postgres = { git = "https://github.com/sfackler/rust-postgres", commit = "09a63d62553da1625c0f8385ab15e815b78d587d", features = ["with-uuid-0_7"] }

[sfackler]

That commit doesn't change any code in tokio-postgres. It changes code in postgres.

[sfackler]

While I see a ton of variance across runs, the performance of querying one row from a pre-prepared statement is roughly the same in the current master branch and postgres 0.15.

[bikeshedder]

I think this one can be closed. The performance of tokio-postgres is fine and when using a statement cache it outperforms the old postgres-0.15.2 crate with ease.