Merge remote-tracking branch 'origin/mdb.RE/0.9'

[openldap] / servers / slapd / result.c

diff --git a/servers/slapd/result.c b/servers/slapd/result.c
index a54e32844b8a6e5d3f6006aac7681b03c7940d1e..d958b979533c3ade5beda1ce2929a6cdcf3b0385 100644 (file)
--- a/servers/slapd/result.c
+++ b/servers/slapd/result.c
@@ -37,6 +37,24 @@
 
 #include "slap.h"
 
+#if SLAP_STATS_ETIME
+#define ETIME_SETUP \
+       struct timeval now; \
+       (void) gettimeofday( &now, NULL ); \
+       now.tv_sec -= op->o_time; \
+       now.tv_usec -= op->o_tincr; \
+       if ( now.tv_usec < 0 ) { \
+               --now.tv_sec; now.tv_usec += 1000000; \
+       }
+#define ETIME_LOGFMT   "etime=%d.%06d "
+#define StatslogEtime(lvl,fmt,pfx,tag,err,etxt,xtra) \
+       Statslog7(lvl,fmt,pfx,tag,err,(int)now.tv_sec,(int)now.tv_usec,etxt,xtra)
+#else
+#define ETIME_SETUP
+#define ETIME_LOGFMT   ""
+#define StatslogEtime  Statslog
+#endif /* SLAP_STATS_ETIME */
+
 const struct berval slap_dummy_bv = BER_BVNULL;
 
 int slap_null_cb( Operation *op, SlapReply *rs )
@@ -819,8 +837,9 @@ send_ldap_disconnect( Operation     *op, SlapReply *rs )
        }
 
        if ( send_ldap_response( op, rs ) == SLAP_CB_CONTINUE ) {
-               Statslog( LDAP_DEBUG_STATS,
-                       "%s DISCONNECT tag=%lu err=%d text=%s\n",
+               ETIME_SETUP;
+               StatslogEtime( LDAP_DEBUG_STATS,
+                       "%s DISCONNECT tag=%lu err=%d "ETIME_LOGFMT"text=%s\n",
                        op->o_log_prefix, rs->sr_tag, rs->sr_err,
                        rs->sr_text ? rs->sr_text : "", 0 );
        }
@@ -884,14 +903,15 @@ abandon:
        }
 
        if ( send_ldap_response( op, rs ) == SLAP_CB_CONTINUE ) {
+               ETIME_SETUP;
                if ( op->o_tag == LDAP_REQ_SEARCH ) {
-                       Statslog( LDAP_DEBUG_STATS,
-                               "%s SEARCH RESULT tag=%lu err=%d nentries=%d text=%s\n",
+                       StatslogEtime( LDAP_DEBUG_STATS,
+                               "%s SEARCH RESULT tag=%lu err=%d "ETIME_LOGFMT"nentries=%d text=%s\n",
                                op->o_log_prefix, rs->sr_tag, rs->sr_err,
                                rs->sr_nentries, rs->sr_text ? rs->sr_text : "" );
                } else {
-                       Statslog( LDAP_DEBUG_STATS,
-                               "%s RESULT tag=%lu err=%d text=%s\n",
+                       StatslogEtime( LDAP_DEBUG_STATS,
+                               "%s RESULT tag=%lu err=%d "ETIME_LOGFMT"text=%s\n",
                                op->o_log_prefix, rs->sr_tag, rs->sr_err,
                                rs->sr_text ? rs->sr_text : "", 0 );
                }
@@ -917,8 +937,9 @@ send_ldap_sasl( Operation *op, SlapReply *rs )
        rs->sr_msgid = (rs->sr_tag != LBER_SEQUENCE) ? op->o_msgid : 0;
 
        if ( send_ldap_response( op, rs ) == SLAP_CB_CONTINUE ) {
-               Statslog( LDAP_DEBUG_STATS,
-                       "%s RESULT tag=%lu err=%d text=%s\n",
+               ETIME_SETUP;
+               StatslogEtime( LDAP_DEBUG_STATS,
+                       "%s RESULT tag=%lu err=%d "ETIME_LOGFMT"text=%s\n",
                        op->o_log_prefix, rs->sr_tag, rs->sr_err,
                        rs->sr_text ? rs->sr_text : "", 0 );
        }
@@ -941,8 +962,9 @@ slap_send_ldap_extended( Operation *op, SlapReply *rs )
        rs->sr_msgid = (rs->sr_tag != LBER_SEQUENCE) ? op->o_msgid : 0;
 
        if ( send_ldap_response( op, rs ) == SLAP_CB_CONTINUE ) {
-               Statslog( LDAP_DEBUG_STATS,
-                       "%s RESULT oid=%s err=%d text=%s\n",
+               ETIME_SETUP;
+               StatslogEtime( LDAP_DEBUG_STATS,
+                       "%s RESULT oid=%s err=%d "ETIME_LOGFMT"text=%s\n",
                        op->o_log_prefix, rs->sr_rspoid ? rs->sr_rspoid : "",
                        rs->sr_err, rs->sr_text ? rs->sr_text : "", 0 );
        }