10

We have Nginx as a reverse proxy in front of Tomcat. Both of them log access with ISO 8601 timestamps, but tomcat adds in milliseconds (which is part of the standard). So if Nginx gets a request and passes it onto Tomcat, the Nginx log might have a timestamp of "2015-10-29T00:37:02+00:00" and Tomcat will have a timestamp of "2015-10-29T00:37:02,106+0000" for the same access. I'm not concerned about the minor differences in formatting, but not having milliseconds (the ",106" part in the Tomcat log) is a problem because it prevents us from correlating the logs correctly.

Is there any way to make Nginx include milliseconds in it's logs?

SamBarham
  • 123
  • 1
  • 4
  • Did you check the [docs](http://nginx.org/en/docs/http/ngx_http_log_module.html)? – jordanm Oct 29 '15 at 01:48
  • 1
    Yes I did. From that I can't see any way to log ISO 8601 timestamps with millisecond resolution, but that seems like a ridiculous oversight to me, especially given that it can log msec timestamps with millisecond resolution. So I was wondering/hoping that someone might know of a way to make Nginx log the way I want – SamBarham Oct 29 '15 at 02:44

3 Answers3

4

The question requested ISO 8601 plus milliseconds - here is a one-liner for that specific use case, based on Oleksandr's answer but using ISO rather than local format:

map "$time_iso8601 # $msec" $time_iso8601_ms { "~(^[^+]+)(\+[0-9:]+) # \d+\.(\d+)$" $1.$3$2; }

The result is constructed from the regex match groups as follows:

  • $1 = just the date and time part of $time_iso8601 e.g. 2021-05-21T10:26:19
  • $2 = just the timezone part of $time_iso8601 e.g. +00:00
  • $3 = just the millisecond part of $msec e.g. 123 extracted from 1621594635.123

If the one-liner feels too opaque, see this post (as commented on another answer) which uses multiple map statements.

sparrowt
  • 245
  • 2
  • 7
4

Unfortunately, based on reading the source code to nginx, there doesn't seem to be a simple way to do this. You would need to post-process the logs (you could take the output of $msec and turn it into ISO8601 with ms yourself) or patch nginx to add this.

Interestingly a patch was proposed years ago that would have given enough flexibility to make it possible, but I don't think it went anywhere: http://nginx.2469901.n2.nabble.com/PATCH-time-custom-supports-a-custom-log-timestamp-td3505292.html#none

Ed Rowe
  • 56
  • 1
3

Here is a workaround that I found. Add the following line to the http {} block:

map "$time_local:$msec" $time_local_ms { ~(^\S+)(\s+\S+):\d+\.(\d+)$ $1.$3$2; }

Then, in your log_format line change [$time_local] to [$time_local_ms], or create your own log format, e.g. the one that I use for Datadog:

log_format  common  '$remote_addr - $remote_user [$time_local_ms] "$request" '
                    '$status $body_bytes_sent $request_time "$http_referer" '
                    '"$http_user_agent" "$http_x_forwarded_for"';

Example of access log:

172.17.0.1 - - [23/Apr/2021:13:06:02.802 +0000] "GET /static/image.jpg HTTP/1.1" 304 0 0.000 "http://localhost/" "Mozilla" "-"

Source: https://grangerx.wordpress.com/2019/08/28/nginx-improve-logs-by-adding-millisecond-msec-resolution-to-time_local/

Oleksandr Shmyrko
  • 133
  • 5