Quick and Hacky: Creating an Apache Slow Requests Log

As long as I'm on the topic of debugging web apps, here's a useful technique I don't believe I've blogged about before.

First off, add the following to your Apache configuration:

  CustomLog /var/logs/httpd/server.debug_log "%{X-Forwarded-For}i\t%t\t%U\t%{ms}T"

Now, restart the server and confirm it's giving you intelligent output:

$ tail -3 /var/logs/httpd/server.debug_log

zz.zzz.zzz.zzz  [01/Apr/2016:18:33:07 +0000]    /xxxxx/xxxxx/xxxxx  109
zz.zzz.z.zzz    [01/Apr/2016:18:33:07 +0000]    /xxxxx/xxxxx/xxxxx  142
zzz.zzz.zz.zzz  [01/Apr/2016:18:33:07 +0000]    /xxxxx/xxxxx/xxxxx  177

That's: IP address, timestamp, URI, duration in milliseconds.

Now, for the magic. Use awk to filter the stream to only requests that take longer the N millis:

$ tail -f /var/logs/httpd/server.debug_log   | \
   awk '{if($5 > 800) { print $0}}'

The above will show you all requests that take more than 800 milliseconds to complete.

Send this to a log file, and you've got the web version of a MySQL Slow Queries log.

Happy debugging!