#47979 Under DEL stress, DEL operations are very slow
Closed: wontfix Opened by tbordaz.

DEL ops are very slow compare to MOD or ADD.

The instance contains 2 suffixes (o=test_bis_create and o=test_create)

[24/Dec/2014:06:24:14 -0800] conn=110 op=21 ADD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:24:14 -0800] conn=110 op=21 RESULT err=0 tag=105 nentries=0 etime=0
[24/Dec/2014:06:24:20 -0800] conn=259 op=22 ADD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:24:20 -0800] conn=259 op=22 RESULT err=0 tag=105 nentries=0 etime=0
[24/Dec/2014:06:31:31 -0800] conn=208 op=206 MOD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:31:31 -0800] conn=208 op=206 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:31:32 -0800] conn=241 op=23 MOD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:31:32 -0800] conn=241 op=23 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:33:57 -0800] conn=363 op=22 MOD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:33:57 -0800] conn=363 op=22 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:34:00 -0800] conn=314 op=206 MOD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:34:00 -0800] conn=314 op=206 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:35:54 -0800] conn=515 op=22 MOD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:35:54 -0800] conn=515 op=22 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:35:57 -0800] conn=578 op=21 MOD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:35:57 -0800] conn=578 op=21 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:41:08 -0800] conn=660 op=22 ADD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:41:08 -0800] conn=660 op=22 RESULT err=68 tag=105 nentries=0 etime=0
[24/Dec/2014:06:41:12 -0800] conn=806 op=20 ADD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:41:12 -0800] conn=806 op=20 RESULT err=68 tag=105 nentries=0 etime=0
[24/Dec/2014:06:41:40 -0800] conn=897 op=21 MOD dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:06:41:40 -0800] conn=897 op=21 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:06:41:46 -0800] conn=956 op=22 MOD dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:06:41:46 -0800] conn=956 op=22 RESULT err=0 tag=103 nentries=0 etime=0
[24/Dec/2014:07:06:20 -0800] conn=1265 op=6 DEL dn="cn=mr000002050,o=People,o=test_bis_create"
[24/Dec/2014:07:06:23 -0800] conn=1265 op=6 RESULT err=0 tag=107 nentries=0 etime=3
[24/Dec/2014:07:06:24 -0800] conn=1271 op=6 DEL dn="cn=mr000002050,o=People,o=test_create"
[24/Dec/2014:07:06:27 -0800] conn=1271 op=6 RESULT err=0 tag=107 nentries=0 etime=3

One thread is sleeping (while holding the backend lock) in

    Thread 30 (Thread 0x7f2db6fbd700 (LWP 16521)):
    #0  0x00007f2dff131463 in select () at ../sysdeps/unix/syscall-template.S:81
    #1  0x00007f2e016acf19 in DS_Sleep (ticks=<optimized out>) at ldap/servers/slapd/util.c:1118
    #2  0x00007f2df73acb8c in ldbm_back_delete (pb=0x7f2db6fbcae0) at ldap/servers/slapd/back-ldbm/ldbm_delete.c:516
    #3  0x00007f2e016307c0 in op_shared_delete (pb=pb@entry=0x7f2db6fbcae0) at ldap/servers/slapd/delete.c:364
    #4  0x00007f2e01630a83 in do_delete (pb=pb@entry=0x7f2db6fbcae0) at ldap/servers/slapd/delete.c:128
    #5  0x00007f2e01b493de in connection_dispatch_operation (pb=0x7f2db6fbcae0, op=0x7f2e0453fff0, conn=0x7f2e01a3c950) at ldap/servers/slapd/connection.c:650
    #6  connection_threadmain () at ldap/servers/slapd/connection.c:2534
    #7  0x00007f2dffa6ae3b in _pt_root (arg=0x7f2e044f56e0) at ../../../nspr/pr/src/pthreads/ptthread.c:212
    #8  0x00007f2dff40aee5 in start_thread (arg=0x7f2db6fbd700) at pthread_create.c:309
    #9  0x00007f2dff139b8d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

How to reproduce

do ADD, on both suffix in parallele
do MOD, on both suffix in parallele
do DEL, on both suffix in parallele
ADD:
        ldclt \
            -h $Host -p $Port \
            -D "$RootDN" -w "$RootPasswd" \
            -e add,person,incr,noloop,commoncounter \
            -r0 -R100000 \
            -I68 \
            -n100 \
            -f cn=mrXXXXXXXXX -b o=People,$SUFFIX1 \
            -v -q
MOD:
        ldclt -h $Host -p $Port \
            -D "$RootDN" -w "$RootPasswd" \
             -b "o=People,$SUFFIX1" \
            -f "cn=mrXXXXXXXXX" -e incr,commoncounter -e noloop \
            -r 0 -R 50000 \
          -I 32 -I 68 \
          -e attreplace='sn: toru' \
            -n 100
DEL:
        ldclt \
            -h $Host -p $Port \
            -D "$RootDN" -w "$RootPasswd" \
            -e delete,incr,noloop,commoncounter \
            -r 5000 -R 50000 \
            -I32 \
            -n10 \
            -f cn=mrXXXXXXXXX -b o=People,$SUFFIX1 \
            -v -q

The instance is tuned to reduce IOs
nsslapd-threadnumber: 100
nsslapd-db-transaction-batch-val: 20
nsslapd-backend-opt-level: 7

The workload is :
10 ldap client doing DEL on entries in o=test_bis_create
10 ldap client doing DEL on entries in o=test_create


The DEL perf are still bad with nsslapd-backend-opt-level: 3.
But if batch-val is turned of (nsslapd-backend-opt-level: 1, nsslapd-db-transaction-batch-val: 1), then the performance ADD and DEL are similar.

After triage we concluded to close that bug.

With default batch-val/optlevel values, the performance of DEL/ADD are equivalent.
Using optlevel: 7 is a corner case.

Metadata Update from @tbordaz:
- Issue set to the milestone: 1.3.4 backlog

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/1310

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata Update from @spichugi:
- Issue close_status updated to: wontfix (was: Invalid)

Metadata