Lost events in index

[pichertklaus]

Hi All,

We have a strange problem here.
On a Linux syslog server, the logs from different systems are each saved as a file.

These files are monitored by Splunk UF and forwarded to two heavy forwarders to be saved on the indexer. We have now noticed that the number of events in the Splunk index sometimes differs from the syslog data delivered, sometimes events are missing in the middle.

Since reports and alerts are configured on the Splunk data, it is of course essential that ALL events arrive in Splunk.

Is such a behavior known, where can I find how many events have been processed on the HFs, for example?

Regards

Klaus

[pichertklaus]

Thank you all so far

[gcusello]

Hi @pichertklaus,

this can be possible if you have many events or if you have few resources in your HFs and IDXs.

At first,I hint to use an rsyslog (or syslog-ng) server to receive syslogs, so you take the syslogs also if Splunk is down or overbooked.

Then, how many events are you receiving by syslog?

which resources have your servers?.

Ciao.

Giuseppe

[pichertklaus]

We are running a syslog-ng system which receives the data from various appliances.

From what I can tell, on the syslog server itself all data is stored in files per sending host/date and the event count matches the event count on the generating host. We checked some random samples for accuracy.
So the syslog server itself seem not to be the limit.

sudo syslog-ng-ctl query get "source.*"
source.s_udp514.processed=844024
source.s_tcp514.processed=11100270
source.s_tcp1514.processed=3150959

Syslog Server: 2 CPUs, 8GB RAM

We are running 2 Heavy Forwarders which receive the date from the Universal Forwarder installed on the syslog-ng server and sendig them to 6 Splunk Indexers.

As we are not operating the HFs/IDXs I cannot say much about their sizing

[PickleRick]

Well... there are several things to consider here.

1. Are all files being read properly (check status of inputs on the UF, check for errors, verify that you're not hitting some limits on opened files and so on)?

2. Are other files from the same UF (the typical candidates for cross-checking would be UF's own logs) getting ingested properly?

3. How did you verify the discrepancy between those numbers?

4. Are your time parsing rules properly set up? That can heavily influence _where_ (or rather "when") the events are indexed. So you might be getting the events ingested "properly" but you might just not be seeing them while searching.

5. Do you have any rules (props/transforms, ingest actions) on your HFs/indexers that filter the events (or move them to other indexes).

There are many things that could affect your ingestion process.

[pichertklaus]

1) I didn't find any errors in splunkd.log on the UF.
How would I "check status of inputs on the UF"?

2) I found the differences in various logs, but I will check the internal logs - didn't do that yet

3) Discrepancy: see other replies to Guiseppe

4) Time parsing: I have added some samples below - as the time formats are consistant over the other events...

5) So far there are no rules on the HFs

[PickleRick]

1)

splunk list monitor

and

splunk list inputstatus

3) Remember that Splunk searches by _time, which typically is the timestamp extracted from the event. In order to verify how much data you ingest during given period of time you need to aggregate it over _indextime. That's why I was asking about time parsing.

You can also check metrics on your HFs but if you have many sources, those UFs might not show in metrics.log at all if they don't fall into the "most active" subset.

4) It's not about the time formats being consistent or not. It's about how they are parsed in Splunk and if they fit the proper time. Otherwise the events might get indexed at a completely different time than you'd expect.

And one more thing - even on your syslog receiver, the events can be delayed and if those files are rotated with logrotate (as they probably are) you might be doing a summary of a day's worth of events but those events could be shifted in time versus the "midnight to midnight" period. Did you verify that?

[pichertklaus]

I have checked the following:

splunk list inputstatus
/data/syslog/opswat/metadefender/10.x.y.z/2024-04-23-engine.log
file position = 176673
file size = 176673
parent = /data/syslog/opswat/metadefender/10.x.y.z/*-engine.log
percent = 100.00
type = finished reading

Checking the file itself

more /data/syslog/opswat/metadefender/10.x.y.z/2024-04-23-engine.log | wc
584 11089 176673

And in Splunk there are the following events for 2024-04-23

index=mb_secgw_cdr_tst_logs | stats count
460

I have selected an event from the syslog data and searched all over the index with no success, so probably the event is not indexed.

Syslog-ng ist configured to write the log per host per day in separate files. And events are missing at random all over the day.

I try to get more information from the HFs

[gcusello]

Hi @pichertklaus,

if you're sure that in the files (written bu syslog-ng) there are all the events, you have to search in the Splunk inputs.

Are you sure that there aren't duplicated data in these files? because Splunk doesn't index twice duplicated data, event if having different file names.

Then, are you sure about the parsing? if the missed events are in the first 12 days of each mont, maybe there's a timestamp parsing issue related to the timestamp format.

di you checked if there are some events grouped in the same events? maybe the issue is in the event breaking rules.

Ciao.

Giuseppe

[pichertklaus]

Some sample logs:

MD Core Data 
[INFO ] 2024.04.23 01:02:36.169: (common.update) Metadescriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/metadescriptor', downloadlink='https://xxx.domain.tld:9000/console/core/metadescriptor?version=5.8.0&deployment=MSCW6YaXaCaj1y1gv23U4JxzRHFhNUZLENEX&key=2041ed80a6043bf436fc7be518df4a13&serial=1' [msgid: 622]
[INFO ] 2024.04.23 01:02:36.371: (common.update) Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/bitdefender_1_windows/bitdefender_1_windows-database-1713819646-1713819720.yml' [msgid: 618]
[INFO ] 2024.04.23 01:02:36.442: (common.update) Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml' [msgid: 2320]
[INFO ] 2024.04.23 01:02:36.454: (common.update) Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/eset_1_windows/eset_1_windows-database-1713821049-1713821161.yml' [msgid: 618]
[INFO ] 2024.04.23 01:02:36.459: (common.update) Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml' [msgid: 2320]
[INFO ] 2024.04.23 01:02:51.383: (common.update) Package successfully downloaded, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz' [msgid: 671]
[INFO ] 2024.04.23 01:02:51.383: (common.update) Checksum validation of package content is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', packageName='bitdefender_1_windows-database-1713819646.zip', type='database', filesChecked='951' [msgid: 2321]
[INFO ] 2024.04.23 01:02:57.775: (common.update) Package successfully downloaded, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y' [msgid: 671]
[INFO ] 2024.04.23 01:02:57.775: (common.update) Checksum validation of package content is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml', packageName='eset_1_windows-database-1713821049.zip', type='database', filesChecked='36' [msgid: 2321]
[INFO ] 2024.04.23 01:03:00.597: (engines) Default parallel count set for engine, engineId='eset_1_windows', parallelcount='20' [msgid: 4602]
[INFO ] 2024.04.23 01:03:00.718: (engines) Accepting local socket, engine_id='eset_1_windows', socket='\\.\pipe\C:/Windows/Temp/ometascan/9e14Ds_13680', socketDescriptor='5924' [msgid: 4547]
[INFO ] 2024.04.23 01:03:01.415: (engines) Default parallel count set for engine, engineId='bitdefender_1_windows', parallelcount='20' [msgid: 4602]
[INFO ] 2024.04.23 01:03:01.512: (engines) Accepting local socket, engine_id='bitdefender_1_windows', socket='\\.\pipe\C:/Windows/Temp/ometascan/yC8oEL_14344', socketDescriptor='7852' [msgid: 4547]
[INFO ] 2024.04.23 01:03:04.056: (engines) Try to swap engineprocess log, engine_id='eset_1_windows' [msgid: 5594]
[INFO ] 2024.04.23 01:03:10.902: (common.update) Successfully verified product [msgid: 4696]
[INFO ] 2024.04.23 01:05:03.731: (engines) Try to swap engineprocess log, engine_id='bitdefender_1_windows' [msgid: 5594]

Syslog Data
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Metadescriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/metadescriptor', downloadlink='https://xxx.domain.tld:9000/console/core/metadescriptor?version=5.8.0&deployment=MSCW6YaXaCaj1y1gv23U4JxzRHFhNUZLENEX&key=2041ed80a6043bf436fc7be518df4a13&serial=1' [msgid: 622]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/bitdefender_1_windows/bitdefender_1_windows-database-1713819646-1713819720.yml' [msgid: 618]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml' [msgid: 2320]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/eset_1_windows/eset_1_windows-database-1713821049-1713821161.yml' [msgid: 618]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml' [msgid: 2320]
Apr 23 01:02:51 10.178.102.75 MSCW[2456] Package successfully downloaded, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz' [msgid: 671]
Apr 23 01:02:51 10.178.102.75 MSCW[2456] Checksum validation of package content is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', packageName='bitdefender_1_windows-database-1713819646.zip', type='database', filesChecked='951' [msgid: 2321]
Apr 23 01:02:57 10.178.102.75 MSCW[2456] Package successfully downloaded, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y' [msgid: 671]
Apr 23 01:02:57 10.178.102.75 MSCW[2456] Checksum validation of package content is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml', packageName='eset_1_windows-database-1713821049.zip', type='database', filesChecked='36' [msgid: 2321]
Apr 23 01:03:00 10.178.102.75 MSCW[2456] Default parallel count set for engine, engineId='eset_1_windows', parallelcount='20' [msgid: 4602]
Apr 23 01:03:00 10.178.102.75 MSCW[2456] Accepting local socket, engine_id='eset_1_windows', socket='\\.\pipe\C:/Windows/Temp/ometascan/9e14Ds_13680', socketDescriptor='5924' [msgid: 4547]
Apr 23 01:03:01 10.178.102.75 MSCW[2456] Default parallel count set for engine, engineId='bitdefender_1_windows', parallelcount='20' [msgid: 4602]
Apr 23 01:03:01 10.178.102.75 MSCW[2456] Accepting local socket, engine_id='bitdefender_1_windows', socket='\\.\pipe\C:/Windows/Temp/ometascan/yC8oEL_14344', socketDescriptor='7852' [msgid: 4547]
Apr 23 01:03:04 10.178.102.75 MSCW[2456] Try to swap engineprocess log, engine_id='eset_1_windows' [msgid: 5594]
Apr 23 01:03:10 10.178.102.75 MSCW[2456] Successfully verified product [msgid: 4696]
Apr 23 01:05:03 10.178.102.75 MSCW[2456] Try to swap engineprocess log, engine_id='bitdefender_1_windows' [msgid: 5594]

Splunk
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Metadescriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/metadescriptor', downloadlink='https://xxx.domain.tld:9000/console/core/metadescriptor?version=5.8.0&deployment=MSCW6YaXaCaj1y1gv23U4JxzRHFhNUZLENEX&key=2041ed80a6043bf436fc7be518df4a13&serial=1' [msgid: 622]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/bitdefender_1_windows/bitdefender_1_windows-database-1713819646-1713819720.yml' [msgid: 618]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml' [msgid: 2320]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Package descriptor received, file_name='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml', url='https://xxx.domain.tld:9000/console/core/package/eset_1_windows/eset_1_windows-database-1713821049-1713821161.yml' [msgid: 618]
Apr 23 01:02:36 10.178.102.75 MSCW[2456] Checksum and digital signature validation of package descriptor is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/eset_1_windows_WNDq4Y/packagedescriptor.yml' [msgid: 2320]
Apr 23 01:02:51 10.178.102.75 MSCW[2456] Package successfully downloaded, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz' [msgid: 671]
Apr 23 01:02:51 10.178.102.75 MSCW[2456] Checksum validation of package content is ok, packageDir='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz', descriptor='C:/Program Files/OPSWAT/MetaDefender Data/data/updates/db/bitdefender_1_windows_GiYkXz/packagedescriptor.yml', packageName='bitdefender_1_windows-database-1713819646.zip', type='database', filesChecked='951' [msgid: 2321]
Apr 23 01:05:03 10.178.102.75 MSCW[2456] Try to swap engineprocess log, engine_id='bitdefender_1_windows' [msgid: 5594]

There is no duplicate data in the logs.

It happens not only in the first 12 days of the month as you can see in the example logs above...

[pichertklaus]

There are no packet errors on the UF

ip -s link show ens192
2: ens192: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000
link/ether 00:50:56:bb:07:59 brd ff:ff:ff:ff:ff:ff
RX: bytes packets errors dropped overrun mcast
13730859826 7324421 0 0 0 358
TX: bytes packets errors dropped carrier collsns
1976804117 6163908 0 0 0 0