Use the "recent time" cache to optimize timestamp generation for

the httpd error log

Background: According to some profile data that we collected on Solaris,
half the run time of ap_log_rerror() was spent in localtime(3).   With
this change, the recent-time cache ensures that the error logger won't
cause more than one localtime() call per second, no matter how high the
error rate is.

git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@93977 13f79535-47bb-0310-9956-ffa450edef68

diff --git a/CHANGES b/CHANGES
index 195fe4c11d0cba9809d6c87978ffe3cb73cdb59e..62b777ed29e7eaf7391f847548165c72400b1163 100644 (file)
--- a/CHANGES
+++ b/CHANGES
@@ -1,5 +1,7 @@
 Changes with Apache 2.0.34-dev
 
+  *) Performance improvement for the error logger [Brian Pane]
+
   *) Change configure so that Solaris 8 and above have 
      SINGLE_LISTEN_UNSERIALIZED_ACCEPT defined by default.
      according to sun people solaris 8+ doesn't have a thundering

diff --git a/include/util_time.h b/include/util_time.h
index d595170716c296ed5954e096dcf45dd4a78748bd..1852f89fe5fd506cf41b0dbd4667d696766cf45b 100644 (file)
--- a/include/util_time.h
+++ b/include/util_time.h
@@ -102,6 +102,13 @@ AP_DECLARE(apr_status_t) ap_explode_recent_gmt(apr_time_exp_t *tm,
                                                apr_time_t t);
 
 
+/**
+ * format a recent timestamp in the ctime() format.
+ * @param date_str String to write to.
+ * @param t the time to convert 
+ */
+AP_DECLARE(apr_status_t) ap_recent_ctime(char *date_str, apr_time_t t);
+
 #ifdef __cplusplus
 }
 #endif

diff --git a/server/log.c b/server/log.c
index 5198f7003ea0f0bb2c994f3e9fe89083a736dcef..2e9488c7cd19aebcef0d9f2ab2ad0a1b4d6ff240 100644 (file)
--- a/server/log.c
+++ b/server/log.c
@@ -409,7 +409,7 @@ static void log_error_core(const char *file, int line, int level,
 
     if (logf && ((level & APLOG_STARTUP) != APLOG_STARTUP)) {
         errstr[0] = '[';
-        apr_ctime(errstr + 1, apr_time_now());
+        ap_recent_ctime(errstr + 1, apr_time_now());
         errstr[1 + APR_CTIME_LEN - 1] = ']';
         errstr[1 + APR_CTIME_LEN    ] = ' ';
         len = 1 + APR_CTIME_LEN + 1;

diff --git a/server/util_time.c b/server/util_time.c
index 1b2988d1638dca56c93f6c56e9f971b8baf1aae2..5b33e3ff4e9af1299911bd0776ba1350cbf1405c 100644 (file)
--- a/server/util_time.c
+++ b/server/util_time.c
@@ -173,3 +173,48 @@ AP_DECLARE(apr_status_t) ap_explode_recent_gmt(apr_time_exp_t * tm,
 {
     return cached_explode(tm, t, exploded_cache_gmt, 1);
 }
+
+AP_DECLARE(apr_status_t) ap_recent_ctime(char *date_str, apr_time_t t)
+{
+    /* ### This code is a clone of apr_ctime(), except that it
+     * uses ap_explode_recent_localtime() instead of apr_explode_localtime().
+     */
+    apr_time_exp_t xt;
+    const char *s;
+    int real_year;
+
+    /* example: "Wed Jun 30 21:49:08 1993" */
+    /*           123456789012345678901234  */
+
+    ap_explode_recent_localtime(&xt, t);
+    s = &apr_day_snames[xt.tm_wday][0];
+    *date_str++ = *s++;
+    *date_str++ = *s++;
+    *date_str++ = *s++;
+    *date_str++ = ' ';
+    s = &apr_month_snames[xt.tm_mon][0];
+    *date_str++ = *s++;
+    *date_str++ = *s++;
+    *date_str++ = *s++;
+    *date_str++ = ' ';
+    *date_str++ = xt.tm_mday / 10 + '0';
+    *date_str++ = xt.tm_mday % 10 + '0';
+    *date_str++ = ' ';
+    *date_str++ = xt.tm_hour / 10 + '0';
+    *date_str++ = xt.tm_hour % 10 + '0';
+    *date_str++ = ':';
+    *date_str++ = xt.tm_min / 10 + '0';
+    *date_str++ = xt.tm_min % 10 + '0';
+    *date_str++ = ':';
+    *date_str++ = xt.tm_sec / 10 + '0';
+    *date_str++ = xt.tm_sec % 10 + '0';
+    *date_str++ = ' ';
+    real_year = 1900 + xt.tm_year;
+    *date_str++ = real_year / 1000 + '0';
+    *date_str++ = real_year % 1000 / 100 + '0';
+    *date_str++ = real_year % 100 / 10 + '0';
+    *date_str++ = real_year % 10 + '0';
+    *date_str++ = 0;
+
+    return APR_SUCCESS;
+}