Hi,

I am using Nginx as reverse proxy to my backend (Java app with Spring boot). In overall (avg, p50, p90, p95, p99 latencies) it performs well. But time to time, I see latency spikes around 100-200 milliseconds. When I enabled the access logs, I see that upstream response time (upstream_response_time) is very low even though request time (request_time) is high. For example,

[25/Apr/2020:18:28:17 +0000] "XXX" XXX - request="POST /v1/composite-monitoring-data HTTP/1.1" status=429 request_time=0.081 trace_id="Root=1-5ea48141-2f8e07a4c7c71a1360d9c5f5" request_length=9864 bytes_sent=979 body_bytes_sent=623 upstream_addr=127.0.0.1:5000 upstream_status=429 upstream_response_time=0.004 upstream_connect_time=0.000 upstream_header_time=0.004 user_agent="okhttp/3.10.0" current_time_msec=1587839297.256
...
[25/Apr/2020:18:28:17 +0000] "XXX" XXX - request="POST /v1/composite-monitoring-data HTTP/1.1" status=429 request_time=0.084 trace_id="Root=1-5ea48141-51f0d12a6f7c4b0651f6ef42" request_length=20534 bytes_sent=979 body_bytes_sent=623 upstream_addr=127.0.0.1:5000 upstream_status=429 upstream_response_time=0.000 upstream_connect_time=0.000 upstream_header_time=0.000 user_agent="okhttp/3.10.0" current_time_msec=1587839297.278

Also here is my nginx.conf file:

worker_processes auto;
worker_rlimit_nofile 32768;

events {
worker_connections 4096;
use epoll;
multi_accept on;
}

http {

include /etc/nginx/mime.types;
include /etc/nginx/conf.d/*.conf;

default_type application/json;

sendfile on;
tcp_nopush off;
tcp_nodelay on;

keepalive_timeout 300;
keepalive_requests 10000;

client_body_timeout 15;
client_header_timeout 15;
client_body_buffer_size 4m;
client_max_body_size 4m;

log_format main '[$time_local] "$http_x_forwarded_for" $remote_addr - '
'request="$request" status=$status request_time=$request_time trace_id="$http_x_amzn_trace_id" '
'request_length=$request_length bytes_sent=$bytes_sent body_bytes_sent=$body_bytes_sent '
'upstream_addr=$upstream_addr '
'upstream_status=$upstream_status '
'upstream_response_time=$upstream_response_time '
'upstream_connect_time=$upstream_connect_time '
'upstream_header_time=$upstream_header_time '
'user_agent="$http_user_agent" '
'current_time_msec=$msec';

access_log /var/log/nginx/access.log main;

upstream http_backend {
server 127.0.0.1:5000;

keepalive 1024;
}

server {

listen 80;
listen [::]:80;

server_name _ localhost;

location /v1 {
proxy_pass http://http_backend/v1;
proxy_set_header Host $host;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Request-Start $msec;
proxy_set_header Connection "";
proxy_http_version 1.1;

keepalive_timeout 300;
keepalive_requests 10000;
}

location /ping {
proxy_pass http://http_backend/ping;
}

}

}

What might cause this big difference between the request time and upstream response time? Is there anything I need to configure and not configured properly?