module tracking for access log, error log, etc.

[Jeff Trawick <tr...@gmail.com>]

There's a note that contains the module name, return code, and hook
name when a module fails a request.  Here it is in the access log:

127.0.0.1 - x [04/Nov/2010:16:40:45 -0400] "GET /index.html HTTP/1.1"
500 528 mod_auth_basic.c/500/check_user_id
127.0.0.1 - - [04/Nov/2010:17:26:02 -0400] "GET /test HTTP/1.1" 500 15
mod_test.c/500/handler

There's a debug log message potentially written at the same time:

[Thu Nov 04 17:26:02.381117 2010] [core:debug] [pid 11684:tid
3043707760] log.c(1753): [client 127.0.0.1:54095] mod_test.c handler
-> 500

There's a note that contains the active module, if any.  Here it is
logged from mod_whatkilledus:

[Thu Nov  4 17:25:48 2010] pid 11682 mod_whatkilledus sig 11 crash
[Thu Nov  4 17:25:48 2010] pid 11682 mod_whatkilledus active
connection: 127.0.0.1:54094->127.0.0.1:8080 (conn_rec 9239e20)
[Thu Nov  4 17:25:48 2010] pid 11682 mod_whatkilledus active request
(request_rec 923fcf8):
GET /test?crash HTTP/1.1|Host:127.0.0.1%3a8080|User-Agent:Mozilla/5.0
(X11; U; Linux i686; en-US; rv%3a1.9.2.12) Gecko/20101027 Ubuntu/10.04
(lucid) Firefox/3.6.12|Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8|Accept-Language:en-us,en;q=0.5|Accept-Encoding:gzip,deflate|Accept-Charset:ISO-8859-1,utf-8;q=0.7,*;q=0.7|Keep-Alive:115|Connection:keep-alive|Authorization:Basic
eDp4
[Thu Nov  4 17:25:48 2010] pid 11682 mod_whatkilledus active module:
mod_test.c/handler
[Thu Nov  4 17:25:48 2010] pid 11682 mod_whatkilledus end of report

Let's say you want to do stuff like this in your patched httpd.
Accessing args of a hook, which you'd want to do to log or find a good
place to save info for reporting later or other reasons, is a pain.

args are represented inside the hook macros as ([arg1][,arg2]...)
since different hooks have different argument lists.  I don't know how
to get rid of those parens in order to pass 1 or more to a function
that has other parameters.  IOW, you can't do

my_logging_fn(hook_name, (arg1,arg2,arg3))

Since I only cared about the first arg in my demonstration, I created
a function that can grab the first arg to the hook.  It is invoked
inside the macro as

ap_hook_probe_arg1 args

which expands to

ap_hook_probe_arg1(arg1, arg2, arg3, ...)

That works ok except for hooks which have no args.  AFAIK you can't
have a variadic function with 0 args.  I think the two current hooks
with 0 args are mpm_get_name and optional_fn_retrieve.  The latter
probably deserves a server_rec ptr, but mpm_get_name doesn't.  (My
patch doesn't encounter mpm_get_name()).

Any C tricks for that?

Short of tricks, I guess manufacturing a function or macro name from
the hook name (as is done for DTrace) is the required solution, and
you end up creating a bunch of functions or macros, one set per hook.

Another issue is that the return code types are not consistent (mostly
int, but a few pointers) and I've also kludged that up by casting
everything to void *.  Again, I guess you really need to manufacture a
function or macro name from the hook and invoke that.