Re: (ITS#9051) slapo-accesslog fails to log compare, search

[quanah]

--On Monday, July 08, 2019 11:33 PM + qua...@openldap.org wrote:

Note: compare operations are confirmed also to not log.

:~# ldapcompare -Y EXTERNAL -H ldapi:/// cn=admin,dc=rb,dc=symas,dc=net 
cn:admin
TRUE

ldapsearch -Y EXTERNAL -H ldapi:/// -b cn=accesslog -LLL
dn: cn=accesslog
objectClass: auditContainer
cn: accesslog

dn: reqStart=2019070817.00Z,cn=accesslog
objectClass: auditBind
reqStart: 2019070817.00Z
reqEnd: 2019070817.01Z
reqType: bind
reqSession: 1014
reqAuthzID:
reqDN: cn=admin,dc=rb,dc=symas,dc=net
reqResult: 0
reqVersion: 3
reqMethod: SIMPLE

dn: reqStart=20190709001033.00Z,cn=accesslog
objectClass: auditBind
reqStart: 20190709001033.00Z
reqEnd: 20190709001033.01Z
reqType: bind
reqSession: 1019
reqAuthzID:
reqDN: cn=admin,dc=rb,dc=symas,dc=net
reqResult: 0
reqVersion: 3
reqMethod: SIMPLE


--Quanah



--

Quanah Gibson-Mount
Product Architect
Symas Corporation
Packaged, certified, and supported LDAP solutions powered by OpenLDAP:

(ITS#9051) slapo-accesslog fails to log compare, search

[quanah]

Full_Name: Quanah Gibson-Mount
Version: 2.4.47
OS: N/A
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (47.208.128.44)


In testing out various logging scenarios with the accesslog overlay, it has been
found that it fails to log certain operations in the underlying accesslog DB. 
Specifically, it fails to log "reads" or "compare" + "search".  It does however
log "writes" or "bind".

Example configuration:

dn: olcDatabase={2}mdb,cn=config
objectClass: olcMdbConfig
objectClass: olcDatabaseConfig
olcDatabase: {2}mdb
olcDbDirectory: /var/lib/ldap/accesslog
olcAddContentAcl: FALSE
olcDbIndex: default eq
olcDbIndex: objectClass
olcDbIndex: entryUUID
olcDbIndex: entryCSN
olcDbIndex: reqStart
olcDbIndex: reqEnd
olcDbIndex: reqResult
olcDbIndex: reqDN
olcDbMaxReaders: 0
olcDbMaxSize: 512
olcDbMode: 0600
olcDbNoSync: FALSE
olcDbRtxnSize: 1
olcDbSearchStack: 16
olcLastMod: TRUE
olcMaxDerefDepth: 15
olcMonitoring: TRUE
olcReadOnly: FALSE
olcRootDN: cn=config
olcSuffix: cn=accesslog
olcSyncUseSubentry: FALSE
olcAccess: {0}to * by dn.exact=gidNumber=0+uidNumber=0,cn=peercred,cn=extern
 al,cn=auth manage by * break


dn: olcOverlay={0}accesslog,olcDatabase={1}mdb,cn=config
objectClass: olcAccessLogConfig
objectClass: olcOverlayConfig
olcAccessLogDB: cn=accesslog
olcOverlay: {0}accesslog
olcAccessLogOps: reads
olcAccessLogOps: writes
olcAccessLogPurge: 1+00:00 1+00:00
olcAccessLogSuccess: TRUE


Performing a search in this scenario results in nothing logged.

Changing it to "reads" only (no writes), nothing logged
Changing it to "bind, search, compare", the bind is logged, but nothing else:

root@anvil3:~/accesslog-testing# ldapsearch -Y EXTERNAL -H ldapi:/// -b
cn=accesslog -LLL -Q

dn: cn=accesslog
objectClass: auditContainer
cn: accesslog

dn: reqStart=2019070817.00Z,cn=accesslog
objectClass: auditBind
reqStart: 2019070817.00Z
reqEnd: 2019070817.01Z
reqType: bind
reqSession: 1014
reqAuthzID:
reqDN: cn=admin,dc=rb,dc=symas,dc=net
reqResult: 0
reqVersion: 3
reqMethod: SIMPLE


Search is clearly logged at STATS level logging:

Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 fd=12 ACCEPT from IP=[::1]:51644
(IP=[::]:389)
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=0 BIND
dn="cn=admin,dc=rb,dc=symas,dc=net" method=128
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=0 BIND
dn="cn=admin,dc=rb,dc=symas,dc=net" mech=SIMPLE ssf=0
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=0 RESULT tag=97 err=0 text=
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=1 SRCH
base="dc=rb,dc=symas,dc=net" scope=2 deref=0 filter="(objectClass=*)"
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=1 SEARCH RESULT tag=101 err=0
nentries=2 text=
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 op=2 UNBIND
Jul  8 15:22:17 anvil3 slapd[12993]: conn=1014 fd=12 closed