Re: (ITS#4375) MOD operations not being logged

[quanah@stanford.edu]

On Wednesday 08 February 2006 15:18, hyc@symas.com wrote:
> I don't see any processing error here. The mod operation is rejected
> before the Statslog statement is reached. The same can occur for all of
> the operation types if input validation fails before reaching the
> Statslog. In other words, Statslog only records properly formatted
> requests.

I'm sorry, but what you are saying makes no sense.  There is a MOD line here 
that is missing.  It should absolutely log what was trying to be MODIFIED 
where the MODIFICATION failed.  If Statslog isn't doing this, then it is flat 
out broken.

In the previous example, I should have seen something like:

Feb 8 14:38:08 helpus2.Stanford.EDU slapd[8605]: [ID 588225 local4.debug] 
conn=1 op=1 MOD dn="user.1,ou=peons,dc=stanford,dc=edu"
Feb  8 14:38:08 helpus2.Stanford.EDU slapd[8605]: [ID 588225 local4.debug] 
conn=1 op=1 RESULT tag=103 err=19 text=displayName: multiple values provided

Instead I just see:

Feb  8 14:38:08 helpus2.Stanford.EDU slapd[8605]: [ID 588225 local4.debug] 
conn=1 op=1 RESULT tag=103 err=19 text=displayName: multiple values provided

The fact that only the failure is being logged, and not what entry the MOD 
failed on is a BUG.  This didn't happen with the earlier 2.3 releases, i.e, 
this is new behavior with 2.3.19.

I note I'm using loglevel 256.  "loglevel 256" in the slapd.conf file 
specifically states that it:


              256  (0x100        stats)        stats         log
                    connections/operations/results

So according to that definition:

connections should be logged
operations should be logged
results should be logged

However, as noted above, the operation "MOD" is *not* being logged.  This is 
an obvious violation of what slapd.conf purports.

As an alternative example, here is what I believe you would call a "not 
properly formatted request" that is logged by the uniqueness overlay just 
fine:

Feb  6 01:53:23 ldap0.Stanford.EDU slapd[2620]: [ID 249368 local4.debug] 
conn=5134 op=13 MOD 
dn="suRegID=625a690e9f4911d2bca42436000baa77,cn=People,dc=Stanfo
rd,dc=edu"
Feb  6 01:53:23 ldap0.Stanford.EDU slapd[2620]: [ID 396994 local4.debug] 
conn=5134 op=13 MOD attr=suvisibaffiliation3 sugwaffiliation3 postaladdress 
street s
ugwaffiladdress3 suvisibstreet suvisibaffiladdress3 suproxycardnumber 
sugeneralid sucardnumber
Feb  6 01:53:23 ldap0.Stanford.EDU slapd[2620]: [ID 588225 local4.debug] 
conn=5134 op=13 RESULT tag=103 err=19 text=some attributes not unique


i.e., this is inconsentent behavior on the part of OpenLDAP, and the behavior 
is not matching what is specified in the slapd.conf man page.

--Quanah


-- 
Quanah Gibson-Mount
Principal Software Developer
ITS/Shared Application Services
Stanford University
GnuPG Public Key: http://www.stanford.edu/~quanah/pgp.html