def __init__(self, app, calls_to_track: Dict[str, Tuple[Callable]], max_profiler_mem: int = 50_000_000): for metric_name, profiled_functions in calls_to_track.items(): if len(metric_name) == 0: raise ValueError('A Server-Timing metric name cannot be empty') # https://httpwg.org/specs/rfc7230.html#rule.token.separators # USASCII (7 bits), only visible characters (no non-printables or space), no double-quote or delimiter if not metric_name.isascii( ) or not metric_name.isprintable() or re.search( r'[ "(),/:;<=>?@\[\\\]{}]', metric_name) is not None: raise ValueError( '"{}" contains an invalid character for a Server-Timing metric name' .format(metric_name)) if not all( inspect.isfunction(profiled) for profiled in profiled_functions): raise TypeError( 'One of the targeted functions for key "{}" is not a function' .format(metric_name)) self.app = app self.calls_to_track = { name: list(tracked_funcs) for name, tracked_funcs in calls_to_track.items() } self.max_profiler_mem = max_profiler_mem yappi.set_tag_callback(_get_context_tag) yappi.set_clock_type("wall") yappi.start()
def setUp(self): # reset everything back to default yappi.stop() yappi.clear_stats() yappi.set_clock_type('cpu') # reset to default clock type yappi.set_context_id_callback(None) yappi.set_context_name_callback(None) yappi.set_tag_callback(None)
def test_invalid_tag(self): def tag_cbk(): return -1 yappi.set_tag_callback(tag_cbk) yappi.start() tag_cbk() yappi.stop() stats = yappi.get_func_stats() stat = find_stat_by_name(stats, 'tag_cbk') self.assertEqual(stat.ncall, 1)
def test_tagging_cputime(self): tlocal = threading.local() def tag_cbk(): try: return tlocal._tag except Exception as e: #print(e) return -1 def a(tag): tlocal._tag = tag burn_cpu(0.1) _TCOUNT = 5 ts = [] yappi.set_clock_type("cpu") tlocal._tag = 0 yappi.set_tag_callback(tag_cbk) yappi.start() for i in range(_TCOUNT): t = threading.Thread(target=a, args=(i + 1, )) ts.append(t) for t in ts: t.start() for t in ts: t.join() yappi.stop() traces = yappi.get_func_stats() t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 5 0.000137 0.500562 0.000000 ../yappi/tests/utils.py:125 burn_cpu 5 0.000000 0.500424 0.000000 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 1}) t1 = ''' ../yappi/tests/utils.py:125 burn_cpu 1 0.000000 0.100125 0.100125 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 3}) t1 = ''' ../yappi/tests/utils.py:125 burn_cpu 1 0.000000 0.100128 0.100128 ''' self.assert_traces_almost_equal(t1, traces)
def test_tagging_cputime(self): def tag_cbk(): cthread = threading.current_thread() try: return cthread._tag except: return -1 def a(): burn_cpu(0.1) _TCOUNT = 5 ts = [] yappi.set_clock_type("cpu") threading.current_thread()._tag = 0 yappi.set_tag_callback(tag_cbk) yappi.start() for i in range(_TCOUNT): t = threading.Thread(target=a) t._tag = i + 1 ts.append(t) for t in ts: t.start() for t in ts: t.join() yappi.stop() traces = yappi.get_func_stats() t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 5 0.000137 0.500562 0.000000 ../yappi/tests/utils.py:125 burn_cpu 5 0.000000 0.500424 0.000000 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 1}) t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 1 0.000000 0.100183 0.100183 ../yappi/tests/utils.py:125 burn_cpu 1 0.000000 0.100125 0.100125 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 3}) t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 1 0.000000 0.100161 0.100161 ../yappi/tests/utils.py:125 burn_cpu 1 0.000000 0.100128 0.100128 ''' self.assert_traces_almost_equal(t1, traces)
def test_tagging_walltime(self): tlocal = threading.local() def tag_cbk(): try: return tlocal._tag except Exception as e: #print(e) return -1 def a(tag): tlocal._tag = tag burn_io(0.1) _TCOUNT = 20 yappi.set_clock_type("wall") tlocal._tag = 0 yappi.set_tag_callback(tag_cbk) yappi.start() ts = [] for i in range(_TCOUNT): t = threading.Thread(target=a, args=(i + 1, )) ts.append(t) for t in ts: t.start() for t in ts: t.join() yappi.stop() traces = yappi.get_func_stats() t1 = ''' ..p/yappi/tests/utils.py:134 burn_io 20 0.000638 2.004059 0.100203 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 3}) t1 = ''' ..p/yappi/tests/utils.py:134 burn_io 1 0.000038 0.100446 0.100446 ''' self.assert_traces_almost_equal(t1, traces)
def test_tagging_walltime(self): def tag_cbk(): cthread = threading.current_thread() try: return cthread._tag except: return -1 def a(): burn_io(0.1) _TCOUNT = 20 yappi.set_clock_type("wall") threading.current_thread()._tag = 0 yappi.set_tag_callback(tag_cbk) yappi.start() ts = [] for i in range(_TCOUNT): t = threading.Thread(target=a) t._tag = i + 1 ts.append(t) for t in ts: t.start() for t in ts: t.join() yappi.stop() traces = yappi.get_func_stats() t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 20 0.000516 2.004575 0.100229 ..p/yappi/tests/utils.py:134 burn_io 20 0.000638 2.004059 0.100203 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 3}) t1 = ''' ..op/p/yappi/tests/test_tags.py:21 a 1 0.000033 0.100479 0.100479 ..p/yappi/tests/utils.py:134 burn_io 1 0.000038 0.100446 0.100446 ''' self.assert_traces_almost_equal(t1, traces)
def test_simple_tagging(self): def tag_cbk(): return 1 def tag_cbk2(): return 2 # test cpu-time yappi.set_tag_callback(tag_cbk) yappi.start() burn_cpu(0.1) yappi.set_tag_callback(tag_cbk2) burn_cpu(0.1) yappi.stop() traces = yappi.get_func_stats() t1 = ''' ../yappi/tests/utils.py:125 burn_cpu 2 0.000000 0.200156 0.100078 ''' self.assert_traces_almost_equal(t1, traces) tagged_traces = yappi.get_func_stats(filter={'tag': 1}) t1 = ''' ../yappi/tests/utils.py:125 burn_cpu 1 0.000000 0.100062 0.100062 ''' self.assert_traces_almost_equal(t1, tagged_traces) yappi.clear_stats() # test wall yappi.set_clock_type("wall") yappi.set_tag_callback(tag_cbk) yappi.start() burn_io(0.1) yappi.set_tag_callback(tag_cbk2) burn_io(0.1) yappi.stop() traces = yappi.get_func_stats() t1 = ''' ..p/yappi/tests/utils.py:134 burn_io 2 0.000000 0.208146 0.104073 ''' self.assert_traces_almost_equal(t1, traces) tagged_traces = yappi.get_func_stats(filter={'tag': 2}) t1 = ''' ..p/yappi/tests/utils.py:134 burn_io 1 0.000000 0.105063 0.105063 ''' self.assert_traces_almost_equal(t1, tagged_traces) yappi.clear_stats()
async def profile_tasks_coroutine(self): yappi.set_tag_callback(get_async_context_id) await super().profile_tasks_coroutine()
async def profile_tasks_coroutine(self): yappi.set_tag_callback(get_async_context_id) yappi.start() tasks = self.get_tasks() await asyncio.gather(*tasks) yappi.stop()
def test_basic(self): def a(): gevent.sleep(0.3) burn_cpu(0.4) def b(): g = gevent.spawn(a) return g.get() def recursive_a(n): if not n: return burn_io(0.3) gevent.sleep(0.3) g = gevent.spawn(recursive_a, n - 1) return g.get() tlocal = threading.local() def tag_cbk(): try: return tlocal._tag except: return -1 yappi.set_clock_type("wall") tlocal._tag = 0 yappi.set_tag_callback(tag_cbk) class GeventTestThread(threading.Thread): def __init__(self, tag, func, args): super().__init__() self.tag = tag self.func = func self.args = args def run(self): tlocal._tag = self.tag self.g = gevent.spawn(self.func, *self.args) self.g.join() def result(self): self.join() # wait for thread completion return self.g.get() # get greenlet result _ctag = 1 ts = [] for func, args in ((a, ()), (recursive_a, (5, )), (b, ())): t = GeventTestThread(_ctag, func, args) t.start() ts.append(t) _ctag += 1 def driver(): for t in ts: t.result() yappi.start() driver() yappi.stop() traces = yappi.get_func_stats() t1 = ''' tests/test_asyncio.py:137 driver 1 0.000061 3.744064 3.744064 tests/test_asyncio.py:96 recursive_a 6/1 0.000188 3.739663 0.623277 tests/test_asyncio.py:8 async_sleep 7 0.000085 2.375271 0.339324 tests/utils.py:135 burn_io 5 0.000044 1.700000 0.437400 tests/test_asyncio.py:87 a 2 0.000019 1.600000 0.921138 tests/utils.py:126 burn_cpu 2 0.800000 0.800000 0.509730 tests/test_asyncio.py:92 b 1 0.000005 0.800000 0.921055 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 2}) t1 = ''' tests/test_asyncio.py:96 recursive_a 6/1 0.000211 3.720011 0.620002 tests/utils.py:135 burn_io 5 0.000079 1.700000 0.431813 async_sleep 5 0.000170 1.560735 0.312147 ''' self.assert_traces_almost_equal(t1, traces)
def test_basic(self): @asyncio.coroutine def a(): yield from async_sleep(0.1) burn_cpu(0.2) @asyncio.coroutine def b(): yield from a() @asyncio.coroutine def recursive_a(n): if not n: return burn_io(0.1) yield from async_sleep(0.1) yield from recursive_a(n - 1) def tag_cbk(): cthread = threading.current_thread() try: return cthread._tag except: return -1 yappi.set_clock_type("wall") threading.current_thread()._tag = 0 yappi.set_tag_callback(tag_cbk) def _thread_event_loop(loop): asyncio.set_event_loop(loop) loop.run_forever() _TCOUNT = 3 _ctag = 1 ts = [] for i in range(_TCOUNT): _loop = asyncio.new_event_loop() t = threading.Thread(target=_thread_event_loop, args=(_loop, )) t._tag = _ctag t._loop = _loop t.start() ts.append(t) _ctag += 1 @asyncio.coroutine def stop_loop(): asyncio.get_event_loop().stop() @asyncio.coroutine def driver(): futs = [] fut = asyncio.run_coroutine_threadsafe(a(), ts[0]._loop) futs.append(fut) fut = asyncio.run_coroutine_threadsafe(recursive_a(5), ts[1]._loop) futs.append(fut) fut = asyncio.run_coroutine_threadsafe(b(), ts[2]._loop) futs.append(fut) for fut in futs: fut.result() # stop asyncio loops in threads for t in ts: asyncio.run_coroutine_threadsafe(stop_loop(), t._loop) yappi.start() asyncio.get_event_loop().run_until_complete(driver()) yappi.stop() traces = yappi.get_func_stats() t1 = ''' tests/test_asyncio.py:140 driver 1 0.000022 1.015813 1.015813 ..ts/test_asyncio.py:103 recursive_a 6/1 0.000071 1.014597 0.169099 async_sleep 7 0.000000 0.714345 0.102049 tests/test_asyncio.py:94 a 2 0.000025 0.610155 0.305078 tests/utils.py:135 burn_io 5 0.000018 0.505879 0.101176 tests/utils.py:126 burn_cpu 2 0.380813 0.404432 0.202216 tests/test_asyncio.py:99 b 1 0.000005 0.305355 0.305355 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 2}) t1 = ''' ..ts/test_asyncio.py:103 recursive_a 6/1 0.000160 1.062948 0.177158 async_sleep 5 0.000000 0.561803 0.112361 tests/utils.py:135 burn_io 5 0.000035 0.500985 0.100197 ''' self.assert_traces_almost_equal(t1, traces)
def test_basic(self): @asyncio.coroutine def a(): yield from async_sleep(0.3) burn_cpu(0.4) @asyncio.coroutine def b(): yield from a() @asyncio.coroutine def recursive_a(n): if not n: return burn_io(0.3) yield from async_sleep(0.3) yield from recursive_a(n - 1) tlocal = threading.local() def tag_cbk(): try: return tlocal._tag except: return -1 yappi.set_clock_type("wall") tlocal._tag = 0 yappi.set_tag_callback(tag_cbk) def _thread_event_loop(loop, tag): tlocal._tag = tag asyncio.set_event_loop(loop) loop.run_forever() _TCOUNT = 3 _ctag = 1 ts = [] for i in range(_TCOUNT): _loop = asyncio.new_event_loop() t = threading.Thread(target=_thread_event_loop, args=(_loop, _ctag)) t._loop = _loop t.start() ts.append(t) _ctag += 1 @asyncio.coroutine def stop_loop(): asyncio.get_event_loop().stop() @asyncio.coroutine def driver(): futs = [] fut = asyncio.run_coroutine_threadsafe(a(), ts[0]._loop) futs.append(fut) fut = asyncio.run_coroutine_threadsafe(recursive_a(5), ts[1]._loop) futs.append(fut) fut = asyncio.run_coroutine_threadsafe(b(), ts[2]._loop) futs.append(fut) for fut in futs: fut.result() # stop asyncio loops in threads for t in ts: asyncio.run_coroutine_threadsafe(stop_loop(), t._loop) yappi.start() asyncio.get_event_loop().run_until_complete(driver()) yappi.stop() traces = yappi.get_func_stats() t1 = ''' tests/test_asyncio.py:137 driver 1 0.000061 3.744064 3.744064 tests/test_asyncio.py:96 recursive_a 6/1 0.000188 3.739663 0.623277 tests/test_asyncio.py:8 async_sleep 7 0.000085 2.375271 0.339324 tests/utils.py:135 burn_io 5 0.000044 1.700000 0.437400 tests/test_asyncio.py:87 a 2 0.000019 1.600000 0.921138 tests/utils.py:126 burn_cpu 2 0.800000 0.800000 0.509730 tests/test_asyncio.py:92 b 1 0.000005 0.800000 0.921055 ''' self.assert_traces_almost_equal(t1, traces) traces = yappi.get_func_stats(filter={'tag': 2}) t1 = ''' tests/test_asyncio.py:96 recursive_a 6/1 0.000211 3.720011 0.620002 tests/utils.py:135 burn_io 5 0.000079 1.700000 0.431813 async_sleep 5 0.000170 1.560735 0.312147 ''' self.assert_traces_almost_equal(t1, traces)
from starlette.responses import Response from starlette.types import ASGIApp from yappi import YFuncStats yappi_request_id = ContextVar('yappi_request_id') yappi_request_id.set(-10) def get_context_id() -> int: try: return yappi_request_id.get() except LookupError: return -2 yappi.set_tag_callback(get_context_id) class BenchMiddleware(BaseHTTPMiddleware): def __init__(self, app: ASGIApp, calls_to_track: Dict[str, str]) -> None: self.calls_to_track = calls_to_track super().__init__(app, None) async def dispatch(self, request: Request, call_next) -> Response: ctx_id = id(request) yappi_request_id.set(ctx_id) assert yappi_request_id.get() == ctx_id response = await call_next(request) tracked_stats: Dict[str, YFuncStats] = {}