Issue #14632: Updated WatchedFileHandler to deal with race condition. Thanks to John Mulligan for the problem report and patch.
diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py
index 75b3e4d..ee1c211 100644
--- a/Lib/test/test_logging.py
+++ b/Lib/test/test_logging.py
@@ -1,6 +1,6 @@
#!/usr/bin/env python
#
-# Copyright 2001-2011 by Vinay Sajip. All Rights Reserved.
+# Copyright 2001-2012 by Vinay Sajip. All Rights Reserved.
#
# Permission to use, copy, modify, and distribute this software and its
# documentation for any purpose and without fee is hereby granted,
@@ -18,7 +18,7 @@
"""Test harness for the logging module. Run all tests.
-Copyright (C) 2001-2011 Vinay Sajip. All Rights Reserved.
+Copyright (C) 2001-2012 Vinay Sajip. All Rights Reserved.
"""
import logging
@@ -33,6 +33,7 @@
import json
import os
import queue
+import random
import re
import select
import socket
@@ -539,8 +540,8 @@
h = logging.handlers.WatchedFileHandler(fn, delay=True)
if existing:
dev, ino = h.dev, h.ino
- self.assertNotEqual(dev, -1)
- self.assertNotEqual(ino, -1)
+ self.assertEqual(dev, -1)
+ self.assertEqual(ino, -1)
r = logging.makeLogRecord({'msg': 'Test'})
h.handle(r)
# Now remove the file.
@@ -581,6 +582,41 @@
self.assertFalse(h.shouldFlush(r))
h.close()
+ @unittest.skipUnless(threading, 'Threading required for this test.')
+ def test_race(self):
+ # Issue #14632 refers.
+ def remove_loop(fname, tries):
+ for _ in range(tries):
+ try:
+ os.unlink(fname)
+ except OSError:
+ pass
+ time.sleep(0.004 * random.randint(0, 4))
+
+ def cleanup(remover, fn, handler):
+ handler.close()
+ remover.join()
+ if os.path.exists(fn):
+ os.unlink(fn)
+
+ fd, fn = tempfile.mkstemp('.log', 'test_logging-3-')
+ os.close(fd)
+ del_count = 1000
+ log_count = 1000
+ remover = threading.Thread(target=remove_loop, args=(fn, del_count))
+ remover.daemon = True
+ remover.start()
+ for delay in (False, True):
+ h = logging.handlers.WatchedFileHandler(fn, delay=delay)
+ self.addCleanup(cleanup, remover, fn, h)
+ f = logging.Formatter('%(asctime)s: %(levelname)s: %(message)s')
+ h.setFormatter(f)
+ for _ in range(log_count):
+ time.sleep(0.005)
+ r = logging.makeLogRecord({'msg': 'testing' })
+ h.handle(r)
+
+
class BadStream(object):
def write(self, data):
raise RuntimeError('deliberate mistake')
@@ -3724,7 +3760,6 @@
# Failures occur on some systems for MIDNIGHT and W0.
# Print detailed calculation for MIDNIGHT so we can try to see
# what's going on
- import time
if when == 'MIDNIGHT':
try:
if rh.utc: