From ec451c415f6d4f2073d39e5923fdc93df9cb2dd0 Mon Sep 17 00:00:00 2001 From: William Brown Date: Fri, 5 Feb 2016 15:21:37 +1000 Subject: [PATCH] Ticket 47982 - improve timestamp resolution in logs Bug Description: An rfe was proposed to increase the resolution of timestamps in logs to allow better automated machine sorting and time analysis of events. Fix Description: This patch enables a configuration option nsslapd-logging-hr-timestamps-enabled, default to on that provides nanosecond accurate timestamps in logs. This is only avaliable on platforms that support clock_gettime. Additionally, this patch removes the str buffer as it actually slowed down logging performance. https://fedorahosted.org/389/ticket/47982 Author: wibrown Review by: ??? --- config.h.in | 3 + configure | 2 +- configure.ac | 2 +- ldap/schema/01core389.ldif | 1 + ldap/servers/slapd/libglobs.c | 30 +++++++ ldap/servers/slapd/log.c | 143 +++++++++++++++-------------- ldap/servers/slapd/proto-slap.h | 11 +++ ldap/servers/slapd/slap.h | 7 ++ ldap/servers/slapd/time.c | 194 ++++++++++++++++++++++++++++++++++++++++ 9 files changed, 318 insertions(+), 75 deletions(-) diff --git a/config.h.in b/config.h.in index 041a18f..ea9369b 100644 --- a/config.h.in +++ b/config.h.in @@ -78,6 +78,9 @@ /* Define to 1 if your system has a working `chown' function. */ #undef HAVE_CHOWN +/* Define to 1 if you have the `clock_gettime' function. */ +#undef HAVE_CLOCK_GETTIME + /* Define to 1 if you have the declaration of `strerror_r', and to 0 if you don't. */ #undef HAVE_DECL_STRERROR_R diff --git a/configure b/configure index 2a88f1a..641e9d1 100755 --- a/configure +++ b/configure @@ -17676,7 +17676,7 @@ fi done -for ac_func in setrlimit endpwent ftruncate getcwd gethostbyname inet_ntoa localtime_r memmove memset mkdir munmap putenv rmdir socket strcasecmp strchr strcspn strdup strerror strncasecmp strpbrk strrchr strstr strtol tzset +for ac_func in clock_gettime endpwent ftruncate getcwd gethostbyname inet_ntoa localtime_r memmove memset mkdir munmap putenv rmdir setrlimit socket strcasecmp strchr strcspn strdup strerror strncasecmp strpbrk strrchr strstr strtol tzset do : as_ac_var=`$as_echo "ac_cv_func_$ac_func" | $as_tr_sh` ac_fn_c_check_func "$LINENO" "$ac_func" "$as_ac_var" diff --git a/configure.ac b/configure.ac index 7f93b6a..d8376fc 100644 --- a/configure.ac +++ b/configure.ac @@ -63,7 +63,7 @@ AC_FUNC_STAT AC_FUNC_STRERROR_R AC_FUNC_STRFTIME AC_FUNC_VPRINTF -AC_CHECK_FUNCS([setrlimit endpwent ftruncate getcwd gethostbyname inet_ntoa localtime_r memmove memset mkdir munmap putenv rmdir socket strcasecmp strchr strcspn strdup strerror strncasecmp strpbrk strrchr strstr strtol tzset]) +AC_CHECK_FUNCS([clock_gettime endpwent ftruncate getcwd gethostbyname inet_ntoa localtime_r memmove memset mkdir munmap putenv rmdir setrlimit socket strcasecmp strchr strcspn strdup strerror strncasecmp strpbrk strrchr strstr strtol tzset]) AC_MSG_CHECKING(for --enable-debug) AC_ARG_ENABLE(debug, AS_HELP_STRING([--enable-debug], [Enable debug features (default: no)]), diff --git a/ldap/schema/01core389.ldif b/ldap/schema/01core389.ldif index 0b14c06..5628e99 100644 --- a/ldap/schema/01core389.ldif +++ b/ldap/schema/01core389.ldif @@ -292,6 +292,7 @@ attributeTypes: ( 2.16.840.1.113730.3.1.2326 NAME 'nsslapd-auditfaillog-logging- attributeTypes: ( 2.16.840.1.113730.3.1.2327 NAME 'nsslapd-auditfaillog' DESC 'Netscape defined attribute type' SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 SINGLE-VALUE X-ORIGIN 'Netscape Directory Server' ) attributeTypes: ( 2.16.840.1.113730.3.1.2328 NAME 'nsslapd-auditfaillog-list' DESC 'Netscape defined attribute type' SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 X-ORIGIN 'Netscape Directory Server' ) attributeTypes: ( 2.16.840.1.113730.3.1.2330 NAME 'nsslapd-logging-backend' DESC 'Netscape defined attribute type' SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 X-ORIGIN 'Netscape Directory Server' ) +attributeTypes: ( 2.16.840.1.113730.3.1.2331 NAME 'nsslapd-logging-hr-timestamps-enabled' DESC 'Netscape defined attribute type' SYNTAX 1.3.6.1.4.1.1466.115.121.1.15 X-ORIGIN 'Netscape Directory Server' ) # # objectclasses # diff --git a/ldap/servers/slapd/libglobs.c b/ldap/servers/slapd/libglobs.c index 51fd2b4..33f2f92 100644 --- a/ldap/servers/slapd/libglobs.c +++ b/ldap/servers/slapd/libglobs.c @@ -183,6 +183,7 @@ slapi_onoff_t init_auditlog_logging_enabled; slapi_onoff_t init_auditlog_logging_hide_unhashed_pw; slapi_onoff_t init_auditfaillog_logging_enabled; slapi_onoff_t init_auditfaillog_logging_hide_unhashed_pw; +slapi_onoff_t init_logging_hr_timestamps; slapi_onoff_t init_csnlogging; slapi_onoff_t init_pw_unlock; slapi_onoff_t init_pw_must_change; @@ -1190,6 +1191,12 @@ static struct config_get_and_set { CONFIG_STRING_OR_EMPTY, NULL, NULL/* deletion is not allowed */}, /* End audit fail log configuration */ /* warning: initialization makes pointer from integer without a cast [enabled by default]. Why do we get this? */ +#ifdef HAVE_CLOCK_GETTIME + {CONFIG_LOGGING_HR_TIMESTAMPS, config_set_logging_hr_timestamps, + NULL, 0, + (void**)&global_slapdFrontendConfig.logging_hr_timestamps, + CONFIG_ON_OFF, NULL, &init_logging_hr_timestamps}, +#endif {CONFIG_LOGGING_BACKEND, NULL, log_set_backend, 0, (void**)&global_slapdFrontendConfig.logging_backend, @@ -1619,6 +1626,11 @@ FrontendConfig_init () { init_auditfaillog_logging_hide_unhashed_pw = cfg->auditfaillog_logging_hide_unhashed_pw = LDAP_ON; +#ifdef HAVE_CLOCK_GETTIME + init_logging_hr_timestamps = + cfg->logging_hr_timestamps = LDAP_ON; +#endif + init_entryusn_global = cfg->entryusn_global = LDAP_OFF; cfg->entryusn_import_init = slapi_ch_strdup(ENTRYUSN_IMPORT_INIT); cfg->allowed_to_delete_attrs = slapi_ch_strdup("passwordadmindn nsslapd-listenhost nsslapd-securelistenhost nsslapd-defaultnamingcontext"); @@ -1765,6 +1777,24 @@ config_set_auditfaillog_unhashed_pw(const char *attrname, char *value, char *err return retVal; } +#ifdef HAVE_CLOCK_GETTIME +int +config_set_logging_hr_timestamps(const char *attrname, char *value, char *errorbuf, int apply) +{ + slapdFrontendConfig_t *slapdFrontendConfig = getFrontendConfig(); + int retVal = LDAP_SUCCESS; + + retVal = config_set_onoff ( attrname, value, &(slapdFrontendConfig->logging_hr_timestamps), + errorbuf, apply); + if(strcasecmp(value,"on") == 0){ + log_enable_hr_timestamps(); + } else { + log_disable_hr_timestamps(); + } + return retVal; +} +#endif + /* * Utility function called by many of the config_set_XXX() functions. * Returns a non-zero value if 'value' is NULL and zero if not. diff --git a/ldap/servers/slapd/log.c b/ldap/servers/slapd/log.c index 07bc762..fceb6b1 100644 --- a/ldap/servers/slapd/log.c +++ b/ldap/servers/slapd/log.c @@ -36,9 +36,7 @@ PRUintn logbuf_tsdindex; struct logbufinfo *logbuf_accum; static struct logging_opts loginfo; static int detached=0; - -/* used to lock the timestamp info used by vslapd_log_access */ -static PRLock *ts_time_lock = NULL; +static int logging_hr_timestamps_enabled = 1; /* * Note: the order of the values in the slapi_log_map array must exactly @@ -188,9 +186,8 @@ void g_log_init(int log_enabled) { slapdFrontendConfig_t *slapdFrontendConfig = getFrontendConfig(); - ts_time_lock = PR_NewLock(); - if (! ts_time_lock) - exit(-1); + /* There might be a better place to put this function in the future. */ + time_create_cache_lock(); /* ACCESS LOG */ loginfo.log_access_state = 0; @@ -1814,6 +1811,24 @@ log_set_expirationtimeunit(const char *attrname, char *expunit, int logtype, cha return rv; } +/* + * Enables HR timestamps in logs. + */ +void +log_enable_hr_timestamps() +{ + logging_hr_timestamps_enabled = 1; +} + +/* + * Disables HR timestamps in logs. + */ +void +log_disable_hr_timestamps() +{ + logging_hr_timestamps_enabled = 0; +} + /****************************************************************************** * Write title line in log file *****************************************************************************/ @@ -2219,37 +2234,34 @@ vslapd_log_error( va_list ap, int locked ) { - time_t tnl; - long tz; - struct tm *tmsp, tms; - char tbuf[ TBUFSIZE ]; - char sign; char buffer[SLAPI_LOG_BUFSIZ]; int blen; char *vbuf; int header_len = 0; int err = 0; - tnl = current_time(); - (void)localtime_r( &tnl, &tms ); - tmsp = &tms; -#ifdef BSD_TIME - tz = tmsp->tm_gmtoff; -#else /* BSD_TIME */ - tz = - timezone; - if ( tmsp->tm_isdst ) { - tz += 3600; - } -#endif /* BSD_TIME */ - sign = ( tz >= 0 ? '+' : '-' ); - if ( tz < 0 ) { - tz = -tz; + +#ifdef HAVE_CLOCK_GETTIME + if (logging_hr_timestamps_enabled == 1) { + struct timespec *tsnow = malloc(sizeof(struct timespec)); + if (clock_gettime(CLOCK_REALTIME, tsnow) != 0) { + /* Make an error */ + } + /* We would probably check the HR timer boolean here */ + if (format_localTime_hr_log(tsnow->tv_sec, tsnow->tv_nsec, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { + /* Make error - But's it's not like we had any handling before */ + } + free(tsnow); + } else { +#endif + time_t tnl; + tnl = current_time(); + if (format_localTime_log(tnl, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { + /* Make error - But's it's not like we had any handling before */ + } +#ifdef HAVE_CLOCK_GETTIME } - (void)strftime( tbuf, (size_t)TBUFSIZE, "%d/%b/%Y:%H:%M:%S", tmsp); - sprintf( buffer, "[%s %c%02d%02d]%s%s - ", tbuf, sign, - (int)( tz / 3600 ), (int)( tz % 3600 ), - subsystem ? " " : "", - subsystem ? subsystem : ""); +#endif /* Bug 561525: to be able to remove timestamp to not over pollute syslog, we may need to skip the timestamp part of the message. @@ -2263,12 +2275,13 @@ vslapd_log_error( + size of ] */ - header_len = strlen(tbuf) + 8; + /* Due to the change to use format_localTime_log, this is now blen */ + header_len = blen; if ((vbuf = PR_vsmprintf(fmt, ap)) == NULL) { return -1; } - blen = strlen(buffer); + /* blen = strlen(buffer); */ PR_snprintf (buffer+blen, sizeof(buffer)-blen, "%s", vbuf); buffer[sizeof(buffer)-1] = '\0'; @@ -2389,54 +2402,38 @@ slapi_is_loglevel_set ( const int loglevel ) ******************************************************************************/ static int vslapd_log_access(char *fmt, va_list ap) { - time_t tnl; - long tz; - struct tm *tmsp, tms; - char tbuf[ TBUFSIZE ]; - char sign; char buffer[SLAPI_LOG_BUFSIZ]; char vbuf[SLAPI_LOG_BUFSIZ]; int blen; int vlen; - /* info needed to keep us from calling localtime/strftime so often: */ - static time_t old_time = 0; - static char old_tbuf[SLAPI_LOG_BUFSIZ]; - static int old_blen = 0; - - tnl = current_time(); - - /* check if we can use the old strftime buffer */ - PR_Lock(ts_time_lock); - if (tnl == old_time) { - strcpy(buffer, old_tbuf); - blen = old_blen; - PR_Unlock(ts_time_lock); + time_t tnl; + +#ifdef HAVE_CLOCK_GETTIME + if (logging_hr_timestamps_enabled == 1) { + struct timespec *tsnow = malloc(sizeof(struct timespec)); + tnl = tsnow->tv_sec; + if (clock_gettime(CLOCK_REALTIME, tsnow) != 0) { + /* Make an error */ + } + /* We would probably check the HR timer boolean here */ + /* We need to make a version of localTime_hr, that caches the strftime */ + /* if (format_localTime_hr_cached_log(tsnow->tv_sec, tsnow->tv_nsec, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { */ + if (format_localTime_hr_log(tsnow->tv_sec, tsnow->tv_nsec, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { + /* Make error - But's it's not like we had any handling before */ + } + free(tsnow); } else { - /* nope... painstakingly create the new strftime buffer */ - (void)localtime_r( &tnl, &tms ); - tmsp = &tms; - -#ifdef BSD_TIME - tz = tmsp->tm_gmtoff; -#else /* BSD_TIME */ - tz = - timezone; - if ( tmsp->tm_isdst ) { - tz += 3600; - } -#endif /* BSD_TIME */ - sign = ( tz >= 0 ? '+' : '-' ); - if ( tz < 0 ) { - tz = -tz; +#endif + tnl = current_time(); + /* This function takes care of the strbuf re-use for us! Magic! */ + /* if (format_localTime_cached_log(tnl, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { */ + if (format_localTime_log(tnl, SLAPI_LOG_BUFSIZ, buffer, &blen) != 0) { + /* Make error - But's it's not like we had any handling before */ } - (void)strftime( tbuf, (size_t)TBUFSIZE, "%d/%b/%Y:%H:%M:%S", tmsp); - sprintf( buffer, "[%s %c%02d%02d] ", tbuf, sign, - (int)( tz / 3600 ), (int)( tz % 3600)); - old_time = tnl; - strcpy(old_tbuf, buffer); - blen = strlen(buffer); - old_blen = blen; - PR_Unlock(ts_time_lock); +#ifdef HAVE_CLOCK_GETTIME } +#endif + vlen = PR_vsnprintf(vbuf, SLAPI_LOG_BUFSIZ, fmt, ap); if (! vlen) { diff --git a/ldap/servers/slapd/proto-slap.h b/ldap/servers/slapd/proto-slap.h index 8a0bdd3..aee5198 100644 --- a/ldap/servers/slapd/proto-slap.h +++ b/ldap/servers/slapd/proto-slap.h @@ -401,6 +401,12 @@ int config_set_maxsimplepaged_per_conn( const char *attrname, char *value, char int log_set_backend(const char *attrname, char *value, int logtype, char *errorbuf, int apply); +#ifdef HAVE_CLOCK_GETTIME +int config_set_logging_hr_timestamps(const char *attrname, char *value, char *errorbuf, int apply); +void log_enable_hr_timestamps(); +void log_disable_hr_timestamps(); +#endif + int config_get_SSLclientAuth(); int config_get_ssl_check_hostname(); char *config_get_SSL3ciphers(); @@ -1146,11 +1152,16 @@ struct slapi_filter *str2simple(); /* * time.c */ +void time_create_cache_lock(); char *get_timestring(time_t *t); void free_timestring(char *timestr); time_t current_time(); time_t poll_current_time(); char* format_localTime (time_t from); +int format_localTime_log(time_t t, int initsize, char *buf, int *bufsize); +int format_localTime_hr_log(time_t t, long nsec, int initsize, char *buf, int *bufsize); +int format_localTime_cached_log(time_t t, int initsize, char *buf, int *bufsize); +int format_localTime_hr_cached_log(time_t t, long nsec, int initsize, char *buf, int *bufsize); time_t parse_localTime (char* from); #ifndef HAVE_TIME_R diff --git a/ldap/servers/slapd/slap.h b/ldap/servers/slapd/slap.h index 5bb9252..4d392b0 100644 --- a/ldap/servers/slapd/slap.h +++ b/ldap/servers/slapd/slap.h @@ -2124,6 +2124,10 @@ typedef struct _slapdEntryPoints { #define CONFIG_MAXSIMPLEPAGED_PER_CONN_ATTRIBUTE "nsslapd-maxsimplepaged-per-conn" #define CONFIG_LOGGING_BACKEND "nsslapd-logging-backend" +#ifdef HAVE_CLOCK_GETTIME +#define CONFIG_LOGGING_HR_TIMESTAMPS "nsslapd-logging-hr-timestamps-enabled" +#endif + /* getenv alternative */ #define CONFIG_MALLOC_MXFAST "nsslapd-malloc-mxfast" #define CONFIG_MALLOC_TRIM_THRESHOLD "nsslapd-malloc-trim-threshold" @@ -2319,6 +2323,9 @@ typedef struct _slapdFrontendConfig { slapi_onoff_t auditfaillog_logging_hide_unhashed_pw; char *logging_backend; +#ifdef HAVE_CLOCK_GETTIME + slapi_onoff_t logging_hr_timestamps; +#endif slapi_onoff_t return_exact_case; /* Return attribute names with the same case as they appear in at.conf */ diff --git a/ldap/servers/slapd/time.c b/ldap/servers/slapd/time.c index 15d8fcf..4387fb4 100644 --- a/ldap/servers/slapd/time.c +++ b/ldap/servers/slapd/time.c @@ -23,6 +23,18 @@ unsigned long strntoul( char *from, size_t len, int base ); #define mktime_r(from) mktime (from) /* possible bug: is this thread-safe? */ +/* Warning! We should share these in a .h, but I'm not sure which ... */ + +#define TBUFSIZE 50 /* size for time buffers */ +#define SLAPI_LOG_BUFSIZ 2048 /* size for data buffers */ +#define NSEC_TOLERANCE 800000000 + +/* used to lock the timestamp info used by vslapd_log_access */ +static PRLock *ts_time_lock = NULL; +#ifdef HAVE_CLOCK_GETTIME +static PRLock *ts_time_hr_lock = NULL; +#endif + static time_t currenttime; static int currenttime_set = 0; /* XXX currenttime and currenttime_set are used by multiple threads, @@ -36,6 +48,22 @@ static int currenttime_set = 0; * assignment to it non-atomic. */ +void +time_create_cache_lock() +{ + /* These functions should make more noise to the CLI ... */ + ts_time_lock = PR_NewLock(); + if (! ts_time_lock) { + exit(-1); + } +#ifdef HAVE_CLOCK_GETTIME + ts_time_hr_lock = PR_NewLock(); + if (! ts_time_hr_lock) { + exit(-1); + } +#endif +} + #ifndef HAVE_TIME_R PRLock *time_func_mutex; @@ -166,6 +194,172 @@ time_plus_sec (time_t l, long r) return mktime_r (&t); } + +/* + * format_localTime_log will take a time value, and prepare it for + * log printing. + * + * \param time_t t - the time to convert + * \param int initsize - the initial buffer size + * \param char *buf - The destitation string + * \param int *bufsize - The size of the resulting buffer + * + * \return int success - 0 on correct format, >= 1 on error. + */ +int +format_localTime_log(time_t t, int initsize, char *buf, int *bufsize) +{ + + long tz; + struct tm *tmsp, tms; + char tbuf[ TBUFSIZE ]; + char sign; + /* nope... painstakingly create the new strftime buffer */ + (void)localtime_r( &t, &tms ); + tmsp = &tms; + +#ifdef BSD_TIME + tz = tmsp->tm_gmtoff; +#else /* BSD_TIME */ + tz = - timezone; + if ( tmsp->tm_isdst ) { + tz += 3600; + } +#endif /* BSD_TIME */ + sign = ( tz >= 0 ? '+' : '-' ); + if ( tz < 0 ) { + tz = -tz; + } + (void)strftime( tbuf, (size_t)TBUFSIZE, "%d/%b/%Y:%H:%M:%S", tmsp); + sprintf( buf, "[%s %c%02d%02d] ", tbuf, sign, + (int)( tz / 3600 ), (int)( tz % 3600)); + *bufsize = strlen(buf); + return 0; +} + +#ifdef HAVE_CLOCK_GETTIME +/* + * format_localTime_hr_log will take a time value, and prepare it for + * log printing. + * + * \param time_t t - the time to convert + * \param long nsec - the nanoseconds elapsed in the current second. + * \param int initsize - the initial buffer size + * \param char *buf - The destitation string + * \param int *bufsize - The size of the resulting buffer + * + * \return int success - 0 on correct format, >= 1 on error. + */ +int +format_localTime_hr_log(time_t t, long nsec, int initsize, char *buf, int *bufsize) +{ + + long tz; + struct tm *tmsp, tms; + char tbuf[ TBUFSIZE ]; + char sign; + /* nope... painstakingly create the new strftime buffer */ + (void)localtime_r( &t, &tms ); + tmsp = &tms; + +#ifdef BSD_TIME + tz = tmsp->tm_gmtoff; +#else /* BSD_TIME */ + tz = - timezone; + if ( tmsp->tm_isdst ) { + tz += 3600; + } +#endif /* BSD_TIME */ + sign = ( tz >= 0 ? '+' : '-' ); + if ( tz < 0 ) { + tz = -tz; + } + (void)strftime( tbuf, (size_t)TBUFSIZE, "%d/%b/%Y:%H:%M:%S", tmsp); + sprintf( buf, "[%s.%09ld %c%02d%02d] ", tbuf, nsec, sign, + (int)( tz / 3600 ), (int)( tz % 3600)); + *bufsize = strlen(buf); + return 0; +} +#endif /* HAVE_CLOCK_GETTIME */ + +/* + * format_localTime_cached_log will take a time value, and prepare it for + * log printing. If the time is within 1 second, we will return a cached + * version of the timestamp. + * + * \param time_t t - the time to convert + * \param int initsize - the initial buffer size + * \param char *buf - The destitation string + * \param int *bufsize - The size of the resulting buffer + * + * \return int success - 0 on correct format, >= 1 on error. + */ +int format_localTime_cached_log(time_t t, int initsize, char *buf, int *bufsize) +{ + static time_t old_time = 0; + static char old_tbuf[SLAPI_LOG_BUFSIZ]; + static int old_bufsize = 0; + int res = 0; + /* check if we can use the old strftime buffer */ + PR_Lock(ts_time_lock); + if (t == old_time) { + strcpy(buf, old_tbuf); + *bufsize = old_bufsize; + } else { + res = format_localTime_log(t, initsize, buf, bufsize); + old_time = t; + strcpy(old_tbuf, buf); + old_bufsize = *bufsize; + } + PR_Unlock(ts_time_lock); + return res; +} + +#ifdef HAVE_CLOCK_GETTIME +/* + * format_localTime_hr_cached_log will take a time value, and prepare it for + * log printing. If the time is within 1 second, we will return a cached + * version of the timestamp. + * + * \param time_t t - the time to convert + * \param long nsec - the nanoseconds elapsed in the current second. + * \param int initsize - the initial buffer size + * \param char *buf - The destitation string + * \param int *bufsize - The size of the resulting buffer + * + * \return int success - 0 on correct format, >= 1 on error. + */ +int format_localTime_hr_cached_log(time_t t, long nsec, int initsize, char *buf, int *bufsize) +{ + static time_t old_hr_time = 0; + static long old_hr_nsec = 0; + static char old_hr_tbuf[SLAPI_LOG_BUFSIZ]; + static int old_hr_bufsize = 0; + int res = 0; + /* check if we can use the old strftime buffer */ + /* This lock may be more harmful than good. + * Why you ask? Well, because it means that all searches that hit the access + * log are serialising around this tiny block of code in the name of "performance increase. + * Some testing needs to be done to see if the uncached version is faster + */ + + /* With the HR version, we can't check the exact nsec, so check we are within a tolerance. */ + + PR_Lock(ts_time_hr_lock); + if (t == old_hr_time && (old_hr_nsec + NSEC_TOLERANCE) > nsec) { + strcpy(buf, old_hr_tbuf); + *bufsize = old_hr_bufsize; + } else { + res = format_localTime_hr_log(t, nsec, initsize, buf, bufsize); + old_hr_time = t; + strcpy(old_hr_tbuf, buf); + old_hr_bufsize = *bufsize; + } + PR_Unlock(ts_time_hr_lock); + return res; +} +#endif /* HAVE_CLOCK_GETTIME */ + char* format_localTime (time_t from) /* return a newly-allocated string containing the given time, expressed -- 2.5.0