make LDAPConnectionPoolTTL more conservative, use r->request_time rather than

end-of-request time, and only update it after a round-trip with the LDAP
server rather than every time we check back into the pool.



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

CHANGES

@@ -1,6 +1,9 @@
                                                          -*- coding: utf-8 -*-
 Changes with Apache 2.5.0
 
+  *) mod_ldap: Be more conservative with the last-used time for
+     LDAPConnectionPoolTTL. PR54587 [Eric Covener]
+
   *) mod_deflate: Don't fail when flushing inflated data to the user-agent
      and that coincides with the end of stream ("Zlib error flushing inflate
      buffer"). PR 56196. [Christoph Fausak <christoph fausak glueckkanja.com>]

docs/manual/mod/mod_ldap.xml

@@ -757,10 +757,15 @@ connection client certificates.</description>
     connection pool.  The default value of -1, and any other negative value,
     allows connections of any age to be reused.</p>
 
-    <p>The timemout is based on when the LDAP connection is returned to the
+    <p>For performance reasons, the reference time used by this directive is 
-    pool, not based on the last time I/O has been performed over the backend
+    based on when the LDAP connection is returned to the pool, not the time
-    connection.  If the information is cached, the apparent idle time can exceed
+    of the last successful I/O with the LDAP server.  </p>
-    the <directive>LDAPConnectionPoolTTL</directive>. </p>
+
+    <p>Since 2.4.10, new measures are in place to avoid the reference time
+    from being inflated by cache hits or slow requests.  First, the reference
+    time is not updated if no backend LDAP conncetions were needed. Second,
+    the reference time uses the time the HTTP request was received instead
+    of the time the request is completed.</p>
     
     <note><p>This timeout defaults to units of seconds, but accepts
     suffixes for milliseconds (ms), minutes (min), and hours (h).

include/ap_mmn.h

@@ -463,6 +463,7 @@
                            ap_mpm_register_socket_callback_timeout.
  * 20140611.1 (2.5.0-dev)  Add ap_proxy_connect_uds().
  * 20140627.0 (2.5.0-dev)  Revert 20140611.0 change.
+ * 20140627.1 (2.5.0-dev)  add last_backend_conn to util_ldap_connection_t
  */
 
 #define MODULE_MAGIC_COOKIE 0x41503235UL /* "AP25" */
@@ -470,7 +471,7 @@
 #ifndef MODULE_MAGIC_NUMBER_MAJOR
 #define MODULE_MAGIC_NUMBER_MAJOR 20140627
 #endif
-#define MODULE_MAGIC_NUMBER_MINOR 0                  /* 0...n */
+#define MODULE_MAGIC_NUMBER_MINOR 1                 /* 0...n */
 
 /**
  * Determine if the server's current MODULE_MAGIC_NUMBER is at least a

include/util_ldap.h

@@ -135,6 +135,7 @@ typedef struct util_ldap_connection_t {
     apr_pool_t *rebind_pool;            /* frequently cleared pool for rebind data */
     int must_rebind;                    /* The connection was last bound with other then binddn/bindpw */
     request_rec *r;                     /* request_rec used to find this util_ldap_connection_t */
+    apr_time_t last_backend_conn;       /* the approximate time of the last backend LDAP requst */
 } util_ldap_connection_t;
 
 typedef struct util_ldap_config_t {

modules/ldap/util_ldap.c

@@ -524,6 +524,7 @@ static int uldap_simple_bind(util_ldap_connection_t *ldc, char *binddn,
         return uldap_ld_errno(ldc);
     }
     else { 
+        ldc->last_backend_conn = ldc->r->request_time;
         ap_log_rerror(APLOG_MARK, APLOG_TRACE5, 0, ldc->r, "LDC %pp bind", ldc);
     }
     return rc;
@@ -730,10 +731,10 @@ static util_ldap_connection_t *
             && !compare_client_certs(dc->client_certs, l->client_certs))
         {
             if (st->connection_pool_ttl > 0) {
-                if (l->bound && (now - l->freed) > st->connection_pool_ttl) {
+                if (l->bound && (now - l->last_backend_conn) > st->connection_pool_ttl) {
                     ap_log_rerror(APLOG_MARK, APLOG_TRACE1, 0, r,
                                   "Removing LDAP connection last used %" APR_TIME_T_FMT " seconds ago",
-                                  (now - l->freed) / APR_USEC_PER_SEC);
+                                  (now - l->last_backend_conn) / APR_USEC_PER_SEC);
                     l->r = r;
                     uldap_connection_unbind(l);
                     /* Go ahead (by falling through) and use it, so we don't create more just to unbind some other old ones */
@@ -768,10 +769,10 @@ static util_ldap_connection_t *
                 !compare_client_certs(dc->client_certs, l->client_certs))
             {
                 if (st->connection_pool_ttl > 0) {
-                    if (l->bound && (now - l->freed) > st->connection_pool_ttl) {
+                    if (l->bound && (now - l->last_backend_conn) > st->connection_pool_ttl) {
                         ap_log_rerror(APLOG_MARK, APLOG_TRACE1, 0, r,
                                 "Removing LDAP connection last used %" APR_TIME_T_FMT " seconds ago",
-                                (now - l->freed) / APR_USEC_PER_SEC);
+                                (now - l->last_backend_conn) / APR_USEC_PER_SEC);
                         l->r = r;
                         uldap_connection_unbind(l);
                         /* Go ahead (by falling through) and use it, so we don't create more just to unbind some other old ones */
@@ -995,6 +996,7 @@ start_over:
         return result;
     }
 
+    ldc->last_backend_conn = r->request_time;
     entry = ldap_first_entry(ldc->ldap, res);
     searchdn = ldap_get_dn(ldc->ldap, entry);
 
@@ -1146,6 +1148,7 @@ start_over:
         goto start_over;
     }
 
+    ldc->last_backend_conn = r->request_time;
     ldc->reason = "Comparison complete";
     if ((LDAP_COMPARE_TRUE == result) ||
         (LDAP_COMPARE_FALSE == result) ||
@@ -1271,6 +1274,7 @@ start_over:
         return res;
     }
 
+    ldc->last_backend_conn = r->request_time;
     entry = ldap_first_entry(ldc->ldap, sga_res);
 
     /*
@@ -1753,6 +1757,7 @@ start_over:
      * We should have found exactly one entry; to find a different
      * number is an error.
      */
+    ldc->last_backend_conn = r->request_time;
     count = ldap_count_entries(ldc->ldap, res);
     if (count != 1)
     {
@@ -2013,6 +2018,7 @@ start_over:
      * We should have found exactly one entry; to find a different
      * number is an error.
      */
+    ldc->last_backend_conn = r->request_time;
     count = ldap_count_entries(ldc->ldap, res);
     if (count != 1)
     {