pytest (py.test) 在 cygwin 中启动非常慢
pytest (py.test) very slow startup in cygwin
在 cygwin 中，py.test 启动非常慢。由于两个原因，它看起来不像是集合问题：相同的测试在 linux 中快速启动。有时，如果在 cygwin 中足够快地重新运行相同的测试，它会在不到 1 秒的时间内启动。 运行 通过时间命令告诉它在 0.4 秒或 11.7 秒内启动，当提供 --collection-only 选项以避免 运行 实际测试时。我还在钩子 pytest_configure() 和 pytest_ignore_collect() 上添加了打印，以确保它确实在收集开始之前。
还有其他问题，linke how to speed up py.test等，但是没看到cygwin下为什么慢，怎么解决。
更新：运行 通过 python -m cProfile -s cumulat ~/.../py.test conftest.py 的分析。以下是结果中的前 20 名。我倾向于认为这是 cygwin 或 cygwin python 包中的 posix.stat 或各个地方的 exists 和 isfile 的问题。
104699 function calls (102659 primitive calls) in 12.223 CPU seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.016 0.016 12.223 12.223 {execfile}
1 0.000 0.000 12.223 12.223 <string>:1(<module>)
1 0.000 0.000 12.207 12.207 py.test:4(<module>)
1 0.000 0.000 12.051 12.051 config.py:23(main)
48/22 0.000 0.000 12.051 0.548 core.py:526(_docall)
48/22 0.000 0.000 12.051 0.548 core.py:520(__call__)
129/82 0.000 0.000 12.051 0.147 core.py:387(execute)
1 0.000 0.000 11.926 11.926 config.py:634(pytest_cmdline_parse)
1 0.000 0.000 11.926 11.926 config.py:70(_prepareconfig)
1 0.000 0.000 11.926 11.926 config.py:741(parse)
4/3 0.000 0.000 11.926 3.975 core.py:97(wrapped_call)
4/3 0.000 0.000 11.926 3.975 core.py:121(__init__)
1 0.000 0.000 11.911 11.911 config.py:706(_preparse)
70 0.000 0.000 11.817 0.169 local.py:363(check)
260 11.817 0.045 11.817 0.045 {posix.stat} <<<<this one???
1 0.000 0.000 9.302 9.302 config.py:698(_initini)
1 0.000 0.000 9.286 9.286 config.py:896(determine_setup)
188 0.000 0.000 9.286 0.049 genericpath.py:15(exists) <<<<this one???
18 0.000 0.000 6.861 0.381 config.py:845(exists) <<<<this one???
1 0.000 0.000 6.861 6.861 config.py:851(getcfg) <<<<this one???
1 0.000 0.000 2.531 2.531 config.py:694(pytest_load_initial_conftests)
1 0.000 0.000 2.531 2.531 config.py:477(setinitial)
1 0.000 0.000 2.531 2.531 config.py:503(_try_load_conftest)
13 0.000 0.000 2.531 0.195 config.py:511(getconftestmodules)
32 0.000 0.000 2.531 0.079 genericpath.py:26(isfile) <<<<this one???
8 0.000 0.000 2.425 0.303 common.py:261(exists)
1 0.000 0.000 0.156 0.156 pytest.py:4(<module>)
1 0.000 0.000 0.125 0.125 main.py:73(wrap_session)
1 0.000 0.000 0.125 0.125 config.py:615(do_configure)
1 0.000 0.000 0.125 0.125 main.py:115(pytest_cmdline_main)
关于在分析中排序的注意事项：很难弄清楚要使用什么关键字。添加一行打印 pstats.py 中的 sort_arg_defs 可以给出一个想法：
$ cat -n /usr/lib/python2.x.x/pstats.py
214 sort_arg_defs = self.get_sort_arg_defs()
215 sort_tuple = ()
216 self.sort_type = ""
217 connector = ""
218 for word in field:
219 sort_tuple = sort_tuple + sort_arg_defs[word][0]
220 self.sort_type += connector + sort_arg_defs[word][1]
221 connector = ", "
结论摘要：格式错误的文件路径，如 //setup.py（应该是 /setup.py，开头没有双斜杠），揭示了一个四个软件部分之一的问题：pytest config.determine_setup()、pytest config 使用的 py.path、cygwin python 库或 cygwin posix 实现。
问题是 pytest 搜索 //pytest.ini、//tox.ini、//setup.cfg 和 //setup.py。它们中的每一个都导致 genericpath.exists() 或 genericpath.isfile() 消耗大约 2.5 秒。
修复方法是将下面的行添加到 genericpath.exists() 和 genericpath.isfile() 以跳过这四个特定路径。
if path.startswith(r'//'):
return False
另一种解决方法是修改 _pytest/config.py，这样它就不会在搜索路径中形成那些双斜线。
用于找出确切问题的代码粘贴在下面。设置 myshow = True 以便显示它搜索的每个文件所消耗的时间。
$ diff -u /usr/lib/python2.6/genericpath.py genericpath.py
--- /usr/lib/python2.6/genericpath.py 2012-06-09 08:33:12.000000000 -0700
+++ genericpath.py 2015-06-11 11:46:33.674285900 -0700
@@ -9,14 +9,29 @@
__all__ = ['commonprefix', 'exists', 'getatime', 'getctime', 'getmtime',
'getsize', 'isdir', 'isfile']
+myshow = False
+import time as mytime
+mybasetime = mytime.time()
+def myshowtime():
+ currenttime = mytime.time()
+ tmdiff = currenttime - mybasetime
+ global mybasetime
+ mybasetime = currenttime
+ return tmdiff
# Does a path exist?
# This is false for dangling symbolic links on systems that support them.
def exists(path):
"""Test whether a path exists. Returns False for broken symbolic links"""
+ pretime = myshowtime()
+ if path.startswith(r'//'):
+ if myshow: print "\n genericpath exists %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
+ return False
try:
st = os.stat(path)
+ if myshow: print "\n genericpath exists %8.3f %8.3f True " % (pretime, myshowtime()), " ", path, "\n"
except os.error:
+ if myshow: print "\n genericpath exists %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
return False
return True
@@ -25,9 +40,15 @@
# for the same path ono systems that support symlinks
def isfile(path):
"""Test whether a path is a regular file"""
+ pretime = myshowtime()
+ if path.startswith(r'//'):
+ if myshow: print "\n genericpath isfile %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
+ return False
try:
st = os.stat(path)
+ if myshow: print "\n genericpath isfile %8.3f %8.3f True " % (pretime, myshowtime()), " ", path, "\n"
except os.error:
+ if myshow: print "\n genericpath isfile %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
return False
return stat.S_ISREG(st.st_mode)
在 cygwin 中，py.test 启动非常慢。由于两个原因，它看起来不像是集合问题：相同的测试在 linux 中快速启动。有时，如果在 cygwin 中足够快地重新运行相同的测试，它会在不到 1 秒的时间内启动。 运行 通过时间命令告诉它在 0.4 秒或 11.7 秒内启动，当提供 --collection-only 选项以避免 运行 实际测试时。我还在钩子 pytest_configure() 和 pytest_ignore_collect() 上添加了打印，以确保它确实在收集开始之前。
还有其他问题，linke how to speed up py.test等，但是没看到cygwin下为什么慢，怎么解决。
更新：运行 通过 python -m cProfile -s cumulat ~/.../py.test conftest.py 的分析。以下是结果中的前 20 名。我倾向于认为这是 cygwin 或 cygwin python 包中的 posix.stat 或各个地方的 exists 和 isfile 的问题。
104699 function calls (102659 primitive calls) in 12.223 CPU seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.016 0.016 12.223 12.223 {execfile}
1 0.000 0.000 12.223 12.223 <string>:1(<module>)
1 0.000 0.000 12.207 12.207 py.test:4(<module>)
1 0.000 0.000 12.051 12.051 config.py:23(main)
48/22 0.000 0.000 12.051 0.548 core.py:526(_docall)
48/22 0.000 0.000 12.051 0.548 core.py:520(__call__)
129/82 0.000 0.000 12.051 0.147 core.py:387(execute)
1 0.000 0.000 11.926 11.926 config.py:634(pytest_cmdline_parse)
1 0.000 0.000 11.926 11.926 config.py:70(_prepareconfig)
1 0.000 0.000 11.926 11.926 config.py:741(parse)
4/3 0.000 0.000 11.926 3.975 core.py:97(wrapped_call)
4/3 0.000 0.000 11.926 3.975 core.py:121(__init__)
1 0.000 0.000 11.911 11.911 config.py:706(_preparse)
70 0.000 0.000 11.817 0.169 local.py:363(check)
260 11.817 0.045 11.817 0.045 {posix.stat} <<<<this one???
1 0.000 0.000 9.302 9.302 config.py:698(_initini)
1 0.000 0.000 9.286 9.286 config.py:896(determine_setup)
188 0.000 0.000 9.286 0.049 genericpath.py:15(exists) <<<<this one???
18 0.000 0.000 6.861 0.381 config.py:845(exists) <<<<this one???
1 0.000 0.000 6.861 6.861 config.py:851(getcfg) <<<<this one???
1 0.000 0.000 2.531 2.531 config.py:694(pytest_load_initial_conftests)
1 0.000 0.000 2.531 2.531 config.py:477(setinitial)
1 0.000 0.000 2.531 2.531 config.py:503(_try_load_conftest)
13 0.000 0.000 2.531 0.195 config.py:511(getconftestmodules)
32 0.000 0.000 2.531 0.079 genericpath.py:26(isfile) <<<<this one???
8 0.000 0.000 2.425 0.303 common.py:261(exists)
1 0.000 0.000 0.156 0.156 pytest.py:4(<module>)
1 0.000 0.000 0.125 0.125 main.py:73(wrap_session)
1 0.000 0.000 0.125 0.125 config.py:615(do_configure)
1 0.000 0.000 0.125 0.125 main.py:115(pytest_cmdline_main)
关于在分析中排序的注意事项：很难弄清楚要使用什么关键字。添加一行打印 pstats.py 中的 sort_arg_defs 可以给出一个想法：
$ cat -n /usr/lib/python2.x.x/pstats.py
214 sort_arg_defs = self.get_sort_arg_defs()
215 sort_tuple = ()
216 self.sort_type = ""
217 connector = ""
218 for word in field:
219 sort_tuple = sort_tuple + sort_arg_defs[word][0]
220 self.sort_type += connector + sort_arg_defs[word][1]
221 connector = ", "
结论摘要：格式错误的文件路径，如 //setup.py（应该是 /setup.py，开头没有双斜杠），揭示了一个四个软件部分之一的问题：pytest config.determine_setup()、pytest config 使用的 py.path、cygwin python 库或 cygwin posix 实现。
问题是 pytest 搜索 //pytest.ini、//tox.ini、//setup.cfg 和 //setup.py。它们中的每一个都导致 genericpath.exists() 或 genericpath.isfile() 消耗大约 2.5 秒。
修复方法是将下面的行添加到 genericpath.exists() 和 genericpath.isfile() 以跳过这四个特定路径。
if path.startswith(r'//'):
return False
另一种解决方法是修改 _pytest/config.py，这样它就不会在搜索路径中形成那些双斜线。
用于找出确切问题的代码粘贴在下面。设置 myshow = True 以便显示它搜索的每个文件所消耗的时间。
$ diff -u /usr/lib/python2.6/genericpath.py genericpath.py
--- /usr/lib/python2.6/genericpath.py 2012-06-09 08:33:12.000000000 -0700
+++ genericpath.py 2015-06-11 11:46:33.674285900 -0700
@@ -9,14 +9,29 @@
__all__ = ['commonprefix', 'exists', 'getatime', 'getctime', 'getmtime',
'getsize', 'isdir', 'isfile']
+myshow = False
+import time as mytime
+mybasetime = mytime.time()
+def myshowtime():
+ currenttime = mytime.time()
+ tmdiff = currenttime - mybasetime
+ global mybasetime
+ mybasetime = currenttime
+ return tmdiff
# Does a path exist?
# This is false for dangling symbolic links on systems that support them.
def exists(path):
"""Test whether a path exists. Returns False for broken symbolic links"""
+ pretime = myshowtime()
+ if path.startswith(r'//'):
+ if myshow: print "\n genericpath exists %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
+ return False
try:
st = os.stat(path)
+ if myshow: print "\n genericpath exists %8.3f %8.3f True " % (pretime, myshowtime()), " ", path, "\n"
except os.error:
+ if myshow: print "\n genericpath exists %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
return False
return True
@@ -25,9 +40,15 @@
# for the same path ono systems that support symlinks
def isfile(path):
"""Test whether a path is a regular file"""
+ pretime = myshowtime()
+ if path.startswith(r'//'):
+ if myshow: print "\n genericpath isfile %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
+ return False
try:
st = os.stat(path)
+ if myshow: print "\n genericpath isfile %8.3f %8.3f True " % (pretime, myshowtime()), " ", path, "\n"
except os.error:
+ if myshow: print "\n genericpath isfile %8.3f %8.3f False " % (pretime, myshowtime()), " ", path, "\n"
return False
return stat.S_ISREG(st.st_mode)