从subprocess调用Python程序永远挂起

点testing套件使用subprocess调用来运行集成testing。 最近一个公关被删除了一些旧的兼容性代码。 特别是它明确使用b""文字replace了一个b()函数。 然而,这似乎已经打破了一个特定的subprocess调用永远挂起的地方。 更糟糕的是,它只能永远停留在Python 3.3(也许只有Python 3.3.5)上,并且不能在Travis之外轻松地复制。

相关的请求:

  • https://github.com/pypa/pip/pull/1901
  • https://github.com/pypa/pip/pull/1900
  • https://github.com/pypa/pip/pull/1878

其他Pull请求也会出现类似的问题,但是在不同版本的Python和不同的testing用例上会失败。 这些Pull请求是:

  • https://github.com/pypa/pip/pull/1882
  • https://github.com/pypa/pip/pull/1912(Python 3.3再次)

另一位用户今天在IRC上向我报告了类似的问题,他们说他们可以在Ubuntu 14.04上使用Python 3.3从本地复制它(而不是在OSX上),而不仅仅是在Travis上,就像我迄今为止所做的那样。 他们已经让我步骤重现哪些是:

 $ git clone git@github.com:xavfernandez/pip.git $ cd pip $ git checkout debug_stuck $ pip install pytest==2.5.2 scripttest==1.3 virtualenv==1.11.6 mock==1.0.1 pretend==1.0.8 setuptools==4.0 $ # The below should pass just fine $ py.test -k test_env_vars_override_config_file -v -s $ # Now edit pip/req/req_set.py and remove method remove_me_to_block or change its content to print('KO') or pass $ # The below should hang forever $ py.test -k test_env_vars_override_config_file -v -s 

在上面的例子中, remove_me_to_block方法在任何地方都不被调用,仅仅存在它就足以使得testing不被阻塞,而不存在它(或者改变它的内容)足以使testing块永远存在。

大部分的debugging都是在这个PR( https://github.com/pypa/pip/pull/1901 )中进行的。 在一次推送一个提交之后,testing通过,直到应用这个特定的提交 – https://github.com/dstufft/pip/commit/d296df620916b4cd2379d9fab988cbc088e28fe0 。 特别是使用b'\r\n'或者(entry + endline).encode("utf-8")会触发它,但是这些东西都不在pip install -vvv INITools的执行path中它无法执行的命令。

在试图"something".encode("utf8")问题时,我注意到如果我用(lambda: "something")().encode("utf8")代替至less一个调用"something".encode("utf8") ,它就起作用。

试图debugging的另一个问题是,我试过的各种东西(添加打印语句,无操作的atexit函数,对asynchronoussubprocess使用trollious)将简单地将问题从特定的Python版本的特定testing案例转移到不同版本的Python上的不同testing用例。

我知道,如果你直接读/写subprocess.Popen().stdout/stderr/stdinsubprocess模块会死锁。 但是,这段代码使用了应该解决这些问题的communicate()方法。 这是communicate()wait()调用的内部,这个进程永远挂起,等待pip进程退出。

其他信息:

  • 这是非常可怕的,我已经设法使它消失,或根据各种不应该有任何影响的东西转移。
  • 我已经将pip本身的执行追溯到代码path的末尾,直到sys.exit()
  • sys.exit()replaceos._exit()修复了所有悬而未决的问题,但是我宁愿不这样做,因为我们正在跳过Python解释器的清理工作。
  • 没有额外的线程正在运行(通过threading.enumeratevalidation)。
  • 我已经有一些变化的组合,即使没有subprocess.PIPE被挂起,但stdout /标准错误/ stdin,但其他组合将不会挂起,如果这些不使用(或它会转移到一个不同的testingcase / python版本)。
  • 它似乎没有与时间有关,任何特定的提交将会在影响testing用例/ Pythons上100%的时间失败,或者在0%的时间内失败。
  • 很多时候,被改变的代码甚至没有被pip子stream程中的那个特定的代码path执行,然而仅仅这个改变的存在似乎破坏了它。
  • 我试过使用PYTHONDONTWRITEBYTECODE=1来禁止生成字节码,这在一个组合中有效,但在其他组合中却没有效果。
  • subprocess调用的命令不会在每个调用中挂起(类似的命令是通过testing套件发出的),但是它总是挂在特定提交的相同位置。
  • 到目前为止,我已经完全无法在testing套件中通过子subproccess调用外部重现,但是我不知道它是否与此相关。

我完全不知道是什么原因造成的。

更新#1

使用faulthandler.dump_traceback_later()我得到了这个结果:

 Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/requests/packages/urllib3/response.py", line 287 in closed Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/requests/packages/urllib3/response.py", line 287 in closed Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ Timeout (0:00:05)! Current thread 0x00007f417bd92740: File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/requests/packages/urllib3/response.py", line 285 in closed File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ [ Duplicate Lines Snipped ] File "/tmp/pytest-10/test_env_vars_override_config_file0/pip_src/pip/_vendor/cachecontrol/filewrapper.py", line 24 in __getattr__ 

这向我暗示,也许这个问题与垃圾收集和urllib3有关? 使用Filewrapper中的pip._vendor.cachecontrol.filewrapper作为urllib3响应对象(该子类为io.IOBase )的包装器,以便我们可以使用read()方法将每个读取调用的结果存储在缓冲区中作为返回它,然后一旦文件已被完全消耗,使用该缓冲区的内容运行callback,以便我们可以将项目存储在caching中。 这可能会以某种方式与GC进行交互?

更新#2

如果我将一个def __del__(self): pass方法添加到Filewrapper类中,那么在我尝试过的情况下,一切正常。 我testing,以确保这不是因为我只是碰巧定义一个方法(这“修复”它有时)通过改变,以def __del2__(self): pass并且它开始失败再次。 我不知道为什么这个工作正确,一个无操作__del__方法似乎不是最佳的。

更新#3

添加一个import gc; gc.set_debug(gc.DEBUG_UNCOLLECTABLE) import gc; gc.set_debug(gc.DEBUG_UNCOLLECTABLE)在挂起的pip命令的执行过程中两次打印stderr,它们是:

 gc: uncollectable <CallbackFileWrapper 0x7f66385c1cd0> gc: uncollectable <dict 0x7f663821d5a8> gc: uncollectable <functools.partial 0x7f663831de10> gc: uncollectable <_io.BytesIO 0x7f663804dd50> gc: uncollectable <method 0x7f6638219170> gc: uncollectable <tuple 0x7f663852bd40> gc: uncollectable <HTTPResponse 0x7f663831c7d0> gc: uncollectable <PreparedRequest 0x7f66385c1a90> gc: uncollectable <dict 0x7f663852cb48> gc: uncollectable <dict 0x7f6637fdcab8> gc: uncollectable <HTTPHeaderDict 0x7f663831cb90> gc: uncollectable <CaseInsensitiveDict 0x7f66385c1ad0> gc: uncollectable <dict 0x7f6638218ab8> gc: uncollectable <RequestsCookieJar 0x7f663805d7d0> gc: uncollectable <dict 0x7f66382140e0> gc: uncollectable <dict 0x7f6638218680> gc: uncollectable <list 0x7f6638218e18> gc: uncollectable <dict 0x7f6637f14878> gc: uncollectable <dict 0x7f663852c5a8> gc: uncollectable <dict 0x7f663852cb00> gc: uncollectable <method 0x7f6638219d88> gc: uncollectable <DefaultCookiePolicy 0x7f663805d590> gc: uncollectable <list 0x7f6637f14518> gc: uncollectable <list 0x7f6637f285a8> gc: uncollectable <list 0x7f6637f144d0> gc: uncollectable <list 0x7f6637f14ab8> gc: uncollectable <list 0x7f6637f28098> gc: uncollectable <list 0x7f6637f14c20> gc: uncollectable <list 0x7f6637f145a8> gc: uncollectable <list 0x7f6637f14440> gc: uncollectable <list 0x7f663852c560> gc: uncollectable <list 0x7f6637f26170> gc: uncollectable <list 0x7f663821e4d0> gc: uncollectable <list 0x7f6637f2d050> gc: uncollectable <list 0x7f6637f14fc8> gc: uncollectable <list 0x7f6637f142d8> gc: uncollectable <list 0x7f663821d050> gc: uncollectable <list 0x7f6637f14128> gc: uncollectable <tuple 0x7f6637fa8d40> gc: uncollectable <tuple 0x7f66382189e0> gc: uncollectable <tuple 0x7f66382183f8> gc: uncollectable <tuple 0x7f663866cc68> gc: uncollectable <tuple 0x7f6637f1e710> gc: uncollectable <tuple 0x7f6637fc77a0> gc: uncollectable <tuple 0x7f6637f289e0> gc: uncollectable <tuple 0x7f6637f19f80> gc: uncollectable <tuple 0x7f6638534d40> gc: uncollectable <tuple 0x7f6637f259e0> gc: uncollectable <tuple 0x7f6637f1c7a0> gc: uncollectable <tuple 0x7f6637fc8c20> gc: uncollectable <tuple 0x7f6638603878> gc: uncollectable <tuple 0x7f6637f23440> gc: uncollectable <tuple 0x7f663852c248> gc: uncollectable <tuple 0x7f6637f2a0e0> gc: uncollectable <tuple 0x7f66386a6ea8> gc: uncollectable <tuple 0x7f663852f9e0> gc: uncollectable <tuple 0x7f6637f28560> 

接着

 gc: uncollectable <CallbackFileWrapper 0x7f66385c1350> gc: uncollectable <dict 0x7f6638c33320> gc: uncollectable <HTTPResponse 0x7f66385c1590> gc: uncollectable <functools.partial 0x7f6637f03ec0> gc: uncollectable <_io.BytesIO 0x7f663804d600> gc: uncollectable <dict 0x7f6637f1f680> gc: uncollectable <method 0x7f663902d3b0> gc: uncollectable <tuple 0x7f663852be18> gc: uncollectable <HTTPMessage 0x7f66385c1c10> gc: uncollectable <HTTPResponse 0x7f66385c1450> gc: uncollectable <PreparedRequest 0x7f66385cac50> gc: uncollectable <dict 0x7f6637f2f248> gc: uncollectable <dict 0x7f6637f28b90> gc: uncollectable <dict 0x7f6637f1e638> gc: uncollectable <list 0x7f6637f26cb0> gc: uncollectable <list 0x7f6637f2f638> gc: uncollectable <HTTPHeaderDict 0x7f66385c1f90> gc: uncollectable <CaseInsensitiveDict 0x7f66385b2890> gc: uncollectable <dict 0x7f6638bd9200> gc: uncollectable <RequestsCookieJar 0x7f663805da50> gc: uncollectable <dict 0x7f6637f28a28> gc: uncollectable <dict 0x7f663853aa28> gc: uncollectable <list 0x7f663853a6c8> gc: uncollectable <dict 0x7f6638ede5f0> gc: uncollectable <dict 0x7f6637f285f0> gc: uncollectable <dict 0x7f663853a4d0> gc: uncollectable <method 0x7f663911f710> gc: uncollectable <DefaultCookiePolicy 0x7f663805d210> gc: uncollectable <list 0x7f6637f28ab8> gc: uncollectable <list 0x7f6638215050> gc: uncollectable <list 0x7f663853a200> gc: uncollectable <list 0x7f6638215a28> gc: uncollectable <list 0x7f663853a950> gc: uncollectable <list 0x7f663853a998> gc: uncollectable <list 0x7f6637f21638> gc: uncollectable <list 0x7f6637f0cd40> gc: uncollectable <list 0x7f663853ac68> gc: uncollectable <list 0x7f6637f22c68> gc: uncollectable <list 0x7f663853a170> gc: uncollectable <list 0x7f6637fa6a28> gc: uncollectable <list 0x7f66382153b0> gc: uncollectable <list 0x7f66386a5e60> gc: uncollectable <list 0x7f663852f2d8> gc: uncollectable <list 0x7f66386a3320> [<pip._vendor.cachecontrol.filewrapper.CallbackFileWrapper object at 0x7f66385c1cd0>, <pip._vendor.cachecontrol.filewrapper.CallbackFileWrapper object at 0x7f66385c1350>] 

这是有用的信息吗? 我从来没有使用过这个标志,所以我不知道这是否是不寻常的。

在Python 2中,如果一组对象在链(引用循环)中链接在一起,并且至less有一个对象具有__del__方法,则垃圾回收器将不会删除这些对象。 如果你有一个引用周期,添加__del__()方法可能只是隐藏错误(解决方法错误)。

根据你的更新#3,看起来像你有这样的问题。