Why is difference between timestamps not working after doing a join command?

[vrmandadi]

Below is the search I am using.I am joining two indexes and then doing a differences between two timefields Last_Boot_Time ,log_time .But I am unable to get the difference .

index=preos host=* 
| stats values(Boot_Time) as Last_Boot_Time values(SN) as SN VALUES(PN) AS PN VALUES(VBIS) AS NV_VBIS VALUES(NV) AS NV values(PCI) as PCI BY id host
| fillnull value=clear 
| search SN!=clear PN!=clear NV_VBIS!=clear NV!=clear
| fields host id Last_Boot_Time PCI NV_VBIS NV_DRIVER PN SN 

| sort Last_Boot_Time 
    | join 
    [search index=syslog 
| search Error_Code="***"
| stats count by host _time PC Error_Code pid name Log_Message 
| eval log_time=strftime(_time,"%Y-%m-%d %H:%M:%S") 
| table log_time host PC Error_Code pid name Log_Message count
| sort by -log_time 
| dedup pid]|eval diff=log_time-Last_Boot_Time

. Following are sample events for index=preos (here Boot time is considered as timestamp)
2022-09-22T13:20:38.713211-07:00 preo log-inventory.sh[24193]: Boot timestamp: 2022-09-22 13:09:59

Index=syslog
2022-09-22T11:51:34.272862-07:00 preo kernel: [74400.062429] NVRM: Xid (PCI:xxx): 119, pid=17993, name=che_mr_ent, Timeout waiting for on 76 (P_RM_CONTROL) (0x20800a4c 0x4).


Thanks in Advance

[inventsekar]

the join command is a pretty complex one.

and ur join command looks like something wrong..

i would try something like this

| join host [search index=syslog

[vrmandadi]

I do get the output if I dot use join by host .But as you suggested I did use host but when I am calculating 
|eval diff=log_time - Last_Boot_Time  it is not showing the result

[bowesmana]

You can't calculate differences of time if the times are strings - you have created a formatted string for log_time and boot time is also a string - you have to convert those to epoch time to calculate differences.

You should leave log_time as _time in the join subsearch and then convert Last_Boot_Time to epoch then calculate the difference.

Note that join has limitations - you can only have max 50,000 results in the subsearch otherwise join will just not work properly.

[vrmandadi]

@bowesmana  if I remove  | eval log_time=strftime(_time,"%Y-%m-%d %H:%M:%S.%3N") and just use in search in the join I dont see the _time field being shown. I get all other table columns but not _time .I am using the below search

index=pre host=abc
| eval epoch = strptime('Boot_Time', "%Y-%m-%d %H:%S")
| stats values(epoch) as Last_Boot_Time values(SN) as SN VALUES(PN) AS PN by id host
| fillnull value=clear
| fields host id Last_Boot_Time PN SN
| join
[ search index=syslog host=abc

| stats count by host _time PCIe_Bus_Id Error_Code pid name Log_Message

| dedup pid]

[bowesmana]

I am not sure if join will join _time, so just rename _time in the join to some other field, e.g. something like this

| join host [
  search index=syslog host=abc
  | stats count by host _time PCIe_Bus_Id Error_Code pid name Log_Message
  | dedup pid
  | rename _time as eror_time
]  

then you have error_time as the field in the outer. Note that it is probably a good idea to be explicit with the fields you want to join with rather than just letting Splunk find all matching fields.

Note that your Last_Boot_Time may be a multi-value field (stats values()...) so you can't then do a simple calculation with error_time-Last_Boot_Time unless you only have ONE Last_Boot_Time value.

Without knowing your data, it's difficult to suggest the right solution, but at least from your original question, you need to have 2 epoch values, one in each field, and then you can do the calculations. 

[vrmandadi]

@bowesmana  Thank you for your reply and sorry for the late reply... I did the change and made both the timestamps to epoch time . but when doing a difference I dont see the value

Last_Boot_Time - 1663311600.000000

eror_time - 1663782065.763202

Following are two Raw events from join:

2022-10-02T22:50:39.841330-07:00 abc log-inventory.sh[24384]: Boot timestamp: 2022-10-02 22:39:53

2022-10-03T05:20:41.545640-07:00 abc kernel: [24052.421284] NVRM: Xid (x): 74, pid='<unknown>', name=<unknown>, nk: link 6(0x10000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)

[bowesmana]

Those two epoch dates don't seem to represent the dates in those logs.

Note that you have written "eror_time" not error_time - so depending on what your calculation is doing, this could be the reason why you don't see any result.

It's useful to show your code and an copy/paste/screenshot of your results - because if you have a statement that says

| eval diff=error_time - Last_Boot_Time

then this would give you a result - assuming your field is actually "error_time".

[vrmandadi]

@bowesmana  I am sorry its a typo ... I guess the issue is Boot_Time  is we are using stats values(Boot_Time) so it has two or three values which is difficult to get the difference..is there way to get the difference

[bowesmana]

@vrmandadi It is always possible to achieve anything with SPL, so the first thing you need to do is understand what values you want to perform the necessary calculations. If you think you will have more than one value after your initial 

| stats values(Boot_Time) as Last_Boot_Time...

then what does that mean for your use case? If you want the most recent value of Boot_Time to be Last_Boot_Time, then use 

| stats max(Boot_Time) as Last_Boot_Time

instead, then you will only have a single value. However, you need to understand your data to know if that answers the question you are asking with your search.

[vrmandadi]

@bowesmana  I am using two different indexes and joining using host as common field ..The first index is preos which has events as below for each  host .Below preo1 is the host 

2022-10-06T06:26:22.075037-07:00 preo1 log-inventory.sh[24540]: Boot timestamp: 2022-10-06 06:15:43

2022-10-06T06:26:22.074872-07:00 preo1 log-inventory.sh[24540]: G driver: version: 55.16, md5sum: B67829A0

2022-10-06T06:26:22.073636-07:00 preo1 log-inventory.sh[24540]: GP: PCISLOT: 000:5:00.0, MODEL: H0 e, PN: 2336-884-A1, SN: 133120196, VBIOS: 6.0.A.00, INFOROM: 520.01.01.

I am using the below query using the above index

index=preos host=preo1  ("Boot timestamp" OR "GPU driver: version: " OR *0000:45:00*) 
| rex field=_raw "sh\[\d*\]\:\s*(?<GPU>[^\:]+)\s*\:\s*PCISLOT\:\s*(?<PCIe_Bus_Id>[^\,]+)\,\s*\w*\:\s.*\PN\:(?<PN>[^\,]+)\,\s*SN\:\s*(?<SN>[^.\,]+)\,\s*VBIOS\:\s*(?<VBIOS>[^\,]+)"
| rex field=_raw "Boot\s*timestamp\:\s*(?<Boot_Time>[^.*]+)"
| rex field=_raw "log\-inventory\.sh\[(?<fru_log_id>[^\]]+)" 
| rex field=PCIe_Bus_Id "0000(?<PCIe_Bus_Id>[^\.\0]+)"
| rex field=_raw "GPU\sdriver\:\sversion\:\s(?<NV_Driver>[^\,]+)\," 
| stats values(Boot_Time) as Last_Boot_Time values(SN) as SN VALUES(PN) AS PN VALUES(VBIOS) AS NV_VBIOS VALUES(NV_Driver) AS NV_DRIVER values(PCIe_Bus_Id) as PCIe_Bus_Id BY fru_log_id host
| fillnull value=clear 
| search SN!=clear PN!=clear NV_VBIOS!=clear NV_DRIVER!=clear
| fields host fru_log_id Last_Boot_Time PCIe_Bus_Id NV_VBIOS NV_DRIVER PN SN 

The second index is index=syslog  with for the same host preo1.Below is the sample event

2022-10-03T05:20:41.545640-07:00 preo1 kernel: [24052.421284] NVRM: Xid (PCI:0000:85:00): 74, pid='<unknown>', name=<unknown>, NVLink: fatal error detected on link 6(0x10000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)

Below is the query I am using 

index=syslog "*NVRM: Xid " process=kernel host IN (preo1)
| rex field=_raw "NVRM\:\sXid\s*\(PCI\:(?<PCIe_Bus_Id>[^ ]+)\)\:\s*(?<Error_Code>[^ ]+)\,\spid\=(?<pid>[^ ]+)\,\s*name\=(?<name>[^ ]+)\,\s(?<Log_Message>.*)" 
| search Error_Code="***"
| stats count by host _time PCIe_Bus_Id Error_Code pid name Log_Message 
| addcoltotals count labelfield=host label=_Total
| rename _time as eror_time
| table eror_time host PCIe_Bus_Id Error_Code pid name Log_Message count
| sort by -log_time 
| dedup pid

Now from the above two searches .I am trying to join by host using below search

index=preos_inventory host=preos0036  ("Boot timestamp" OR "GPU driver: version: " OR *0000:45:00*) 
| rex field=_raw "sh\[\d*\]\:\s*(?<GPU>[^\:]+)\s*\:\s*PCISLOT\:\s*(?<PCIe_Bus_Id>[^\,]+)\,\s*\w*\:\s.*\PN\:(?<PN>[^\,]+)\,\s*SN\:\s*(?<SN>[^.\,]+)\,\s*VBIOS\:\s*(?<VBIOS>[^\,]+)"
| rex field=_raw "Boot\s*timestamp\:\s*(?<Boot_Time>[^.*]+)"
| rex field=_raw "log\-inventory\.sh\[(?<fru_log_id>[^\]]+)" 
| rex field=PCIe_Bus_Id "0000(?<PCIe_Bus_Id>[^\.\0]+)"
| rex field=_raw "GPU\sdriver\:\sversion\:\s(?<NV_Driver>[^\,]+)\," 
| stats values(Boot_Time) as Last_Boot_Time values(SN) as SN VALUES(PN) AS PN VALUES(VBIOS) AS NV_VBIOS VALUES(NV_Driver) AS NV_DRIVER values(PCIe_Bus_Id) as PCIe_Bus_Id BY fru_log_id host
| fillnull value=clear 
| search SN!=clear PN!=clear NV_VBIOS!=clear NV_DRIVER!=clear
| fields host fru_log_id Last_Boot_Time PCIe_Bus_Id NV_VBIOS NV_DRIVER PN SN 

| sort Last_Boot_Time 
    | join host
    [search index=syslog "*NVRM: Xid " process=kernel host IN (preos0036)
| rex field=_raw "NVRM\:\sXid\s*\(PCI\:(?<PCIe_Bus_Id>[^ ]+)\)\:\s*(?<Error_Code>[^ ]+)\,\spid\=(?<pid>[^ ]+)\,\s*name\=(?<name>[^ ]+)\,\s(?<Log_Message>.*)" 
| search Error_Code="***"
| stats count by host _time PCIe_Bus_Id Error_Code pid name Log_Message 
| addcoltotals count labelfield=host label=_Total
| rename _time as eror_time
| table eror_time host PCIe_Bus_Id Error_Code pid name Log_Message count
| sort by -log_time 
| dedup pid]
| eval eror_time=strftime(eror_time,"%Y-%m-%d %H:%M:%S") 
| eval diff=eror_time-Last_Boot_Time

But the issue is when I am trying to join .I see all results..no issues ..but when I am trying to get the difference between Last_Boot_Time and eror_time I dont get any results.I hope this is clear with events

[bowesmana]

You still seem to have the issues that have been discussed in this thread over the last two weeks.

Firstly you are trying to do time arithmetic on non-time based fields

| eval eror_time=strftime(eror_time,"%Y-%m-%d %H:%M:%S") 
| eval diff=eror_time-Last_Boot_Time

This has already been discussed in earlier posts.

Secondly, as discussed last week, your Last_Boot_Time can be multivalued, so you need to decide on WHICH value of those you want, as I mentioned on Friday.

Until you resolve these two issues, as suggested, you will not get reliable results.

Other observations - you seem to have code from your original posting from two weeks ago that is no longer relevant

| sort by -log_time 

There is no field log_time and there is no need to sort anyway in the result of a join statement.

You are sorting on Last_Boot_Time in your outer search. which is a multivalue field - that will not work and it is unnecessary to sort before the join. You should leave sorting to the last possible moment.

[inventsekar]

Not sure if this will help, but, did you try a table at the end...

| eval diff=log_time - Last_Boot_Time

| table diff 

[vrmandadi]

Yes no luck with that...I am assuming its something do with the date/time format .

Sample logs: index=preos

022-09-22T13:20:38.713211-07:00 preos log-inventory.sh[24193]: Boot timestamp: 2022-09-22 13:09:59

index=syslog

2022-09-22T11:51:34.272862-07:00 preos kernel: [74400.062429] NVRM: Xid (PCI:0000:45:00): 119, pid=17993, name=cache_mgr_event, Timeout waiting for RPC from GSP! Expected function 76 (GSP_RM_CONTROL) (0x20800a4c 0x4).

[inventsekar]

ok, lets do this.. remove your last eval and add this table. lets see if this is printing both times. one time will fail, so we can understand if the join worked or not. 

| table log_time Last_Boot_Time

[vrmandadi]

The issue is not with the two time fields displaying.. the join or working and I see those two time fields are showing up but when I do a difference it's not working... if I do a difference between id and pid I am able to get the result but not with these two time fields 

[inventsekar]

ok, lets do this and this will solve ur issue. 

convert both times to epoch time and then eval diff..

and while printing you can convert from epoch to human readable.  hope you got, it.. let us know, thanks.