co-relate random events

[stwong]

Hello,

We've an application with logs looks like following.  See below for some sample cases of single connection.

With some characteristics of the logs:

* same ID (conn) for the same connection.

* the search is to check login result (BIND and RESULT pair)

* same connection can have more than 1 login operation at the same time or different time.

* events of different connection are interleaving

* the only assuming is the RESULT event comes after the BIND event of same login

We use transaction to do that but also want to see if it's possible to use more efficient way like using streamstats/eventstats (still studying) as the log size is large.

Would anyone please shed some light ?

Thanks a lot.

Best Rgds

/stwong

======  basic case
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123456,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=123456,dc=mydomain,dc=hk"

====== 
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123456,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - RESULT err=49 tag=97 nentries=0 etime=0 
[04/Aug/2023:15:26:22 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123456,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:22 +0800] conn=3497880 op=0 msgId=1 - RESULT err=49 tag=97 nentries=0 etime=0 

======  can only assume the first RESULT is for the first BIND operation.
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123456,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123457,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - RESULT err=49 tag=97 nentries=0 etime=0 
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - RESULT err=48 tag=97 nentries=0 etime=0 

======
[04/Aug/2023:15:26:21 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123456,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:21 +0800] conn=3498439 op=1 msgId=2 - SRCH base="dc=mydomain,dc=hk" scope=2 filter="(myId=a12345)" attrs="uidNumber"
[04/Aug/2023:15:26:23 +0800] conn=3498439 op=0 msgId=1 - RESULT err=0 tag=97 nentries=0 etime=0 
[04/Aug/2023:15:26:22 +0800] conn=3497880 op=0 msgId=1 - BIND dn="uid=123457,dc=mydomain,dc=hk" method=128 version=3
[04/Aug/2023:15:26:22 +0800] conn=3497880 op=0 msgId=1 - RESULT err=49 tag=97 nentries=0 etime=0 
[04/Aug/2023:15:26:23 +0800] conn=3497880 op=0 msgId=1 - RESULT err=49 tag=97 nentries=0 etime=0 

[stwong]

Thanks for all your advice.   Will study and test.

For successful BIND operation, the RESULT event has the corresponding DN which is much easier to link up.

However, for those failed one, there is no DN or related information except the connection ID while some client will use same connection for multiple login operation.  When busy, we can see something like this for the same conn ID:

bind1
bind2
blah blah
bind3
blah blah
result1
result2
blah blah
result3

Can only assume those RESULT events come in same order as BIND, though there are lot of 'noise' events in between and even transaction may not work if the maxevent is small enough.

Thanks again.

Best Rgds

[ITWhisperer]

Simplistically, you could do something like this:

| rex "conn=(?<conn>\d+)\s\S+\s\S+\s-\s(?<eventtype>\S+)"
| streamstats count as occurrence by conn eventtype

Then events with the same conn and occurrence are assumed to be related. However, this would rely on complete and correct sequencing of BIND and RESULT. It also assumes that the events are in chronological order (which your example doesn't appear to be assuming the first field is a timestamp).

[yuanliu]

First of all, thank you for perfectly illustrating characteristics in your data.  You are correct to think that transaction is not often the most efficient.  But what is more efficient really depends on what problem you are trying to solve.

For example, stats is most often considered a more efficient alternative.  Without knowledge of your needs, I can only imagine a really generic approach:

| stats list(*) as * list(_time) as _time by conn

There is a possibility that this is more efficient than transaction.  But this is almost certainly not the best approach.  You also mentioned eventstats.  That usually is inefficient.

You hinted that you want to check bind results.  I assume that you are only interested in dn and err.  In that case,

| where isnotnull(dn) OR isnotnull(err)
| stats list(dn) as dn list(err) as err list(_time) as _time by conn

From here, how to get what you need is yet different from using transaction.  Hope this helps.