[issue33369] Removing Popen log files in threads is racy on Windows

[Peter Boström]

Peter Boström  added the comment:

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

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue33369] Removing Popen log files in threads is racy on Windows

[Zachary Ware]

Zachary Ware  added the comment:

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.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue33369] Removing Popen log files in threads is racy on Windows

[Peter Boström]

New submission from Peter Boström :

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

--
components: Windows
files: racy_windows.py
messages: 315822
nosy: paul.moore, pbos, steve.dower, tim.golden, zach.ware
priority: normal
severity: normal
status: open
title: Removing Popen log files in threads is racy on Windows
type: behavior
versions: Python 2.7
Added file: https://bugs.python.org/file47552/racy_windows.py

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com