[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
proxy cache not really caching?
- To: openldap-technical@openldap.org
- Subject: proxy cache not really caching?
- From: Tyler Gates <tgates81@gmail.com>
- Date: Sat, 13 Jun 2009 10:12:44 -0400
- Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:date:from:to:subject :message-id:x-mailer:mime-version:content-type :content-transfer-encoding; bh=854fUo9Nm3HOfPM6qpqZoCTCatMoEL42+4ScCDAYS5Q=; b=ZZQNj1fmBCjZvJPOfqTCIe4bP6eRH8VzQ/dNzGDpiAoLzcdccKZv4xfVbfDIDGaV2/ sD1nkbEJR/eFTZB4m0asPFSjU+bcGLS47+QZRi4+jIFPHY9mWh3/LGo0NnVGO4pl3+uo 6EMvLUGGPTy+Mo9xXEazs0EX6YZZD8yqw+Cbk=
- Domainkey-signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=date:from:to:subject:message-id:x-mailer:mime-version:content-type :content-transfer-encoding; b=cXZka4+vOben16BX+Wk8Xppz9a3p7HKNx8/zRgRbH+rnMNpYx9jA95bAySlmk5bll9 Dgr2aFSqW6tzew0pvh07Yd8rm1iIHb7MjPmnFpu1jPL9QrlHaqlBZ9v1jwK7HgXNhH4H BmsTTmkVEoGZCXr3yADyQwelwMAYBOza0lYzE=
Hello,
I've been running my openldap 2.4 proxy directory server using
back_ldap and pcache in front of two masters for a few days and have
been a little confused about why I'm not getting more "QUERY ANSWERED"
messages in the logs considering all the "QUERY CACHED" messages.
According to the script I wrote to parse the log file for certain key
words, I'm seeing data like this:
*******************************
QUERIES ANSWERED: 26901
QUERIES NOT ANSWERED: 142386
QUERIES CACHEABLE: 114491
QUERIES NOT CACHEABLE: 27895
-------------------------------
TOTAL QUERIES: 169287
QUERIES ADDED: 114080
QUERIES STORED: 7
QUERY HIT: %15.8907653866
*******************************
As you can see my templates are catching a good majority of the queries
and they appear to be added to cache. For example I see messages like
this: 'Added query expires at 1244899436 (NEGATIVE)'
But even though I've tried bumping the ttl up, I'm still seeing a lot
of QUERY NOT ANSWERABLE messages fly by about queries that should have
been in cache before. For example, this snippet below appears to cache
querystr '(&(objectClass=posixGroup)(memberUid=xfs))' but then one
query later the exact same query comes up and it says its not
answerable and adds it to cache again.
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=99 op=1658 SRCH base="dc=castlebranch,dc=com" scope=2 deref=0 filter="(&(objectClass=posixGroup)(memberUid=xfs))"
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=99 op=1658 SRCH attr=gidNumber
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: query template of incoming query = (&(objectClass=)(memberUid=))
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Entering QC, querystr = (&(objectClass=posixGroup)(memberUid=xfs))
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Lock QC index = 0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Not answerable: Unlock QC index=0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY NOT ANSWERABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY CACHEABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Added query expires at 1244899436 (NEGATIVE)
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Lock AQ index = 0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: TEMPLATE 0x8354560 QUERIES++ 1
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Unlock AQ index = 0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=99 op=1658 SEARCH RESULT tag=101 err=0 nentries=0 text=
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=86 op=1661 SRCH base="dc=castlebranch,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=xfs))"
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: query template of incoming query = (&(objectClass=)(uid=))
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY NOT ANSWERABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY NOT CACHEABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=86 op=1661 SEARCH RESULT tag=101 err=0 nentries=0 text=
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=86 op=1662 SRCH base="dc=castlebranch,dc=com" scope=2 deref=0 filter="(&(objectClass=posixGroup)(memberUid=xfs))"
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: conn=86 op=1662 SRCH attr=gidNumber
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: query template of incoming query = (&(objectClass=)(memberUid=))
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Entering QC, querystr = (&(objectClass=posixGroup)(memberUid=xfs))
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Lock QC index = 0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Not answerable: Unlock QC index=0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY NOT ANSWERABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: QUERY CACHEABLE
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Added query expires at 1244899436 (NEGATIVE)
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Lock AQ index = 0x8354560
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: TEMPLATE 0x8354560 QUERIES++ 1
Jun 13 09:08:56 directory-proxy slapd2.4[20842]: Unlock AQ index =
0x8354560
According to the logs I currently have 7 cached queries and about a
%15.8 hit rate which seems ridiculous given all the 'added query'
messages I'm getting.
Is there something wrong with my caching engine on the directory server
or am I missing something with how the caching mechanism works?
Thanks,
Tyler