pytest (py.test) very slow startup in cygwin

Question

In cygwin, py.test starts up very slow. It does not look like a collection issue because of two reasons: The same test starts up quickly in linux. And sometimes, if rerun the same test fast enough in cygwin, it starts up in less than 1 second. Running through the time command tells it starts up in either 0.4 seconds, or 11.7 seconds, when supplied with the --collection-only option to avoid running the actual tests. I also added a print to the hooks pytest_configure() and pytest_ignore_collect() to be sure indeed it is before the collection starts.

There have been other questions, linke how to speed up py.test, etc. But I have not seen why under cygwin it is slow, and how to resolve the problem.

Update: Ran it through profiling by python -m cProfile -s cumulat ~/.../py.test conftest.py. Below is the top 20 in the result. I tend to think it is the problem with posix.stat in the cygwin or cygwin python package, or the exists and isfile at various places.

   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)

A note about sorting in profiling: It is hard to figure out what keyword to use. Adding a line to print out the sort_arg_defs in pstats.py could give an idea:

$ 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 = ", "

Conclusion summary: A malformed file path, like //setup.py (which should be /setup.py without the double-slash at the start), reveals a problem in one of four software parts: the pytest config.determine_setup(), the py.path which is used by pytest config, the cygwin python library, or the cygwin posix implementation.

Tedmann

Answer 1

The problem is that pytest searches for //pytest.ini, //tox.ini, //setup.cfg, and //setup.py. Each of them caused either genericpath.exists() or genericpath.isfile() to consume about 2.5 seconds.

On fix is to add the lines below to genericpath.exists() and genericpath.isfile() to skip those four specific paths.

if path.startswith(r'//'):
    return False

An alternative fix would be to modify _pytest/config.py so it does not form those double-slash in the paths to search.

The code used to find out the exact problem is pasted below. Set myshow = True so it will show how time is consumed for every file it is searching for.

$ 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)

Tedmann

Another way not to edit/hack the installation is to have cygwin invoke a windows native python instead of the cygwin python. That is, replace the command py.test with c:/python/path/Scripts/python.exe c:/ython/path/Scripts/py.test-script.py, if your windows python is installed at c:/python/path. – Tedmann

In sum the thing learned here is that Unix-style absolute paths on cygwin's Python are slow. Relative paths to shorten the path or using a non-cygwin Python don't suffer the same problems. – Gosney

Rocky, that comment is too broad. The specific problem is that the malformed file path, like //setup.py (which should be /setup.py), reveals a problem in one of four software parts: the pytest config.determine_setup(), the py.path, the cygwin python, or cygwin posix implementation. – Tedmann

Absolute paths work well if they don't start with a double-slash. – Tedmann

About absolute paths or relative paths. The main thing to keep in mind is that there is time used on each path component. So you want to use the one that has the least number of path components. There is a time penalty for switching between filesystems and absolute paths are more prone to that than relative paths. On cygwin in particular it appears that working with paths is slow. The double-slash acerbates this problem, but it is apparently something that sadly you need to keep in mind. – Gosney