[Date Prev][Date Next] [Chronological] [Thread] [Top]
No entries in Accesslog

To: OpenLDAP-software@OpenLDAP.org
Subject: No entries in Accesslog
From: Michael.Heep@o2.com
Date: Fri, 23 Sep 2005 15:02:43 +0200
Hi,

I'm trying to get the slapo-accesslog overlay to work, but it doesn't seem 
to fill up with any entries.

I'm using OL2.3.7 + BDB4.2.52 + 4 official + OL transactions Patch.
The relevant part of my slapd.conf looks like this:

# accesslog db
database bdb
suffix cn=accesslog
rootdn "cn=root,cn=accesslog"
rootpw <cleartext pass>
directory /var/lib/ldap/openldap-accesslog

index reqStart eq

# db with actual data
database bdb
suffix "dc=o2online,dc=de"
rootdn "cn=root,dc=o2online,dc=de"
rootpw <hashed ;)>
directory /var/lib/ldap/openldap-data

overlay accesslog
logdb cn=accesslog
logops all
logpurge 30+00:00 01+:00:00

index objectclass eq
... other indices, uniqueness overlay, etc ...


When I issue an ldapsearch -b "dc=o2online,dc=de" -D 
"uid=<myuid>,ou=People,dc=o2online,dc=de" -h ldap://<ldaphost> -W -x -ZZ 
objectclass=* I get all the results I'm supposed to get from the directory 
server.

Issueing an ldapsearch -b "cn=accesslog" -D "cn=root,cn=accesslog" -W -x 
-ZZ -H ldap://<ldaphost> objectlass=* returns a result: 32 No such object

Probably I'm missing something or it's simply not in the documentation.
The slapd log with loglevel -1 contains the following after starting up 
and issueing the ldapsearch on cn=accesslog:

Sep 23 14:22:44 sgmldap02 slapd[23385]: slapd startup: initiated. 
Sep 23 14:22:44 sgmldap02 slapd[23385]: backend_startup_one: starting 
"cn=config" 
Sep 23 14:22:44 sgmldap02 slapd[23385]: backend_startup_one: starting 
"cn=accesslog" 
Sep 23 14:22:44 sgmldap02 slapd[23385]: bdb_db_open: cn=accesslog 
Sep 23 14:22:44 sgmldap02 slapd[23385]: bdb_db_open: Warning - No 
DB_CONFIG file found in directory /var/lib/ldap/openldap-accesslog: (2) 
Expect poor performance for suffix cn=accesslog. 
Sep 23 14:22:44 sgmldap02 slapd[23385]: bdb_db_open: 
dbenv_open(/var/lib/ldap/openldap-accesslog) 
Sep 23 14:22:44 sgmldap02 slapd[23385]: backend_startup_one: starting 
"dc=o2online,dc=de" 
Sep 23 14:22:44 sgmldap02 slapd[23385]: bdb_db_open: dc=o2online,dc=de 
Sep 23 14:22:44 sgmldap02 slapd[23385]: bdb_db_open: 
dbenv_open(/var/lib/ldap/openldap-data) 
Sep 23 14:22:44 sgmldap02 slapd[23385]: unique_open: overlay initialized 
Sep 23 14:22:44 sgmldap02 slapd[23385]: slapd starting 
Sep 23 14:22:44 sgmldap02 slapd[23385]: daemon: added 4r 
Sep 23 14:22:44 sgmldap02 slapd[23385]: daemon: added 6r 
Sep 23 14:22:44 sgmldap02 slapd[23385]: daemon: added 7r 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_entry_get: ndn: 
"dc=o2online,dc=de" 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_entry_get: oc: "(null)", 
at: "contextCSN" 
Sep 23 14:22:45 sgmldap02 slapd[23385]: bdb_dn2entry("dc=o2online,dc=de") 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_dn2id("dc=o2online,dc=de") 
Sep 23 14:22:45 sgmldap02 slapd[23385]: <= bdb_dn2id: got id=0x00000001 
Sep 23 14:22:45 sgmldap02 slapd[23385]: entry_decode: "dc=o2online,dc=de" 
Sep 23 14:22:45 sgmldap02 slapd[23385]: <= entry_decode(dc=o2online,dc=de) 

Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_entry_get: found entry: 
"dc=o2online,dc=de" 
Sep 23 14:22:45 sgmldap02 slapd[23385]: bdb_entry_get: rc=0 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => access_allowed: read access to 
"dc=o2online,dc=de" "contextCSN" requested 
Sep 23 14:22:45 sgmldap02 slapd[23385]: <= root access granted 
Sep 23 14:22:45 sgmldap02 slapd[23385]: connection_get(14) 
Sep 23 14:22:45 sgmldap02 slapd[23385]: connection_get(14): got connid=0 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: added 14r 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:45 sgmldap02 slapd[23385]:  14r
Sep 23 14:22:45 sgmldap02 slapd[23385]: 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: read activity on 14 
Sep 23 14:22:45 sgmldap02 slapd[23385]: connection_get(14) 
Sep 23 14:22:45 sgmldap02 slapd[23385]: connection_get(14): got connid=0 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_search 
Sep 23 14:22:45 sgmldap02 slapd[23385]: bdb_dn2entry("cn=accesslog") 
Sep 23 14:22:45 sgmldap02 slapd[23385]: => bdb_dn2id("cn=accesslog") 
Sep 23 14:22:45 sgmldap02 slapd[23385]: <= bdb_dn2id: get failed: 
DB_NOTFOUND: No matching key/data pair found (-30990) 
Sep 23 14:22:45 sgmldap02 slapd[23385]: send_ldap_result: conn=-1 op=0 p=0 

Sep 23 14:22:45 sgmldap02 slapd[23385]: send_ldap_result: err=10 
matched="" text="" 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:45 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: new connection on 15 
Sep 23 14:22:46 sgmldap02 slapd[23385]: conn=0 fd=15 ACCEPT from 
IP=127.0.0.1:32836 (IP=0.0.0.0:389) 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: added 15r 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:46 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:46 sgmldap02 slapd[23385]: 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:46 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:46 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:46 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:46 sgmldap02 slapd[23385]: ber_get_next on fd 15 failed 
errno=11 (Resource temporarily unavailable) 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:46 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:46 sgmldap02 slapd[23385]: do_extended 
Sep 23 14:22:47 sgmldap02 slapd[23385]: do_extended: 
oid=1.3.6.1.4.1.1466.20037 
Sep 23 14:22:47 sgmldap02 slapd[23385]: conn=0 op=0 STARTTLS 
Sep 23 14:22:47 sgmldap02 slapd[23385]: send_ldap_extended: err=0 oid= 
len=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: send_ldap_response: msgid=1 
tag=120 err=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: conn=0 op=0 RESULT oid= err=0 
text= 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:47 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:47 sgmldap02 slapd[23385]: 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:47 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:47 sgmldap02 slapd[23385]: 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: connection_read(15): unable to get 
TLS client DN, error=49 id=0 
Sep 23 14:22:47 sgmldap02 slapd[23385]: conn=0 fd=15 TLS established 
tls_ssf=256 ssf=256 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:47 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:48 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:48 sgmldap02 slapd[23385]: 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:48 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:48 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:48 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:48 sgmldap02 slapd[23385]: ber_get_next on fd 15 failed 
errno=11 (Resource temporarily unavailable) 
Sep 23 14:22:48 sgmldap02 slapd[23385]: do_bind 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:48 sgmldap02 slapd[23385]: >>> dnPrettyNormal: 
<cn=root,cn=accesslog> 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:48 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:48 sgmldap02 slapd[23385]: <<< dnPrettyNormal: 
<cn=root,cn=accesslog>, <cn=root,cn=accesslog> 
Sep 23 14:22:48 sgmldap02 slapd[23385]: do_bind: version=3 
dn="cn=root,cn=accesslog" method=128 
Sep 23 14:22:48 sgmldap02 slapd[23385]: conn=0 op=1 BIND 
dn="cn=root,cn=accesslog" method=128 
Sep 23 14:22:48 sgmldap02 slapd[23385]: ==> bdb_bind: dn: 
cn=root,cn=accesslog 
Sep 23 14:22:48 sgmldap02 slapd[23385]: conn=0 op=1 BIND 
dn="cn=root,cn=accesslog" mech=SIMPLE ssf=0 
Sep 23 14:22:48 sgmldap02 slapd[23385]: do_bind: v3 bind: 
"cn=root,cn=accesslog" to "cn=root,cn=accesslog" 
Sep 23 14:22:48 sgmldap02 slapd[23385]: send_ldap_result: conn=0 op=1 p=3 
Sep 23 14:22:48 sgmldap02 slapd[23385]: send_ldap_result: err=0 matched="" 
text="" 
Sep 23 14:22:48 sgmldap02 slapd[23385]: send_ldap_response: msgid=2 tag=97 
err=0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: conn=0 op=1 RESULT tag=97 err=0 
text= 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:49 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:49 sgmldap02 slapd[23385]: 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: ber_get_next on fd 15 failed 
errno=11 (Resource temporarily unavailable) 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: do_search 
Sep 23 14:22:49 sgmldap02 slapd[23385]: >>> dnPrettyNormal: <cn=accesslog> 

Sep 23 14:22:49 sgmldap02 slapd[23385]: <<< dnPrettyNormal: 
<cn=accesslog>, <cn=accesslog> 
Sep 23 14:22:49 sgmldap02 slapd[23385]: SRCH "cn=accesslog" 2 0
Sep 23 14:22:49 sgmldap02 slapd[23385]:     0 0 0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: begin get_filter 
Sep 23 14:22:49 sgmldap02 slapd[23385]: PRESENT 
Sep 23 14:22:49 sgmldap02 slapd[23385]: end get_filter 0 
Sep 23 14:22:49 sgmldap02 slapd[23385]:     filter: (objectClass=*) 
Sep 23 14:22:49 sgmldap02 slapd[23385]:     attrs:
Sep 23 14:22:49 sgmldap02 slapd[23385]: 
Sep 23 14:22:49 sgmldap02 slapd[23385]: conn=0 op=2 SRCH 
base="cn=accesslog" scope=2 deref=0 filter="(objectClass=*)" 
Sep 23 14:22:49 sgmldap02 slapd[23385]: => bdb_search 
Sep 23 14:22:49 sgmldap02 slapd[23385]: bdb_dn2entry("cn=accesslog") 
Sep 23 14:22:49 sgmldap02 slapd[23385]: => bdb_dn2id("cn=accesslog") 
Sep 23 14:22:49 sgmldap02 slapd[23385]: <= bdb_dn2id: get failed: 
DB_NOTFOUND: No matching key/data pair found (-30990) 
Sep 23 14:22:49 sgmldap02 slapd[23385]: send_ldap_result: conn=0 op=2 p=3 
Sep 23 14:22:49 sgmldap02 slapd[23385]: send_ldap_result: err=10 
matched="" text="" 
Sep 23 14:22:49 sgmldap02 slapd[23385]: send_ldap_response: msgid=3 
tag=101 err=32 
Sep 23 14:22:49 sgmldap02 slapd[23385]: conn=0 op=2 SEARCH RESULT tag=101 
err=32 nentries=0 text= 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on:
Sep 23 14:22:49 sgmldap02 slapd[23385]:  15r
Sep 23 14:22:49 sgmldap02 slapd[23385]: 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: read activity on 15 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_get(15) 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_get(15): got connid=0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_read(15): checking for 
input on id=0 
Sep 23 14:22:49 sgmldap02 slapd[23385]: do_unbind 
Sep 23 14:22:49 sgmldap02 slapd[23385]: conn=0 op=3 UNBIND 
Sep 23 14:22:49 sgmldap02 slapd[23385]: ber_get_next on fd 15 failed 
errno=0 (Success) 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_read(15): input 
error=-2 id=0, closing. 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_closing: readying 
conn=0 sd=15 for close 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_close: deferring conn=0 
sd=15 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: activity on 1 descriptors 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=6 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: daemon: select: listen=7 
active_threads=0 tvp=zero 
Sep 23 14:22:49 sgmldap02 slapd[23385]: connection_resched: attempting 
closing conn=0 sd=15 
Sep 23 14:22:50 sgmldap02 slapd[23385]: connection_close: conn=0 sd=15 
Sep 23 14:22:50 sgmldap02 slapd[23385]: daemon: removing 15 
Sep 23 14:22:50 sgmldap02 slapd[23385]: conn=0 fd=15 closed 

Any help would be much apreciated. 

Regards,
Michael Heep
Follow-Ups:
- Re: No entries in Accesslog
  - From: Howard Chu <hyc@symas.com>
Prev by Date: Re: OpenLDAP with PostgreSQL backend, berkley just don't work for me.
Next by Date: Re: No entries in Accesslog
Index(es):
- Chronological
- Thread