dynlist vs memberof performance issues
by Mark Cairney
Hi,
I've been out the LDAP loop for a bit but the recent discussion of the
memberof overlay on 2.5 piqued my curiosity. Having upgraded a Dev box,
removed the memberof elements from the database and replaced the
memberof overlay with dynlist the queries appear to work as expected but
are both a) slow and b) heavily CPU-intensive on the LDAP server.
2021-09-01T12:47:17.603513+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 fd=12 ACCEPT from IP=192.168.152.33:58738
(IP=129.215.17.9:636)
2021-09-01T12:47:17.687488+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 fd=12 TLS established tls_ssf=256 ssf=256
tls_proto=TLSv1.3 tls_cipher=TLS_AES_256_GCM_SHA384
2021-09-01T12:47:17.688032+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=0 SRCH base="" scope=0 deref=0
filter="(objectClass=*)"
2021-09-01T12:47:17.688470+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=0 SRCH attr=supportedSASLMechanisms
2021-09-01T12:47:17.688878+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=0 SEARCH RESULT tag=101 err=0 qtime=0.000014
etime=0.000214 nentries=1 text=
2021-09-01T12:47:17.811279+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=1 BIND dn="" method=163
2021-09-01T12:47:17.819249+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=1 RESULT tag=97 err=14 qtime=0.000030
etime=0.009084 text=SASL(0): successful result:
2021-09-01T12:47:17.908889+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=2 BIND dn="" method=163
2021-09-01T12:47:17.909836+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=2 RESULT tag=97 err=14 qtime=0.000031
etime=0.000181 text=SASL(0): successful result:
2021-09-01T12:47:17.938839+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=3 BIND dn="" method=163
2021-09-01T12:47:17.939621+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=3 BIND authcid="mcairney(a)EASE.ED.AC.UK"
authzid="mcairney(a)EASE.ED.AC.UK"
2021-09-01T12:47:17.940213+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=3 BIND
dn="uid=mcairney,ou=people,ou=central,dc=authorise-dev,dc=ed,dc=ac,dc=uk"
mech=GSSAPI bind_ssf=256 ssf=256
2021-09-01T12:47:17.940616+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=3 RESULT tag=97 err=0 qtime=0.000024
etime=0.000409 text=
2021-09-01T12:47:18.227342+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=4 SRCH
base="dc=authorise-dev,dc=ed,dc=ac,dc=uk" scope=2 deref=0
filter="(uid=mcairney)"
2021-09-01T12:47:18.227703+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=4 SRCH attr=* +
2021-09-01T12:47:31.392255+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=5 UNBIND
2021-09-01T12:47:31.460705+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 op=4 SEARCH RESULT tag=101 err=0 qtime=0.000031
etime=13.233679 nentries=1 text=
2021-09-01T12:47:31.461098+01:00 bonsai.authorise-dev.is.ed.ac.uk
slapd[30075]: conn=1019 fd=12 closed
I'm guessing that as the values are computed that this will be heavier
on the CPU but it seems a bit excessive? Has anyone else noticed any
similar performance issues?
This is a relatively low-specced DEV server (2 vCPUs, 4GB RAM) so I
guess this could be a factor but there's no io waiting on the server and
no swapping?
The database is on a par in size with our Production service ( about
400K user objects with 1 group object per user and then about 80K actual
groups of users)
The config for the primary DB (ACLs and rootPW redacted) is:
dn: olcDatabase={1}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {1}mdb
olcDbDirectory: /opt/openldap/var/openldap-data/authorise
olcSuffix: dc=authorise-dev,dc=ed,dc=ac,dc=uk
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcMaxDerefDepth: 2
olcReadOnly: FALSE
olcSecurity: ssf=1
olcSecurity: update_ssf=112
olcSecurity: simple_bind=64
olcSizeLimit: unlimited
olcSyncUseSubentry: FALSE
olcTimeLimit: unlimited
olcMonitoring: TRUE
olcDbEnvFlags: writemap
olcDbEnvFlags: nometasync
olcDbNoSync: FALSE
olcDbIndex: objectClass eq
olcDbIndex: entryUUID eq
olcDbIndex: entryCSN eq
olcDbIndex: cn pres,eq,sub
olcDbIndex: uid pres,eq,sub
olcDbIndex: uidNumber pres,eq
olcDbIndex: gidNumber pres,eq
olcDbIndex: eduniType eq
olcDbIndex: gecos pres,eq,sub
olcDbIndex: eduniCategory eq
olcDbIndex: mail pres,eq,sub
olcDbIndex: eduniSchoolCode eq
olcDbIndex: eduniIDStatus eq
olcDbIndex: eduniCollegeCode eq
olcDbIndex: eduniOrgCode eq
olcDbIndex: memberOf pres,eq
olcDbIndex: eduniLibraryBarcode pres,eq
olcDbIndex: eduniOrganisation pres,eq,sub
olcDbIndex: eduniServiceCode pres,eq
olcDbIndex: krbName pres,eq
olcDbIndex: eduPersonAffiliation pres,eq
olcDbIndex: eduPersonEntitlement pres,eq
olcDbIndex: sn pres,eq,sub
olcDbIndex: eduniIdmsId pres,eq
olcDbIndex: member pres,eq
olcDbIndex: memberUid pres,eq
olcDbIndex: eduniRefNo pres,eq
olcDbIndex: eduniTitle pres,eq
olcDbIndex: title pres,eq,sub
olcDbIndex: eduniCardNumber pres,eq
olcDbIndex: eduniYearOfStudy eq
olcDbIndex: description pres,eq,sub
olcDbIndex: givenName pres,eq,sub
olcDbIndex: aliasedObjectName eq
olcDbIndex: yubiKeyId pres,eq
olcDbIndex: isMemberOf pres,eq
olcDbIndex: hasMember pres,eq
olcDbIndex: proxyAddresses pres,eq,sub
olcDbMaxReaders: 96
olcDbMaxSize: 32212254720
olcDbMode: 0600
olcDbSearchStack: 16
structuralObjectClass: olcMdbConfig
dn: olcOverlay={0}syncprov,olcDatabase={1}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcConfig
objectClass: top
objectClass: olcSyncProvConfig
olcOverlay: {0}syncprov
structuralObjectClass: olcSyncProvConfig
dn: olcOverlay={1}accesslog,olcDatabase={1}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcAccessLogConfig
olcOverlay: {1}accesslog
olcAccessLogDB: cn=accesslog
olcAccessLogOps: writes
olcAccessLogPurge: 02+00:00 00+04:00
olcAccessLogSuccess: TRUE
structuralObjectClass: olcAccessLogConfig
dn: olcOverlay={2}dynlist,olcDatabase={1}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcDynListConfig
olcOverlay: {2}dynlist
olcDynListAttrSet: {0}groupOfURLs memberURL member+memberOf@groupOfNames
structuralObjectClass: olcDynListConfig
--
/****************************
Mark Cairney
ITI Enterprise Services
Information Services
University of Edinburgh
Tel: 0131 650 6565
Email: Mark.Cairney(a)ed.ac.uk
*******************************/
The University of Edinburgh is a charitable body, registered in Scotland, with registration number SC005336. Is e buidheann carthannais a th’ ann an Oilthigh Dhùn Èideann, clàraichte an Alba, àireamh clàraidh SC005336.
2 months, 2 weeks
Replication N-way
by bourguijl＠gmail.com
Dears,
I've 4 masters in mirror mode and I try to sort out of replication issue for config DB.
When I modify one parameter, sometimes it's replicated on all masters but for some other modification it's not.
Here is extract from logs :
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: do_syncrep2: rid=003 cookie=rid=003,sid=003
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: syncrepl_message_to_entry: rid=003 DN: olcDatabase={0}config,cn=config, UUID: 94f2e3c6-7209-102f-9dc5-7b3f1ec29d0e
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: syncrepl_entry: rid=003 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_MODIFY) csn=(none) tid 0x7f5f890fb700
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: dn_callback : entries have identical CSN olcDatabase={0}config,cn=config 20210921161430.588403Z#000000#002#000000
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: syncrepl_entry: rid=003 be_search (0)
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: syncrepl_entry: rid=003 olcDatabase={0}config,cn=config
Sep 21 18:14:57 obesulus prod-corp-M[3073666]: syncrepl_entry: rid=003 entry unchanged, ignored (olcDatabase={0}config,cn=config)
I don't know why I've this "entries have identical CSN" while entry has been modified on one master.
I checked my syncrepl definition against URI and it's OK so I don't know what's the clue.
Can you help me ?
Thx,
Jean-Luc.
1 year, 5 months
OpenLDAP 2.6.0 testing call #2
by Quanah Gibson-Mount
This is the second testing call for OpenLDAP 2.6.0 Release. Depending on
the results, this may be the final testing call.
Generally, get the code for RE26:
<https://git.openldap.org/openldap/openldap/-/archive/OPENLDAP_REL_ENG_2_6...>
Extract, configure, and build.
Execute the test suite (via make test) after it is built. Optionally, cd
tests && make its to run through the regression suite.
A list of items fixed and added in 2.6 can be found at:
<https://bugs.openldap.org/buglist.cgi?bug_status=RESOLVED&bug_status=VERI...>
A major change with 2.6 is the ability to bypass syslog for logging
(ITS#6949). This significantly improves slapd performance. Currently this
is being adjusted so that lloadd also supports this new feature, but it can
be tested with slapd at this time.
Additionally, the following deprecated backends have been removed:
back-ndb
back-shell
Known issues:
*) The standalone form of lloadd does not honor olcLogLevel when combined
with the new logging parameters. It will honor debug level settings passed
via the -d option.
*) The standalone form of lloadd can deadlock if the monitor backend is
enabled.
Regards,
Quanah
--
Quanah Gibson-Mount
Product Architect
Symas Corporation
Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
<http://www.symas.com>
1 year, 5 months
2.5.7 - help understanding syslog local4
by Dave Macias
Hello,
On 2.4.X i didnt have any issues using rsyslog with "local4.*
/var/log/slapd/slapd.log" and I would get all the connection and searches
done on the db. Which was great!!
I am having a hard time doing the same thing with 2.5.7.
Without any changes to the service file, just running slapd on rocky linux
8 i get these logs on /var/log/slapd/slapd.log only
Sep 23 10:10:18 localhost slapd[3992243]: @(#) $OpenLDAP: slapd 2.5.7 (Aug
19 2021 17:48:53) $#012#011mockbuild@3b6af787015541c89363999d4338d587
:/builddir/build/BUILD/openldap-2.5.7/servers/slapd
If i change the service file with (-d 256):
ExecStart=/opt/symas/lib/slapd -d 256 -h ${SLAPD_URLS} $SLAPD_OPTIONS
I get at least these msgs:
614c8ac4.0dc359b2 0x7fdf0f91f700 conn=1000 fd=17 ACCEPT from
IP=[xxxx]:55556 (IP=[xxxx]:389)
614c8ac4.0dc5b882 0x7fdf0f91f700 conn=1000 op=0 BIND dn="" method=128
614c8ac4.0dc709f0 0x7fdf0f91f700 conn=1000 op=0 RESULT tag=97 err=0
qtime=0.000016 etime=0.000135 text=
614c8ac4.17c7146d 0x7fdf0f91f700 conn=1000 op=1 SRCH
base="dc=domain,dc=net" scope=2 deref=0 filter="(objectClass=*)"
614c8ac4.36abd8fd 0x7fdf0f91f700 conn=1000 op=1 SEARCH RESULT tag=101 err=4
qtime=0.000028 etime=0.518395 nentries=500 text=
614c8ac5.06b07c4b 0x7fdf0f91f700 conn=1000 op=2 UNBIND
614c8ac5.06b1d67d 0x7fdf0f91f700 conn=1000 fd=17 closed
But unfortunately I do not get them to log into my slapd.log file.
I even added -l local4 but no change.
Is (-d 256) even correct?
/opt/symas/lib/slapd -d ?
Installed log subsystems:
Any (-1, 0xffffffff)
Trace (1, 0x1)
Packets (2, 0x2)
Args (4, 0x4)
Conns (8, 0x8)
BER (16, 0x10)
Filter (32, 0x20)
Config (64, 0x40)
ACL (128, 0x80)
Stats (256, 0x100)
Stats2 (512, 0x200)
Shell (1024, 0x400)
Parse (2048, 0x800)
Sync (16384, 0x4000)
None (32768, 0x8000)
Any input as to what I may be doing wrong is much appreciated!
Thank you,
Dave
1 year, 5 months
Communication exception during 500+ concurrent requests
by shekhar.shrinivasan＠gmail.com
Hi,
Was load testing against openldap (slapd-meta) where we were trying to submit 1000 concurrent bind requests. This was done using the JMeter load testing tool. In every run approximately only 420-430 bind requests are successful and remaining 500+ bind requests fail with "Communication Exception" error. We also tried with 500 bind requests and the result was somewhat same - 420 odd successful and 70-80 failed with communication exception.
We have openldap 2.4.56 installed on a RHEL 8.1 host with 32GB memory and 8CPU. We have configured max open files for the slapd process to be 65K .
Our requirement is to support 6000 concurrent requests at minimum. Is there any configuration that can be tweaked to support this amount of concurrent load ? I do see "olcConcurrency" & "olcThreads" set to 0 and 16 respectively. Should we be tweaking these to support the required load, if yes what should be the values for those ? Please assist. Thank you for your help !
1 year, 5 months
Re: OpenLDAP 2.6.0 testing call
by Nick Folino
Yes. I saw the update and tested it this morning.
It's working now as I had previously assumed it would.
Nick
On Thu, Sep 30, 2021 at 11:38 AM Quanah Gibson-Mount <quanah(a)symas.com>
wrote:
>
>
> --On Wednesday, September 29, 2021 7:36 PM -0400 Nick Folino
> <nick(a)folino.us> wrote:
>
> >
> > Yes. Logging now continues to work after changes to config.
> >
> >
> > But - adding levels works on the fly, but removing them doesn't.
> > For instance this works fine:
> > olcLogLevel: stats
> >
> >
> > If I change it to "stats ACL" then the ACL data starts getting added to
> > the log. No restart required.
> > If I change it back to "stats" I keep getting ACL data until the
> > directory is restarted.
>
> This should now be fixed.
>
> --Quanah
>
> --
>
> Quanah Gibson-Mount
> Product Architect
> Symas Corporation
> Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
> <http://www.symas.com>
>
1 year, 5 months
Re: OpenLDAP 2.6.0 testing call
by Nick Folino
Yes. Logging now continues to work after changes to config.
But - adding levels works on the fly, but removing them doesn't.
For instance this works fine:
olcLogLevel: stats
If I change it to "stats ACL" then the ACL data starts getting added to the
log. No restart required.
If I change it back to "stats" I keep getting ACL data until the directory
is restarted.
Nick
On Wed, Sep 29, 2021 at 5:49 PM Quanah Gibson-Mount <quanah(a)symas.com>
wrote:
>
>
> --On Wednesday, September 29, 2021 9:17 AM -0400 Nick Folino
> <nick(a)folino.us> wrote:
>
> >
> > I don't know what the expected results should be, but changing
> > olcLogLevel while running causes all logging to the specified file to
> > stop.
> >
> > Logging starts with the new level upon restart.
>
> This should now be fixed. :)
>
> --Quanah
>
>
> --
>
> Quanah Gibson-Mount
> Product Architect
> Symas Corporation
> Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
> <http://www.symas.com>
>
1 year, 5 months
Re: OpenLDAP 2.6.0 testing call
by Nick Folino
Verified. New log options look good on Fedora 34.
No issues with tests either.
Thanks!
Nick
On Tue, Sep 28, 2021 at 3:10 PM Quanah Gibson-Mount <quanah(a)symas.com>
wrote:
>
>
> --On Friday, September 17, 2021 10:13 AM -0700 Quanah Gibson-Mount
> <quanah(a)symas.com> wrote:
>
> >
> >
> > --On Tuesday, September 7, 2021 7:07 PM -0400 Nick Folino
> > <nick(a)folino.us> wrote:
> >
> >>
> >> Thanks Quanah. olcLogFile and olcLogFileOnly seem to have no effect.
> >> Using them I still get logs only to the journal on Fedora 34.
> >
> > Hi Nick,
> >
> > I was able to reproduce this and have reopened the issue report.
>
> This is now fixed for slapd, work pending to fix for lloadd.
>
> --Quanah
>
>
> --
>
> Quanah Gibson-Mount
> Product Architect
> Symas Corporation
> Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
> <http://www.symas.com>
>
1 year, 5 months
Re: OpenLDAP 2.6.0 testing call
by Nick Folino
Thanks Quanah. olcLogFile and olcLogFileOnly seem to have no effect.
Using them I still get logs only to the journal on Fedora 34.
Nick
On Tue, Sep 7, 2021 at 5:19 PM Quanah Gibson-Mount <quanah(a)symas.com> wrote:
>
>
> --On Tuesday, September 7, 2021 4:15 PM -0400 Nick Folino <nick(a)folino.us>
>
> wrote:
>
> >
> > No issues on Fedora 34. Any docs on how to work with the new logging
> > options?
>
> See slapd.conf(5) or slapd-config(5). In slapd.conf(5), search for
> "logfile", in slapd-config(5), search for olcLogFile
>
>
> Regards,
> Quanah
>
>
>
> --
>
> Quanah Gibson-Mount
> Product Architect
> Symas Corporation
> Packaged, certified, and supported LDAP solutions powered by OpenLDAP:
> <http://www.symas.com>
>
1 year, 5 months
RESULT etime vs. qtime
by Michael Ströder
HI!
I'm adapting my mtail program for log-based slapd metrics for release 2.5.
2.5 introduces qtime= and etime= in RESULT lines. Great!
I could easily grab histogram metrics for both but that doubles
time-series data in Prometheus.
So I wonder what's the difference? Is it worth to always look at both?
Ciao, Michael.
1 year, 5 months
