classification
Title: WatchedFileHandler can fail due to race conditions or file open issues.
Type: Stage: resolved
Components: Versions: Python 3.4, Python 3.5, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: python-dev, vinay.sajip, vishvananda
Priority: normal Keywords: patch

Created on 2014-06-13 00:56 by vishvananda, last changed 2014-06-14 09:23 by python-dev. This issue is now closed.

Files
File name Uploaded Description Edit
log.py vishvananda, 2014-06-13 00:58 Concurrency Error Repro
log2.py vishvananda, 2014-06-13 01:00 Permission Denied Error Repro
log.diff vishvananda, 2014-06-13 01:09 Potential Fix
Messages (6)
msg220403 - (view) Author: Vishvananda Ishaya (vishvananda) Date: 2014-06-13 00:56
If there is a failure during the re-opening of the file WatchedFileHandler can lose the ability to log and starts throwing IOErrors.
msg220404 - (view) Author: Vishvananda Ishaya (vishvananda) Date: 2014-06-13 00:58
The attached file illustrates the error when attempting to call handler.emit() from multiple threads at the same time.
msg220405 - (view) Author: Vishvananda Ishaya (vishvananda) Date: 2014-06-13 01:00
The attached file illustrates the error when attempting to call handler.emit() when the file cannot be opened. Even if this situation is later remedied all future emit() calls will fail since stream.flush() is called on a fd that has already been closed.
msg220408 - (view) Author: Vishvananda Ishaya (vishvananda) Date: 2014-06-13 01:09
Example diff against python 2.7.6 that fixes the issues
msg220540 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2014-06-14 09:16
There *is* a race condition with WatchedFileHandler - see #14632 - but there is not much that can be done about it (see the various comments in that issue). BTW, I wasn't able to reproduce the threading problem from your script: there were no errors and the file 'foo' contained three lines with 'foo', as expected.

Your suggested fix doesn't seem right, either - the problem is that a failed _open() leaves a closed stream in self.stream, and the correct fix is to set this to None in case the _open fails. But thanks for the suggestion.
msg220541 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2014-06-14 09:23
New changeset bb8b0c7fefd0 by Vinay Sajip in branch '2.7':
Issue #21742: Set stream to None after closing.
http://hg.python.org/cpython/rev/bb8b0c7fefd0

New changeset 6f1f38775991 by Vinay Sajip in branch '3.4':
Issue #21742: Set stream to None after closing.
http://hg.python.org/cpython/rev/6f1f38775991

New changeset 9913ab26ca6f by Vinay Sajip in branch 'default':
Closes #21742: Merged fix from 3.4.
http://hg.python.org/cpython/rev/9913ab26ca6f
History
Date User Action Args
2014-06-14 09:23:34python-devsetstatus: open -> closed

nosy: + python-dev
messages: + msg220541

resolution: fixed
stage: resolved
2014-06-14 09:16:14vinay.sajipsetmessages: + msg220540
versions: - Python 3.1, Python 3.2, Python 3.3
2014-06-13 01:53:51ned.deilysetnosy: + vinay.sajip
2014-06-13 01:09:39vishvanandasetfiles: + log.diff
keywords: + patch
messages: + msg220408
2014-06-13 01:00:35vishvanandasetfiles: + log2.py

messages: + msg220405
2014-06-13 00:58:29vishvanandasetfiles: + log.py

messages: + msg220404
2014-06-13 00:56:54vishvanandacreate