[issue14632] Race condition in WatchedFileHandler leads to unhandled exception

[Charles-François Natali]

Charles-François Natali <neologix at free.fr> added the comment:

> I can't see why this always works, while John's script sometimes fails.

It does fail consistently on my machine.
I'm attaching the diff just in case.

----------
Added file: http://bugs.python.org/file25345/test_logging_race.diff

_______________________________________
Python tracker <report at bugs.python.org>
<http://bugs.python.org/issue14632>
_______________________________________
-------------- next part --------------
diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py
--- a/Lib/test/test_logging.py
+++ b/Lib/test/test_logging.py
@@ -33,6 +33,7 @@
 import json
 import os
 import queue
+import random
 import re
 import select
 import socket
@@ -527,6 +528,39 @@
         self.assertEqual(h.name, 'anothergeneric')
         self.assertRaises(NotImplementedError, h.emit, None)
 
+    @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()
+        h = logging.handlers.WatchedFileHandler(fn)
+        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)
+
     def test_builtin_handlers(self):
         # We can't actually *use* too many handlers in the tests,
         # but we can try instantiating them with various options