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 1732053 - etime can contain invalid nanosecond value
Summary: etime can contain invalid nanosecond value
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base
Version: 7.6
Hardware: All
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: thierry bordaz
QA Contact: RHDS QE
Marc Muehlfeld
URL:
Whiteboard: sync-to-jira
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-07-22 14:35 UTC by thierry bordaz
Modified: 2020-09-13 22:21 UTC (History)
8 users (show)

Fixed In Version: 389-ds-base-1.3.10.1-1.el7
Doc Type: Bug Fix
Doc Text:
.Directory Server improved the logging of the `etime` value Previously, if an operation started and completed at the border of a second and the operation took less than one second, Directory Server logged an incorrectly calculated `etime` value. As a consequence, the logged value was too big. This updates fixes the problem. As a result, the calculated `etime` value is now closer to the start and end time stamp.
Clone Of:
Environment:
Last Closed: 2020-03-31 19:46:14 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 3566 0 None None None 2020-09-13 22:21:51 UTC
Red Hat Product Errata RHBA-2020:1064 0 None None None 2020-03-31 19:46:55 UTC

Description thierry bordaz 2019-07-22 14:35:11 UTC 
Description of problem:
The etime is computed as end_time - start_time. time is composed of two counters sec/nsec (timespec). When end_time.nsec > start_time.nsec then the nsec value in the etime is invalid.

It should be 1B - (start_time.nsec - end_time.nsec) but it is 1B + (start_time.nsec - end_time.nsec)

Then we can have logs like:

[17/Jul/2019:10:12:02.880310556 -0400] conn=1642 op=34 SRCH base="cn=my_group,cn=groups,cn=accounts,<suffix>" scope=0 filter="(objectClass=*)" attrs="objectClass posixgroup cn userPassword gidNumber member ipaUniqueID ipaNTSecurityIdentifier modifyTimestamp entryusn ipaExternalMember uid"
[17/Jul/2019:10:12:03.575336828 -0400] conn=1642 op=34 RESULT err=0 tag=101 nentries=1 etime=0.1301729719

Here etime should be close to 
1000000000 - (880310556 - 575336828) = 0.695026272


This impact function slapi_timespec_diff


Version-Release number of selected component (if applicable):
All RHEL7


How reproducible:
Not systematic. Run fast commands (search on cn=config), when start and end cover a second border, start.nsec > end.nsec


Actual results:
etime can contain wrong nsec value


Expected results:
etime should contain valid nsec value


Additional info:
Comment 2 thierry bordaz 2019-07-23 08:24:03 UTC 
Upstream ticket:
https://pagure.io/389-ds-base/issue/50510
Comment 3 thierry bordaz 2019-07-25 13:57:55 UTC 
Upstream pushed upstream -> POST
Comment 5 sgouvern 2019-09-04 13:43:20 UTC 
Verified on 389-ds-base: 1.3.10.1-1.el7

ds/dirsrvtests/tests/suites/ds_logs/ds_logs_test.py::test_etime_at_border_of_second output :

=============================================== test session starts ================================================
platform linux -- Python 3.6.3, pytest-5.1.2, py-1.8.0, pluggy-0.12.0 -- /opt/rh/rh-python36/root/usr/bin/python3
cachedir: .pytest_cache
metadata: {'Python': '3.6.3', 'Platform': 'Linux-3.10.0-1077.el7.x86_64-x86_64-with-redhat-7.8-Maipo', 'Packages': {'pytest': '5.1.2', 'py': '1.8.0', 'pluggy': '0.12.0'}, 'Plugins': {'metadata': '1.8.0', 'html': '1.22.0'}}
389-ds-base: 1.3.10.1-1.el7
nss: 3.44.0-5.el7
nspr: 4.21.0-1.el7
openldap: 2.4.44-21.el7_6
cyrus-sasl: 2.1.26-23.el7
FIPS: disabled
rootdir: /mnt/tests/rhds/tests/upstream/ds/dirsrvtests, inifile: pytest.ini
plugins: metadata-1.8.0, html-1.22.0
collected 1 item                                                                                                   

ds/dirsrvtests/tests/suites/ds_logs/ds_logs_test.py::test_etime_at_border_of_second PASSED                   [100%]
Comment 9 errata-xmlrpc 2020-03-31 19:46:14 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:1064
Note You need to log in before you can comment on or make changes to this bug.