Mailing-List: contact issues-help@commons.apache.org; run by ezmlm
Precedence: bulk
Reply-To: issues@commons.apache.org
Date: Wed, 1 Feb 2017 04:20:51 +0000 (UTC)
From: "ASF GitHub Bot (JIRA)" <jira@apache.org>
To: issues@commons.apache.org
Message-ID: <JIRA.13039382.1485922721000.5489.1485922851561@Atlassian.JIRA>
In-Reply-To: <JIRA.13039382.1485922721000@Atlassian.JIRA>
References: <JIRA.13039382.1485922721000@Atlassian.JIRA> <JIRA.13039382.1485922721581@jira-lw-us.apache.org>
Subject: [jira] [Commented] (IO-528) Tailer.run race condition runaway
 logging
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit
archived-at: Wed, 01 Feb 2017 04:21:02 -0000


    [ https://issues.apache.org/jira/browse/IO-528?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15848000#comment-15848000 ] 

ASF GitHub Bot commented on IO-528:
-----------------------------------

GitHub user davidmoten opened a pull request:

    https://github.com/apache/commons-io/pull/29

    [IO-528] fix Tailer.run race condition runaway logging

    `Tailer.run` has a race condition that can have serious effects. 
    
    The `run()` method has two while loops. The first waits till the file exists and the second loop reads lines from the file doing some file rotation checking on the way.  If the file is deleted while the second loop is in progress then the loop goes crazy logging warnings that look like this:
    
    `
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
    INFO: file rotated
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
    WARNING: file not found
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
    INFO: file rotated
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
    WARNING: file not found
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
    INFO: file rotated
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
    WARNING: file not found
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
    INFO: file rotated
    Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
    WARNING: file not found
    `
    
    In our case this had serious effects. The file being tailed was deleted by another process and all available disk space was rapidly used up by the logging. This crashed a system.
    
    The fix is to put a sleep after the call to `fileNotFound()`.
    
    I haven't made a unit test because reliably triggering this problem would involve a major refactor of the `run` method to make it testable.

You can merge this pull request into a Git repository by running:

    $ git pull https://github.com/davidmoten/commons-io fix-tailer-race-condition

Alternatively you can review and apply these changes as the patch at:

    https://github.com/apache/commons-io/pull/29.patch

To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:

    This closes #29
    
----
commit b6c13341564475f4b804ec8e46f665211236b7f7
Author: Dave Moten <davidmoten@gmail.com>
Date:   2017-02-01T03:54:00Z

    fix Tailer.run race condition runaway logging

----


> Tailer.run race condition runaway logging
> -----------------------------------------
>
>                 Key: IO-528
>                 URL: https://issues.apache.org/jira/browse/IO-528
>             Project: Commons IO
>          Issue Type: Bug
>          Components: Utilities
>    Affects Versions: 2.5
>            Reporter: Dave Moten
>
> `Tailer.run` has a race condition that can have serious effects. 
> The `run()` method has two while loops. The first waits till the file exists and the second loop reads lines from the file doing some file rotation checking on the way.  If the file is deleted while the second loop is in progress then the loop goes crazy logging warnings that look like this:
> `
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
> INFO: file rotated
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
> WARNING: file not found
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
> INFO: file rotated
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
> WARNING: file not found
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
> INFO: file rotated
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
> WARNING: file not found
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileRotated
> INFO: file rotated
> Dec 06, 2016 1:02:18 AM com.github.davidmoten.logan.LogFile$1 fileNotFound
> WARNING: file not found
> `
> In our case this had serious effects. The file being tailed was deleted by another process and all available disk space was rapidly used up by the logging. This crashed a system.
> The fix is to put a sleep after the call to `fileNotFound()`.
> This problem was raised in IO-398 three years ago but no change was made to the code base.
> PR submitted via github repo.


--
This message was sent by Atlassian JIRA
(v6.3.15#6346)