RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 918711 - [RFE] logconv.pl should handle microsecond timing
Summary: [RFE] logconv.pl should handle microsecond timing
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base
Version: 7.0
Hardware: Unspecified
OS: Unspecified
medium
unspecified
Target Milestone: rc
: ---
Assignee: Rich Megginson
QA Contact: Sankar Ramalingam
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-03-06 18:16 UTC by Nathan Kinder
Modified: 2020-09-13 20:21 UTC (History)
4 users (show)

Fixed In Version: 389-ds-base-1.3.1.2-1.el7
Doc Type: Enhancement
Doc Text:
Cause: etimes were incorrectly processed by logconv.pl if microsecond access logging was being used. Consequence: The reported statistics that used "etime" could be incorrect. Change: The script properly reads and processes microsecond etimes. Result: The generated report has correct results.
Clone Of:
Environment:
Last Closed: 2014-06-13 12:32:33 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 539 0 None None None 2020-09-13 20:21:23 UTC

Description Nathan Kinder 2013-03-06 18:16:17 UTC 
This bug is created as a clone of upstream ticket:
https://fedorahosted.org/389/ticket/539

When using the LDAP_DEBUG_TIMING access log level to collect microsecond etime timing, logconv.pl should be able to read this data and calculate statistics with microsecond resolution.
Comment 1 Rich Megginson 2013-10-01 23:25:02 UTC 
moving all ON_QA bugs to MODIFIED in order to add them to the errata (can't add bugs in the ON_QA state to an errata).  When the errata is created, the bugs should be automatically moved back to ON_QA.
Comment 3 Sankar Ramalingam 2014-01-15 17:47:09 UTC 
Hi Mark, request you to please add more details for this bugzilla. QE would like know what needs to be tested.
Comment 4 Nathan Kinder 2014-01-15 17:52:19 UTC 
(In reply to Sankar Ramalingam from comment #3)
> Hi Mark, request you to please add more details for this bugzilla. QE would
> like know what needs to be tested.

The access log has long supported the option of using microsecond resolution for it's timestamps.  You simply need to enable microsecond logging as described in the documentation:

    https://access.redhat.com/site/documentation/en-US/Red_Hat_Directory_Server/9.0/html/Configuration_Command_and_File_Reference/logs-reference.html#Access_Log_Content-Access_Logging_Levels

As mentioned in the initial bug description, you should then make sure that logconv.pl is able to work against access logs that use microsecond resolution.
Comment 5 srkrishn@redhat.com 2014-01-24 12:58:49 UTC 
hi,
i added the following testcase for the microsecond timing using the following steps
1. added microsecond timing by changing the modifying the config file using ldapmodify command and changing the nsslapd-accesslog-level to 131328
2.added 10000 entries.
3.used a ldapsearch to get information from all 10000 entries.
4.using the logconv tool tried to get the etime information from them with the logconv -t option.
5.the output obtained from the temp logs is as follows
----- Top 20 Most Frequent etimes -----

8461            etime=0
268             etime=1
1               etime=2


----- Top 20 Longest etimes -----

etime=2         1
etime=1         268
etime=0         8461

is it possible to mention what should be tested?
Comment 6 mreynolds 2014-01-24 15:41:01 UTC 
(In reply to srkrishn from comment #5)
> hi,
> i added the following testcase for the microsecond timing using the
> following steps
> 1. added microsecond timing by changing the modifying the config file using
> ldapmodify command and changing the nsslapd-accesslog-level to 131328
> 2.added 10000 entries.
> 3.used a ldapsearch to get information from all 10000 entries.
> 4.using the logconv tool tried to get the etime information from them with
> the logconv -t option.
> 5.the output obtained from the temp logs is as follows
> ----- Top 20 Most Frequent etimes -----
> 
> 8461            etime=0
> 268             etime=1
> 1               etime=2
> 
> 
> ----- Top 20 Longest etimes -----
> 
> etime=2         1
> etime=1         268
> etime=0         8461
> 
> is it possible to mention what should be tested?

That is the correct log level, can you verify the access log actually has microsecond etimes?  Maybe there was log buffering, and you ran the script too soon.  Waiting 30 seconds will allow the logging to be flushed to disk.

I just ran a test and logconv.pl is working for me:

----- Top 20 Most Frequent etimes -----

2               etime=0.001000
1               etime=0.000000
1               etime=0.002000
1               etime=0.004000


----- Top 20 Longest etimes -----

etime=0.004000    1         
etime=0.002000    1         
etime=0.001000    2         
etime=0.000000    1
Comment 7 srkrishn@redhat.com 2014-02-04 13:38:16 UTC 
hi,
i added the following testcase and verified the microsecond timing issue which has been resolved in the logconv.pl script using the following steps
> 1. added microsecond timing by changing the modifying the config file using
> ldapmodify command and changing the nsslapd-accesslog-level to 131328
> 2.added 10000 entries.
> 3.used a ldapsearch to get information from all 10000 entries.
> 4.using the logconv tool tried to get the etime information from them with
> the logconv -t option.
microsecond timing has been successfully tracked by the logconv tool time1 =
2               etime=0.000000
1               etime=0.008000
1               etime=9.148000
1               etime=0.001000
1               etime=0.230000
etime=9.148000    1         
etime=0.230000    1         
etime=0.008000    1         
etime=0.001000    1         
etime=0.000000    2         
[root@hp-dl380pgen8-02-vm-1 logfile]#
Comment 8 Sankar Ramalingam 2014-02-04 13:40:58 UTC 
Based on Sriram's comment #7, marking the bug as Verified.

Build tested - 389-ds-base-1.3.1.6-15
Comment 9 Sankar Ramalingam 2014-02-13 11:51:23 UTC 
Test cases automated in ./logfile/logconv.sh
Comment 10 Ludek Smid 2014-06-13 12:32:33 UTC 
This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.
Note You need to log in before you can comment on or make changes to this bug.