problem getting results

[sarit_s]

Hello,

I have a query that return results if im running it for 1 hour but if im trying to run the query for more than 1 our it returns no result.. 

index=clientlogs sourcetype=clientlogs Mode=Real ApplicationIdentifier="*" "orders-for-open" (Action="OpenPositionRequest" AND Level=Info) 

| eval StartTime=strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N") 
| rename Request_Id AS RequestId
| stats min(StartTime) as StartTime min(_time) AS _time BY RequestId

| join RequestId
    [ search index=clientlogs sourcetype=clientlogs Mode=Real ApplicationIdentifier="*" Message="Create OrderForOpen" 
      | rename OrderID AS PushEventData_Position_OrderID ]
      
      | join PushEventData_Position_OrderID
      [ search index=clientlogs sourcetype=clientlogs Mode=Real ApplicationIdentifier="*" (Message="Position.Open" AND (PushEventData_Position_OrderType=17 OR PushEventData_Position_OrderType=18)) 
         | eval finishTime=strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N") 
         | stats min(finishTime) as finishTime min(_time) AS _time BY PushEventData_Position_OrderID ] 

| eval Latency=finishTime-StartTime 
| where Latency>0 
| timechart avg(Latency) span=1m

[johnhuang]

Here's a shot at it. Could have typos

index=clientlogs sourcetype=clientlogs Mode=Real ((OpenPositionRequest AND orders-for-open) OR ("Create OrderForOpen") OR ("PushEventData_Position_OrderType" AND (":17" OR ":18")))
| eval _time=strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N")
| rename Request_Id AS request_id
| eval event_type=CASE(searchmatch("OpenPositionRequest"), "event_start", searchmatch("PushEventData_Position_OrderType"), "event_end")
| transaction request_id startswith=(event_type="event_start") endswith=(event_type="event_end") maxspan=30m  maxopentxn=500000
| eval start_time=strftime(_time, "%Y-%m-%d %H:%M:%S")
| eval end_time=strftime(_time+duration, "%Y-%m-%d %H:%M:%S")
| eval duration_sec=duration
| eval duration_min=ROUND(duration/60, 2)
| table start_time end_time duration_sec duration_min request_id 

[johnhuang]

Your search could be easily simplified with stats or transactions. Also the filtering can be significantly improved.

Could you provide 3 examples of the logs that would be used to complete a transaction? E.g.

• OpenPositionRequest
• Create OrderForOpen
• Position.Open(PushEventData_Position_OrderType)

[sarit_s]

Message":"Create OrderForOpen"

"Action":"OpenPositionRequest"

"PushEventData_Position_OrderType":17

[johnhuang]

That helps somewhat. Could you post the entire _raw events?

[sarit_s]

im not sure i can .. i think i will have issue with security

[johnhuang]

You can always redact the sensitive part or send it to me by PM.

The Request_Id field is found on all in scope events?

For the last event, you are looking specifically for PushEventData_Position_OrderType=17 OR 18?

[ITWhisperer]

What does your job inspector say? For example, are your subsearches being truncated, which may mean your joins find no matches.

Have you tried reworking the search so you don't need to use joins at all? (Joins are usually best avoided if possible due to the restrictions on subsearches.)

[sarit_s]

if im getting results for 1 hour (no matter what time) so the joins returns results 

the problem is it is not returning results for more than 1 our

if you think there is a way to run it without join i will be more than happy to see

[ITWhisperer]

Yes, you said that, but what does the job inspector say happened when the failing search ran compared to the successful search?

To remove the joins, you could try something like a single primary search 

index=clientlogs sourcetype=clientlogs Mode=Real ApplicationIdentifier="*"

Then evaluate various fields depending on what events you have, for example:

| eval StartTime=if(searchmatch("\\\"orders-for-open\\\" (Action=\\\"OpenPositionRequest\\\" AND Level=Info)"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())

 and

| eval finishTime=if(searchmatch("(Message=\\\"Position.Open\\\" AND (PushEventData_Position_OrderType=17 OR PushEventData_Position_OrderType=18))"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())

Then gather the fields by RequestId

| stats min(StartTime) as StartTime min(finishTime) as finishTime min(_time) AS _time BY RequestId

 This may not be exactly what you need, since it isn't clear exactly what your search is doing or what your events actually look like, but the gist of it is hopefully clear.

[sarit_s]

this is what im getting while running for more than an hour. (im not getting this when running for 1 hour)

[ITWhisperer]

Did you notice the message in bold about the results being truncated at 50000? This is why the longer time periods fail - the join(s) have truncated results which probably means the events you were attempting to join with have no matches, so the overall search returns no results.

[sarit_s]

what im trying to do is to join 3 searches by unique field and i couldn't find a way to do it without join

[ITWhisperer]

Can you share some anonymised sample events from your 3 searches? Preferably use a code block </> when posting them to prevent formatting corruption

[sarit_s]

what i found is that this part of your query does not return any results :

| eval StartTime=if(searchmatch("\\\"orders-for-open\\\" (Action=\\\"OpenPositionRequest\\\" AND Level=Info)"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())
| eval finishTime=if(searchmatch("(Message=\\\"Trading.Position.Open\\\" AND (PushEventData_Position_OrderType=17 OR PushEventData_Position_OrderType=18))"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())

[ITWhisperer]

Can you post some events that it should have matched with?

[sarit_s]

this is the first event and we are calulating this field between the first event and the third

ClientDateTime":"2022-01-25T18:21:13.964Z"

Request_Id":"ccb245e4-5c41-4e70-92a0-60ce0d435bff"

the requestid is the common field i want to use, this is the field that combine all the 3 searches together

does it helps ?

[ITWhisperer]

Not really - apart from it looks like it might be JSON, so perhaps using spath to extract the fields might make it easier.

If you don't want to provide sample events, it makes it difficult for us to develop sample queries to help you work out what may be the issue, so you will have to try and figure it out yourself.

[sarit_s]

i took the query you suggested and add some other part but it is not returning any results (also for 1 hour)

this part returns results :

index=clientlogs sourcetype=clientlogs Mode=Real ApplicationIdentifier="*" "orders-for-open" (Action="OpenPositionRequest" AND Level=Info)
| eval StartTime=if(searchmatch("\\\"orders-for-open\\\" (Action=\\\"OpenPositionRequest\\\" AND Level=Info)"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())
| eval finishTime=if(searchmatch("(Message=\\\"Trading.Position.Open\\\" AND (PushEventData_Position_OrderType=17 OR PushEventData_Position_OrderType=18))"),strptime(ClientDateTime,"%Y-%m-%dT%H:%M:%S.%3N"),null())
| rename Request_Id AS RequestId
| stats min(StartTime) as StartTime min(finishTime) as finishTime min(_time) AS _time BY RequestId

but when im adding this part there are no results :

| eval Latency=finishTime-StartTime 
| where Latency>0 
| timechart avg(Latency) span=1m

[ITWhisperer]

From the first search (without the where command) do the results look correct i.e. has the stats command gathered the correct information from the related events?

[sarit_s]

from high level check looks like it does