Fedora Info: [389-commits] config.h.in configure configure.ac ldap/admin ldap/schema ldap/servers

New commits:
commit dbf16991bc8add44dff1ff39d6a2392414913c22
Author: William Brown <firstyear@redhat.com>
Date: Fri Feb 5 15:21:37 2016 +1000

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.

This patch removes the str buffer as it actually slowed down logging performance.

This enables support in logconv.pl for HR timestamps.

https://fedorahosted.org/389/ticket/47982

Author: wibrown

Review by: nhosoi (Thanks!)

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 142d91a..6a03247 100755
--- a/configure
+++ b/configure
@@ -17666,7 +17666,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 b80a077..c520022 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/admin/src/logconv.pl b/ldap/admin/src/logconv.pl
index 22d1a88..131a8c0 100755
--- a/ldap/admin/src/logconv.pl
+++ b/ldap/admin/src/logconv.pl
@@ -25,6 +25,7 @@ use sigtrap qw(die normal-signals);
use Archive::Tar;
use IO::Uncompress::AnyUncompress qw($AnyUncompressError);
use Scalar::Util qw(looks_like_number);
+use DB;

Getopt::Long::Configure ("bundling");
Getopt::Long::Configure ("permute");
@@ -45,10 +46,10 @@ my $logversion = "8.1";
my $sizeCount = "20";
my $startFlag = 0;
my $startTime = 0;
-my $startTimeInSecs = 0;
+my $startTimeInNsecs = 0;
my $endFlag = 0;
my $endTime = 0;
-my $endTimeInSecs = 0;
+my $endTimeInNsecs = 0;
my $minEtime = 0;
my $reportStats = "";
my $dataLocation = "/tmp";
@@ -361,8 +362,8 @@ my %monthname = (
#
if ($startTime and $endTime){
# Make sure the end time is not earlier than the start time
- my $testStart = convertTimeToSeconds($startTime);
- my $testEnd = convertTimeToSeconds($endTime);
+ my $testStart = convertTimeToNanoseconds($startTime);
+ my $testEnd = convertTimeToNanoseconds($endTime);
if ($testStart > $testEnd){
print "Start time ($startTime) is greater than end time ($endTime)!\n";
exit 1;
@@ -471,7 +472,7 @@ sub doUncompress {
return $TARFH;
}

-sub convertTimeToSeconds {
+sub convertTimeToNanoseconds {
my $log_line = shift;

my $logDate;
@@ -506,11 +507,11 @@ sub convertTimeToSeconds {

my $logTime;
my @timeComps;
- my ($timeHour, $timeMinute, $timeSecond, $timeTotal);
+ my ($timeHour, $timeMinute, $timeSecond, $timeNanosecond, $timeTotal);
$timeTotal = 0;
- if ($log_line =~ / *(:[0-9:]+)/i ){
+ if ($log_line =~ / *(:[0-9:\.]+)/i ){
$logTime = $1;
- @timeComps = split /:/, $logTime;
+ @timeComps = split /:|\./, $logTime;
if ($#timeComps < 3) {
print "The time string ($log_line) is invalid, exiting...\n";
exit(1);
@@ -527,20 +528,26 @@ sub convertTimeToSeconds {
print "The time string ($log_line) has invalid second ($timeComps[3]), exiting...\n";
exit(1);
}
+ if ($#timeComps < 4 || !looks_like_number($timeComps[4]) || length $timeComps[4] != 9){
+ # This isn't an error for nano seconds, we just assume old log format and set nsec to 0
+ $timeNanosecond = 0;
+ } else {
+ $timeNanosecond = $timeComps[4];
+ }
$timeHour = $timeComps[1] * 3600;
$timeMinute = $timeComps[2] * 60;
$timeSecond = $timeComps[3];
$timeTotal = $timeHour + $timeMinute + $timeSecond;
}

- return $timeTotal + $dateTotal;
+ return (($timeTotal + $dateTotal) * 1000000000) + $timeNanosecond;
}

if($startTime){
- $startTimeInSecs = convertTimeToSeconds($startTime);
+ $startTimeInNsecs = convertTimeToNanoseconds($startTime);
}
if($endTime){
- $endTimeInSecs = convertTimeToSeconds($endTime);
+ $endTimeInNsecs = convertTimeToNanoseconds($endTime);
}

$Archive::Tar::WARN = 0; # so new will shut up when reading a regular file
@@ -672,58 +679,61 @@ $allOps = $srchCount + $modCount + $addCount + $cmpCount + $delCount + $modrdnCo

my $start;
if($startTime){
- if ($start =~ / *([0-9a-z:\/]+)/i){$start=$1;}
+ if ($start =~ / *([0-9a-z:\/\.]+)/i){$start=$1;}
}
my $end;
if($endTime){
- if ($end =~ / *([0-9a-z:\/]+)/i){$end =$1;}
+ if ($end =~ / *([0-9a-z:\/\.]+)/i){$end =$1;}
}

#
# Get the start time in seconds
#
my $logStart = $start;
-my $startTotal = convertTimeToSeconds($logStart);
+my $startTotal = convertTimeToNanoseconds($logStart);

#
# Get the end time in seconds
#
my $logEnd = $end;
-my $endTotal = convertTimeToSeconds($logEnd);
+my $endTotal = convertTimeToNanoseconds($logEnd);

#
# Tally the numbers
#
-my $totalTimeInSecs = $endTotal - $startTotal;
-my $remainingTimeInSecs = $totalTimeInSecs;
+my $totalTimeInNsecs = $endTotal - $startTotal;
+my $remainingTimeInNsecs = $totalTimeInNsecs;
+
+my $totalTimeInSecs = $totalTimeInNsecs / 1000000000;
+my $remainingTimeInSecs = $remainingTimeInNsecs / 1000000000;

#
# Calculate the elapsed time
#

# days
-while(($remainingTimeInSecs - 86400) > 0){
+while(($remainingTimeInNsecs - (86400 * 1000000000)) > 0){
$elapsedDays++;
- $remainingTimeInSecs = $remainingTimeInSecs - 86400;
+ $remainingTimeInNsecs = $remainingTimeInNsecs - (86400 * 1000000000);

}

# hours
my $elapsedHours = 0;
-while(($remainingTimeInSecs - 3600) > 0){
+while(($remainingTimeInNsecs - (3600 * 1000000000 )) > 0){
$elapsedHours++;
- $remainingTimeInSecs = $remainingTimeInSecs - 3600;
+ $remainingTimeInNsecs = $remainingTimeInNsecs - (3600 * 1000000000);
}

# minutes
my $elapsedMinutes = 0;
-while($remainingTimeInSecs - 60 > 0){
+while($remainingTimeInNsecs - (60 * 1000000000) > 0){
$elapsedMinutes++;
- $remainingTimeInSecs = $remainingTimeInSecs - 60;
+ $remainingTimeInNsecs = $remainingTimeInNsecs - (60 * 1000000000);
}

# seconds
-my $elapsedSeconds = $remainingTimeInSecs;
+my $elapsedSeconds = $remainingTimeInNsecs / 1000000000;

#####################################
# #
@@ -784,7 +794,7 @@ if ($allOps ne "0"){
print "Overall Performance: No Operations to evaluate\n\n";
}

-if ($totalTimeInSecs == 0){
+if ($totalTimeInNsecs == 0){
$searchStat = sprintf "(%.2f/sec) (%.2f/min)\n","0", "0";
$modStat = sprintf "(%.2f/sec) (%.2f/min)\n","0", "0";
$addStat = sprintf "(%.2f/sec) (%.2f/min)\n","0", "0";
@@ -1697,15 +1707,15 @@ parseLineBind {

if($firstFile == 1 && $_ =~ /^\[/){
$start = $_;
- if ($start =~ / *([0-9a-z:\/]+)/i){$start=$1;}
+ if ($start =~ / *([0-9a-z:\/\.]+)/i){$start=$1;}
$firstFile = 0;
}
- if ($endFlag != 1 && $_ =~ /^\[/ && $_ =~ / *([0-9a-z:\/]+)/i){
+ if ($endFlag != 1 && $_ =~ /^\[/ && $_ =~ / *([0-9a-z:\/\.]+)/i){
$end =$1;
}
if ($startTime && !$startFlag) {
- my $currentTimeInSecs = convertTimeToSeconds($_);
- if ($currentTimeInSecs >= $startTimeInSecs) {
+ my $currentTimeInNsecs = convertTimeToNanoseconds($_);
+ if ($currentTimeInNsecs >= $startTimeInNsecs) {
$startFlag = 1;
($start) = $startTime =~ /\D*(\S*)/;
} else {
@@ -1713,8 +1723,8 @@ parseLineBind {
}
}
if ($endTime && !$endFlag) {
- my $currentTimeInSecs = convertTimeToSeconds($_);
- if ($currentTimeInSecs > $endTimeInSecs) {
+ my $currentTimeInNsecs = convertTimeToNanoseconds($_);
+ if ($currentTimeInNsecs > $endTimeInNsecs) {
$endFlag = 1;
($end) = $endTime =~ /\D*(\S*)/;
}
@@ -1867,15 +1877,15 @@ sub parseLineNormal
if($firstFile == 1 && $_ =~ /^\[/){
# if we are using startTime & endTime, this will get overwritten, which is ok
$start = $_;
- if ($start =~ / *([0-9a-z:\/]+)/i){$start=$1;}
+ if ($start =~ / *([0-9a-z:\/\.]+)/i){$start=$1;}
$firstFile = 0;
}
- if ($endFlag != 1 && $_ =~ /^\[/ && $_ =~ / *([0-9a-z:\/]+)/i){
+ if ($endFlag != 1 && $_ =~ /^\[/ && $_ =~ / *([0-9a-z:\/\.]+)/i){
$end =$1;
}
if ($startTime && !$startFlag) {
- my $currentTimeInSecs = convertTimeToSeconds($_);
- if ($currentTimeInSecs >= $startTimeInSecs) {
+ my $currentTimeInNsecs = convertTimeToNanoseconds($_);
+ if ($currentTimeInNsecs >= $startTimeInNsecs) {
$startFlag = 1;
($start) = $startTime =~ /\D*(\S*)/;
} else {
@@ -1883,8 +1893,8 @@ sub parseLineNormal
}
}
if ($endTime && !$endFlag) {
- my $currentTimeInSecs = convertTimeToSeconds($_);
- if ($currentTimeInSecs > $endTimeInSecs) {
+ my $currentTimeInNsecs = convertTimeToNanoseconds($_);
+ if ($currentTimeInNsecs > $endTimeInNsecs) {
$endFlag = 1;
($end) = $endTime =~ /\D*(\S*)/;
}
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},
+

Fedora Info

Sunday, March 20, 2016

[389-commits] config.h.in configure configure.ac ldap/admin ldap/schema ldap/servers

No comments:

Post a Comment