[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: AccessLog behaviour

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