Why copytruncate logrotate does not play well with splunk monitoring

[yannK]

I am using logrotate to rotate my files, with the option copytruncate.
http://linuxcommand.org/man_pages/logrotate8.html
And It is causing splunk to reindex the file during the rotation.

see my rotate script /etc/logrotate.d/test

"/home/feed/test.log" { 
rotate 5 
size=50M 
sharedscripts 
copytruncate 
compress 
} 

What happens is :
- the rotation creates a new rotated file. (test.log.1)
- the rotation copy the content of the file to the new file (from line 1 to line X), then compress it.
- the rotation then truncates the original file by removing the first lines per chunks, until reaching the line X.

At the same time, splunk is monitoring the file, and check the first 256 chars for the crc.
- during the truncate, because the first lines are changing, splunk redetect the file as new, and reindex it all.
- we find duplicates of the lines, the first lines with fewer duplicates, the last lines with more duplicates.

How to identify the issue :
- look for duplicates and the time when they were generated. (not the event timestamp)
source=path/to/my/logfile | convert ctime(_indextime) AS indextime| stats count values(indextime) AS indextime by _raw | where count >1
- at the time of the rotation, look on the forwarder splunkd.log, check for multiple events like :
11-05-2014 10:48:33.924 +0000 INFO WatchedFile - Will begin reading at offset=0 for file='/home/feed/test.log
11-05-2014 10:48:34.234 +0000 INFO WatchedFile - Will begin reading at offset=0 for file='/home/feed/test.log
etc...

[hrawat_splunk]

This issue is resolved by
7.1 (SPL-149198)
7.0.4 (SPL-153453)
6.6.7(SPL-146190)

[hrawat_splunk]

I checked logrotate code (https://github.com/logrotate/logrotate/blob/master/logrotate.c) and it's using ftruncate(). So underlying linux do_truncate() in open.c is simply modifying inode entry for size. In logrotate case file size will be changed to 0.
https://elixir.free-electrons.com/linux/latest/source/fs/open.c

The only possible issue from man logrotate -> copytruncate

   copytruncate
          Truncate the original log file in place after creating a copy, instead of moving the old log file and optionally creating a new one.  It can be used when some program cannot
          be  told  to  close its logfile and thus might continue writing (appending) to the previous log file forever.  Note that there is a very small time slice between copying the
          file and truncating it, so some logging data might be lost.  When this option is used, the create option will have no effect, as the old log file stays in place.

To avoid possible loss of few lines, monitor rotated file as well. Splunk will read missing line from backup file.

[twinspop]

Except you can't trust Splunk's logic in ignoring log files it's already seen. I've had to disabled the monitoring of rolled files in almost all situations because we end up with duplicate logs. Splunk's support has been, to be blunt, useless with tracking this down. Really, super frustrating.

[hrawat_splunk]

If you can tell your case number, I will make sure issue is resolved. However there is one possibility that splunk might see rolled file while it's still < 256 bytes, then in that case initcrc will not match.

[twinspop]

Case 000466442

And also this question: https://answers.splunk.com/answers/515448/why-does-splunk-re-index-this-rolled-file-how-to-t.html

[hrawat_splunk]

Appreciate your help on Case 000466442. The attached DEBUG logs were very helpful to understand the problem. Now I can re-pro the issue at will. Fixing it for next release.

[hrawat_splunk]

Issue is resolved by 7.1.0 ( SPL-143553).

[trross33]

I realize this is a little old, but for posterity...

Depending on what your needs are, you can also move the rotated files to a location that is not defined in Splunk's inputs.conf for those files. This capability is available in logrotate. For example if you have a forwarder acting as a syslog server for network/system devices, and you have these logs dumped to /var/log/syslog. You can create a directory for all archived/rotated files, and compress them giving them a different extension from the files you are currently inputting. In our environment we have rsyslog dumping to a file distinguishable by the source ip of the sending device, and the sending protocol (for example the files look like: logfile-x.x.x.x-imudp.log). The inputs.conf file only ingests files ending in *.log from our production syslog server, ignoring the rotated files that end in .gz (compressed with logrotate). You can also rotate to locations that are blacklisted within the inputs.conf, but we found the approach we took easier, and effective. For example, you can define the following in logrotate (adjust for your retention and rotation requirements):

/var/log/syslog/*.log
{
daily
olddir /var/log/syslog/archive
size 1k
copytruncate
rotate 7
compress
sharedscripts
postrotate
/bin/kill -HUP cat /var/run/syslogd.pid 2 > /dev/null 2> /dev/null || true
endscript
}

Splunk will ignore the rotated files because they don't meet the requirements defined within inputs.conf

[yannK]

Hi trross33.

This method works, but has a possible issue.
If Splunk had the time to read 99 lines of the primary file, then the line 100 is added and the file rotate just after, you will end up with a rotated file in a location that is not monitored.
And you will always have a chance to be missing the last lines of a log file, if your logs rotate quickly or if your forwarder is under speed constrains.
This is why It's a good idea to monitor the original file and at least the first copy. Because splunk compares the crc and can pick up the last lines on a rotated copy of the file.

[yannK]

An alternative method is to use a symlink so cancel the monitoring during the rotation.

/home/feed/symlink_test.log -> /home/feed/test.log

Have splunk monitors the symlink only
[monitor://home/feed/symlink_test.log]
followLinks=true

then in the logrotate config
when the rotation occurs : disable the symlink
then after the rotation : recreate the symlink

[yannK · Accepted solution]

The workarounds I found are :
A - replace the copytruncate rotation by a move rotation .
It may not always be a solution, some applications are pretty limited and need to keep the handle of the log file always open.

B- disable the monitoring just before the rotation.

The idea is to disable the monitoring before the rotation and re-enable it just after.
using the logrotate options. Splunk will simply detect the new files, and resume.

Here is my configuration :

• Inputs.conf in splunk in a specific app "input_rotate"
  cat ./opt/splunk/etc/apps/input_rotate/local/inputs.conf

  [monitor://home/feed/.log]
  disabled = false

  add additional parameters

• logrotate script /etc/logrotate.d/test

  "/home/feed/test.log" { 
  rotate 5 
  size=50M
  sharedscripts 
  copytruncate 
  compress 
  prerotate 
  /opt/splunk/bin/splunk disable app input_rotate -auth admin:changeme 
  endscript 
  postrotate 
  /opt/splunk/bin/splunk enable app input_rotate -auth admin:changeme 
  endscript 
  } 
  

Remarks :

• you may want to adapt to your own monitor inputs.
• if you prefer to disable only one input, instead of the app.

/opt/splunk/bin/splunk edit monitor "/home/feed/*.log*" -disabled true -auth admin:changeme

• the path to the splunk CLI has to be adapted to your forwarder path.
• it is important to monitoring the rotated/compressed version of the log file to avoid missing events.(my log.log* instead of just my log.log) Otherwise the last events before and during the copytruncate are lost. The splunk init crc will prevent the rotated versions to generate duplicates. you can compare the source to see from which file the events were monitored.

[hrawat_splunk]

Issue is resolved by code fix for 7.1.0 release ( SPL-143553).