Repository navigation
Leaked semaphore objects in test_concurrent_futures #104090
Description
Bug report
Configuration:
./configure --with-pydebug
$ ./python -m test test_concurrent_futures
0:00:00 load avg: 5.30 Run tests sequentially
0:00:00 load avg: 5.30 [1/1] test_concurrent_futures
/workspace/cpython/Lib/multiprocessing/popen_fork.py:66: DeprecationWarning: This process (pid=150426) is multi-threaded, use of fork() may lead to deadlocks in the child.
self.pid = os.fork()
/workspace/cpython/Lib/multiprocessing/resource_tracker.py:224: UserWarning: resource_tracker: There appear to be 6 leaked semaphore objects to clean up at shutdown
warnings.warn('resource_tracker: There appear to be %d '
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
Traceback (most recent call last):
File "/workspace/cpython/Lib/multiprocessing/util.py", line 300, in _run_finalizers
finalizer()
File "/workspace/cpython/Lib/multiprocessing/util.py", line 224, in __call__
res = self._callback(*self._args, **self._kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/workspace/cpython/Lib/multiprocessing/synchronize.py", line 87, in _cleanup
sem_unlink(name)
FileNotFoundError: [Errno 2] No such file or directory
test_concurrent_futures passed in 2 min 17 sec
== Tests result: SUCCESS ==
1 test OK.
Total duration: 2 min 17 sec
Tests result: SUCCESSYour environment
- CPython versions tested on: CPython 3.12.0a7+
- Operating system and architecture: Ubuntu 22.04.2 LTS | Linux-5.15.0-47-generic-x86_64-with-glibc2.35 little-endian
Linked PRs
- gh-104090: Fix unittest collectedDurations resources leak #106795
- gh-104090: Update Resource Tracker to return exit code based on resource leaked found or not #106807
- [3.12] gh-104090: Fix unittest collectedDurations resources leak (GH-106795) #106888
- gh-104090: Add exit code to multiprocessing ResourceTracker #115410
Activity
sunmy2019 commented on May 3, 2023
The leakage is from FailingInitializerMixin. Don't know how to fix though.
sobolevn commented on May 3, 2023
Two failing tests:
bityob commented on Jul 14, 2023
diff --git a/Lib/unittest/result.py b/Lib/unittest/result.py index 5ca4c23238..fa9bea47c8 100644 --- a/Lib/unittest/result.py +++ b/Lib/unittest/result.py @@ -43,6 +43,7 @@ def __init__(self, stream=None, descriptions=None, verbosity=None): self.skipped = [] self.expectedFailures = [] self.unexpectedSuccesses = [] + self.collectedDurations = [] self.shouldStop = False self.buffer = False self.tb_locals = False @@ -157,6 +158,12 @@ def addUnexpectedSuccess(self, test): """Called when a test was expected to fail, but succeed.""" self.unexpectedSuccesses.append(test) + def addDuration(self, test, elapsed): + """Called when a test finished to run, regardless of its outcome.""" + # support for a TextTestRunner using an old TestResult class + if hasattr(self, "collectedDurations"): + self.collectedDurations.append((test, elapsed)) + def wasSuccessful(self): """Tells whether or not this result was a success.""" # The hasattr check is for test_result's OldResult test. That(reduced the output so it will be clearer)
5. In other hand, when I ignore this line, the sem_ulink for those 3 semaphore objects are called suceesfully after the addDuration function but from another trace
bityob commented on Jul 14, 2023
Ok, found more -
The leaked semaphore objects are from FailingInitializerMixin (as @sunmy2019 mentioned before, but now it's clearer for me).
This line creates a new queue with 3 semaphore related and when the collectedDurations is not empty the self.log_queue is not released (still in used I guess)
Still investigating
shailshouryya commented on Jul 14, 2023
For some additional context, I also ran git bisect and landed on the same commit identified above. I did not get as far as the post above me did in terms of identifying the exact reasons why the 6 leaked semaphore objects were not cleaned up before shutdown, but I also narrowed down the problem and found the 6 leaked semaphore objects warning goes away when the following block (also mentioned above):
def addDuration(self, test, elapsed): """Called when a test finished to run, regardless of its outcome.""" # support for a TextTestRunner using an old TestResult class if hasattr(self, "collectedDurations"): self.collectedDurations.append((test, elapsed))is completely commented out:
Another thing that I found interesting was the leaked semaphore objects look like TemporaryFiles:
However, I'm not sure about this, since it does not look like TemporaryFileis called anywhere in test_concurrent_futures.py except for
cpython/Lib/test/test_concurrent_futures.py
Lines 1248 to 1249 in 89867d2
bityob commented on Jul 14, 2023
@shailshouryya
Not related to TemporaryFile, those are virtual files used by each semaphore object as the system locking mechanisem
Source: https://linux.die.net/man/7/sem_overview
For example, if you stop the process in the middle
you will be able to see those virtual files here
which will be deleted on _multiprocessing.sem_unlink method
bityob commented on Jul 14, 2023
Ok, found how to fix the issue! 🚀
Full details
The current code calls self.collectedDurations.append((test, elapsed)) on addDuration method (as wrote in previous comment).
This causes the 3 sempahors of FailingInitializerMixin.log_queue to not being released before the resource tracker is stopped and clear by itself all left resources.
Example 1 (without .collectedDurations.append), the ResourceTracker is stopped after we clear the 3 semaphors -
Example 2 (current code), the ResourceTracker is stopped before we clear the 3 semaphors -
This happens since we call _run_finalizers() after resource_tracker._resource_tracker._stop()
So, optional solution No.1 will be to change the order of the calls, like this -
And it solves the issue perfectly
@vstinner -
I saw that you were the one who wrote this part,
Can we do such change?
If yes, I'll make a PR for it.
@iritkatriel -
I'll happy to here what you think here, thanks.
Still open question for me, is why the objects are not finalize normally (by the gc I assume) like it was before.
I'm still investigating on this
bityob commented on Jul 15, 2023
Hey,
Found better solution and also what's happening here.
The reason those 3 semaphores were still alive and not deleted, it's because there weren't garabage collected yet, since they have a reference.
How?
Those 3 semaphors are related to FailingInitializerMixin.log_queue object (they are created as part of this queue).
This mixin is used to create the test class ProcessPoolSpawnFailingInitializerTest which was used on the test result private object collectedDurations, and since the result object continue to live after the test object ended, the test object can't be collected and therefore the semaphors too...
Why we need the test object there?
For displaying it on unittest.runner._printDurations method.
So how to fix it?
Very simple, instead of passing the test object, we just need here the test repr only!
And this works perfect! 🚀
I'll create a PR for this
@iritkatriel
iritkatriel commented on Jul 15, 2023
Good find!
Merge branch 'pythongh-104090-leaked-semaphore-objects-in-test_concur…
pythongh-104090: Fix unittest collectedDurations resources leak
Merge remote-tracking branch 'upstream/main' into pythongh-104090-fix…
Merge remote-tracking branch 'upstream/main' into pythongh-104090-fix…
16 remaining items
Merge branch 'main' into pythongh-104090-fix-leaked-semaphors-on-test…
Merge branch 'main' into pythongh-104090-fix-leaked-semaphors-on-test…
gh-104090: Add exit code to multiprocessing ResourceTracker (GH-115410)
encukou commented on Feb 22, 2024
That PR was a helper to make failures like this easier to diagnose.
The issue itself is not fixed; it still appears in refleak tests (./python -m test test_concurrent_futures -R:).
pythongh-104090: Add exit code to multiprocessing ResourceTracker (py…
zulle09 commented on Mar 19, 2024
I get the same error in my case. I'm doing distributed training using spawn multiprocessing and DDP, also at the end of running my application I get a specific number of leaked semaphores.
This is the link of the issue.
I'm wondering if this issue is solved or not.
pythongh-104090: Add exit code to multiprocessing ResourceTracker (py…
pythongh-104090: Add exit code to multiprocessing ResourceTracker (py…