[edit] ngx_http_log_request_speed

The ngx_http_log_request_speed module is helping you to find the heavy requests of your webpage. I originally wrote the module for myself to be able to find the urls of our website that take long time to process, which are probably also the heavy ones that generate a lot of load on the server. By analyzing the slow request logs we can get hints on which parts of the website that we should probably recheck for their efficiency.

http {
      log_request_speed_filter on;
      log_request_speed_filter_timeout 3;
      ...
}

[edit] Directives

[edit] log_request_speed_filter

syntax: log_request_speed_filter [on|off]

default: n/a

context: location, server, http

This directive enables the log_request_speed filter for the location/server/http block you specify it in.

[edit] log_request_speed_filter_timeout

syntax: log_request_speed_filter_timeout [num milisec]

default: 5000

context: location, server, http

The timeout defines how long a request at least has to take to get logged. If the timeout is for example set to 5000 miliseconds, a request that takes 4000 miliseconds won't get a request speed log entry, a 6000 miliseconds taking one will get logged.

[edit] Usage

When a request gets to the log request speed filter and takes at least the defined timeout there will be an error log entry like the following:

2009/11/27 04:44:06 [error] 23261#0: *600563358 --- process request time: 3737 ms ---  while reading response header from upstream, 
client: 80.143.168.130, server: www.domain.com, request: "GET /nachrichten/read/in/neu/369217567 HTTP/1.1", 
upstream: "fastcgi://10.20.0.159:9000", host: "www.domain.com", referrer: "http://www.domain.com/nachrichten/in/neu/1"

The request time in the log is in miliseconds.

Once you got your nginx logging the request times, you can use the analyzer.pl script to find the requests that took the longest time at average.

# cd ~/request_speed_log_analyzer
# tail -n 10000 /var/log/nginx/error.log  | grep 'process request' | ./analyzer.pl  -r

POST /message/ajaxWrite/from_profile/toni32 HTTP/1.1 --- avg ms: 3110, value count: 1
POST /sessionupdate_prod.php HTTP/1.1 --- avg ms: 3312, value count: 137
GET /favoriten/1 HTTP/1.1 --- avg ms: 3345, value count: 76
GET /nachrichten/read/in/neu/369217567 HTTP/1.1 --- avg ms: 3737, value count: 1
POST /login_prod.php HTTP/1.1 --- avg ms: 4117, value count: 14
GET /wan/isonline?NICKNAME=luckynight&rtime=1259292758 HTTP/1.1 --- avg ms: 5267, value count: 1
GET /sessionupdate_prod.php HTTP/1.1 --- avg ms: 5572, value count: 8 <--- THE WINNER

[edit] Bugs/Feedback

In case you find any bugs, please write me a mail and I will try to help.

I tested the module only with nginx 0.6.35 and 0.7.64, no guarantee for other versions (nor the tested ones)

Mail: mauro.stettler(A.T)gmail.com

[edit] Download

File:Ngx http log request speed.tar.gz
File:Log Analyzer.tar.gz

HttpLogRequestSpeed

Contents