Blackbox Logs

I attempted to get a discussion going on ServerFault.com regarding
“blackbox” logs and Nginx. It didn’t get the response I imagined, and
I was told to ask here.

Here is an article about “blackbox” logs in Apache by Chris Josephes
from 2004.

I’ve always kept these logs around on my Apache servers and they have
come in handy. I’m trying to recreate them for Nginx. Here is the
Apache format.

LogFormat “%a/%S %X %t "%r" %s/%>s %{pid}P/%{tid}P %T/%D %I/%O/%B”
blackbox

Here’s what Nginx blackbox format would look like, the unmapped Apache
directives have question marks after their names.
access_log blackbox ‘$remote_addr/$remote_port X? [$time_local]
“$request”’
‘s?/$status $pid/0 T?/D? I?/$bytes_sent/
$body_bytes_sent’
Here’s a table of the variables I’ve been able to map from the Nginx
documentation.
%a = $remote_addr - The IP address of the remote client.
%S = $remote_port - The port of the remote client.
%X = ? - Keep alive status.
%t = $time_local - The start time of the request.
%r = $request - The first line of request containing method verb, path
and protocol.
%s = ? - Status before any redirections.
%>s = $status - Status after any redirections.
%{pid}P = $pid - The process id.
%{tid}P = N/A - The thread id, which is non-applicable to Nignx.
%T = ? - The time in seconds to handle the request.
%D = $request_time - The time in milliseconds to handle the request.
%I = ? - The count of bytes received including headers.
%O = $bytes_sent - The count of bytes sent including headers.
%B = $body_bytes_sent - The count of bytes sent excluding headers, but
with a 0 for none instead of ‘-’.
So, I’m missing %I bytes received and %X keep alive status. The
timings are off, but I don’t mind.
Nginx doesn’t to milliseconds like Apache, but rather seconds with
millisecond precision. Making the log format exactly like the Apache
blackbox log format would be a nice exercise, but it is not
imperative. If Nginx can do simple adjustments using multiplication
that would be cool, but I haven’t tried it yet, nor have I seen any
examples of it.
Alan G. - http://twitter.com/bigeasy

Maxim D. wrote:

Actually, most important thing to log is $upstream_response_time.
So it’s not a good idea to log something in an “apache compatible”
format as you are going to log wrong metrics in this case.

To this point, I’m really looking to create something that is
conceptually compatible to the log format described in the original
article, a log format geared towards generalized performance and
security auditing, rather than hit counting. There is no need to record
thread id, in Nginx, quite obviously. If there was a legacy of scripts
for the “blackbox” log format described by Chris Josephes, that might be
a different matter, but there are not. My own little Nginx “blackbox”
format will include $upstream_response_time as you suggest.

Thank you very much for filling in the blanks for me.

Alan G. - http://twitter.com/bigeasy

Hello!

On Thu, Jun 17, 2010 at 10:59:27AM -0500, Alan G. wrote:

have come in handy. I’m trying to recreate them for Nginx. Here is
$body_bytes_sent’
Here’s a table of the variables I’ve been able to map from the Nginx
documentation.
%a = $remote_addr - The IP address of the remote client.
%S = $remote_port - The port of the remote client.
%X = ? - Keep alive status.

Logging $sent_http_connection should be enough, but due to a bug
it currently always evaluates to “closed” during request logging.
Patch below.

%t = $time_local - The start time of the request.
%r = $request - The first line of request containing method verb,
path and protocol.
%s = ? - Status before any redirections.

There is no such thing in nginx.

%>s = $status - Status after any redirections.
%{pid}P = $pid - The process id.
%{tid}P = N/A - The thread id, which is non-applicable to Nignx.
%T = ? - The time in seconds to handle the request.
%D = $request_time - The time in milliseconds to handle the request.
%I = ? - The count of bytes received including headers.

$request_length

Note that it’s including headers, while documentation says (in
russian) something like “length of request body”.

examples of it.
Actually, most important thing to log is $upstream_response_time.
So it’s not a good idea to log something in an “apache compatible”
format as you are going to log wrong metrics in this case.

Maxim D.

p.s.

diff --git a/src/http/ngx_http_request.c b/src/http/ngx_http_request.c
— a/src/http/ngx_http_request.c
+++ b/src/http/ngx_http_request.c
@@ -2435,10 +2435,10 @@ ngx_http_set_keepalive(ngx_http_request_
}
}

  • ngx_http_free_request(r, 0);
  • r->keepalive = 0;
  • ngx_http_free_request(r, 0);

  • c->data = hc;

    ngx_add_timer(rev, clcf->keepalive_timeout);

Hello!

On Fri, Jun 18, 2010 at 04:14:21PM -0500, Alan G. wrote:

is no need to record thread id, in Nginx, quite obviously. If there
was a legacy of scripts for the “blackbox” log format described by
Chris Josephes, that might be a different matter, but there are not.
My own little Nginx “blackbox” format will include
$upstream_response_time as you suggest.

Just a quick note:

You may also want to include $upstream_addr and
$upstream_status for configurations with more than one upstream
server, and $upstream_cache_status for configurations using
proxy/fastcgi cache.

Other things to consider: $gzip_ratio, $pipe.

Maxim D.