Apache Commons IO Tailer delivers old log messages

My code is given below.

public static void main(String[] args) {
    // TODO code application logic here
    File pcounter_log = new File("c:\development\temp\test.log");

try {

    Tailer tailer = new Tailer(pcounter_log, new FileListener("c:\development\temp\test.log",getLogPattern()), 5000,true);

    Thread thread = new Thread(tailer);
    thread.start();
} catch (Exception e) {
    System.out.println(e);
}
}

public class FileListener extends TailerListenerAdapter {


 public void handle(String line) {
        for (String logPattern : pattern) {
            if (line.contains(logPattern)) {
                logger.info(line);

            }
        }
    }
}

Here getLogPattern() returns an ArrayList containing values like [info,error,abc.catch,warning]. When running this code, I get old log message followed by new log message. I.e. the output is like this:

20 May 2011 07:06:02,305  INFO FileListener:? - 20 May 2011 07:06:01,230 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:06:55,052  INFO FileListener:? - 20 May 2011 07:06:55,016 DEBUG  - readScriptErrorStream()
20 May 2011 07:06:56,056  INFO FileListener:? - 20 May 2011 07:06:55,040 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:07:01,241  INFO FileListener:? - 20 May 2011 07:07:01,219 DEBUG  - readScriptErrorStream()
20 May 2011 07:07:02,245  INFO FileListener:? -  20 May 2011 07:07:01,230 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:07:55,020  INFO FileListener:? -  20 May 2011 07:07:55,016 DEBUG  - readScriptErrorStream()
20 May 2011 07:07:56,024  INFO FileListener:? - 20  2011 07:07:55,030 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:08:01,269  INFO FileListener:? -  20 May 2011 07:08:01,227 DEBUG - readScriptErrorStream()
20 May 2011 07:08:02,273  INFO FileListener:? -  20 May 2011 07:08:01,230 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:08:21,234  INFO FileListener:? -  20 May 2011 06:40:02,461 DEBUG  - readScriptErrorStream()
20 May 2011 07:08:22,237  INFO FileListener:? -  20 May 2011 06:40:02,468 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:08:23,242  INFO FileListener:? -  20 May 2011 06:41:01,224 DEBUG - readScriptErrorStream()
20 May 2011 07:08:24,250  INFO FileListener:? -  20 May 2011 06:41:01,232 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:08:25,261  INFO FileListener:? -  20 May 2011 06:42:01,218 DEBUG  - readScriptErrorStream()
20 May 2011 07:08:26,265  INFO FileListener:? -  20 May 2011 06:42:01,230 DEBUG   - exiting readScriptErrorStream()
20 May 2011 07:08:27,272  INFO FileListener:? -  20 May 2011 06:43:01,223 DEBUG  - readScriptErrorStream()
20 May 2011 07:08:28,275  INFO FileListener:? -  20 May 2011 06:4开发者_JS百科3:01,231 DEBUG   - exiting readScriptErrorStream()

How to avoid to get old log messages from log file like this?

Oh boy, I have wasted an entire day thinking it was my dodgy threading, but I now see others have shared my pain. Oh well, at least I won't waste another day looking at it.

But I did look at the source code. I am sure the error is occuring here in the Tailer.java file:

boolean newer = FileUtils.isFileNewer(file, last); // IO-279, must be done first
...
...
else if (newer) {
    /*
    * This can happen if the file is truncated or overwritten with the 
    * exact same length of information. In cases like this, the file
    * position needs to be reset
    */
    position = 0;
    reader.seek(position);
...

It seems it's possible that the file modification data can change before the data is written. I'm no expert on why this would be. I am getting my log files from the network, so perhaps all sorts of caching is going on that means you are not garunteed that a newer file will contain any more data.

I have updated the source and removed this section. For me, the chances of a file getting truncated/recreated with exactly the same number of bytes is minimal. I'm referencing 10MB rolling log files.

I see that this is a known issue ( IO-279 LINK HERE ). However, it's marked as resolved and that's clearly not the case. I'll contact the developers to see if there's something in the pipeline. It would seem they're of the same opinion as me about the fix.

https://issues.apache.org/jira/browse/IO-279?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel

What version of commons.io are ( were ) you using? I experienced this error with 2.0.1. I updated to 2.3, and it seems to be working properly ( so far )

I know that this is a very old thread, but I just ran into a similar issue with Tailer. It turned out that Tailer had two threads reading the file concurrently.

I traced it back to how I had created the Tailer instance. Rather than using one of their 3 recommendations (static helper method, Executor, or Thread) I had created the instance with the static helper method and then fed the instance created into a Thread which seemed to result in two threads reading the file.

Once I corrected this (by removing the call to the static helper method and just using one of the overloaded Tailer constructors and a Thread) the issue went away.

Hope this helps someone.