I expect this to block for a reasonable amount of time (maybe max 60s) and succeed in creating the virtualenvs, the logging around locking appears to be broken
$ tail -n999 log*
==> log5 <==
131 setup logging to DEBUG [DEBUG report:43]
140 find interpreter for spec PythonSpec(path=/usr/bin/python3.6) [INFO builtin:44]
140 proposed PythonInfo(spec=CPython3.6.8.final.0-64, exe=/home/asottile/workspace/pre-commit/venv1/bin/python3, platform=linux, version='3.6.8 (default, Oct 7 2019, 12:59:55) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [INFO builtin:48]
141 Attempting to acquire lock 140634594459776 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:270]
141 Timeout on acquiring lock 140634594459776 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:277]
141 done in 12ms [INFO __main__:23]
Traceback (most recent call last):
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 77, in _lock_file
lock.acquire(0.0001)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 22, in acquire
super(_CountedFileLock, self).acquire(timeout=timeout, poll_intervall=poll_intervall)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/filelock.py", line 278, in acquire
raise Timeout(self._lock_file)
filelock.Timeout: The file lock '/home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock' could not be acquired.
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "venv1/bin/virtualenv", line 8, in <module>
sys.exit(run())
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/__main__.py", line 16, in run
run_via_cli(args)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/run/__init__.py", line 21, in run_via_cli
session = session_via_cli(args)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/run/__init__.py", line 31, in session_via_cli
interpreter = discover.interpreter
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/discover.py", line 25, in interpreter
self._interpreter = self.run()
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/builtin.py", line 33, in run
return get_interpreter(self.python_spec)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/builtin.py", line 46, in get_interpreter
for interpreter, impl_must_match in propose_interpreters(spec):
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/builtin.py", line 61, in propose_interpreters
yield PythonInfo.from_exe(spec.path), True
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/py_info.py", line 285, in from_exe
return from_exe(exe, raise_on_error=raise_on_error, ignore_cache=ignore_cache)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/cached_py_info.py", line 32, in from_exe
result = _get_from_cache(exe, ignore_cache=ignore_cache)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/cached_py_info.py", line 48, in _get_from_cache
py_info = _get_via_file_cache(resolved_resolved_path, exe)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/discovery/cached_py_info.py", line 64, in _get_via_file_cache
with fs_path.lock_for_key(key):
File "/usr/lib/python3.6/contextlib.py", line 81, in __enter__
return next(self.gen)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 92, in lock_for_key
self._lock_file(lock)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 79, in _lock_file
logging.debug("lock file %s present, will block until released", self._lock.lock_file)
AttributeError: 'NoneType' object has no attribute 'lock_file'
==> log6 <==
124 setup logging to DEBUG [DEBUG report:43]
132 find interpreter for spec PythonSpec(path=/usr/bin/python3.6) [INFO builtin:44]
132 proposed PythonInfo(spec=CPython3.6.8.final.0-64, exe=/home/asottile/workspace/pre-commit/venv1/bin/python3, platform=linux, version='3.6.8 (default, Oct 7 2019, 12:59:55) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [INFO builtin:48]
133 Attempting to acquire lock 139959630463216 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:270]
133 Lock 139959630463216 acquired on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [INFO filelock:274]
133 get PythonInfo from /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.json for /usr/bin/python3.6 [DEBUG cached_py_info:70]
135 Attempting to release lock 139959630463216 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:315]
135 Lock 139959630463216 released on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [INFO filelock:318]
135 proposed PythonInfo(spec=CPython3.6.9.final.0-64, exe=/usr/bin/python3.6, platform=linux, version='3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [INFO builtin:48]
135 accepted target interpreter PythonInfo(spec=CPython3.6.9.final.0-64, exe=/usr/bin/python3.6, platform=linux, version='3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [DEBUG builtin:50]
136 filesystem is case-sensitive [DEBUG info:28]
167 create virtual environment via CPython3Posix(dest=/home/asottile/workspace/pre-commit/venv6, global=False, clear=False) [INFO session:24]
168 create folder /home/asottile/workspace/pre-commit/venv6/bin [DEBUG _sync:22]
168 create folder /home/asottile/workspace/pre-commit/venv6/lib/python3.6/site-packages [DEBUG _sync:22]
168 write /home/asottile/workspace/pre-commit/venv6/pyvenv.cfg [DEBUG pyenv_cfg:33]
168 home = /usr [DEBUG pyenv_cfg:37]
168 include-system-site-packages = false [DEBUG pyenv_cfg:37]
168 implementation = CPython [DEBUG pyenv_cfg:37]
168 version_info = 3.6.9.final.0 [DEBUG pyenv_cfg:37]
168 virtualenv = 0.1.dev49+g2e3f6c8 [DEBUG pyenv_cfg:37]
168 base-prefix = /usr [DEBUG pyenv_cfg:37]
168 base-exec-prefix = /usr [DEBUG pyenv_cfg:37]
168 base-executable = /usr/bin/python3.6 [DEBUG pyenv_cfg:37]
168 symlink /usr/bin/python3.6 to /home/asottile/workspace/pre-commit/venv6/bin/python [DEBUG _sync:41]
169 hard link /home/asottile/workspace/pre-commit/venv6/bin/python to python3 [DEBUG _sync:55]
169 hard link /home/asottile/workspace/pre-commit/venv6/bin/python to python3.6 [DEBUG _sync:55]
169 ============================== target debug ============================== [DEBUG session:26]
170 debug via /home/asottile/workspace/pre-commit/venv6/bin/python /home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/create/debug.py [DEBUG creator:181]
169 {
"sys": {
"executable": "/home/asottile/workspace/pre-commit/venv6/bin/python",
"_base_executable": null,
"prefix": "/home/asottile/workspace/pre-commit/venv6",
"base_prefix": "/usr",
"real_prefix": null,
"exec_prefix": "/home/asottile/workspace/pre-commit/venv6",
"base_exec_prefix": "/usr",
"path": [
"/usr/lib/python36.zip",
"/usr/lib/python3.6",
"/usr/lib/python3.6/lib-dynload",
"/home/asottile/workspace/pre-commit/venv6/lib/python3.6/site-packages"
],
"meta_path": [
"<class '_frozen_importlib.BuiltinImporter'>",
"<class '_frozen_importlib.FrozenImporter'>",
"<class '_frozen_importlib_external.PathFinder'>"
],
"fs_encoding": "utf-8",
"io_encoding": "UTF-8"
},
"version": "3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]",
"os": "<module 'os' from '/usr/lib/python3.6/os.py'>",
"site": "<module 'site' from '/usr/lib/python3.6/site.py'>",
"datetime": "<module 'datetime' from '/usr/lib/python3.6/datetime.py'>",
"math": "<module 'math' (built-in)>",
"json": "<module 'json' from '/usr/lib/python3.6/json/__init__.py'>"
} [DEBUG session:27]
206 add seed packages via FromAppData pip=latest setuptools=latest wheel=latest app_data_dir=/home/asottile/.local/share/virtualenv/seed-v1 [INFO session:31]
206 Attempting to acquire lock 139959654705360 on /home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock [DEBUG filelock:270]
207 Timeout on acquiring lock 139959654705360 on /home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock [DEBUG filelock:277]
207 done in 84ms [INFO __main__:23]
Traceback (most recent call last):
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 77, in _lock_file
lock.acquire(0.0001)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 22, in acquire
super(_CountedFileLock, self).acquire(timeout=timeout, poll_intervall=poll_intervall)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/filelock.py", line 278, in acquire
raise Timeout(self._lock_file)
filelock.Timeout: The file lock '/home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock' could not be acquired.
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "venv1/bin/virtualenv", line 8, in <module>
sys.exit(run())
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/__main__.py", line 16, in run
run_via_cli(args)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/run/__init__.py", line 22, in run_via_cli
session.run()
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/session.py", line 19, in run
self._seed()
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/session.py", line 32, in _seed
self.seeder.run(self.creator)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/seed/via_app_data/via_app_data.py", line 39, in run
with self._get_seed_wheels(creator, base_cache) as name_to_whl:
File "/usr/lib/python3.6/contextlib.py", line 81, in __enter__
return next(self.gen)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/seed/via_app_data/via_app_data.py", line 61, in _get_seed_wheels
with base_cache.lock_for_key("wheels"):
File "/usr/lib/python3.6/contextlib.py", line 81, in __enter__
return next(self.gen)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 92, in lock_for_key
self._lock_file(lock)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 79, in _lock_file
logging.debug("lock file %s present, will block until released", self._lock.lock_file)
AttributeError: 'NoneType' object has no attribute 'lock_file'
==> log7 <==
139 setup logging to DEBUG [DEBUG report:43]
147 find interpreter for spec PythonSpec(path=/usr/bin/python3.6) [INFO builtin:44]
147 proposed PythonInfo(spec=CPython3.6.8.final.0-64, exe=/home/asottile/workspace/pre-commit/venv1/bin/python3, platform=linux, version='3.6.8 (default, Oct 7 2019, 12:59:55) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [INFO builtin:48]
148 Attempting to acquire lock 140626263552128 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:270]
148 Lock 140626263552128 acquired on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [INFO filelock:274]
148 get PythonInfo from /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.json for /usr/bin/python3.6 [DEBUG cached_py_info:70]
154 Attempting to release lock 140626263552128 on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [DEBUG filelock:315]
154 Lock 140626263552128 released on /home/asottile/.local/share/virtualenv/py-info/0.1.dev49+g2e3f6c8/30295c5bec572e859485b1ffa5e89b8b3e2022ef6e3e739c1ac40f143a557caf.lock [INFO filelock:318]
154 proposed PythonInfo(spec=CPython3.6.9.final.0-64, exe=/usr/bin/python3.6, platform=linux, version='3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [INFO builtin:48]
154 accepted target interpreter PythonInfo(spec=CPython3.6.9.final.0-64, exe=/usr/bin/python3.6, platform=linux, version='3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]', encoding_fs_io=utf-8-UTF-8) [DEBUG builtin:50]
155 filesystem is case-sensitive [DEBUG info:28]
193 create virtual environment via CPython3Posix(dest=/home/asottile/workspace/pre-commit/venv7, global=False, clear=False) [INFO session:24]
194 create folder /home/asottile/workspace/pre-commit/venv7/bin [DEBUG _sync:22]
194 create folder /home/asottile/workspace/pre-commit/venv7/lib/python3.6/site-packages [DEBUG _sync:22]
194 write /home/asottile/workspace/pre-commit/venv7/pyvenv.cfg [DEBUG pyenv_cfg:33]
194 home = /usr [DEBUG pyenv_cfg:37]
194 include-system-site-packages = false [DEBUG pyenv_cfg:37]
194 implementation = CPython [DEBUG pyenv_cfg:37]
194 version_info = 3.6.9.final.0 [DEBUG pyenv_cfg:37]
194 virtualenv = 0.1.dev49+g2e3f6c8 [DEBUG pyenv_cfg:37]
194 base-prefix = /usr [DEBUG pyenv_cfg:37]
194 base-exec-prefix = /usr [DEBUG pyenv_cfg:37]
194 base-executable = /usr/bin/python3.6 [DEBUG pyenv_cfg:37]
194 symlink /usr/bin/python3.6 to /home/asottile/workspace/pre-commit/venv7/bin/python [DEBUG _sync:41]
195 hard link /home/asottile/workspace/pre-commit/venv7/bin/python to python3 [DEBUG _sync:55]
195 hard link /home/asottile/workspace/pre-commit/venv7/bin/python to python3.6 [DEBUG _sync:55]
195 ============================== target debug ============================== [DEBUG session:26]
196 debug via /home/asottile/workspace/pre-commit/venv7/bin/python /home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/create/debug.py [DEBUG creator:181]
195 {
"sys": {
"executable": "/home/asottile/workspace/pre-commit/venv7/bin/python",
"_base_executable": null,
"prefix": "/home/asottile/workspace/pre-commit/venv7",
"base_prefix": "/usr",
"real_prefix": null,
"exec_prefix": "/home/asottile/workspace/pre-commit/venv7",
"base_exec_prefix": "/usr",
"path": [
"/usr/lib/python36.zip",
"/usr/lib/python3.6",
"/usr/lib/python3.6/lib-dynload",
"/home/asottile/workspace/pre-commit/venv7/lib/python3.6/site-packages"
],
"meta_path": [
"<class '_frozen_importlib.BuiltinImporter'>",
"<class '_frozen_importlib.FrozenImporter'>",
"<class '_frozen_importlib_external.PathFinder'>"
],
"fs_encoding": "utf-8",
"io_encoding": "UTF-8"
},
"version": "3.6.9 (default, Nov 7 2019, 10:44:02) \n[GCC 8.3.0]",
"os": "<module 'os' from '/usr/lib/python3.6/os.py'>",
"site": "<module 'site' from '/usr/lib/python3.6/site.py'>",
"datetime": "<module 'datetime' from '/usr/lib/python3.6/datetime.py'>",
"math": "<module 'math' (built-in)>",
"json": "<module 'json' from '/usr/lib/python3.6/json/__init__.py'>"
} [DEBUG session:27]
235 add seed packages via FromAppData pip=latest setuptools=latest wheel=latest app_data_dir=/home/asottile/.local/share/virtualenv/seed-v1 [INFO session:31]
236 Attempting to acquire lock 140626287794384 on /home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock [DEBUG filelock:270]
236 Timeout on acquiring lock 140626287794384 on /home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock [DEBUG filelock:277]
236 done in 99ms [INFO __main__:23]
Traceback (most recent call last):
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 77, in _lock_file
lock.acquire(0.0001)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 22, in acquire
super(_CountedFileLock, self).acquire(timeout=timeout, poll_intervall=poll_intervall)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/filelock.py", line 278, in acquire
raise Timeout(self._lock_file)
filelock.Timeout: The file lock '/home/asottile/.local/share/virtualenv/seed-v1/3.6/wheels.lock' could not be acquired.
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "venv1/bin/virtualenv", line 8, in <module>
sys.exit(run())
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/__main__.py", line 16, in run
run_via_cli(args)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/run/__init__.py", line 22, in run_via_cli
session.run()
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/session.py", line 19, in run
self._seed()
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/session.py", line 32, in _seed
self.seeder.run(self.creator)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/seed/via_app_data/via_app_data.py", line 39, in run
with self._get_seed_wheels(creator, base_cache) as name_to_whl:
File "/usr/lib/python3.6/contextlib.py", line 81, in __enter__
return next(self.gen)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/seed/via_app_data/via_app_data.py", line 61, in _get_seed_wheels
with base_cache.lock_for_key("wheels"):
File "/usr/lib/python3.6/contextlib.py", line 81, in __enter__
return next(self.gen)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 92, in lock_for_key
self._lock_file(lock)
File "/home/asottile/workspace/pre-commit/venv1/lib/python3.6/site-packages/virtualenv/util/lock.py", line 79, in _lock_file
logging.debug("lock file %s present, will block until released", self._lock.lock_file)
AttributeError: 'NoneType' object has no attribute 'lock_file'
I expect this to block for a reasonable amount of time (maybe max 60s) and succeed in creating the virtualenvs, the logging around locking appears to be broken
(the actual interesting stuff is in the logs)