OS: Windows 10, version 1607 (OS Build 14393.2189)
Python --version: Python 2.7.3

Removing logfiles files just after Popen().wait() outside an open() block is racy on Windows. This seems to require multiple parallel workers to pull off, not sure where the synchronization issue lies (interpreter or os).

This report is spun off from the following pull request where we ran into the issue (we always log to log files instead of memory pipes but sometimes discard them after the worker has finished): https://github.com/google/gtest-parallel/pull/59#issuecomment-369551914

Attaching repro script, in it essentially all workers do this:

  command = ['ping', '-n', '1', '127.0.0.1']
  with open(file_name, 'w') as file_obj:
    task = subprocess.Popen(command, stdout=file_obj, stderr=file_obj)
    task.wait()

  print 'Removing %s\n' % file_name
  os.remove(file_name)

Here os.remove() fails fairly often with an exception even though there should be no handles left to the file: WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '25436.log'

Run (this seems to repro pretty reliably, more than half of the time on my machine):

C:\src>del *.log

C:\src>python racy_windows.py
Logging to 24788.log
Logging to 1052.log


Logging to 32320.log
Logging to 29316.log


Removing 1052.log

Exception in thread Thread-2:
Traceback (most recent call last):
  File "C:\python_27_amd64\files\lib\threading.py", line 551, in __bootstrap_inner
    self.run()
  File "C:\python_27_amd64\files\lib\threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)
  File "racy_windows.py", line 19, in __call__
    os.remove(file_name)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '1052.log'

Removing 24788.log

Exception in thread Thread-1:
Traceback (most recent call last):
  File "C:\python_27_amd64\files\lib\threading.py", line 551, in __bootstrap_inner
    self.run()
  File "C:\python_27_amd64\files\lib\threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)
  File "racy_windows.py", line 19, in __call__
    os.remove(file_name)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '24788.log'

Removing 29316.log
Removing 32320.log

You will get no support for Python 2.7.3 out of us (that patch release is over 6 years old!  At least try 2.7.14, or wait a week for 2.7.15) and most of us have lost interest in 2.7 altogether, particularly on Windows.  However, this sounds very much like other issues I've seen around the timing of Windows file handle handling.  Try adding a retry loop with a short sleep around your `os.remove` call.

Wow that's old, yeah that's fair (I wouldn't expect this to be backported to any old releases).

Our current "workaround" is to try os.remove, sleep, repeat X times. This seems still racy and not something we'd like to have in our script if it can be resolved upstream. Retried on 2.7.15rc1:

C:\src>del *.log
Could Not Find C:\src\*.log

C:\src>C:\Python2.7.15rc1\python.exe --version
Python 2.7.15rc1

C:\src>C:\Python2.7.15rc1\python.exe racy_windows.py
Logging to 5656.log

Logging to 13068.log

Logging to 27620.log

Logging to 18384.log

Removing 5656.log

ERxception in thread Thread-1:
Traceback (most recent call last):
  File "C:\Python2.7.15rc1\lib\threading.py", line 801, in __bootstrap_inner
    self.run()
  File "C:\Python2.7.15rc1\lib\threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "racy_windows.py", line 19, in __call__
    os.remove(file_name)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '5656.log'
emoving 13068.log
R
emoving 27620.log


Exception in thread Thread-3:
Traceback (most recent call last):
  File "C:\Python2.7.15rc1\lib\threading.py", line 801, in __bootstrap_inner
    self.run()
  File "C:\Python2.7.15rc1\lib\threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "racy_windows.py", line 19, in __call__
    os.remove(file_name)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '27620.log'
Exception in thread Thread-2:
Traceback (most recent call last):
  File "C:\Python2.7.15rc1\lib\threading.py", line 801, in __bootstrap_inner
    self.run()
  File "C:\Python2.7.15rc1\lib\threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "racy_windows.py", line 19, in __call__
    os.remove(file_name)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: '13068.log'


Removing 18384.log