httpd-cvs mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From rj...@apache.org
Subject svn commit: r1681269 - in /httpd/httpd/branches/2.2.x: CHANGES STATUS modules/loggers/mod_log_config.c
Date Sat, 23 May 2015 06:38:14 GMT
Author: rjung
Date: Sat May 23 06:38:13 2015
New Revision: 1681269

URL: http://svn.apache.org/r1681269
Log:
mod_log_config: Backport get_request_end_time().
This makes data consistent if a log format uses
multiple %{...}T and/or %D.
The end time of a request is only taken once and
the same time is used for each log field.

Backport of r979120 (partial) plus r1467765 from trunk
resp. r979120 (partial) plus r1467981 from 2.4.x.

Committed By: rjung
Reviewed By: rjung, trawick, wrowe
Backported By: rjung

Modified:
    httpd/httpd/branches/2.2.x/CHANGES
    httpd/httpd/branches/2.2.x/STATUS
    httpd/httpd/branches/2.2.x/modules/loggers/mod_log_config.c

Modified: httpd/httpd/branches/2.2.x/CHANGES
URL: http://svn.apache.org/viewvc/httpd/httpd/branches/2.2.x/CHANGES?rev=1681269&r1=1681268&r2=1681269&view=diff
==============================================================================
--- httpd/httpd/branches/2.2.x/CHANGES [utf-8] (original)
+++ httpd/httpd/branches/2.2.x/CHANGES [utf-8] Sat May 23 06:38:13 2015
@@ -4,6 +4,10 @@ Changes with Apache 2.2.30
   *) mpm_winnt: Accept utf-8 (Unicode) service names and descriptions for
      internationalization.  [William Rowe]
 
+  *) mod_log_config: Ensure that time data is consistent if multiple
+     duration patterns are used in combination, e.g. %D and %{ms}T.
+     [Rainer Jung]
+
   *) mod_log_config: Add "%{UNIT}T" format to output request duration in
      seconds, milliseconds or microseconds depending on UNIT ("s", "ms", "us").
      [Ben Reser, Rainer Jung]

Modified: httpd/httpd/branches/2.2.x/STATUS
URL: http://svn.apache.org/viewvc/httpd/httpd/branches/2.2.x/STATUS?rev=1681269&r1=1681268&r2=1681269&view=diff
==============================================================================
--- httpd/httpd/branches/2.2.x/STATUS (original)
+++ httpd/httpd/branches/2.2.x/STATUS Sat May 23 06:38:13 2015
@@ -101,18 +101,6 @@ RELEASE SHOWSTOPPERS:
 PATCHES ACCEPTED TO BACKPORT FROM TRUNK:
   [ start all new proposals below, under PATCHES PROPOSED. ]
 
-   * mod_log_config: Backport get_request_end_time().
-     This makes data consistent if a log format uses multiple %{...}T
-     and/or %D. The end time of a request is only taken once and the
-     same time is used for each log field.
-     trunk patch: http://svn.apache.org/r979120 (partial)
-                  http://svn.apache.org/r1467765
-     2.4.x patch: http://svn.apache.org/r979120 (partial)
-                  http://svn.apache.org/r1467981
-     2.2.x patch: http://people.apache.org/~rjung/patches/httpd-2.2.x-mod_log_config-get_request_end_time.patch
-     +1: rjung, trawick, wrowe
-
-
 PATCHES PROPOSED TO BACKPORT FROM TRUNK:
   [ New proposals should be added at the end of the list ]
 
@@ -128,7 +116,7 @@ PATCHES PROPOSED TO BACKPORT FROM TRUNK:
      as time stamp in log (httpd traditionally uses start, many
      other components, e.g. Tomcat use end time, so they are kind
      of hard to correlate). Also add more format choices for time stamps.
-     Assumes backport of get_request_end_time() above.
+     Needed get_request_end_time() was already ported back.
      trunk patch: http://svn.apache.org/r979120 (remaining parts)
      2.4.x patch: http://svn.apache.org/r979120 (remaining parts)
      2.2.x patch: http://people.apache.org/~rjung/patches/httpd-2.2.x-mod_log_config-more_time_formats.patch

Modified: httpd/httpd/branches/2.2.x/modules/loggers/mod_log_config.c
URL: http://svn.apache.org/viewvc/httpd/httpd/branches/2.2.x/modules/loggers/mod_log_config.c?rev=1681269&r1=1681268&r2=1681269&view=diff
==============================================================================
--- httpd/httpd/branches/2.2.x/modules/loggers/mod_log_config.c (original)
+++ httpd/httpd/branches/2.2.x/modules/loggers/mod_log_config.c Sat May 23 06:38:13 2015
@@ -269,6 +269,14 @@ typedef struct {
 } config_log_state;
 
 /*
+ * log_request_state holds request specific log data that is not
+ * part of the request_rec.
+ */
+typedef struct {
+    apr_time_t request_end_time;
+} log_request_state;
+
+/*
  * Format items...
  * Note that many of these could have ap_sprintfs replaced with static buffers.
  */
@@ -591,6 +599,21 @@ typedef struct {
 #define TIME_CACHE_MASK 3
 static cached_request_time request_time_cache[TIME_CACHE_SIZE];
 
+static apr_time_t get_request_end_time(request_rec *r)
+{
+    log_request_state *state = (log_request_state *)ap_get_module_config(r->request_config,
+                                                                         &log_config_module);
+    if (!state) {
+        state = apr_pcalloc(r->pool, sizeof(log_request_state));
+        ap_set_module_config(r->request_config, &log_config_module, state);
+    }
+    if (state->request_end_time == 0) {
+        state->request_end_time = apr_time_now();
+    }
+    return state->request_end_time;
+}
+
+
 static const char *log_request_time(request_rec *r, char *a)
 {
     apr_time_exp_t xt;
@@ -613,7 +636,7 @@ static const char *log_request_time(requ
          * log_request_time_custom is not inlined right here.)
          */
 #ifdef I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE
-        ap_explode_recent_localtime(&xt, apr_time_now());
+        ap_explode_recent_localtime(&xt, get_request_end_time(r));
 #else
         ap_explode_recent_localtime(&xt, r->request_time);
 #endif
@@ -627,7 +650,7 @@ static const char *log_request_time(requ
         cached_request_time* cached_time = apr_palloc(r->pool,
                                                       sizeof(*cached_time));
 #ifdef I_INSIST_ON_EXTRA_CYCLES_FOR_CLF_COMPLIANCE
-        apr_time_t request_time = apr_time_now();
+        apr_time_t request_time = get_request_end_time(r);
 #else
         apr_time_t request_time = r->request_time;
 #endif
@@ -668,12 +691,12 @@ static const char *log_request_time(requ
 static const char *log_request_duration_microseconds(request_rec *r, char *a)
 {
     return apr_psprintf(r->pool, "%" APR_TIME_T_FMT,
-                        (apr_time_now() - r->request_time));
+                        (get_request_end_time(r) - r->request_time));
 }
 
 static const char *log_request_duration_scaled(request_rec *r, char *a)
 {
-    apr_time_t duration = apr_time_now() - r->request_time;
+    apr_time_t duration = get_request_end_time(r) - r->request_time;
     if (*a == '\0' || !strcasecmp(a, "s")) {
         duration = apr_time_sec(duration);
     }
@@ -1075,6 +1098,12 @@ static int multi_log_transaction(request
     int i;
 
     /*
+     * Initialize per request state
+     */
+    log_request_state *state = apr_pcalloc(r->pool, sizeof(log_request_state));
+    ap_set_module_config(r->request_config, &log_config_module, state);
+
+    /*
      * Log this transaction..
      */
     if (mls->config_logs->nelts) {



Mime
View raw message