6.6.3 issues reading syslog files after syslog rolls a file and restarts.

[dfronck]

We log just about everything to syslog and have Splunk read the syslog files. This has been working forever until we upgraded from 6.6.1 to 6.6.3.

Now, when syslog rolls a file, splunkd doesn't start reading the new file until we restart spunk.

/logs/file.log rolls to /logs/file.log.1
The new file is /logs/file.log

Splunk doesn't read either of those until the restart.

Anyone else seeing this?

[dfronck]

Sorry I can't help other than to say that upgrading from 6.6.3 to 6.6.4 fixed it for us. Now we're on 7.1.4 with a whole bunch of new issues!

[Paul1896]

Thanks @dfronck , we'll update our version today and then check it again.

[Paul1896]

We have the same issue with Splunk 6.6.8. Is there any solution now?

[hardikJsheth]

Do you see any error in Splunkd.log?

Following link has good steps to debug this type of issues.
https://wiki.splunk.com/Community:Troubleshooting_Monitor_Inputs

[dfronck]

We didn't seem to have this issue before we upgraded from 6.6.1 to 6.6.3. Maybe it was an issue but not as bad but I'm pretty sure this is new with 6.6.3.

There are no errors in the logs. In debug, I can see that the file rotates and splunk keeps looking at the .log.1 file descriptor and never changing offset.

I did some more testing. Configured splunk to monitor .log*. It still just looks at the old .log.1 file. It doesn't seem to care about the brand new .log file that's getting a ton of new data! It doesn't seem to be monitoring the directory for changes.

Anyway, the current work around that guarantees a consistent loss of data is to use copytruncate. Splunk keeps monitoring the same file so I don't lose a ton of logs anymore, just the 3 seconds that occur when the file gets truncated before splunk has re-read the new logs.

[dfronck]

I enabled debug for these 3 process and found what I suspected.

Splunk keeps monitoring the old log file even though there's a new /logs/file.log and the old file has been renamed to /logs/file.log.1.

It keeps using the old file descriptor and offset until you restart splunk.

11-06-2017 13:06:38.551 -0500 DEBUG TailReader - Enqueued file=/logs/file.log in tailreader0
11-06-2017 13:06:38.551 -0500 DEBUG TailReader - Start reading file="/logs/file.log" in tailreader0 thread
11-06-2017 13:06:38.551 -0500 DEBUG TailReader -   Will attempt to read file: /logs/file.log from existing fd.
11-06-2017 13:06:38.551 -0500 DEBUG TailReader -   Will attempt to read file: /logs/file.log from existing fd.
11-06-2017 13:06:38.551 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:38.551 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:38.551 -0500 DEBUG WatchedFile - seeking /logs/file.log to off=527773500
11-06-2017 13:06:38.551 -0500 DEBUG WatchedFile - Reached EOF: fname=/logs/file.log fishstate=key=0x6284c567d04aff4f sptr=527773500 scrc=0x876eab63e055a62d fnamecrc=0x864d9a294109368b modtime=1509991598
11-06-2017 13:06:38.551 -0500 DEBUG TailReader - Finished reading file='/logs/file.log' in tailreader0 thread, disposition=NO_DISPOSITION, deferredBy=3.000
11-06-2017 13:06:38.551 -0500 DEBUG TailReader - Defering notification for file=/logs/file.log by 3.000ms
11-06-2017 13:06:41.385 -0500 DEBUG TailingProcessor - Deferred notification for path='/logs/file.log'.

11-06-2017 13:06:41.385 -0500 DEBUG TailReader - Enqueued file=/logs/file.log in tailreader0
11-06-2017 13:06:41.385 -0500 DEBUG TailReader - Enqueued file=/logs/file.log in tailreader0
11-06-2017 13:06:41.387 -0500 DEBUG TailReader - Start reading file="/logs/file.log" in tailreader0 thread
11-06-2017 13:06:41.387 -0500 DEBUG TailReader -   Will attempt to read file: /logs/file.log from existing fd.
11-06-2017 13:06:41.389 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:41.389 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:41.389 -0500 DEBUG WatchedFile - seeking /logs/file.log to off=527773500
11-06-2017 13:06:41.389 -0500 DEBUG WatchedFile - Reached EOF: fname=/logs/file.log fishstate=key=0x6284c567d04aff4f sptr=527773500 scrc=0x876eab63e055a62d fnamecrc=0x864d9a294109368b modtime=1509991601
11-06-2017 13:06:41.389 -0500 DEBUG TailReader - Finished reading file='/logs/file.log' in tailreader0 thread, disposition=NO_DISPOSITION, deferredBy=3.000
11-06-2017 13:06:41.389 -0500 DEBUG TailReader - Finished reading file='/logs/file.log' in tailreader0 thread, disposition=NO_DISPOSITION, deferredBy=3.000
11-06-2017 13:06:41.389 -0500 DEBUG TailReader - Defering notification for file=/logs/file.log by 3.000ms
11-06-2017 13:06:44.220 -0500 DEBUG TailingProcessor - Deferred notification for path='/logs/file.log'.
11-06-2017 13:06:44.220 -0500 DEBUG TailingProcessor - Deferred notification for path='/logs/file.log'.

11-06-2017 13:06:44.220 -0500 DEBUG TailReader - Enqueued file=/logs/file.log in tailreader0
11-06-2017 13:06:44.220 -0500 DEBUG TailReader - Enqueued file=/logs/file.log in tailreader0
11-06-2017 13:06:44.220 -0500 DEBUG TailReader - Start reading file="/logs/file.log" in tailreader0 thread
11-06-2017 13:06:44.220 -0500 DEBUG TailReader - Start reading file="/logs/file.log" in tailreader0 thread
11-06-2017 13:06:44.221 -0500 DEBUG TailReader -   Will attempt to read file: /logs/file.log from existing fd.
11-06-2017 13:06:44.221 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:44.221 -0500 DEBUG TailReader - About to read data (Reusing existing fd for file='/logs/file.log').
11-06-2017 13:06:44.221 -0500 DEBUG WatchedFile - seeking /logs/file.log to off=527773500
11-06-2017 13:06:44.221 -0500 DEBUG WatchedFile - Reached EOF: fname=/logs/file.log fishstate=key=0x6284c567d04aff4f sptr=527773500 scrc=0x876eab63e055a62d fnamecrc=0x864d9a294109368b modtime=1509991604
11-06-2017 13:06:44.221 -0500 DEBUG WatchedFile - Reached EOF: fname=/logs/file.log fishstate=key=0x6284c567d04aff4f sptr=527773500 scrc=0x876eab63e055a62d fnamecrc=0x864d9a294109368b modtime=1509991604
11-06-2017 13:06:44.221 -0500 DEBUG TailReader - Finished reading file='/logs/file.log' in tailreader0 thread, disposition=NO_DISPOSITION, deferredBy=3.000
11-06-2017 13:06:44.221 -0500 DEBUG TailReader - Defering notification for file=/logs/file.log by 3.000ms
11-06-2017 13:06:47.052 -0500 DEBUG TailingProcessor - Deferred notification for path='/logs/file.log'.
11-06-2017 13:06:47.052 -0500 DEBUG TailingProcessor - Deferred notification for path='/logs/file.log'.

category.TailingProcessor=DEBUG
category.WatchedFile=DEBUG
category.TailReader=DEBUG