Why does data stop getting indexed after a log rotation?

[Arkon]

Hi,

I noticed that, right after a log rotation, the data is not being indexed anymore.
Data is still going through /var/log/myapp.log and /var/log/messages (rsyslog UDP), so it all arrives on the machine (at 100%), but it is not being indexed.

On Splunk, I am monitoring logs arriving with real-time searches. Before log-rotate, everything is fine and logs are arriving on a regular basis. After logrotate, I do not get anything anymore.

Here is my inputs.conf:

[monitor:///var/log/myapp.log]
sourcetype = myappsourcetype
crcSalt = <SOURCE>
crcSalt = 2048
disabled = 0

My log rotate conf:

"/var/log/myapp.log" {
  monthly
  size 100M
  rotate 30
  compress
  postrotate
/bin/kill -HUP `cat /var/run/syslogd.pid 2>/dev/null` &> /dev/null || true
  endscript
}

My sourcetype shouldn't be the problem as it only contains some side fields extractions.

Thank you very much in advance

[jkat54]

The ultimate solution is monitoring *.log
AND putting the date time stamp in your log file names instead of in a path to the log:

YEAR-DAY-MONTH-filename.log

This way syslogng creates new files every day for each host that sends it data, and splunk will be looking for *.log etc, and never run into these crc issues.

Syslog ng has macros for year, day, month, etc that are easy to use in your destination statements.

[jkat54]

and log rotate can just compress old files

[jkat54]

@Arkon can you tell me if this helps?

It’s what we do everywhere and works great for our customers.

Hopefully you already know how to use syslog ng macros but if you don’t I can provide an example.

[sjohnson_splunk · Accepted solution]

I have encountered the problem. Upon rotation the current logfile is moved and compressed. Then a new file is created with the same name. That is a problem since Splunk has the log file opened at the time of rotation, it seems to follow the old file (nothing else is written to it so you don't see any more data).

The solution is with your log rotate script. You either need to use the copytruncate option or else the postrotate/script option to restart the Splunk forwarder.

[witski]

I have the same issue with my suse forwarder 6.4.3.
The log file will be renamed when its size reaches 20MB. And a new log file with the original name will be created to log data. For example, after abc.123.log reaches 20MB, it will be renamed as abc.123.1501.log. And a new abc.123.log will be created.
After the log was rotated, there's a chance that the new data in the log will not be collected. And if you use lsof command to check splunkd's pid, you may find that splunkd opens the renamed history log(abc.123.1501.log), not the right file(abc.123.log).
Is this a bug?

[thirusama]

We are on forwarder 7.0.3. We seem to have similar issue. What should be the ideal fix from Splunk monitoring side?
Below is the monitoring stanza

[monitor:///opt/mapr/hadoop/hadoop/logs/nodemanager]
sourcetype = my_st
index = my_index
disabled = 0
ignoreOlderThan = 2h

The latest file will be with yarn-mapr-nodemanager-host_name.log and the latest archived file be with yarn-mapr-nodemanager-host_name.log.1.

What is interesting is intermittently on certain servers, the current file gets indexed only at the time of its roll/archival i.e. lets say after 6 hours. And the issue of live/current file not getting indexed on time does not happen all the time. The next live file might get indexed on time. To me, it sounds like what @sjohnson_splunk has mentioned. But there should be ideal settings to avoid this. Any insights on this will be helpful.

[witski]

Hi, @thirusama , I believe you can resolve your problem by changing your monitored path.

There is no need to collect the archived file again since you have already collected the current file (if it functions normally).
Hence, there is no need to monitor the whole path. You can add .log to the end of your current path, which will be "/opt/mapr/hadoop/hadoop/logs/nodemanager/.log".
Doing this will let your splunk forwarder to focus on current files.

And my issue has been confirmed by the official support team as a bug solved since 6.6.4. It's recorded as SPL-142334.

[thirusama]

@witski But we are already on forwarder version 7.0.3. The issue still seem to exist. Are we missing anything?

[witski]

Hi thirusama, interesting, please read "Fixed issues" version 7.0.4. It recorded an issue “SPL-153180, SPL-148346” - "UF ignores files that are currently being written to".

[twinspop]

I'm not a fan of this recommendation. Things happen. Unless Splunk is watching all the rolled files you risk missing data that rolled before Splunk could read it. In my experience, best practice is to watch the rolled files as well as the original. My 2 cents.

[witski]

Splunk will not release a file handler immediately when the monitored file changes its name. According to the parameter time_before_close, splunk will only close the fd when the difference between the current EOF time and the prior EOF time is larger than 3 seconds(default).
According to @thirusama 's log name, I believe in his/her case, the log rotation policy should be 'rename and recreate'. If so, it means current log file will be renamed when it hits the rotation threshold. When rotating, Splunk will not close the fd immediately and switch to the new file if the forwarder functions as it says in Splunk Docs. And this mechanism will let Splunk collect events when log file rotates.

[thirusama]

Yes, I agree. For this exact reason, we had put to monitor all files with additional setting of ignoring older files (>2h). We had seen issue of missing last few events active file, before getting rolled in the past.

[twinspop]

Wow, good one to know! Almost seems like a bug, or at least a potential feature enhancement.

[Arkon]

You, Sir, made my day (and probably a few more).

[hardikJsheth]

I agree with twinspop, you don't need crcSalt and initCrcLength parameters. What problem are you facing? Is your file not getting monitored?

Why are you using postrotate? Do you need to kill any process on log rotation? Try removing this parameter.

[Arkon]

I supposed that Splunk was not reading enough data in each event so I increased initCrcLength.
As for CrcSalt, it was just a bet, I removed it.
My file is getting monitoring but the data is not getting to the dashboard, I do not see them after my logrotate. But the file is still getting filled with incoming data.

As for the -HUP, it is simply to close the file and reload rsyslog, to make the process cleaner. I tried removing it and it does not help at all.

[twinspop]

Can you explain why you think you need crcSalt? And I'm guessing you meant initCrcLength for the second crcSalt entry.

There are very particular reasons for using crcSalt, and I'm going to take a guess that UDP delivered syslog will not fit that criteria 99% of the time. You would only need initCrcLength if the beginning of your file always had a long header that was identical each time.

Try removing both crcSalt entries and see what happens.

[Arkon]

Thank you very much, I removed crcSalt but I am still encoutering the same issue.

[ddrillic]

For one thing -

crcSalt = <SOURCE>
crcSalt = 2048

Should probably be -

crcSalt = <SOURCE>
initCrcLength = 2048

[ddrillic]

In our place we normally add crcSalt and initCrcLength when things don't work as expected. However, since we already speak about it, it's fun to look further.

A very thorough explanation about How Splunk software handles log file rotation

It says at the end of the page -

-- Do not use crcSalt = with rolling log files, or any other scenario in which logfiles get renamed or moved to another monitored location. Doing so prevents Splunk software from recognizing log files across the roll or rename, which results in the data being reindexed.