If MMR - perhaps via log consolidation - e.g. ELK stack (grok filter)? Similar to https://discuss.elastic.co/t/how-filter-openldap-logs/2492. ________________________________________ From: 389-users-bounces(a)lists.fedoraproject.org [389-users-bounces(a)lists.fedoraproject.org] on behalf of Burn Alting [burn(a)swtf.dyndns.org] Sent: Friday, July 03, 2015 04:49 To: 389-users(a)lists.fedoraproject.org Subject: [389-users] 389-ds access.log parsing - turning LDAP request type into an audit event Has anyone authored code to parse a 389 Directory Server's access.log file(s) with an aim of generating audit events based around the LDAP request type. Basically, take the log sequence [21/Apr/2007:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2007:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2007:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [21/Apr/2007:11:39:51 -0700] conn=11 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(uid=bjensen)" [21/Apr/2007:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=1000 notes=U [21/Apr/2007:11:39:51 -0700] conn=11 op=2 UNBIND [21/Apr/2007:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 And turn this into an audit event with a date/time (21/Apr/2007:11:39:51 -0700), a client location (207.1.153.51), server location (192.18.122.139), a user (cn=Directory Manager), an event (SRCH) and event metadata of (query - base="dc=example,dc=com" scope=2 filter="(uid=bjensen)", result set size - 1, timetaken = 1000 sec, etc) The logconv.pl script seems to do all sorts of analysis, but no event representation. Thanks in advance -- 389 users mailing list 389-users(a)lists.fedoraproject.org https://admin.fedoraproject.org/mailman/listinfo/389-users

On 07/03/2015 05:49 AM, Burn Alting wrote: > Has anyone authored code to parse a 389 Directory Server's access.log > file(s) with an aim of generating audit events based around the LDAP > request type. Basically, take the log sequence > > [21/Apr/2007:11:39:51 -0700] conn=11 fd=608 slot=608 connection from > 207.1.153.51 to 192.18.122.139 > [21/Apr/2007:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory > Manager" method=128 version=3 > [21/Apr/2007:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 > nentries=0 etime=0 > [21/Apr/2007:11:39:51 -0700] conn=11 op=1 SRCH > base="dc=example,dc=com" scope=2 filter="(uid=bjensen)" > [21/Apr/2007:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 > nentries=1 etime=1000 notes=U > [21/Apr/2007:11:39:51 -0700] conn=11 op=2 UNBIND > [21/Apr/2007:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 > > And turn this into an audit event with > > a date/time (21/Apr/2007:11:39:51 -0700), a client location > (207.1.153.51), server location (192.18.122.139), a user (cn=Directory > Manager), an event (SRCH) and event metadata of (query - > base="dc=example,dc=com" scope=2 filter="(uid=bjensen)", result set size > - 1, timetaken = 1000 sec, etc) > > The logconv.pl script seems to do all sorts of analysis, but no event > representation. This sounds like a request for a new feature. Would you be able to write up a description of the new feature based on http://www.port389.org/docs/389ds/design/design-template.html? If so, I will post it to the 389 wiki and assign a ticket. > > Thanks in advance > > -- > 389 users mailing list > 389-users(a)lists.fedoraproject.org > https://admin.fedoraproject.org/mailman/listinfo/389-users -- 389 users mailing list 389-users(a)lists.fedoraproject.org https://admin.fedoraproject.org/mailman/listinfo/389-users

On Mon, 2015-07-06 at 08:00 -0600, Rich Megginson wrote: > On 07/03/2015 05:49 AM, Burn Alting wrote: > > Has anyone authored code to parse a 389 Directory Server's access.log > > file(s) with an aim of generating audit events based around the LDAP > > request type. Basically, take the log sequence > > > > [21/Apr/2007:11:39:51 -0700] conn=11 fd=608 slot=608 connection from > > 207.1.153.51 to 192.18.122.139 > > [21/Apr/2007:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory > > Manager" method=128 version=3 > > [21/Apr/2007:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 > > nentries=0 etime=0 > > [21/Apr/2007:11:39:51 -0700] conn=11 op=1 SRCH > > base="dc=example,dc=com" scope=2 filter="(uid=bjensen)" > > [21/Apr/2007:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 > > nentries=1 etime=1000 notes=U > > [21/Apr/2007:11:39:51 -0700] conn=11 op=2 UNBIND > > [21/Apr/2007:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 > > > > And turn this into an audit event with > > > > a date/time (21/Apr/2007:11:39:51 -0700), a client location > > (207.1.153.51), server location (192.18.122.139), a user (cn=Directory > > Manager), an event (SRCH) and event metadata of (query - > > base="dc=example,dc=com" scope=2 filter="(uid=bjensen)", result set size > > - 1, timetaken = 1000 sec, etc) > > > > The logconv.pl script seems to do all sorts of analysis, but no event > > representation. > > This sounds like a request for a new feature. Would you be able to > write up a description of the new feature based on > http://www.port389.org/docs/389ds/design/design-template.html? If so, I > will post it to the 389 wiki and assign a ticket. > Rich, Find the write up below. Regards Burn Alting

Title ----- Parse audit-able events from 389/directory server access logs Overview -------- A utility is required to parse 389/directory server access logs whose output is a well defined record (event) of the LDAP request and any resultant responses. Each event would contain the initiating host address and the current authenticated DN to make subsequent entity access analysis more efficient. In essence, generate a single event for every operation (common op=) performed for a unique connection. The events need to be well formed and consideration given to further downstream parsing. As the access log records are well documented, the output event should minimize changes to the content (if changed at all). The utility would need to support time based queries. That is, generate events between a given start and end time. Note that if the connection and authentication occurs BEFORE the given start time, this detail still needs to decorate the event output. The utility would need to indicate if the authenticated DN or initiating client could not be ascertained. That is, the information is NOT in the file(s) processed. Optionally can ignore internal operations. Use Cases --------- The following cases show a logfile extract and resultant parsed output. The output is in XML. Other well formed and parsable output could be chosen (eg json) - the intent is that downstream capability needs to parse the information. #1 Extract: [21/Apr/2009:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.57 to 192.18.122.139 [21/Apr/2009:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2009:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [21/Apr/2009:11:39:51 -0700] conn=11 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(mobile=+1 123 456-7890)" [21/Apr/2009:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U [21/Apr/2009:11:39:51 -0700] conn=11 op=2 UNBIND [21/Apr/2009:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 Resultant sub-extract and Event output: [21/Apr/2009:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.57 to 192.18.122.139 [21/Apr/2009:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [21/Apr/2009:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0 <Event> <DateTime>21/Apr/2009:11:39:51 -0700</DateTime> <Client>207.1.153.57</Client> <Server>192.18.122.139</Server> <Connection>11</Connection> <Operation>0</Operation> <AuthenticatedDN>cn=Directory Manager</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;cn=Directory Manager&quot; method=128 version=3</Request> </Requests> <Responses> <Response>RESULT err=0 tag=97 nentries=0 etime=0</Response> </Responses> </Event> [21/Apr/2009:11:39:51 -0700] conn=11 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(mobile=+1 123 456-7890)" [21/Apr/2009:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U <Event> <DateTime>21/Apr/2009:11:39:51 -0700</DateTime> <Client>207.1.153.57</Client> <Server>192.18.122.139</Server> <Connection>11</Connection> <Operation>1</Operation> <AuthenticatedDN>cn=Directory Manager</AuthenticatedDN> <Action>SRCH</Action> <Requests> <Request>SRCH base=&quot;dc=example,dc=com&quot; scope=2 filter=&quot;(mobile=+1 123 456-7890)&quot;</Request> </Requests> <Responses> <Response>RESULT err=0 tag=101 nentries=1 etime=3 notes=U</Response> </Responses> </Event> [21/Apr/2009:11:39:51 -0700] conn=11 op=2 UNBIND [21/Apr/2009:11:39:51 -0700] conn=11 op=2 fd=608 closed - U1 <Event> <DateTime>21/Apr/2009:11:39:51 -0700</DateTime> <Client>207.1.153.57</Client> <Server>192.18.122.139</Server> <Connection>11</Connection> <Operation>2</Operation> <AuthenticatedDN>cn=Directory Manager</AuthenticatedDN> <Action>UNBIND</Action> <Requests> <Request>UNBIND</Request> </Requests> <Responses> <Response>fd=608 closed - U1</Response> </Responses> </Event> #2 Extract: [07/May/2009:11:43:28 -0700] conn=877 fd=608 slot=608 connection from 207.1.153.32 to 192.18.122.139 [07/May/2009:11:43:28 -0700] conn=877 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [07/May/2009:11:43:28 -0700] conn=877 op=0 RESULT err=0 tag=97 nentries=0 etime=0 [07/May/2009:11:43:29 -0700] conn=877 op=1 SRCH base="(ou=People)" scope=2 filter="(uid=*)" [07/May/2009:11:43:29 -0700] conn=877 op=1 SORT uid [07/May/2009:11:43:29 -0700] conn=877 op=1 VLV 0:5:0210 10:5397 (0) [07/May/2009:11:43:29 -0700] conn=877 op=1 RESULT err=0 tag=101 nentries=1 etime=0 Resultant sub-extract and Event output: [07/May/2009:11:43:28 -0700] conn=877 fd=608 slot=608 connection from 207.1.153.32 to 192.18.122.139 [07/May/2009:11:43:28 -0700] conn=877 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [07/May/2009:11:43:28 -0700] conn=877 op=0 RESULT err=0 tag=97 nentries=0 etime=0 <Event> <DateTime>07/May/2009:11:43:28 -0700</DateTime> <Client>207.1.153.32</Client> <Server>192.18.122.139</Server> <Connection>877</Connection> <Operation>0</Operation> <AuthenticatedDN>cn=Directory Manager</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;cn=Directory Manager&quot; method=128 version=3</Request> </Requests> <Responses> <Response>RESULT err=0 tag=97 nentries=0 etime=0</Response> </Responses> </Event> [07/May/2009:11:43:29 -0700] conn=877 op=1 SRCH base="(ou=People)" scope=2 filter="(uid=*)" [07/May/2009:11:43:29 -0700] conn=877 op=1 SORT uid [07/May/2009:11:43:29 -0700] conn=877 op=1 VLV 0:5:0210 10:5397 (0) [07/May/2009:11:43:29 -0700] conn=877 op=1 RESULT err=0 tag=101 nentries=1 etime=0 <Event> <DateTime>07/May/2009:11:43:29 -0700</DateTime> <Client>207.1.153.32</Client> <Server>192.18.122.139</Server> <Connection>877</Connection> <Operation>1</Operation> <AuthenticatedDN>cn=Directory Manager</AuthenticatedDN> <Action>SRCH</Action> <Requests> <Request>SRCH base=&quot;(ou=People)&quot; scope=2 filter=&quot;(uid=*)&quot;</Request> <Request>SORT uid</Request> <Request>VLV 0:5:0210 10:5397 (0)</Request> <Responses> <Response>RESULT err=0 tag=101 nentries=1 etime=0</Response> </Responses> </Event> #3 Extract: [21/Apr/2009:11:39:55 -0700] conn=14 fd=700 slot=700 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2009:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2009:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress [21/Apr/2009:11:39:55 -0700] conn=14 op=1 BIND dn="uid=jdoe,dc=example,dc=com" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2009:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com" Resultant sub-extract and Event output: [21/Apr/2009:11:39:55 -0700] conn=14 fd=700 slot=700 connection from 207.1.153.51 to 192.18.122.139 [21/Apr/2009:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2009:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress <Event> <DateTime>21/Apr/2009:11:39:53 -0700</DateTime> <Client>207.1.153.51</Client> <Server>192.18.122.139</Server> <Connection>14</Connection> <Operation>0</Operation> <AuthenticatedDN>__Anonymous__</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;&quot; method=sasl version=3 mech=DIGEST-MD5</Request> </Requests> <Responses> <Response>RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress</Response> </Responses> </Event> [21/Apr/2009:11:39:55 -0700] conn=14 op=1 BIND dn="uid=jdoe,dc=example,dc=com" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2009:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com" <Event> <DateTime>21/Apr/2009:11:39:55 -0700</DateTime> <Client>207.1.153.51</Client> <Server>192.18.122.139</Server> <Connection>14</Connection> <Operation>2</Operation> <AuthenticatedDN>uid=jdoe,dc=example,dc=com</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;uid=jdoe,dc=example,dc=com&quot; method=sasl version=3 mech=DIGEST-MD5</Request> </Requests> <Responses> <Response>RESULT err=0 tag=97 nentries=0 etime=0 dn=&quot;uid=jdoe,dc=example,dc=com&quot;</Response> </Responses> </Event> #4 Extract: [02/Sep/2014:11:05:56 -0400] conn=35 op=1 fd=64 closed - U1 [02/Sep/2014:11:05:56 -0400] conn=36 fd=64 slot=64 connection from 127.0.0.1 to 127.0.0.1 [02/Sep/2014:11:05:56 -0400] conn=36 op=0 BIND dn="" method=128 version=3 [02/Sep/2014:11:05:56 -0400] conn=36 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="" [02/Sep/2014:11:05:56 -0400] conn=36 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(uid=scarter)" attrs="c" [02/Sep/2014:11:05:56 -0400] conn=36 op=1 RESULT err=0 tag=101 nentries=1 etime=0 [02/Sep/2014:11:05:56 -0400] conn=36 op=2 BIND dn="uid=scarter,ou=people,dc=example,dc=com" method=128 version=3 [02/Sep/2014:11:05:56 -0400] conn=36 op=2 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=scarter,ou=people,dc=example,dc=com" [02/Sep/2014:11:05:56 -0400] conn=36 op=3 UNBIND [02/Sep/2014:11:05:56 -0400] conn=36 op=3 fd=64 closed - U1 Resultant sub-extract and Event output: [02/Sep/2014:11:05:56 -0400] conn=36 fd=64 slot=64 connection from 127.0.0.1 to 127.0.0.1 [02/Sep/2014:11:05:56 -0400] conn=36 op=0 BIND dn="" method=128 version=3 [02/Sep/2014:11:05:56 -0400] conn=36 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="" <Event> <DateTime>02/Sep/2014:11:05:56 -0400</DateTime> <Client>127.0.0.1</Client> <Server>127.0.0.1</Server> <Connection>36</Connection> <Operation>0</Operation> <AuthenticatedDN>__Anonymous__</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;&quot; method=128 version=3</Request> </Requests> <Responses> <Response>RESULT err=0 tag=97 nentries=0 etime=0 dn=&quot;&quot;</Response> </Responses> </Event> [02/Sep/2014:11:05:56 -0400] conn=36 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(uid=scarter)" attrs="c" [02/Sep/2014:11:05:56 -0400] conn=36 op=1 RESULT err=0 tag=101 nentries=1 etime=0 <Event> <DateTime>02/Sep/2014:11:05:56 -0400</DateTime> <Client>127.0.0.1</Client> <Server>127.0.0.1</Server> <Connection>36</Connection> <Operation>1</Operation> <AuthenticatedDN>__Anonymous__</AuthenticatedDN> <Action>SRCH</Action> <Requests> <Request>SRCH base=&quot;dc=example,dc=com&quot; scope=2 filter=&quot;(uid=scarter)&quot; attrs=&quot;c&quot;</Request> </Requests> <Responses> <Response>RESULT err=0 tag=101 nentries=1 etime=0</Response> </Responses> </Event> [02/Sep/2014:11:05:56 -0400] conn=36 op=2 BIND dn="uid=scarter,ou=people,dc=example,dc=com" method=128 version=3 [02/Sep/2014:11:05:56 -0400] conn=36 op=2 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=scarter,ou=people,dc=example,dc=com" <Event> <DateTime>02/Sep/2014:11:05:56 -0400</DateTime> <Client>127.0.0.1</Client> <Server>127.0.0.1</Server> <Connection>36</Connection> <Operation>2</Operation> <AuthenticatedDN>uid=scarter,ou=people,dc=example,dc=com</AuthenticatedDN> <Action>BIND</Action> <Requests> <Request>BIND dn=&quot;uid=scarter,ou=people,dc=example,dc=com&quot; method=128 version=3</Request> </Requests> <Responses> <Response>RESULT err=0 tag=97 nentries=0 etime=0 dn=&quot;uid=scarter,ou=people,dc=example,dc=com&quot;</Response> </Responses> </Event> [02/Sep/2014:11:05:56 -0400] conn=36 op=3 UNBIND [02/Sep/2014:11:05:56 -0400] conn=36 op=3 fd=64 closed - U1 <Event> <DateTime>02/Sep/2014:11:05:56 -0400</DateTime> <Client>127.0.0.1</Client> <Server>127.0.0.1</Server> <Connection>36</Connection> <Operation>3</Operation> <AuthenticatedDN>uid=scarter,ou=people,dc=example,dc=com</AuthenticatedDN> <Action>UNBIND</Action> <Requests> <Request>UNBIND</Request> </Requests> <Responses> <Response>fd=64 closed - U1</Response> </Responses> </Event> Design ------ Assuming an extension to the logconv.pl script New options: -A, --audit <ignoreinternal=yes|no> Default: yes Generate well formed events of operations found in the access log(s). Events will contain the identified connected client address and authenticated DN performing the operation. Internal operations, if logged, will be ignored by default. Specify no to emit events for internal operations. Logic flow: for every "active" connection (ie not closed) maintain a list of client, server and current authenticated DN. for every operation for which we have an "active" connection, emit an event at the close of the operation. Implementation -------------- Extend the logconv.pl command as it contains existing access log file management.