SEO

Hi guys,

I needed microsecond logging in the httpd, so I added the %D option to
LogFormat. [I followed the conventions used in Apache 2.x.]

This applies cleanly against the source for 4.2 (and should apply
cleanly to -current.)

*** WARNING ************
* Be sure to run:

make -f Makefile.bsd-wrapper includes

or the updated httpd.h file won't be installed.

* Rebuild any non-default apache modules from ports, or they will
probably blow chunks.

Cheers, Matthew


File /usr/src/usr.sbin/httpd/obj is not a regular file or directory and was skipped
diff -urN /usr/src/usr.sbin/httpd/src/include/httpd.h httpd-hprd/httpd/src/include/httpd.h
--- /usr/src/usr.sbin/httpd/src/include/httpd.h Wed Feb 22 08:07:12 2006
+++ httpd-hprd/httpd/src/include/httpd.h Tue Jan 8 04:08:07 2008
@@ -693,6 +693,7 @@
const char *hostname; /* Host, as set by full URI or Host: */

time_t request_time; /* When the request started */
+ long request_time_usec; /* The microsecond when the request started */

const char *status_line; /* Status line, if set by script */
int status; /* In any case */
diff -urN /usr/src/usr.sbin/httpd/src/main/http_main.c httpd-hprd/httpd/src/main/http_main.c
--- /usr/src/usr.sbin/httpd/src/main/http_main.c Fri Aug 10 06:52:02 2007
+++ httpd-hprd/httpd/src/main/http_main.c Tue Jan 8 23:36:33 2008
@@ -780,7 +780,11 @@
if (!current_conn->keptalive) {
/* in some cases we come here before setting the time */
if (log_req->request_time == 0) {
- log_req->request_time = time(NULL);
+ struct timeval tv;
+ struct timezone tz;
+ gettimeofday(&tv, &tz);
+ log_req->request_time = (time_t)tv.tv_sec;
+ log_req->request_time_usec = tv.tv_usec;
}
ap_log_transaction(log_req);
}
diff -urN /usr/src/usr.sbin/httpd/src/main/http_protocol.c httpd-hprd/httpd/src/main/http_protocol.c
--- /usr/src/usr.sbin/httpd/src/main/http_protocol.c Mon Nov 20 01:20:34 2006
+++ httpd-hprd/httpd/src/main/http_protocol.c Tue Jan 8 23:37:28 2008
@@ -965,13 +965,17 @@
* have to block during a read.
*/
ap_bsetflag(conn->client, B_SAFEREAD, 1);
+ struct timeval tv;
+ struct timezone tz;
while ((len = ap_getline(l, sizeof(l), conn->client, 0)) <= 0) {
if ((len < 0) || ap_bgetflag(conn->client, B_EOF)) {
ap_bsetflag(conn->client, B_SAFEREAD, 0);
/* this is a hack to make sure that request time is set,
* it's not perfect, but it's better than nothing
*/
- r->request_time = time(0);
+ gettimeofday(&tv, &tz);
+ r->request_time = (time_t)tv.tv_sec;
+ r->request_time_usec = tv.tv_usec;
return 0;
}
}
@@ -980,7 +984,9 @@

ap_bsetflag(conn->client, B_SAFEREAD, 0);

- r->request_time = time(NULL);
+ gettimeofday(&tv, &tz);
+ r->request_time = (time_t)tv.tv_sec;
+ r->request_time_usec = tv.tv_usec;
r->the_request = ap_pstrdup(r->pool, l);
r->method = ap_getword_white(r->pool, &ll);
uri = ap_getword_white(r->pool, &ll);
diff -urN /usr/src/usr.sbin/httpd/src/main/http_request.c httpd-hprd/httpd/src/main/http_request.c
--- /usr/src/usr.sbin/httpd/src/main/http_request.c Wed Feb 9 05:13:10 2005
+++ httpd-hprd/httpd/src/main/http_request.c Tue Jan 8 04:04:39 2008
@@ -671,6 +671,7 @@
rnew = make_sub_request(r);
rnew->hostname = r->hostname;
rnew->request_time = r->request_time;
+ rnew->request_time_usec = r->request_time_usec;
rnew->connection = r->connection;
rnew->server = r->server;
rnew->request_config = ap_create_request_config(rnew->pool);
@@ -766,6 +767,7 @@
rnew = make_sub_request(r);
rnew->hostname = r->hostname;
rnew->request_time = r->request_time;
+ rnew->request_time_usec = r->request_time_usec;
rnew->connection = r->connection;
rnew->server = r->server;
rnew->request_config = ap_create_request_config(rnew->pool);
@@ -1284,6 +1286,7 @@
new->proto_num = r->proto_num;
new->hostname = r->hostname;
new->request_time = r->request_time;
+ new->request_time_usec = r->request_time_usec;
new->main = r->main;

new->headers_in = r->headers_in;
diff -urN /usr/src/usr.sbin/httpd/src/modules/standard/mod_log_config.c httpd-hprd/httpd/src/modules/standard/mod_log_config.c
--- /usr/src/usr.sbin/httpd/src/modules/standard/mod_log_config.c Wed Feb 9 05:13:10 2005
+++ httpd-hprd/httpd/src/modules/standard/mod_log_config.c Tue Jan 8 04:04:39 2008
@@ -146,6 +146,7 @@
* %...{format}t: The time, in the form given by format, which should
* be in strftime(3) format.
* %...T: the time taken to serve the request, in seconds.
+ * %...D: the time taken to serve the request, in microseconds.
* %...u: remote user (from auth; may be bogus if return status (%s) is 401)
* %...U: the URL path requested.
* %...v: the configured name of the server (i.e. which virtual host?)
@@ -449,6 +450,14 @@
return ap_psprintf(r->pool, "%ld", (long)(time(NULL) - r->request_time));
}

+static const char *log_request_duration_microseconds(request_rec *r, char *a)
+{
+ struct timeval tv;
+ struct timezone tz;
+ gettimeofday(&tv, &tz);
+ return ap_psprintf(r->pool, "%ld", (long)((tv.tv_sec - r->request_time)) * 1000000 + tv.tv_usec - r->request_time_usec);
+}
+
/* These next two routines use the canonical nameort so that log
* parsers don't need to duplicate all the vhost parsing crud.
*/
@@ -520,6 +529,9 @@
},
{
'T', log_request_duration, 1
+ },
+ {
+ 'D', log_request_duration_microseconds, 1
},
{
'r', log_request_line, 1