[pypy-issue] Issue #2905: "error: release unlocked lock" (pypy/pypy)

hugovk issues-reply at bitbucket.org
Thu Oct 25 11:10:07 EDT 2018


New issue 2905: "error: release unlocked lock"
https://bitbucket.org/pypy/pypy/issues/2905/error-release-unlocked-lock

hugovk:

The Pillow imaging library is tested against PyPy and PyPy3 (both 5.8) on Travis CI (Linux) and PyPy2 (6.0) on AppVeyor (Windows).

Occasionally the PyPy build on AppVeyor errors. It passes after restarting the build. Here's five. Of a sequence of 19 builds, 5 failed due to this, 13 passed, one was a valid fail. This has been happening since at least July 2018.


```
Tests/test_image_resample.py::TestImagingCoreResampleAccuracy::test_enlarge_bilinear ERROR [ 61%]
=================================== ERRORS ====================================
_ ERROR at teardown of TestImagingCoreResampleAccuracy.test_enlarge_bilinear __
self = <contextlib.GeneratorContextManager object at 0x077b5c70>, type = None
value = None, traceback = None
    def __exit__(self, type, value, traceback):
        if type is None:
            try:
>               self.gen.next()
c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py:24: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py:24: in __exit__
    self.gen.next()
c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py:1331: in removeHandler
    _releaseLock()
c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py:232: in _releaseLock
    _lock.release()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <_RLock owner=None count=0>
    def release(self):
        """Release a lock, decrementing the recursion level.
    
            If after the decrement it is zero, reset the lock to unlocked (not owned
            by any thread), and if any other threads are blocked waiting for the
            lock to become unlocked, allow exactly one of them to proceed. If after
            the decrement the recursion level is still nonzero, the lock remains
            locked and owned by the calling thread.
    
            Only call this method when the calling thread owns the lock. A
            RuntimeError is raised if this method is called when the lock is
            unlocked.
    
            There is no return value.
    
            """
        if self.__owner != _get_ident():
            raise RuntimeError("cannot release un-acquired lock")
        self.__count = count = self.__count - 1
        if not count:
            self.__owner = None
>           self.__block.release()
E           error: release unlocked lock
c:\pypy2-v6.0.0-win32\lib-python\2.7\threading.py:208: error
```

https://ci.appveyor.com/project/Python-pillow/pillow/build/3948/job/928xtaxbx0rgbfaq#L3355


```
Tests/test_decompression_bomb.py::TestDecompressionBomb::test_no_warning_small_file PASSED [  5%]
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 178, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 215, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 236, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\runner.py", line 65, in pytest_runtest_protocol
INTERNALERROR>     item.ihook.pytest_runtest_logfinish(nodeid=item.nodeid, location=item.location)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 196, in _multicall
INTERNALERROR>     gen.send(outcome)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 470, in pytest_runtest_logfinish
INTERNALERROR>     yield
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py", line 24, in __exit__
INTERNALERROR>     self.gen.next()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 443, in _runtest_for
INTERNALERROR>     item.add_report_section(when, "log", log)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py", line 24, in __exit__
INTERNALERROR>     self.gen.next()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 188, in catching_logs
INTERNALERROR>     root_logger.removeHandler(handler)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 1331, in removeHandler
INTERNALERROR>     _releaseLock()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 232, in _releaseLock
INTERNALERROR>     _lock.release()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\threading.py", line 208, in release
INTERNALERROR>     self.__block.release()
INTERNALERROR> error: release unlocked lock
==================== 60 passed, 4 skipped in 24.66 seconds ====================
Command exited with code 3
```
https://ci.appveyor.com/project/Python-pillow/pillow/build/3941/job/euy6n2ecsw8mvn3u#L2690


```
Tests/test_color_lut.py::TestColorLut3DCoreAPI::test_wrong_args FAILED   [  2%]
================================== FAILURES ===================================
____________________ TestColorLut3DCoreAPI.test_wrong_args ____________________
self = <contextlib.GeneratorContextManager object at 0x060367d0>, type = None
value = None, traceback = None
    def __exit__(self, type, value, traceback):
        if type is None:
            try:
>               self.gen.next()
c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py:24: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py:24: in __exit__
    self.gen.next()
c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py:1331: in removeHandler
    _releaseLock()
c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py:232: in _releaseLock
    _lock.release()
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <_RLock owner=None count=0>
    def release(self):
        """Release a lock, decrementing the recursion level.
    
            If after the decrement it is zero, reset the lock to unlocked (not owned
            by any thread), and if any other threads are blocked waiting for the
            lock to become unlocked, allow exactly one of them to proceed. If after
            the decrement the recursion level is still nonzero, the lock remains
            locked and owned by the calling thread.
    
            Only call this method when the calling thread owns the lock. A
            RuntimeError is raised if this method is called when the lock is
            unlocked.
    
            There is no return value.
    
            """
        if self.__owner != _get_ident():
            raise RuntimeError("cannot release un-acquired lock")
        self.__count = count = self.__count - 1
        if not count:
            self.__owner = None
>           self.__block.release()
E           error: release unlocked lock
c:\pypy2-v6.0.0-win32\lib-python\2.7\threading.py:208: error
```
https://ci.appveyor.com/project/Python-pillow/pillow/build/3940/job/0ufyc0d2mgd4gsa1#L2654



```
Tests/test_image_rotate.py::TestImageRotate::test_alpha_rotate_no_fill 
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 178, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 215, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 236, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\runner.py", line 63, in pytest_runtest_protocol
INTERNALERROR>     item.ihook.pytest_runtest_logstart(nodeid=item.nodeid, location=item.location)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 196, in _multicall
INTERNALERROR>     gen.send(outcome)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 465, in pytest_runtest_logstart
INTERNALERROR>     yield
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py", line 24, in __exit__
INTERNALERROR>     self.gen.next()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 443, in _runtest_for
INTERNALERROR>     item.add_report_section(when, "log", log)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py", line 24, in __exit__
INTERNALERROR>     self.gen.next()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 188, in catching_logs
INTERNALERROR>     root_logger.removeHandler(handler)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 1331, in removeHandler
INTERNALERROR>     _releaseLock()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 232, in _releaseLock
INTERNALERROR>     _lock.release()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\threading.py", line 208, in release
INTERNALERROR>     self.__block.release()
INTERNALERROR> error: release unlocked lock
================== 654 passed, 112 skipped in 53.98 seconds ===================
Command exited with code 3
```
https://ci.appveyor.com/project/Python-pillow/pillow/build/3934/job/pvvqg5i7h1fy34no#L3392



```
Tests/test_file_mic.py::TestFileMic::test_n_frames SKIPPED               [ 28%]
INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 178, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 215, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\main.py", line 236, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 180, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\runner.py", line 65, in pytest_runtest_protocol
INTERNALERROR>     item.ihook.pytest_runtest_logfinish(nodeid=item.nodeid, location=item.location)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 617, in __call__
INTERNALERROR>     return self._hookexec(self, self._nonwrappers + self._wrappers, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 222, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook, methods, kwargs)
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\__init__.py", line 216, in <lambda>
INTERNALERROR>     firstresult=hook.spec_opts.get('firstresult'),
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 201, in _multicall
INTERNALERROR>     return outcome.get_result()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 77, in get_result
INTERNALERROR>     _reraise(*ex)  # noqa
INTERNALERROR>   File "C:\vp\pypy2\site-packages\pluggy\callers.py", line 175, in _multicall
INTERNALERROR>     next(gen)   # first yield
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 469, in pytest_runtest_logfinish
INTERNALERROR>     with self._runtest_for(None, "finish"):
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\contextlib.py", line 17, in __enter__
INTERNALERROR>     return self.gen.next()
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 420, in _runtest_for
INTERNALERROR>     LogCaptureHandler(), formatter=self.formatter, level=self.log_level
INTERNALERROR>   File "C:\vp\pypy2\site-packages\_pytest\logging.py", line 196, in __init__
INTERNALERROR>     logging.StreamHandler.__init__(self, py.io.TextIO())
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 846, in __init__
INTERNALERROR>     Handler.__init__(self)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 688, in __init__
INTERNALERROR>     _addHandlerRef(self)
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 667, in _addHandlerRef
INTERNALERROR>     _releaseLock()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\logging\__init__.py", line 232, in _releaseLock
INTERNALERROR>     _lock.release()
INTERNALERROR>   File "c:\pypy2-v6.0.0-win32\lib-python\2.7\threading.py", line 208, in release
INTERNALERROR>     self.__block.release()
INTERNALERROR> error: release unlocked lock
=================== 247 passed, 90 skipped in 37.09 seconds ===================
Command exited with code 3
```
https://ci.appveyor.com/project/Python-pillow/pillow/build/3931/job/l6k406iw6o6pbnth#L2963


Here's our issue on the Pillow tracker: https://github.com/python-pillow/Pillow/issues/3239#issuecomment-433080563

Paul Ganssle just commented there:

> I'm getting the same thing on several dateutil builds using pypy-5.4 on Travis, so I don't think it's related to either PyPy 6.0 or Appveyor. [Example](https://travis-ci.org/dateutil/dateutil/jobs/445799715#L1074)
>
> I never see it on the 3.x series of PyPy, though.


Any ideas what's up?

Thank you!




More information about the pypy-issue mailing list