Just to share experience with the community, my problem was related to idlcachesize, that was (relatively) too small for the dimension of my db. I augmented that value to a very larger value and performances increases very much.
Just to give a concrete example of what I'm saying, my purge job went from:
- search and delete of "1-day entries" in about 22hours
to
- search and delete of "9-days entries" in 40minutes
Marco
On Thu, Feb 3, 2011 at 7:23 PM, Marco Pizzoli marco.pizzoli@gmail.comwrote:
Hi Howard, probably you are addressing me to this part:
"When using a log database that supports ordered indexing on generalizedTime attributes, specifying an eq index on the* reqStart*attribute will greatly benefit the performance of the purge operation."
My accesslog db is back-hdb and I have that eq index defined, but however my slapd seems to work slowly. I can see in that logs that the presented search appear only 14 per second, so I'm purging more slowly than writing to it.
I would like to know if I made a configuration mistake.
Thanks again Marco
On Thu, Feb 3, 2011 at 6:40 PM, Howard Chu hyc@symas.com wrote:
Marco Pizzoli wrote:
Hi all, I would like to know the internal behaviour of slapo-accesslog.
Read the slapo-accesslog(5) manpage. Re-read the logpurge description and don't skip any of it.
I would like to have accesslog with a data retention of 10 days. In my
ldap usage scenario this retention produce an accesslog db of quite 10GB of data.
Things are working quite fine, but when the log db contains data older than the retention I defined after restart slapd has a thread allocated at 100% of cpu of one processor. I logged at loglevel 992 = 512 + 256 + 128 + 64 + 32, blocked with iptables every external ldap access and saw these lines in the log:
[cut] Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042854.000008Z,cn=log03,dc=mycorp.it <http://mycorp.it
"
"reqStart" requested Feb 3 09:37:08 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:08 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:08 ldap03 slapd[16289]: => test_filter Feb 3 09:37:08 ldap03 slapd[16289]: LE Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042854.000010Z,cn=log03,dc=mycorp.it" "reqStart" requested Feb 3 09:37:08 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:08 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:08 ldap03 slapd[16289]: => test_filter Feb 3 09:37:08 ldap03 slapd[16289]: LE Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042854.000012Z,cn=log03,dc=mycorp.it" "reqStart" requested Feb 3 09:37:08 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:08 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:08 ldap03 slapd[16289]: => test_filter Feb 3 09:37:08 ldap03 slapd[16289]: LE Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042854.000014Z,cn=log03,dc=mycorp.it" "reqStart" requested Feb 3 09:37:08 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:08 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:08 ldap03 slapd[16289]: => test_filter Feb 3 09:37:08 ldap03 slapd[16289]: LE Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042855.000000Z,cn=log03,dc=mycorp.it" "reqStart" requested Feb 3 09:37:08 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:08 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:08 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:09 ldap03 slapd[16289]: => test_filter Feb 3 09:37:09 ldap03 slapd[16289]: LE Feb 3 09:37:09 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042855.000002Z,cn=log03,dc=mycorp.it" "reqStart" requested Feb 3 09:37:09 ldap03 slapd[16289]: <= root access granted Feb 3 09:37:09 ldap03 slapd[16289]: => access_allowed: search access granted by manage(=mwrscxd) Feb 3 09:37:09 ldap03 slapd[16289]: <= test_filter 6 Feb 3 09:37:09 ldap03 slapd[16289]: => test_filter Feb 3 09:37:09 ldap03 slapd[16289]: LE Feb 3 09:37:09 ldap03 slapd[16289]: => access_allowed: search access to "reqStart=20110202042855.000004Z,cn=log03,dc=mycorp.it" "reqStart" requested [cut]
I could assume that slapo-accesslog is querying all entries older than the retention and passes to delete them.
What if this step to end the job will take more time than the interval time of re-starting? Augmenting the frequency of this job could help in this meaning?
Every best practice to follow to use accesllog effectively will be very appreciated! :-)
Thanks Marco Pizzoli
-- _________________________________________ Non è forte chi non cade, ma chi cadendo ha la forza di rialzarsi. Jim Morrison
-- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/
-- _________________________________________ Non è forte chi non cade, ma chi cadendo ha la forza di rialzarsi. Jim Morrison