Nginx is awesome, but it’s missing some common features. For instance, a common thing to add to access logs is a unique ID per request, so that you can track the flow of a single request through multiple services. Another thing it’s missing is the ability to log request_time in milliseconds, rather than seconds with a millisecond granularity. Using Lua, we can add these features ourselves.
I’ll show the whole solution, then I’ll break it down into parts:
http {
...
map $host $request_time_ms {
default '';
}
map $host $uuid {
default '';
}
lua_package_path '/etc/nginx/uuid4.lua';
init_by_lua '
uuid4 = require "uuid4"
math = require "math"
';
log_by_lua '
ngx.var.request_time_ms = math.floor(tonumber(ngx.var.request_time) * 1000)
';
log_format mycustomformat '[$time_local] "$request" $status $request_length $bytes_sent $request_time_ms $uuid';
access_log /var/log/nginx/access.log mycustomformat;
...
}
server {
...
set_by_lua $uuid '
if ngx.var.http_x_request_id == nil then
return uuid4.getUUID()
else
return ngx.var.http_x_request_id
end
';
...
}
It’s necessary to set variables before we use them in Lua. Using map is a trick to set variables in the http context (you can’t use set $variable ” in http). For the case of uuid, we are going to set it in the server section (during the rewrite context), but in case it’s not set, we want to avoid throwing errors. Here’s how we set these variables:
map $host $request_time_ms {
default '';
}
map $host $uuid {
default '';
}
Next we add a uuid4 library to our path, and include the libraries into our context:
lua_package_path '/etc/nginx/uuid4.lua';
init_by_lua '
uuid4 = require "uuid4"
math = require "math"
';
Using the log_by_lua function, we’ll set the request_time_ms variable we’ll use in the log_format config. This Lua function is called in the log context, before logs are written, allowing us to make the variables available to it:
log_by_lua '
ngx.var.request_time_ms = math.floor(tonumber(ngx.var.request_time) * 1000)
';
Next we set the log format, and use it for the access log:
log_format mycustomformat '[$time_local] "$request" $status $request_length $bytes_sent $request_time_ms $uuid';
access_log /var/log/nginx/access.log mycustomformat;
Lastly, we set the uuid during the rewrite context in the server section, using set_by_lua. To facilitate following a request across services, we’ll reuse the header if it’s already set. If the header isn’t set, then this request didn’t come from another service, so we’ll generate a UUID:
server {
...
set_by_lua $uuid '
if ngx.var.http_x_request_id == nil then
return uuid4.getUUID()
else
return ngx.var.http_x_request_id
end
'
...
}
If you’re trusting this header data in any way, you should be sure to filter/restrict that header appropriately so that the client can’t change it.
Update (Thursday December 11 2014): Edited the post to move the uuid generation into the server section and using set_by_lua, so that the uuid can be set to/from the header to flow through the stacks properly. Shout out to Asher Feldman for working out a better solution with me.
参考资料：
Using Lua in Nginx for unique request IDs and millisecond times in logs：http://ryandlane.com/blog/2014/12/11/using-lua-in-nginx-for-unique-request-ids-and-millisecond-times-in-logs/
Simple nginx lua script to add UUID to each request for end to end request tracking：https://gist.github.com/erikcw/e999e1fb438dbbb91533
Is there a way to log a per request unique id for nginx?：http://serverfault.com/questions/580394/is-there-a-way-to-log-a-per-request-unique-id-for-nginx
http://stackoverflow.com/questions/17748735/setting-a-trace-id-in-nginx-load-balancer