What is the expected behavior for slow writing log files?

[the_wolverine]

I believe I have an application that is unusually slow in writing its events to a log file. Events are multi-lined but the application (I believe) takes several seconds to write each line.

If I were monitoring this file with Universal forwarder, would this explain some improper linebreaking? If so, is there any setting that can be configured that will tell Splunk to allow X amount of time for the event to complete writing? If not, I could delay indexing of that log file until it is complete.

I have tested indexing of a complete file which writes just fine.

[dwaddle · Accepted solution]

Yes, there could definitely be some improper line breaking going on here. I've seen this before with systems that do not line-buffer the logfile (Oracle JVM and its GC log comes to mind).

As a forwarder is reading a file, if it hits EOF and the file size does not grow for a few seconds, it will send what it has to the indexer with a "done" flag - meaning "I read to EOF and nothing more was forthcoming". The "done" flag will hint to the system doing event parsing (indexer or heavy forwarder) that the event in question is over, and no more breaking/merging is necessary.

If you are in control of the program writing the logs, I would suggest a sane buffering setup. If you are doing multi-line events, then make the stdio buffer at least big enough to hold your largest event, and fflush() the file when your event is written. (This assumes the ANSI C stdio.h API - for other langauges, do the needful translation)

If you are not in control of the program writing the logs you can try adjusting the time_before_close option in your inputs.conf [monitor://] stanza. Set this to a larger value than how long you think the application is taking to write the whole event. Note this will cause the forwarder to use more file handles - depending on how many files you are monitoring in this stanza, you may want to increase the open files limit.

[the_wolverine]

Thanks for your answer, dwaddle. I'm going to give time_before_close setting a try.