Nginx access log variables not set when the header-reading times out

Question

Is there a way to set user-defined variables and use them in access logs before the NGINX rewrite phase? In some error scenarios, like the one defined below, we end-up in the access log phase before any user variable is set.

The following is the access log format example I have:

log_format main '$remote_addr $server_addr $http_host $custom_destination_addr [$custom_request_time] ' ' "$request" $status $body_bytes_sent "$http_user_agent" ';

The fields that start with "custom_" are user-defined variables.

When I send the following get message that has a non-terminated header; i.e., header terminated with "/r/n" instead of "/r/n/r/n":

get = "GET /Vod/mod/video16k_1.mp4 HTTP/1.1\r\nHost: 10.20.20.10:8585\r\nUser-Agent: HTTP Test Suite TestSuite/1.0.2\r\nAccept-Language: en-us,en;q=0.5\r\nAccept-Encoding: gzip,deflate\r\nConnection: keep-alive\r\n"

I get the following info in error.log: [info] 28875#0: *1 client timed out (110: Connection timed out) while reading client request headers, client: 10.20.20.128, server: , request: "GET /Vod/mod/video16k_1.mp4 HTTP/1.1", host: "10.20.20.10:8585"

Then, it generates an access log entry where ALL the user-defined variables are found uninitialized:

2017/09/01 10:03:07 [warn] 28875#0: *1 using uninitialized "custom_destination_addr" variable while logging request, client: 10.20.20.128, server: , request: "GET /Vod/mod/video16k_1.mp4 HTTP/1.1", host: "10.20.20.10:8585"

2017/09/01 10:03:07 [warn] 28875#0: *1 using uninitialized "custom_request_time" variable while logging request, client: 10.20.20.128, server: , request: "GET /Vod/mod/video16k_1.mp4 HTTP/1.1", host: "10.20.20.10:8585"

Access log entry:

10.20.20.128 10.20.20.10 10.20.20.10:8585 [] "GET /Vod/mod/video16k_1.mp4 HTTP/1.1" 408 0 "" "HTTP Test Suite TestSuite/1.0.2"

When I properly set the end of header "/r/n/r/n", then the access logs are fine.

Therefore, under the error condition above (time out when reading header), the access log variables that are user-defined will ALL get EMPTY.

Is there a known solution to this problem, or do we need a new concept/feature in NGIMX to support variable-setting before rewrite phase?

Thanks

Tarun Lalwani · Accepted Answer · 2017-09-05 18:35:44Z

0

Posting as comment in answer because the comment needs formatting

How about using map?

map $custom_request_time $custom_request_time_log {
   default $custom_request_time;
   '' 'Not Available';
}

and then using that in log?

log_format main '$remote_addr $server_addr $http_host $custom_destination_addr [$custom_request_time_log] ' ' "$request" $status $body_bytes_sent "$http_user_agent" ';

answered Sep 5, 2017 at 18:35

Tarun Lalwani

147k11 gold badges218 silver badges279 bronze badges

Sign up to request clarification or add additional context in comments.

5 Comments

developer Over a year ago

How do you set the value of the variable in the map, if I have to do some time formatting using a lua code in log_by_lua? Would appreciate if you could provide details about setting this value in the map based a log by lua code.

Tarun Lalwani Over a year ago

Your code needs to set custom_request_time using ngx.var.custom_request_time and rest will be taken care by map

developer Over a year ago

My fundamental question is: Is it possible to set a variable per request before the NGINX rewrite phase and use that variable in the access logs?

Tarun Lalwani Over a year ago

If you mean for the next request then I doubt, because after the rewrite a 301 will be sent and a new request will come, so the access log can use a variable for 301 but not for the next request. Other possible option is to add PARAMS to querystring or cookie or something else

developer Over a year ago

Setting the variable ngx.var.custom_request_time (as you suggest) requires nginx to go through the rewrite phase. If the request processing stops before that phase, this variable will never be set. This happens, for instance, when you send a request without end-of-header "/r/n/r/n"

Collectives™ on Stack Overflow

Nginx access log variables not set when the header-reading times out

1 Answer 1

5 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

5 Comments

Your Answer

Sign up or log in

Post as a guest

Related