Performance of Hasura over nginx reverse proxy

[rrjanbiah]

We have noticed that when adding nginx reverse proxy for the https support, the performance is degrading to approx 7x times (300ms to 2200ms). Is this a known issue? If this is already solved, can we get the ideal conf documented in https://hasura.io/docs/1.0/graphql/core/deployment/enable-https.html TIA

[tirumaraiselvan]

@rrjanbiah Is nginx colocated with the hasura container?

[rrjanbiah]

@rrjanbiah Is nginx colocated with the hasura container?

@tirumaraiselvan Yes (If you meant the same server)

[tirumaraiselvan]

@rrjanbiah Is it possible to run tcpdump in the server and collect the output?

[tirumaraiselvan]

@rrjanbiah You can also enable logging $upstream_response_time in nginx: https://nginx.org/en/docs/http/ngx_http_upstream_module.html#var_upstream_response_time

[rrjanbiah]

@tirumaraiselvan Sure, thanks a lot. Will try that

[rrjanbiah]

@tirumaraiselvan Please find the details that you requested. If you find anything obvious, please share. TIA

To get consistent result, ab with -c 10 -n 200 is used.

ab result when directly fetching results from Hasura (http on port 8081) with JWT - 322.695 ms mean

ab -n 200 -c 10 -v 4 -H 'accept: */*' -H 'Authorization: Bearer [xxx]' -H 'User-Agent: Mozilla/5.0 \
(X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.75 Safari/537.36' \
 -H 'Origin: http://my.localhost' -H 'Accept-Language: en-US,en;q=0.9' -H 'Accept-Language: \
en-US,en;q=0.9' -p users_gql_query.txt 'http://server.domain.example.com:8081/v1/graphql'

ab_direct_hasura.out.txt

ab result when fetching results from Hasura through nginx reverse proxy (https) with JWT - 2006.157 ms mean

ab -n 200 -c 10 -v 4 -H 'accept: */*' -H 'Authorization: Bearer [xxx]' -H 'User-Agent: Mozilla/5.0 \
(X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.75 Safari/537.36' \
 -H 'Origin: http://my.localhost' -H 'Accept-Language: en-US,en;q=0.9' -H 'Accept-Language: \
en-US,en;q=0.9' -p users_gql_query.txt 'https://server.domain.example.com/api/query'

ab_hasura_nginx.out.txt

tcpdump result when running ab - Hasura calls through nginx reverse proxy (https)

tcpdump.out.txt

access log with upstream_response_time - Hasura calls through nginx reverse proxy (https)

log_format upstream_time as in https://docs.nginx.com/nginx/admin-guide/monitoring/logging/#setting-up-the-access-log

access_log_urt.txt

[tirumaraiselvan]

From https://github.com/hasura/graphql-engine/files/5515049/access_log_urt.txt, we can see the upstream response time (uct, uht, urt) is more or less ~8ms. Though the total request time seems to vary between 0.2 to 1.2s (rt). Should you be running the ab test from a reliable network (maybe on the same machine as the services)?

Anyway, seems like most of the time is being spent by nginx (probably in SSL handshake).

Apart from rerunning the tests from a reliable network, could you also send the tcpdump output with -w filename.pcap flag added? And send across the filename.pcap?

[rrjanbiah]

@tirumaraiselvan Yes sure.

[rrjanbiah]

Directly fetching Hasura from same machine (http on port 8081) with JWT - 31.780 ms mean

1. ab result

ab -n 200 -c 10 -v 4 -H 'accept: */*' -H 'Authorization: Bearer [xxx]' -H \
 'User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) \
 Chrome/86.0.4240.75 Safari/537.36' -H 'Origin: http://localhost' -H \
'Accept-Language: en-US,en;q=0.9' -H 'Accept-Language: en-US,en;q=0.9' -p users_gql_query.txt \
'http://localhost:8081/v1/graphql'

ab_direct_result.out.txt

2. tcpdump pcap

Note: Had to mask server IP, sorry for that

tcpdump_direct.pcap.zip

Fetching Hasura through nginx reverse proxy from same machine (https) with JWT - 1555.028 ms mean

1. ab result

ab -n 200 -c 10 -v 4 -H 'accept: */*' -H 'Authorization: Bearer [xxx]' -H \
'User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) \
Chrome/86.0.4240.75 Safari/537.36' -H 'Origin: http://localhost' -H \
'Accept-Language: en-US,en;q=0.9' -H 'Accept-Language: en-US,en;q=0.9' \
-p users_gql_query.txt 'https://localhost/api/query'

ab_result_nginx.out.txt

2. access log with upstream_response_time

access.log

3. tcpdump pcap

tcpdump_nginx.pcap.zip

[rrjanbiah]

@tirumaraiselvan Forgot to tag you.

[tirumaraiselvan]

@rrjanbiah I don't think the tcpdump output is capturing container traffic on nginx. Please see this blogpost on one way to capture container traffic: https://medium.com/@xxradar/how-to-tcpdump-effectively-in-docker-2ed0a09b5406 . Another way is to exec into nginx container and run tcpdump:

1. docker exec -it nginx-container-name sh
2. apt update && apt install tcpdump
3. tcpdump -i eth0 -w traffic.pcap.
4. Copy the file from the container to host (or mount a volume from host into this container to start with).

Moving this to discussions as this is not a core product issue.

[rrjanbiah]

@tirumaraiselvan Just an update. Still figuring it out... not sure sure how to handle SSL through nginx docker. Our current setup is not using docker. So checking it.

[DhvanilPatel]

@rrjanbiah @tirumaraiselvan I'm facing such an issue too. Some queries which used to be very quick now take upto 2 / 3 seconds. I'm using docker and nginx-reverse-proxy as well. I've noticed this in the past week.

[rrjanbiah]

@DhvanilPatel Glad to know that I'm not alone :-)

[rrjanbiah]

FWIW, also crossposted to the nginx mailing list to see if we can get any insights http://mailman.nginx.org/pipermail/nginx/2020-November/060130.html

[rrjanbiah]

Reinis Rozitis in nginx mailing list has mentioned below. Will try that after Diwali and will share:

Looking at the github discussion - you are comparing http vs https.
Since you are not setting using keepalive 'ab' does the ssl handshake for each request. Try with 'ab -k ...'.

[rrjanbiah]

@tirumaraiselvan Apologies for the delay. Still can't figure out about the tcpdump as you wanted. But, based on the suggestion by Reinis Rozitis in the nginx mailing list, found something interesting.

DLDR;

keep-alive is not triggering in nginx when used with Hasura; but the same works for other REST services. I'm not sure if this is due to any response headers that Hasura is returning, or, due to Hasura's call are in POST. So, IMHO, still this looks like an issue or improvement that required from Hasura end. (FYI @DhvanilPatel)

Tools, commands and applications used

1. ab
2. ab -k
3. Hasura
4. Go True https://github.com/netlify/gotrue, especially the /settings endpoint in GET
5. nginx with 2 different conf (simple and optimized)

Benchmarks and factors

	Time per request (ms)	Factor
Hasura - ab - Direct	36.579	1
Hasura - ab - nginx - simple	1929.93	52.76060034
Hasura - ab - nginx - optimized	1939.657	53.02651795
Hasura - ab -k - Direct	26.944	0.7365975013
Hasura - ab -k - nginx - simple	1919.033	52.46269718
Hasura - ab -k - nginx - optimized	1938.435	52.9931108

	Time per request (ms)	Factor
Go True - ab - Direct	1.407	1
Go True - ab - nginx - simple	441.281	313.6325515
Go True - ab - nginx - optimized	411.653	292.5749822
Go True - ab -k - Direct	1.513	1.075337598
Go True - ab -k - nginx - simple	117.077	83.21037669
Go True - ab -k - nginx - optimized	141.344	100.4577114

Benchmark - detailed ab results

nginx - hasura performance - comparision on ab - All data.csv.txt

nginx conf files used (simple and optimized)

conf.d_used.zip

[tirumaraiselvan]

Let's continue in #6214

[tirumaraiselvan]

Answered here: #6214