Instagram / MonkeyType

A Python library that generates static type annotations by collecting runtime types
Other
4.74k stars 170 forks source link

Performance - MonkeyType Adding Extreme Amount of Overhead #87

Open WillAyd opened 6 years ago

WillAyd commented 6 years ago

Here's a (very poor) set of tests:

import unittest

class TestFoo(unittest.TestCase):

    def test_foo0(self):
        [x for x in range(10_000_000)]
        return 0

    def test_foo1(self):
        [x for x in range(10_000_000)]
        return 1

    def test_foo2(self):
        [x for x in range(10_000_000)]
        return 2

Here's what I get when running directly via unittest:

(py36) williams-imac:Desktop williamayd$ python -m unittest
...
----------------------------------------------------------------------
Ran 3 tests in 1.836s

And now via MonkeyType

(py36) williams-imac:Desktop williamayd$ monkeytype run -m unittest
...
----------------------------------------------------------------------
Ran 3 tests in 43.034s

As you can see the overhead added here increases the runtime of those tests by some factor, even though ultimately MonkeyType does not generate any information about the resource intensive parts of the test (nor does it need to).

Removing the list comprehension and just performing a loop did not exhibit the same performance disparity

carljm commented 6 years ago

I think the overhead is coming from the sys.setprofile() hook that MonkeyType uses (the same one used by e.g. cProfile and coverage.py). I'm curious if the same disparity occurs e.g. running those tests under coverage run.

WillAyd commented 6 years ago

There's a little bit of overhead with coverage but nowhere near the amount of monkeytype

(py36) williams-imac:Desktop williamayd$ coverage run -m unittest
...
----------------------------------------------------------------------
Ran 3 tests in 3.261s

OK
(py36) williams-imac:Desktop williamayd$ monkeytype run -m unittest
...
----------------------------------------------------------------------
Ran 3 tests in 43.069s

OK
WillAyd commented 6 years ago

I think you are right however that the culprit is sys.setprofile() based off of a quick cProfile

In [8]: cProfile.run("with trace(): runpy.run_module('unittest', run_name='__main__', alter_sys=True)")
...
----------------------------------------------------------------------
Ran 3 tests in 29.467s

OK
         406 function calls in 29.514 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:102(release)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:142(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:146(__enter__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:153(__exit__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:159(_get_module_lock)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:173(cb)
       40    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:208(_verbose_message)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:355(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:57(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:698(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:77(acquire)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:771(find_spec)
        7    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:834(__enter__)
        7    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:838(__exit__)
        4    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:852(_find_spec_legacy)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:861(_find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:931(_find_and_load_unlocked)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:958(_find_and_load)
       10    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1080(_path_importer_cache)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1102(_legacy_get_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1117(_get_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1149(find_spec)
        8    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1233(find_spec)
        8    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:37(_relax_case)
       40    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:57(_path_join)
       40    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:59(<listcomp>)
        8    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:75(_path_stat)
        1    0.000    0.000   29.514   29.514 <string>:1(<module>)
        1    0.000    0.000    0.001    0.001 __init__.py:20(trace)
        1    0.000    0.000    0.000    0.000 __init__.py:23(find_module)
        1    0.000    0.000    0.000    0.000 _collections_abc.py:657(get)
        1    0.000    0.000    0.000    0.000 base.py:69(__init__)
        1    0.000    0.000    0.001    0.001 config.py:127(trace_store)
        1    0.000    0.000    0.000    0.000 config.py:136(code_filter)
        1    0.000    0.000    0.001    0.001 config.py:141(get_default_config)
        1    0.000    0.000    0.001    0.001 config.py:55(trace_logger)
        1    0.000    0.000    0.000    0.000 config.py:72(sample_rate)
        1    0.000    0.000    0.000    0.000 contextlib.py:157(helper)
        1    0.000    0.000    0.000    0.000 contextlib.py:60(__init__)
        1    0.000    0.000   29.513   29.513 contextlib.py:80(__enter__)
        1    0.000    0.000    0.000    0.000 os.py:664(__getitem__)
        1    0.000    0.000    0.000    0.000 os.py:740(encode)
        3    0.000    0.000    0.000    0.000 six.py:184(find_module)
        1    0.000    0.000    0.001    0.001 sqlite.py:34(create_call_trace_table)
        1    0.000    0.000    0.000    0.000 sqlite.py:75(__init__)
        1    0.000    0.000    0.001    0.001 sqlite.py:79(make_store)
        1    0.000    0.000    0.000    0.000 tracing.py:190(__init__)
        1    0.000    0.000   29.513   29.513 tracing.py:266(trace_calls)
        7    0.000    0.000    0.000    0.000 {built-in method _imp.acquire_lock}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.is_builtin}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.is_frozen}
        8    0.000    0.000    0.000    0.000 {built-in method _imp.release_lock}
        1    0.000    0.000    0.000    0.000 {built-in method _sqlite3.connect}
        2    0.000    0.000    0.000    0.000 {built-in method _thread.allocate_lock}
        2    0.000    0.000    0.000    0.000 {built-in method _thread.get_ident}
        1    0.000    0.000   29.514   29.514 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.getattr}
       10    0.000    0.000    0.000    0.000 {built-in method builtins.hasattr}
       11    0.000    0.000    0.000    0.000 {built-in method builtins.isinstance}
        1    0.000    0.000   29.513   29.513 {built-in method builtins.next}
        1    0.000    0.000    0.000    0.000 {built-in method posix.getcwd}
        8    0.000    0.000    0.000    0.000 {built-in method posix.stat}
        1    0.000    0.000    0.000    0.000 {built-in method sys.getprofile}
        1   29.513   29.513   29.513   29.513 {built-in method sys.setprofile}
        1    0.000    0.000    0.000    0.000 {method 'encode' of 'str' objects}
        1    0.001    0.001    0.001    0.001 {method 'execute' of 'sqlite3.Connection' objects}
        1    0.000    0.000    0.000    0.000 {method 'extend' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'find_loader' of 'zipimport.zipimporter' objects}
        2    0.000    0.000    0.000    0.000 {method 'format' of 'str' objects}
       40    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'partition' of 'str' objects}
        9    0.000    0.000    0.000    0.000 {method 'rpartition' of 'str' objects}
       80    0.000    0.000    0.000    0.000 {method 'rstrip' of 'str' objects}