Uploaded image for project: 'OpenDJ'
  1. OpenDJ
  2. OPENDJ-4178

Performance drop with complex subtree searches between 2.x and 3.5.1/4.0.0

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 5.5.0, 4.0.0, 3.5.2, 3.5.1, 3.5.0, 3.0.0
    • Fix Version/s: 5.5.0
    • Component/s: core server, performance
    • Labels:
    • Environment:
      Available processors (cores): 6

      Red Hat Enterprise Linux Server release 6.2 (Santiago)

      Name: Linux
      Version: 2.6.32-220.13.1.el6.x86_64
      Arch: amd64

      Quad Core Intel Kaby Lake Xeon machine with 32 GB ram
    • Support Ticket IDs:
    • Sprint:
      OpenDJ Sprint 109, OpenDJ Sprint 112

      Description

      There is a significant drop in performance between 2.x and 3.5.1 with searches.  In many cases etimes are 2-5 times slower on 3.5.1.

      Note: tests on 3.5.1 were completed with 3.5.1+OPENDJ-4027 to gain the schema lock performance gains.

       

      Testcase 1: presence & substring (etimes for 3 searches after startup)

      2.6.0

      opendj; bin/$ ./search.1
      
      [24/Jul/2017:19:11:30 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=wholeSubtree filter="(&(&(exKerberosId=*)(mail=*)(!(|(mail=*an)(mail=*bb)(mail=*cc)))))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:11:42 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=282842 etime=11894
      ...
      [24/Jul/2017:19:11:54 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=282842 etime=8439
      ...
      [24/Jul/2017:19:12:05 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=282842 etime=8521
      

      3.5.1+OPENDJ-4027

      opendj; bin/$ ./search.1
      
      [24/Jul/2017:19:13:57 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=sub filter="(&(&(exKerberosId=*)(mail=*)(!(|(mail=*an)(mail=*bb)(mail=*cc)))))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:14:16 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=282842 etime=18535
      ...
      [24/Jul/2017:19:14:39 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=282842 etime=12854
      ...
      [24/Jul/2017:19:14:56 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=282842 etime=14247
      

      4.0.0

      opendj; bin/$ ./search.1
      
      [24/Jul/2017:19:51:34 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=sub filter="(&(&(exKerberosId=*)(mail=*)(!(|(mail=*an)(mail=*bb)(mail=*cc)))))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:51:58 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=282842 etime=23609
      ...
      [24/Jul/2017:19:53:17 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=282842 etime=13888
      ...
      [24/Jul/2017:19:53:35 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=282842 etime=15452
      

       

      Testcase 2: large equality (etimes for 3 searches after startup)

      2.6.0

      opendj; bin/$ ./search.2
      
      [24/Jul/2017:19:19:08 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=wholeSubtree filter="(|(employeeNumber=222906)(employeeNumber=211670)(employeeNumber=192428)(employeeNumber=167988)(employeeNumber=252679)(employeeNumber=47700)(employeeNumber=174999)(employeeNumber=230512)(employeeNumber=187256)(employeeNumber=30223)(employeeNumber=206920)(employeeNumber=143553)(employeeNumber=102050)(employeeNumber=139979)(employeeNumber=10057)(employeeNumber=37510)(employeeNumber=75369)(employeeNumber=11270)(employeeNumber=187053)(employeeNumber=122653)(employeeNumber=196512)(employeeNumber=235837)(employeeNumber=102874)(employeeNumber=221243)(employeeNumber=224001)(employeeNumber=279892)(employeeNumber=137991)(employeeNumber=213050)(employeeNumber=66054)(employeeNumber=59415)(employeeNumber=276787)(employeeNumber=230057)(employeeNumber=184240)(employeeNumber=141068)(employeeNumber=152296)(employeeNumber=63324)(employeeNumber=98899)(employeeNumber=221316)(employeeNumber=209355)(employeeNumber=72539)(employeeNumber=76203)(employeeNumber=234283)(employeeNumber=12002)(employeeNumber=116833)(employeeNumber=107314)(employeeNumber=77343)(employeeNumber=186208)(employeeNumber=254671)(employeeNumber=22200)(employeeNumber=116682)(employeeNumber=8966)(employeeNumber=125178)(employeeNumber=131563)(employeeNumber=49337)(employeeNumber=209546)(employeeNumber=187918)(employeeNumber=92065)(employeeNumber=99880)(employeeNumber=103625)(employeeNumber=99669)(employeeNumber=28454)(employeeNumber=46035)(employeeNumber=27877)(employeeNumber=112103)(employeeNumber=89833)(employeeNumber=232599)(employeeNumber=77798)(employeeNumber=253409)(employeeNumber=233829)(employeeNumber=258295)(employeeNumber=156943))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:19:08 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=71 etime=145
      ...
      [24/Jul/2017:19:19:12 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=71 etime=38
      ...
      [24/Jul/2017:19:19:13 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=71 etime=24
      

      3.5.1+OPENDJ-4027

      opendj; bin/$ ./search.2
      
      [24/Jul/2017:19:19:47 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=sub filter="(|(employeeNumber=222906)(employeeNumber=211670)(employeeNumber=192428)(employeeNumber=167988)(employeeNumber=252679)(employeeNumber=47700)(employeeNumber=174999)(employeeNumber=230512)(employeeNumber=187256)(employeeNumber=30223)(employeeNumber=206920)(employeeNumber=143553)(employeeNumber=102050)(employeeNumber=139979)(employeeNumber=10057)(employeeNumber=37510)(employeeNumber=75369)(employeeNumber=11270)(employeeNumber=187053)(employeeNumber=122653)(employeeNumber=196512)(employeeNumber=235837)(employeeNumber=102874)(employeeNumber=221243)(employeeNumber=224001)(employeeNumber=279892)(employeeNumber=137991)(employeeNumber=213050)(employeeNumber=66054)(employeeNumber=59415)(employeeNumber=276787)(employeeNumber=230057)(employeeNumber=184240)(employeeNumber=141068)(employeeNumber=152296)(employeeNumber=63324)(employeeNumber=98899)(employeeNumber=221316)(employeeNumber=209355)(employeeNumber=72539)(employeeNumber=76203)(employeeNumber=234283)(employeeNumber=12002)(employeeNumber=116833)(employeeNumber=107314)(employeeNumber=77343)(employeeNumber=186208)(employeeNumber=254671)(employeeNumber=22200)(employeeNumber=116682)(employeeNumber=8966)(employeeNumber=125178)(employeeNumber=131563)(employeeNumber=49337)(employeeNumber=209546)(employeeNumber=187918)(employeeNumber=92065)(employeeNumber=99880)(employeeNumber=103625)(employeeNumber=99669)(employeeNumber=28454)(employeeNumber=46035)(employeeNumber=27877)(employeeNumber=112103)(employeeNumber=89833)(employeeNumber=232599)(employeeNumber=77798)(employeeNumber=253409)(employeeNumber=233829)(employeeNumber=258295)(employeeNumber=156943))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:19:49 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=71 etime=1947
      ...
      [24/Jul/2017:19:19:58 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=71 etime=226
      ...
      [24/Jul/2017:19:21:11 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=71 etime=170
      

      4.0.0

      opendj; bin/$ ./search.2
      
      [24/Jul/2017:19:55:21 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=sub filter="(|(employeeNumber=222906)(employeeNumber=211670)(employeeNumber=192428)(employeeNumber=167988)(employeeNumber=252679)(employeeNumber=47700)(employeeNumber=174999)(employeeNumber=230512)(employeeNumber=187256)(employeeNumber=30223)(employeeNumber=206920)(employeeNumber=143553)(employeeNumber=102050)(employeeNumber=139979)(employeeNumber=10057)(employeeNumber=37510)(employeeNumber=75369)(employeeNumber=11270)(employeeNumber=187053)(employeeNumber=122653)(employeeNumber=196512)(employeeNumber=235837)(employeeNumber=102874)(employeeNumber=221243)(employeeNumber=224001)(employeeNumber=279892)(employeeNumber=137991)(employeeNumber=213050)(employeeNumber=66054)(employeeNumber=59415)(employeeNumber=276787)(employeeNumber=230057)(employeeNumber=184240)(employeeNumber=141068)(employeeNumber=152296)(employeeNumber=63324)(employeeNumber=98899)(employeeNumber=221316)(employeeNumber=209355)(employeeNumber=72539)(employeeNumber=76203)(employeeNumber=234283)(employeeNumber=12002)(employeeNumber=116833)(employeeNumber=107314)(employeeNumber=77343)(employeeNumber=186208)(employeeNumber=254671)(employeeNumber=22200)(employeeNumber=116682)(employeeNumber=8966)(employeeNumber=125178)(employeeNumber=131563)(employeeNumber=49337)(employeeNumber=209546)(employeeNumber=187918)(employeeNumber=92065)(employeeNumber=99880)(employeeNumber=103625)(employeeNumber=99669)(employeeNumber=28454)(employeeNumber=46035)(employeeNumber=27877)(employeeNumber=112103)(employeeNumber=89833)(employeeNumber=232599)(employeeNumber=77798)(employeeNumber=253409)(employeeNumber=233829)(employeeNumber=258295)(employeeNumber=156943))" attrs="exKerberosId,mail"
      [24/Jul/2017:19:55:22 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=71 etime=1152
      ...
      [24/Jul/2017:19:55:33 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=71 etime=290
      ...
      [24/Jul/2017:19:55:42 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=71 etime=344
      

       

      Testcase 3: equality with one filter (etimes for 3 searches after startup)

      2.6.0

      opendj; bin/$ ./search.3
      
      [24/Jul/2017:19:24:28 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=singleLevel filter="(&(exidentity=Wxj))" attrs="exguid,exkerberosid,cn,givenName,sn,title,l,excitycode,co,c,exhrareaname,exdivisionname,exsubdivision,exbusinessunit,exdepartmentname,exdivisioncode,exsubdivisioncode,exbusinessunitcode,exdeptcode,mail"
      [24/Jul/2017:19:24:28 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=24 etime=48
      ...
      [24/Jul/2017:19:24:30 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=24 etime=19
      ...
      [24/Jul/2017:19:24:32 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=24 etime=16
      

      3.5.1+OPENDJ-4027

      opendj; bin/$ ./search.3
      
      [24/Jul/2017:19:24:55 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=one filter="(&(exidentity=Wxj))" attrs="exguid,exkerberosid,cn,givenName,sn,title,l,excitycode,co,c,exhrareaname,exdivisionname,exsubdivision,exbusinessunit,exdepartmentname,exdivisioncode,exsubdivisioncode,exbusinessunitcode,exdeptcode,mail"
      [24/Jul/2017:19:24:58 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=24 etime=2335
      ...
      [24/Jul/2017:19:25:05 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=24 etime=824
      ...
      [24/Jul/2017:19:25:08 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=24 etime=487
      

      4.0.0

      opendj; bin/$ ./search.3
      
      [24/Jul/2017:19:56:24 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=one filter="(&(exidentity=Wxj))" attrs="exguid,exkerberosid,cn,givenName,sn,title,l,excitycode,co,c,exhrareaname,exdivisionname,exsubdivision,exbusinessunit,exdepartmentname,exdivisioncode,exsubdivisioncode,exbusinessunitcode,exdeptcode,mail"
      [24/Jul/2017:19:56:25 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=24 etime=1322
      ...
      [24/Jul/2017:19:56:33 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=24 etime=611
      ...
      [24/Jul/2017:19:56:36 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=24 etime=665
      

      Testcase 3: * huge * equality with 1488 random subfilters (etimes for 3 searches after startup)

      2.6.0

      opendj; bin/$ ./search.4-1488filters
      
      [24/Jul/2017:19:30:22 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=wholeSubtree filter="(|(exkerberosid=TerezMcClintock)(exkerberosid=LeonaZito)(exkerberosid=TammiMaund)(exkerberosid=CoorsBushnell)(exkerberosid=EldaCoombs)(exkerberosid=BridePorter)(exkerberosid=NongKendrick)(exkerberosid=ChareeRasmus)(exkerberosid=FreyaStallings)(exkerberosid=ElliotCosburn)(exkerberosid=BertBenge)(exkerberosid=EdwinConroy)(exkerb...
      [24/Jul/2017:19:30:23 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=1484 etime=1373
      ...
      [24/Jul/2017:19:30:32 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=1484 etime=380
      ...
      [24/Jul/2017:19:31:10 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=1484 etime=274
      

      3.5.1+OPENDJ-4027

      opendj; bin/$ ./search.4-1488filters
      
      [24/Jul/2017:19:31:47 -0600] SEARCH REQ conn=0 op=1 msgID=2 base="ou=people,o=ex.com" scope=sub filter="(|(exkerberosid=TerezMcClintock)(exkerberosid=LeonaZito)(exkerberosid=TammiMaund)(exkerberosid=CoorsBushnell)(exkerberosid=EldaCoombs)(exkerberosid=BridePorter)(exkerberosid=NongKendrick)(exkerberosid=ChareeRasmus)(exkerberosid=FreyaStallings)(exkerberosid=ElliotCosburn)(exkerberosid=BertBenge)(exkerberosid=EdwinConroy)(exkerberosid=MukundJoly)(exkerberosid=CyceliaCapobianco)(exkerberosid=DonelleCicek)(exkerberosid=FloydSprott)(exkerberosid=DarnellSadri)(exkerberosid=LyssaHelmy)(exkerberosid=LillieHalford)(exkerberosid=JacinthaFadlallah)(exkerberosid=GhassemStruble)(exkerberosid=DeepakChamayou)(exkerberosid=ErmaSilgardo)(exkerberosid=CarolienBot)(exkerberosid=JyotiGahir)(exkerberosid=DiegoChirachanchai)(exkerberosid=Peng-DavidKonno)(exkerberosid=IlysaTraut)(exkerberosid=HettiEason)(exkerberosid=EloiseSherban)(exkerberosid=AnjaOran)(exkerberosid=AnthiaOwsiak)(exkerberosid=FreddyDeek)(exkerberosid=Houssein...
      [24/Jul/2017:19:31:51 -0600] SEARCH RES conn=0 op=1 msgID=2 result=0 nentries=1484 etime=3739
      ...
      [24/Jul/2017:19:32:10 -0600] SEARCH RES conn=1 op=1 msgID=2 result=0 nentries=1484 etime=1775
      ...
      [24/Jul/2017:19:32:21 -0600] SEARCH RES conn=2 op=1 msgID=2 result=0 nentries=1484 etime=1519
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                JnRouvignac Jean-Noël Rouvignac
                Reporter:
                lee.trujillo Lee Trujillo
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: