Splunk Search

How do you calculate the time taken during the authentication process?

rakeshyv0807
Explorer

Hi All,

I am trying to achieve the time difference between two logs during the authentication process. During authentication, we capture step by step logs in the process and our requirement is to find the time taken by the users to enter the credentials. From the logs we captured, I can see the two logs that we can take into consideration, and I would like to get suggestions on how to calculate the difference between these two logs:

The sample logs are as follows:

11:01:17.876 AM 2019-04-03 11:01:17,876 tid:XG5HNBNsbPp8uZis90UWNl9vnqQ DEBUG [org.sourceid.util.log.internal.TrackingIdSupport] [cross-reference-message] entityid:ApplicationName subject:null

2019-04-03 11:01:26,579 tid:XG5HNBNsbPp8uZis90UWNl9vnqQ DEBUG [org.sourceid.util.log.internal.TrackingIdSupport] [cross-reference-message] entityid:ApplicationName subject:JohnDoe

In the above logs, the first one is when the user is presented with the login page — In this log, you can see the timestamp, transaction ID (tid), and the application Name, but the subject is null because the user has not yet logged in.

In the second log, you see the same values, but here the timestamp value and subject value have been changed and it captures the actual user ID of the user trying to log in.

Now, the end result that i would like to achieve is to display users who took less than 1-2 seconds to log in to the application. The query should be based on timestamp, tid (unique id generated for each authentication request and is common throughout the user authentication process for that particular app), application Name and the subject.

Can you please help me achieve this? Very thanks in advance.

Thanks,
Rakesh

Tags (1)
0 Karma

somesoni2
Revered Legend

Assuming all fields are already extracted (tid, entityid and subject), give this a try

your base search fetching those logs
| eval loginpage=if(subject="null" OR isnull(subject),_time, null())
| eval loggedin=if(isnull(loginpage),_time,null())
| stats min(loginpage) as loginpage min(loggedin) as loggedin earliest(subject) as subject by tid entityid
| eval duration=loggedin-loginpage | convert ctime(login*) 
0 Karma

rakeshyv0807
Explorer

@somesoni2 Thanks for your response. I have unstructured data and we worked to get it structured and delimited by Pipe. The following are the sample logs for an user authentication mechanism.

2019-04-04 16:48:52,054|tid:sAXbhH5v_q4KCqSj_ATIJIN0Vp0 |SSO | rvenkata| xx.xxx.xxx.xx | | Splunk:Zebra:SAML2| SAML20| IdP| success| [HTML, PINGIDCompoisteAdap]| | 269| | | | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0| application/x-www-form-urlencoded| en-US,en;q=0.5| | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0

2019-04-04 16:48:49,399|tid:sAXbhH5v_q4KCqSj_ATIJIN0Vp0 |AUTHN_ATTEMPT | rvenkata| xx.xxx.xx.xxx | | Splunk:Zebra:SAML2| SAML20| pi.zebra.com| IdP| inprogress| PINGIDCompoisteAdap| | 140| | | | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0| application/x-www-form-urlencoded| en-US,en;q=0.5| | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0

2019-04-04 16:48:49,384|tid:sAXbhH5v_q4KCqSj_ATIJIN0Vp0 |AUTHN_ATTEMPT | | xx.xxx.xx.xx | | Splunk:Zebra:SAML2| SAML20| pi.zebra.com| IdP| success| HTML| | 125| | | | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0| application/x-www-form-urlencoded| en-US,en;q=0.5| | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0

2019-04-04 16:48:49,368|tid:sAXbhH5v_q4KCqSj_ATIJIN0Vp0 |AUTHN_ATTEMPT | rvenkata| xx.xxx.xxx.xx | | Splunk:Zebra:SAML2| SAML20| pi.zebra.com| IdP| success| HTML| | 109| | | | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0| application/x-www-form-urlencoded| en-US,en;q=0.5| | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0

2019-04-04 16:48:47,816|tid:sAXbhH5v_q4KCqSj_ATIJIN0Vp0 |AUTHN_ATTEMPT | | xx.xxx.xx.xxx | | Splunk:Zebra:SAML2| SAML20| pi.zebra.com| IdP| inprogress| HTML| | 15| | | | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0| application/x-www-form-urlencoded| en-US,en;q=0.5| | | Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:66.0) Gecko/20100101 Firefox/66.0

The last log is the first log when the user tries to login and the one above is the log when the user hits on login button. We would like to find the difference between these two logs. The earliest log doesn't have the userid(After AUTHN_ATTEMPT) and the log above it has the userid (rvenkata). When the user tries the app URL and the app loads the login page the last log load without userid and when he enters the credentials the above log will generate with userid.

The tid and the entityId (Splunk:Zebra:SAML2) is common in all the logs. Can you please help me how to get the time difference of first two logs? Thanks, in advance.

0 Karma

somesoni2
Revered Legend

Are all the fields extracted already (tid, entitiyid and user)? If yes, then you should be able to use the same search I gave (just replace field reference for 'subject' with 'user'.

0 Karma

rakeshyv0807
Explorer

Please note that there are around 10 events for the same transaction ID (tid). And, tid and entityid are same for all the logs and subject is also same for all the logs except 1st log where it will generated as null for first record.I need to find the timestamp difference only for the first two logs where subject is null and the first log that was generated with subject.

0 Karma

rakeshyv0807
Explorer

@niketnilay I have seen your responses to few questions of similar kind. Could you please help me when you have some availability? Thanks.

0 Karma
Get Updates on the Splunk Community!

Webinar Recap | Revolutionizing IT Operations: The Transformative Power of AI and ML ...

The Transformative Power of AI and ML in Enhancing Observability   In the realm of IT operations, the ...

.conf24 | Registration Open!

Hello, hello! I come bearing good news: Registration for .conf24 is now open!   conf is Splunk’s rad annual ...

ICYMI - Check out the latest releases of Splunk Edge Processor

Splunk is pleased to announce the latest enhancements to Splunk Edge Processor.  HEC Receiver authorization ...