Writing the total request time in seconds to an nginx access log, possibly using a calculated variable

Question

I'm trying to modify my nginx access log format to include the request duration, in seconds.

I see two possible variables I could use:

1) $request_time

2) $upstream_response_time

However both of these variables are expressed in microseconds, and I need this value to be rendered in seconds. Is there any way to specify the output as an expression (i.e. $request_time * 1000) or accomplish this in some other way?

Thanks

Solution

If you use a reporter like LogStash (ELK stack) you can do some calculation when parsing the log. Here is my example to convert second into millisecond in my Logstash filter for Nginx:

grok {
      match => {
        "message" => "%{IPORHOST:clientip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:timestamp}\] \"%{WORD:verb} %{URIPATHPARAM:logMessage} HTTP/%{NUMBER:httpversion}\" %{NUMBER:response} (?:%{NUMBER:bytes}|-) (?:\"(?:%{URI:referrer}|-)\"|%{QS:referrer}) %{QS:agent} rt=%{NUMBER:duration_sec} cid=%{GREEDYDATA:correlationId}"
      }
}
mutate { convert => [ "duration_sec", "float" ] }
ruby { code => "event['duration_ms'] = event['duration_sec'].to_f * 1000" }

Hope this helps.

Comments

[Maxim Dounin]

Actually, both are already in seconds (with millisecond resolution, i.e. $request_time will look like 1.234). Note well that $upstream_response_time format is more complex as it might contain timing for multiple upstream servers.