5:36 a.m.
Writing a script for parsing openldap logs I found that, for some of my
connections, the BIND log entry precedes the corresponding ACCEPT entry
(which as far as i understand must logically precede the BIND)
example:
2016-01-25T12:54:02.131094+01:00 HOSTNAME slapd[15258]: conn=91596 op=0
BIND dn="" method=128
2016-01-25T12:54:02.131099+01:00 HOSTNAME slapd[15258]: conn=91596 op=0
RESULT tag=97 err=0 text=
2016-01-25T12:54:02.131103+01:00 HOSTNAME slapd[15258]: conn=91596 fd=93
ACCEPT from [CUT]
slapd is started with the '-l local4' parameter, and rsyslogd is
configured to send local4.* to the openldap.log file
suspecting some rsyslogd problems i tried running slapd using the "-d
256" parameter, but in the output i found
56a6202b conn=1004 op=0 BIND dn="" method=128
56a6202b conn=1004 op=0 RESULT tag=97 err=0 text=
56a6202b conn=1004 fd=13 ACCEPT from [CUT]
Is there any way to guarantee openldap to generate ordered logs?
thanks,
dario
8:24 a.m.
On 25. jan. 2016 14:36, Dario Zanzico wrote:
Writing a script for parsing openldap logs I found that, for some of
my
connections, the BIND log entry precedes the corresponding ACCEPT entry
(which as far as i understand must logically precede the BIND)
(...)
Is there any way to guarantee openldap to generate ordered logs?
Maybe it would work to move Statslog( ... ACCEPT ...)
above ldap_pvt_thread_mutex_unlock( &c->c_mutex );
at the end of servers/slapd/connection.c:connection_init().
Holding on to the mutex longer would make slapd a bit
less responsive, though. No idea how much.
Another variant: Put the cost in the log parser instead.
When you see an ACCEPT, delay processing log lines until
you've seen some more lines, in case they are out of order.
I've got an old tweak to contrib/slapd-tools/statslog
which does that and some other stuff, here:
<http://folk.uio.no/hbf/OpenLDAP/statslog.reorder>
Don't remember why I haven't committed it. Maybe
it isn't quite finished or I hoped to optimize it,
since it does slow the script down. I'd be glad to
hear of any improvements from you:-)
Come to think of it, statslog is quite old. It
might need some tweaks to catch up with whatever has
been done to OpenLDAP logs since it was written.
--
Hallvard
3:28 a.m.
On Tue, Jan 26, 2016, at 05:24 PM, Hallvard Breien Furuseth wrote:
Maybe it would work to move Statslog( ... ACCEPT ...)
above ldap_pvt_thread_mutex_unlock( &c->c_mutex );
at the end of servers/slapd/connection.c:connection_init().
Holding on to the mutex longer would make slapd a bit
less responsive, though. No idea how much.
That's kinda what I initially expected openldap to do :D
Another variant: Put the cost in the log parser instead.
yep, that's the way I worked around this problem
When you see an ACCEPT, delay processing log lines until
you've seen some more lines, in case they are out of order.
I've got an old tweak to contrib/slapd-tools/statslog
which does that and some other stuff, here:
<http://folk.uio.no/hbf/OpenLDAP/statslog.reorder>
I was sending my logs through
syslog=>logstash=>elasticsearch
correlating binds and accepts in logstash (whose filters prevented
me to easily implement delays)
So, considering the rarity of the mixed log entries, I decided to:
1) save both accept and bind entries in elasticsearch
2) keep correlating events in passing through logstash, if possible
3) schedule a script which "correlates uncorrelated" binds and deletes
old
connections data from elasticsearch
Don't remember why I haven't committed it. Maybe
it isn't quite finished or I hoped to optimize it,
since it does slow the script down. I'd be glad to
hear of any improvements from you:-)
Perl scares me :)
Come to think of it, statslog is quite old. It
might need some tweaks to catch up with whatever has
been done to OpenLDAP logs since it was written.
I suppose it would be nice to have an option to force Openldap to
write ordered logs (obviously with a performance penalty).
Or maybe enabling logging the real operation timestamp (as in:
generated just before the operation itself), enabling a simple filter to
reorder logs.
Thanks
Hallvard
dario
2687
days inactive
2689
days old
openldap-technical@openldap.org
2 comments
2 participants
participants (2)
-
Dario Zanzico -
Hallvard Breien Furuseth