Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

very slow queries through martin #1315

Closed
pcace opened this issue Apr 24, 2024 · 11 comments · Fixed by #1355
Closed

very slow queries through martin #1315

pcace opened this issue Apr 24, 2024 · 11 comments · Fixed by #1355
Labels
needs more info question

Comments

@pcace
Copy link

pcace commented Apr 24, 2024 •
edited

Hi there,

i am trying to find out why martin is so much slower then a direct query to the db.

this:
http://localhost:3000/query_tile/10/544/339
takes >13s to get the tile from the server via martin.
the martin log looks like this:

[2024-04-24T07:43:12Z DEBUG martin::pg::pg_source] SQL: SELECT "public"."query_tile"($1::integer, $2::integer, $3::integer) AS tile [10,544,339]
[2024-04-24T07:43:12Z DEBUG tokio_postgres::query] executing statement s7 with parameters: [10, 544, 339]
[2024-04-24T07:43:25Z INFO  actix_web::middleware::logger] 127.0.0.1 "GET /query_tile/10/544/339 HTTP/1.1" 200 440578 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36" 13.798128

using the function directly:
EXPLAIN (ANALYZE,VERBOSE) select query_tile(10,544,339)
results in:

"Planning Time: 328.475 ms"
"Execution Time: 0.023 ms"

so there is a gap of 13s where something happens.
i thought it might be the compression, but compressing the mvt tile from the db cannot take 13s. for comparison, the attached file takes 0.05s to compress using gzip. (is this comparable?)

time gzip -c 339 > 339.gz

real	0m0,056s
user	0m0,056s
sys	0m0,000s

how can i narrow down what the issue is? i have attached the resulting tile here.

All rows have spacial indices and are clustered.

339.zip

PS.: this is the martin config (changing from brotli to gzip does not make a huge difference):

keep_alive: 75
listen_addresses: "0.0.0.0:3000"
worker_processes: 8
cache_size_mb: 0
preferred_encoding: brotli
postgres:
  connection_string: "postgresql://postgres:postgrespw@localhost:5432/tilesDBtest"
  default_srid: 4326
  pool_size: 20
  max_feature_count: 100000
  auto_bounds: calc

  functions:
    query_tile:
      schema: public
      function: query_tile
      minzoom: 4
      maxzoom: 20
      bounds: [-180.0, -90.0, 180.0, 90.0]
@sharkAndshark
Copy link
Collaborator

sharkAndshark commented May 11, 2024 •
edited

Hi @pcace
Have you run the select query_tile(10,544,339) (without explain) directly? How many seconds it takes?

@jahermosilla
Copy link

Hi @sharkAndshark, I am in a similar situation.
In my case running the query directly (without EXPLAIN ANALYZE) from postgres takes ~400ms:

select tiles(14,8176,6234)

image

And martin takes ~6 seconds:

[2024-05-16T12:51:04Z INFO actix_web::middleware::logger] 172.19.0.1 "GET /tiles/14/8176/6234 HTTP/1.1" 200 739124 "http://localhost:3000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36" 6.002455

image

@nyurik
Copy link
Member

nyurik commented May 16, 2024

thanks for reporting! This is very concerning. Would it be possible to check if the issue is the same if an older martin version is used?

@jahermosilla
Copy link

I did a quick test on different versions of martin.

It seems to work pretty well from versions 0.9.0 to 0.11.6. I can see a noticeable regression when I use v0.12.0.

@nyurik
Copy link
Member

nyurik commented May 16, 2024

@jahermosilla thank you!!! I will have to dig deeper into what has happened at that point.

One thing that MIGHT help figure it out: would it be possible for you to run some sort of a stress test, e.g. request a tile in a loop using something like Oha, but make sure to use martin --cache-size 0 --pool-size 5 or even smaller pool size). While stress test is running, run this query from psql or other DB tool to see what your DB is doing (from stackoverflow):

SELECT datname, pid, state, query, age(clock_timestamp(), query_start) AS age 
FROM pg_stat_activity
WHERE state <> 'idle' 
    AND query NOT LIKE '% FROM pg_stat_activity %' 
ORDER BY age;

Ensure that there are no running queries in-between running different Martin versions.

This way we can:

  • see if any other slow running queries are still around, possibly slowing down the whole system
  • see if the tile generation query is the same between Martin versions, and if that query really does take many seconds to execute

@jahermosilla
Copy link

@nyurik, here are the results:

Martin config 
keep_alive: 75
listen_addresses: "0.0.0.0:3000"
worker_processes: 8
cache_size_mb: 0
preferred_encoding: gzip

postgres:
  connection_string: "postgresql://postgres:postgres@db:5432/db"
  default_srid: 4326
  pool_size: 4
  disable_bounds: false

  functions:
    tiles:
      schema: geo
      function: tiles
      source_id_format: "{function}"
      buffer: 64
      minzoom: 14
      maxzoom: 25
v0.11.6 
❯ oha -z 120s http://localhost:5000/tiles/14/8176/6234
Summary:
  Success rate: 100.00%
  Total:        120.0008 secs
  Slowest:      5.7591 secs
  Fastest:      0.4354 secs
  Average:      5.2303 secs
  Requests/sec: 9.7666

  Total data:   1000.03 MiB
  Size/request: 912.68 KiB
  Size/sec:     8.33 MiB

Response time histogram:
  0.435 [1]   |
  0.968 [6]   |
  1.500 [5]   |
  2.033 [7]   |
  2.565 [5]   |
  3.097 [4]   |
  3.630 [5]   |
  4.162 [6]   |
  4.694 [4]   |
  5.227 [173] |■■■■■■
  5.759 [906] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■

Response time distribution:
  10.00% in 5.1610 secs
  25.00% in 5.2564 secs
  50.00% in 5.3421 secs
  75.00% in 5.4183 secs
  90.00% in 5.4833 secs
  95.00% in 5.5236 secs
  99.00% in 5.5984 secs
  99.90% in 5.7440 secs
  99.99% in 5.7591 secs


Details (average, fastest, slowest):
  DNS+dialup:   0.0070 secs, 0.0008 secs, 0.1211 secs
  DNS-lookup:   0.0017 secs, 0.0000 secs, 0.0129 secs

Status code distribution:
  [200] 1122 responses

Error distribution:
  [50] aborted due to deadline
v0.12.0 
❯ oha -z 120s http://localhost:5000/tiles/14/8176/6234
Summary:
  Success rate: 100.00%
  Total:        120.0021 secs
  Slowest:      89.4509 secs
  Fastest:      6.0141 secs
  Average:      50.6991 secs
  Requests/sec: 1.0916

  Total data:   63.30 MiB
  Size/request: 800.22 KiB
  Size/sec:     540.14 KiB

Response time histogram:
   6.014 [1]  |■
  14.358 [7]  |■■■■■■■■■■■
  22.701 [8]  |■■■■■■■■■■■■
  31.045 [4]  |■■■■■■
  39.389 [4]  |■■■■■■
  47.733 [5]  |■■■■■■■■
  56.076 [9]  |■■■■■■■■■■■■■■
  64.420 [12] |■■■■■■■■■■■■■■■■■■■
  72.764 [20] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  81.107 [10] |■■■■■■■■■■■■■■■■
  89.451 [1]  |■

Response time distribution:
  10.00% in 16.0105 secs
  25.00% in 31.0666 secs
  50.00% in 60.8164 secs
  75.00% in 69.5884 secs
  90.00% in 74.7607 secs
  95.00% in 77.9642 secs
  99.00% in 89.4509 secs
  99.90% in 89.4509 secs
  99.99% in 89.4509 secs


Details (average, fastest, slowest):
  DNS+dialup:   0.0046 secs, 0.0000 secs, 0.0778 secs
  DNS-lookup:   0.0016 secs, 0.0000 secs, 0.0105 secs

Status code distribution:
  [200] 81 responses

Error distribution:
  [50] aborted due to deadline
Running queries during test on v.0.11.6 (every second) 
 datname | pid  | state  |                                             query                                              |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.004907
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.195591
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.196385
 db      | 1616 | active | SELECT          ST_AsMVT(tile, 'tiles', 4096, 'geometry') FROM (\r           +| 00:00:00.246769
         |      |        |     select\r                                                                                  +|
         |      |        |           [OMITED],
      +|
         |      |        |     ST_AsMVTGeom(\r
      +|
         |      |        |         ST_Transform(ST_CurveToLine(x.geometry), 3857),\r
      +|
         |      |        |         ST_TileEnvelope(z, x, y),\r
      +|
         |      |        |         4096, 64, true\r
      +|
         |      |        |     ) AS geometry\r
      +|
         |      |        |         FROM [OMITED] xx\r

         |      |        |         WHERE xx.geometry && ST_TileEnvelope(z, x, y)\r
      +|
         |      |        |   ) as tile WHERE geometry IS NOT NULL
       |
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.24677
(5 rows)

                                                    Fri May 17 14:00:41 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.054727
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.113057
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.328635
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.371165
(4 rows)

                                                    Fri May 17 14:00:42 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.002267
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.13379
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.231671
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.294789
(4 rows)

                                                    Fri May 17 14:00:43 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.04163
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.114376
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.203973
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.246527
(4 rows)

                                                    Fri May 17 14:00:44 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.136439
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.185399
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.294084
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.294088
(4 rows)

                                                    Fri May 17 14:00:45 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.162713
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.187907
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.272371
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.353877
(4 rows)

                                                    Fri May 17 14:00:46 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.274781
(1 row)

                                                    Fri May 17 14:00:47 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.081421
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.114244
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.168092
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.37592
(4 rows)

                                                    Fri May 17 14:00:48 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.136693
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.209694
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.326173
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.386165
(4 rows)

                                                    Fri May 17 14:00:49 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.134637
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.349381
(2 rows)

                                                    Fri May 17 14:00:50 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.05008
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.15786
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.177105
(3 rows)

                                                    Fri May 17 14:00:51 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.019662
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.021038
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.278052
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.283921
(4 rows)

                                                    Fri May 17 14:00:52 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.0795
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.100143
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.377697
(3 rows)

                                                    Fri May 17 14:00:53 2024 (every 1s)

 datname | pid  | state  |                                             query
       |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1596 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.128012
 db      | 1595 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.164013
 db      | 1589 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.259666
 db      | 1590 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.313145
(4 rows)
Running queries during test on v.0.12.0(every second) 
db=# SELECT datname, pid, state, query, age(clock_timestamp(), query_start) AS age
FROM pg_stat_activity
WHERE state <> 'idle'
    AND query NOT LIKE '% FROM pg_stat_activity %'
ORDER BY age;
 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

db=# \watch 1
 Fri May 17 13:57:40 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:57:41 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:57:42 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:57:43 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:57:44 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

^C
db=# \watch 1
 Fri May 17 13:58:04 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

                                                    Fri May 17 13:58:05 2024 (every 1s)

 datname | pid  | state  |                                             query
  |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1374 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.020556
 db      | 1388 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.020561
(2 rows)

 Fri May 17 13:58:06 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:07 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:08 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:09 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:10 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

                                                    Fri May 17 13:58:11 2024 (every 1s)

 datname | pid  | state  |                                             query
  |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1373 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.000724
 db      | 1389 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.096582
 db      | 1388 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.096583
(3 rows)

 Fri May 17 13:58:12 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:13 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:14 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:15 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:16 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

                                                    Fri May 17 13:58:17 2024 (every 1s)

 datname | pid  | state  |                                             query
  |       age
---------+------+--------+------------------------------------------------------------------------------------------------+-----------------
 db      | 1389 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.121798
 db      | 1373 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.128111
 db      | 1374 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.165167
(3 rows)

                                                    Fri May 17 13:58:18 2024 (every 1s)

 datname | pid  | state  |                                             query
  |      age
---------+------+--------+------------------------------------------------------------------------------------------------+----------------
 db      | 1373 | active | SELECT "geo"."tiles"($1::integer, $2::integer, $3::integer) AS tile | 00:00:00.33792
(1 row)

 Fri May 17 13:58:19 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:20 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

 Fri May 17 13:58:21 2024 (every 1s)

 datname | pid | state | query | age
---------+-----+-------+-------+-----
(0 rows)

@jahermosilla
Copy link

From what I can see from the results it seems martin is doing something when processing a tile that is blocking/enqueueing other request?

@nyurik
Copy link
Member

nyurik commented May 19, 2024

I wish more users would do as much testing to help as you! There's clearly a hiccup somewhere in Martin. The next step is to use something like perf to do sampling profiling of Martin, and see if we can get some stats on the most common stack traces. Of course, it could be some issue related to an upstream lib being updated.

@jahermosilla
Copy link

Thank you for your helpful guidance @nyurik ! I'll try it! What steps should I take? I'm not very familiar with Rust but if you guide me a little bit, I'll take some time and come back with the results.

@nyurik
Copy link
Member

nyurik commented May 26, 2024 •
edited

Running a quick perf test seems to indicate the culprit is Brotli :( I ran a few minute perf test using cargo flamegraph and oha as described above. The two biggest time takers - aprox 80% between the two. I have been working with @danielrh to slowly clean up and reduce the machine generated C++ -> Rust Brotli code and try to speed it up.

The flamegraph below can be examined interactively here.

image
image

flame

@nyurik
Copy link
Member

nyurik commented May 26, 2024 •
edited

Another confirmation for this is that when I run oha -z 1h http://localhost:3000/points1/0/0/0 --disable-compression I see 10x performance improvement. Sadly, OHA does not yet allow specific accept header param (I created an issue for that) - so cannot do direct gzip vs brotli comparison.

This was referenced May 26, 2024
Open
Merged
nyurik added a commit that referenced this issue May 29, 2024
@nyurik
Fix preferred encoding computation (#1355)
e4228fb 
* Decides which encoding to use depending on both `Accept-Encode` and
the preferred encoding (chooses the preferred one in case brotli and
gzip have the same q value)
* Uses `gzip` by default

This will fix #1315
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
needs more info question
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix preferred encoding computation nyurik/martin
4 participants
@pcace @nyurik @sharkAndshark @jahermosilla