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 1894837 - performance search rate: useless poll on network send callback
Summary: performance search rate: useless poll on network send callback
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: 389-ds-base
Version: 8.3
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: 8.0
Assignee: thierry bordaz
QA Contact: RHDS QE
URL:
Whiteboard: sync-to-jira
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-11-05 08:47 UTC by thierry bordaz
Modified: 2021-09-03 16:55 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-09-03 15:00:06 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 4316 0 None closed performance search rate: useless poll on network send callback 2021-02-01 12:51:21 UTC

Description thierry bordaz 2020-11-05 08:47:56 UTC 
Description of problem:

DS writes to the socket using a callback function (openldap_write_function). This function tests (poll) the ability to write before sending pdu. This is useless as there is already a loop that taking care of retry/partial write.
This adds an overhead of 'pool' syscall. It improves througput up to 5%.
Version-Release number of selected component (if applicable):


How reproducible:
searchrate on small db, lookup of a single entry
perf trace -t <worker-tid> -s (taken on top of 51262: nagle off)



Steps to Reproduce:
1.
2.
3.

Actual results:
ns-slapd (93047), 540445 events, 100.0%

   syscall            calls    total       min       avg       max      stddev
                               (msec)    (msec)    (msec)    (msec)        (%)
   --------------- -------- --------- --------- --------- ---------     ------
   futex             103768   524.042     0.001     0.005     2.971      0.67%
   poll               36964   154.968     0.001     0.004     0.044      0.14%
   sendto             36941   140.178     0.001     0.004     0.025      0.20%
   write              36927   135.035     0.002     0.004     0.026      0.16%
   recvfrom           18495    76.359     0.002     0.004     0.027      0.17%


Expected results:
With sendto

 ns-slapd (117421), 319573 events, 100.0%

   syscall            calls    total       min       avg       max      stddev
                               (msec)    (msec)    (msec)    (msec)        (%)
   --------------- -------- --------- --------- --------- ---------     ------
   futex              83704  1021.638     0.000     0.012   100.113     23.99%
   sendto             30268   245.164     0.002     0.008     0.041      0.22%
   write              30301   123.068     0.002     0.004     0.033      0.23%
   recvfrom           15222    65.530     0.002     0.004     0.034      0.28%
   poll                  40     1.146     0.003     0.029     0.098     12.61%


Additional info:
Comment 1 thierry bordaz 2020-11-10 13:28:32 UTC 
How to verify the fix

Create a standalone and provision few entries (e.g. 'uid=demo_user')
Assuming it is tested on a small box client/server should consume few threads: dsconf <instance> config replace nsslapd-threadnumber=5
hammer the instance with 'ldclt -h localhost -p xxx -D 'cn=Directory Manager' -w xxx -b 'dc=example,dc=com' -f '(uid=demo_user)' -n 4 -e esearch'

Select a worker LWP(calls connection_wait_for_new_work) using pstack <pid_of_ns-slapd> ==> LWP is 1033502

Thread 15 (Thread 0x7ff07859f700 (LWP 1033502)):
#0  0x00007ff105851d45 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007ff1058b0d28 in PR_WaitCondVar () from /lib64/libnspr4.so
#2  0x000000000042537b in connection_wait_for_new_work (pb=0x608000484020, interval=4294967295) at ldap/servers/slapd/connection.c:961
#3  0x0000000000428b30 in connection_threadmain () at ldap/servers/slapd/connection.c:1502
#4  0x00007ff1058b6b34 in _pt_root () from /lib64/libnspr4.so
#5  0x00007ff10584b4e2 in start_thread () from /lib64/libpthread.so.0
#6  0x00007ff1057036a3 in clone () from /lib64/libc.so.6
...


Before the fix, #poll >= #write
perf trace -t <LWP_worker> -s
 Summary of events:

 ns-slapd (<LWP_worker>), 9189 events, 100.0%

   syscall            calls  errors  total       min       avg       max       stddev
                                     (msec)    (msec)    (msec)    (msec)        (%)
   --------------- --------  ------ -------- --------- --------- ---------     ------
   futex               1850      0  6417.840     0.000     3.469    22.945      2.19%
   fsync                348      0   450.635     0.633     1.295     3.122      1.14%
   poll                 474      0    18.013     0.001     0.038     0.220      5.86%
...
   write                378      0    12.904     0.002     0.034     0.078      2.41%
...




After the fix, #poll < #write
perf trace -t <LWP_worker> -s

 Summary of events:

 ns-slapd (<LWP_worker>), 16422 events, 100.0%

   syscall            calls  errors  total       min       avg       max       stddev
                                     (msec)    (msec)    (msec)    (msec)        (%)
   --------------- --------  ------ -------- --------- --------- ---------     ------
   futex               7232      0  8637.011     0.002     1.194     9.769      0.57%
   fsync                145      0   174.314     0.000     1.202     2.546      1.90%
...
   write                172      0     5.142     0.003     0.030     0.074      3.21%
   poll                  41      0     3.250     0.005     0.079     0.192     11.24%
...
Comment 2 thierry bordaz 2020-11-12 11:07:22 UTC 
Fix pushed upstream => POST
Note You need to log in before you can comment on or make changes to this bug.