Hello rsyslog community,
I am working on a Centos 7 system that has rsyslog 8.2202.0 configured to monitor and process perhaps 2 dozen log files with the imfile module.
The module is loaded with the module directive like this:
module(load="imfile" mode="inotify")
And the file references are set up using several config files in the /etc/rsyslog.d directory containing entries similar to the following:
input(type="imfile"
File="/var/log/activity*.log"
Severity="info"
Tag="pfx:activity"
readTimeout="2"
reopenOnTruncate="on"
startmsg.regex="^[0-9]{4}-[0-9]{2}-[0-9]{2}"
)
Some of the referenced files normally receive one or more entries every second.
Other referenced files grow very slowly, receiving maybe one or two entries a day.
We must be able to handle that some subset of the entries will be multi-line entries.
Every entry begins with a date stamp. We use the startmsg.regex capability to detect the date stamp at the start of a line so that imfile can correctly detect the start of a new record.
We expect that if no new line is added to any specific file within 2 seconds, then any existing line(s) of unprocessed data in that file can be considered a complete record, so we have configured the "readTimeout" to be "2".
What we expect is that after 2 seconds of no additional content being added to a file, the readTimeout timer will expire and the last line of that file will be considered a complete entry and be processed.
What we are actually seeing is that as long as ANY monitored file has new data added to it within 2 seconds, then no timer expires.
Because some files receive data every second, the last line in each slow growing files is not processed until hours, maybe days after it is written, when another entry is added and the date stamp on the new line matches the startmsg.regex.
When the software on the host is running normally, the continuous stream of log records being added to the frequently updated files prevents the readTimeout from ever occurring. This makes it appear as if the readTimeout never expires. I originally thought this was a recurrence of #1445 (https://github.com/rsyslog/rsyslog/issues/1445), which was fixed in 8.28 by #1598 (https://github.com/rsyslog/rsyslog/pull/1598). Our version (8.2202.0) should contain that fix (I do see it in the release note history). However, the behavior is not exactly the same as described in #1445, because I can cause the final lines to be processed by stopping the processes that are generating the frequent log records. Once there are no new lines to process in any monitored file, then the readTimeout occurs and the final lines of the slow growing files are processed.
Is this the intended behavior? Am I misunderstanding the configuration of the imfile module? Is there any way to get the timeouts to occur on a file-by-file basis instead of requiring all of the monitored files to be unchanged for the readTimeout?
I really wish I could disable the multi-line handling entirely, but as you might guess, the reason we had to configure it this way is that some of the files are generated by software that is not under our control.
I would prefer not to try to write "dummy" records into the files from another process to push out the "straggler" final lines from the slow growing files. Even though they aren't written very often, I just know that someday the external process and the software we're trying to collect the data from will both try to write at nearly the same time and the result will be a mangled mix of the two records.
Thank you for any suggestions,
Russ Miranda
_______________________________________________
rsyslog mailing list
https://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
I am working on a Centos 7 system that has rsyslog 8.2202.0 configured to monitor and process perhaps 2 dozen log files with the imfile module.
The module is loaded with the module directive like this:
module(load="imfile" mode="inotify")
And the file references are set up using several config files in the /etc/rsyslog.d directory containing entries similar to the following:
input(type="imfile"
File="/var/log/activity*.log"
Severity="info"
Tag="pfx:activity"
readTimeout="2"
reopenOnTruncate="on"
startmsg.regex="^[0-9]{4}-[0-9]{2}-[0-9]{2}"
)
Some of the referenced files normally receive one or more entries every second.
Other referenced files grow very slowly, receiving maybe one or two entries a day.
We must be able to handle that some subset of the entries will be multi-line entries.
Every entry begins with a date stamp. We use the startmsg.regex capability to detect the date stamp at the start of a line so that imfile can correctly detect the start of a new record.
We expect that if no new line is added to any specific file within 2 seconds, then any existing line(s) of unprocessed data in that file can be considered a complete record, so we have configured the "readTimeout" to be "2".
What we expect is that after 2 seconds of no additional content being added to a file, the readTimeout timer will expire and the last line of that file will be considered a complete entry and be processed.
What we are actually seeing is that as long as ANY monitored file has new data added to it within 2 seconds, then no timer expires.
Because some files receive data every second, the last line in each slow growing files is not processed until hours, maybe days after it is written, when another entry is added and the date stamp on the new line matches the startmsg.regex.
When the software on the host is running normally, the continuous stream of log records being added to the frequently updated files prevents the readTimeout from ever occurring. This makes it appear as if the readTimeout never expires. I originally thought this was a recurrence of #1445 (https://github.com/rsyslog/rsyslog/issues/1445), which was fixed in 8.28 by #1598 (https://github.com/rsyslog/rsyslog/pull/1598). Our version (8.2202.0) should contain that fix (I do see it in the release note history). However, the behavior is not exactly the same as described in #1445, because I can cause the final lines to be processed by stopping the processes that are generating the frequent log records. Once there are no new lines to process in any monitored file, then the readTimeout occurs and the final lines of the slow growing files are processed.
Is this the intended behavior? Am I misunderstanding the configuration of the imfile module? Is there any way to get the timeouts to occur on a file-by-file basis instead of requiring all of the monitored files to be unchanged for the readTimeout?
I really wish I could disable the multi-line handling entirely, but as you might guess, the reason we had to configure it this way is that some of the files are generated by software that is not under our control.
I would prefer not to try to write "dummy" records into the files from another process to push out the "straggler" final lines from the slow growing files. Even though they aren't written very often, I just know that someday the external process and the software we're trying to collect the data from will both try to write at nearly the same time and the result will be a mangled mix of the two records.
Thank you for any suggestions,
Russ Miranda
_______________________________________________
rsyslog mailing list
https://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.