OpenLDAP Access Log

OpenLDAP access log is an example of a log consisting of multiple different types of events, representing end-user activities during a session. Each event is represented by a record placed on one line. The records may occur in the log in random order - i.e different events from different users are unordered.

It is worth to note that important data elements, such as client IP-address, are not present in all different types of records. This causes several iterations of searches and combining the results when conducting an analysis of activities using a text-based search. We can greatly improve this by extracting the significant data elements so that they can be used directly in the query normalizing records. After that such analysis becomes much simpler and effective.

Example:

Jul 17 16:53:53 server1 slapd[1010]: conn=7448 fd=43 connection from IP=192.168.4.36:40629 (IP=:: 389) accepted.
Jul 17 16:53:53 server1 slapd[1010]: conn=7448 op=0 BIND dn="uid=user1,ou=people,dc=example,dc=com" method=128
Jul 17 16:53:53 server1 slapd[1010]: conn=7448 op=0 RESULT tag=97 err=0 text=
Jul 17 16:53:53 server1 slapd[1010]: conn=7448 op=1 SRCH base="ou=people,dc=example,dc=com" scope=2 filter="(objectClass=*)"
Jul 17 16:53:53 server1 slapd[1010]: conn=7448 op=1 SEARCH RESULT tag=101 err=0 text=
Jul 17 16:53:54 server1 slapd[1010]: conn=7448 op=2 UNBIND
Jul 17 16:53:54 server1 slapd[1010]: conn=-1 fd=43 closed

Hint

You can find sample log file by navigating with Input Data Browser to s3s://spectx-docs/formats/log/ldap/2015-12-31_slapd_access-syslog.log

Parse

The objective of parsing is i) extract different type records so that they’ll be easy to identify and access in queries, and ii) extract significant fields in those records. Others we leave in the text fields which can be extracted further in queries addressing specific events.

Here’s how to extract the different type of records (from any logs):
  1. Declare a subpatterns representing different records
  2. Place the subpatterns into a alternatives group. The parser will then try to match declared records and produce the resultset with all fields.
 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
// every request always begins with timestamp, server and process info, let's capture it as header:
$hdr =
  TIMESTAMP('MMM d HH:mm:ss'):timestamp ' ' LD:host ' ' LD:process '[' INT:pid ']:'
  LD                    //skip spaces between pid and conn
  'conn=' INT:conn_id;   // connection id will be our session identifier

// connect record:
$connRec =
 <'connect'>:type           //metafield (added after parsing) recType contains record type: 'connect'
 $hdr                       //record begins with header
 ' fd=' INT:fd              //followed by 'fd=' key value pair
 LD* ' connection from IP=' //skip everything until string const (note modifier * allows to skip 0 bytes too)
 IPV4SOCKET:c_sock          //client socket exported as 'c_sock'
 LD                         //skip until
 EOL                        //the end of line
;

// operation record:
$opRec =
 <'op'>:type                //metafield (added after parsing) recType contains record type: 'op'
 $hdr                       //record begins with header
 ' op=' INT:op_id            //followed by 'op=' key value pair
 ' ' [A-Z ]+:op             //followed by single space and uppercase keyword describing operation
 LD*:details                //capture details as string
 EOL                        //until the end of line
 ;

// connection close record:
$closeRec =
 <'close'>:type             //metafield (added after parsing) recType contains record type: 'close'
 $hdr                       //record begins with header
 ' fd=' INT:fd              //string 'fd=' key value pair
 ' closed'                  //followed by string constant
 EOL                        //until the end of line
 ;

// this is our main pattern expression
// inside the alternatives group we match records declared above: connection or operation or close.
( $connRec | $opRec | $closeRec );

Hint

see the detailed walk-through of this pattern here or watch the video

Note

depending on the version of the OpenLDAP installation and Syslog configuration the log format may differ. A sample log with a differently formatted timestamp (and few other fields) can be found by navigating with Input Data Browser to s3s://spectx-docs/formats/log/ldap/slapd_access-custom.log

Normalizing Query

Let’s do the simplest normalization: we want to see client’s op records (leaving out connect and disconnect events here) including the client’s IP-address (and port).

As this information is present only in connect records, hence we need to join the c_sock field from connect record to each of the op records of the same client session. In SQL terms we inner join the resultset of a query producing op records with the resultset of a query producing connect records based on the conn_id field.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
@src = PARSE(pattern:FETCH('https://raw.githubusercontent.com/spectx/resources/master/examples/patterns/openldap/slapd-access-syslog.sxp'),
          src:'s3s://spectx-docs/formats/log/ldap/$yyyy$-$MM$-$dd$_slapd_access-syslog.log');

// create a stream with only connect records
@conn = @src
| filter(type = 'connect')
| select(conn_id, c_sock);  // we only need session and client ip-addr/port

// normalized view of ldap op records:
@src
| filter(type = 'op')                         //include only operation records
| join(@conn on left.conn_id = right.conn_id) //join the connection records (to include remote ip-addr)
| select(timestamp,                           //select fields for normalised view:
         c_socket:right.c_sock,
         conn_id,
         op_id,
         op:TRIM(op),
         details
);

Result with 5 first rows:

timestamp c_socket conn_id op_id op details
2015-12-31 16:53:53.000 +0000 192.168.4.36:40629 7448 0 BIND dn=”” method=128
2015-12-31 16:53:53.000 +0000 192.168.4.36:40629 7448 0 RESULT tag=97 err=0 text=
2015-12-31 16:53:53.000 +0000 192.168.4.36:40629 7448 1 SRCH base=”ou=people,dc=example,dc=com” scope=2 filter=”(objectClass=*)”
2015-12-31 16:53:53.000 +0000 192.168.4.36:40629 7448 1 SEARCH RESULT tag=101 err=0 text=
2015-12-31 16:53:54.000 +0000 192.168.4.36:40629 7448 2 UNBIND  

By saving the script as /user/slapd-access-normalised.sx we create a normalised view we can use for analysing LDAP events.

Hint

you may have noticed that the time field of Syslog header has been converted to timestamp field with year 2015. How did this happen? Read here.

Now it is very easy for us to find op events originating from an IP-address. All we need is to append filter statement to the view:

1
@[/user/slapd-access-normalised.sx] | filter(IPADDR(c_socket) = 192.168.2.104);

Querying for events of a particular user involves first selecting the sessions from BIND records filtered by username and then filtering the results of normalized view by these conn_id's:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
init(
  username::STRING  // script input parameter 'username' must be specified at calling the script
);

@sessions = @[/user/slapd-access-normalised.sx]
| filter(type = 'op' AND op='BIND')
| filter(details CONTAINS $username)
| select(conn_id)
;

@[/user/slapd-access-normalised.sx] | filter(conn_id IN (@sessions));

Saving this as /user/slapd-user-events.sx you create a view which can be used by any other analyst in the SpectX web UI or integrated to enterprise application via the API.

Note

the normalization described above can easily be extended. We could add to op requests the result field, which will further simplify analysis since we can omit result records from the resultset. We can also parse (the first layer) of key-value pair event data. See the example here

Hint

You can download full code of the patterns and queries at https://github.com/spectx/resources/tree/master/examples/patterns/openldap