Skip to content

Instantly share code, notes, and snippets.

@zzzeek

zzzeek/test.py

Last active January 1, 2021 16:54
Show Gist options
  • Save zzzeek/dcccd142f03e5c63bd6d80c132c5c5e0 to your computer and use it in GitHub Desktop.
Save zzzeek/dcccd142f03e5c63bd6d80c132c5c5e0 to your computer and use it in GitHub Desktop.
Download ZIP
async sqlalchemy w/ yappi
Raw
test.py
import asyncio
import contextlib
import random
import yappi
# install sqlalchemy from github master:
# pip install git+https://github.com/sqlalchemy/sqlalchemy/
from sqlalchemy import cast
from sqlalchemy import Column
from sqlalchemy import Integer
from sqlalchemy import MetaData
from sqlalchemy import String
from sqlalchemy import Table
from sqlalchemy.ext.asyncio import create_async_engine
@contextlib.contextmanager
def profiled():
yappi.set_context_backend("greenlet")
yappi.set_clock_type("cpu")
yappi.start()
yield
yappi.stop()
print("## Function stats:")
yappi.get_func_stats().print_all()
print("\n## Greenlet stats:")
yappi.get_greenlet_stats().print_all()
meta = MetaData()
t1 = Table(
"t1", meta, Column("id", Integer, primary_key=True), Column("name", String)
)
async def async_setup(engine):
# engine is an instance of AsyncEngine
# conn is an instance of AsyncConnection
async with engine.begin() as conn:
await conn.run_sync(meta.drop_all)
await conn.run_sync(meta.create_all)
await conn.execute(
t1.insert(), [{"name": "some name %d" % i} for i in range(500)]
)
async def run_queries(engine, index):
async with engine.connect() as conn:
result = await conn.execute(
t1.select()
.where(cast(t1.c.name, String).like("some name%"))
.where(t1.c.id % 17 == index)
)
rows = result.fetchall()
assert len(rows) >= 29
async def async_bench(engine):
tasks = [
asyncio.create_task(run_queries(engine, random.randint(1, 16)))
for i in range(1000)
]
for task in tasks:
await task
engine = create_async_engine(
"postgresql+asyncpg://scott:tiger@localhost/test",
)
asyncio.get_event_loop().run_until_complete(async_setup(engine))
with profiled():
asyncio.get_event_loop().run_until_complete(async_bench(engine))
@zzzeek
Copy link
Author

zzzeek commented Jan 1, 2021

function output looks like:


## Function stats:

Clock type: CPU
Ordered by: totaltime, desc

name                                  ncall  tsub      ttot      tavg      
..lectorEventLoop.run_until_complete  1      0.000019  1.135971  1.135971
.._UnixSelectorEventLoop.run_forever  1      0.001613  1.135897  1.135897
..4 _UnixSelectorEventLoop._run_once  1455   0.044194  1.134270  0.000780
..8/asyncio/events.py:79 Handle._run  20748  0.026798  1.024897  0.000049
test3.py:52 run_queries               1000   0.029067  0.780098  0.000780
..currency_py3k.py:81 greenlet_spawn  3000   0.030279  0.423753  0.000141
..ase.py:1438 Connection._execute_20  1000   0.005460  0.414674  0.000415
..:309 Select._execute_on_connection  1000   0.005280  0.408629  0.000409
.. Connection._execute_clauseelement  1000   0.017938  0.403349  0.000403
..ine.py:283 AsyncConnection.execute  1000   0.007254  0.292932  0.000293
..syncpg_cursor._prepare_and_execute  1000   0.016834  0.245718  0.000246
..nts.py:506 Select._compile_w_cache  1000   0.007198  0.201173  0.000201
..y/sql/elements.py:826 Cast.operate  3000   0.005853  0.197345  0.000066
..langhelpers.py:1170 Select.oneshot  1000   0.004565  0.183401  0.000183
...py:264 Select._generate_cache_key  1000   0.003319  0.178836  0.000179
..y:1515 Connection._execute_context  1000   0.022621  0.178688  0.000179
...py:210 Select._generate_cache_key  1000   0.008074  0.175517  0.000176
../type_api.py:67 Comparator.operate  3000   0.008989  0.174492  0.000058

@zzzeek
Copy link
Author

zzzeek commented Jan 1, 2021

by contrast, cprofiles output formatting is readable:


        762338 function calls (724074 primitive calls) in 0.741 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     9092    0.011    0.000  560.560    0.062 /home/classic/dev/sqlalchemy/lib/sqlalchemy/util/_concurrency_py3k.py:81(greenlet_spawn)
    21058    0.024    0.000  310.911    0.015 /opt/python-3.8.3/lib/python3.8/asyncio/events.py:79(_run)
     2083    0.003    0.000  305.081    0.146 /home/classic/dev/sqlalchemy/lib/sqlalchemy/ext/asyncio/base.py:14(__aenter__)
    21058    0.035    0.000  304.248    0.014 {method 'run' of 'Context' objects}
     7092    0.006    0.000  298.806    0.042 test5.py:67(run_queries)
     2083    0.004    0.000  260.227    0.125 /home/classic/dev/sqlalchemy/lib/sqlalchemy/ext/asyncio/engine.py:96(start)
     2010    0.003    0.000  246.040    0.122 /home/classic/dev/sqlalchemy/lib/sqlalchemy/ext/asyncio/engine.py:378(__aexit__)
     2010    0.003    0.000  237.541    0.118 /home/classic/dev/sqlalchemy/lib/sqlalchemy/ext/asyncio/engine.py:218(close)
     1336    0.015    0.000  179.165    0.134 /opt/python-3.8.3/lib/python3.8/asyncio/base_events.py:1784(_run_once)
     4999    0.004    0.000   80.759    0.016 /home/classic/dev/sqlalchemy/lib/sqlalchemy/ext/asyncio/engine.py:283(execute)
 1000/104    0.002    0.000   26.061    0.251 /home/classic/dev/sqlalchemy/lib/sqlalchemy/future/engine.py:245(close)
 1000/104    0.003    0.000   26.059    0.251 /home/classic/dev/sqlalchemy/lib/sqlalchemy/engine/base.py:978(close)
 1000/105    0.001    0.000   25.326    0.241 /home/classic/dev/sqlalchemy/lib/sqlalchemy/engine/base.py:2132(close)
 1000/105    0.009    0.000   15.832    0.151 /home/classic/dev/sqlalchemy/lib/sqlalchemy/engine/base.py:2322(_do_close)

@zzzeek
Copy link
Author

zzzeek commented Jan 1, 2021

the greenlet stats look like the following, which does not seem to be useful, it's just a list of how many greenlets we ran. this is because we arent using greenlets as though they are "threads", we use them for context switching to simulate "await":

## Greenlet stats:

name           id     ttot      scnt        
greenlet       1      1.126238  6031      
..cIoGreenlet  114    0.009781  2         
..cIoGreenlet  2482   0.004530  2         
..cIoGreenlet  3      0.002184  2         
..cIoGreenlet  1645   0.002082  2         
..cIoGreenlet  1218   0.001525  2         
..cIoGreenlet  2514   0.001470  2         
greenlet       1004   0.001078  6         
..cIoGreenlet  1018   0.000931  2         
greenlet       1003   0.000915  6         
..cIoGreenlet  2511   0.000903  2         
..cIoGreenlet  2513   0.000782  2         
greenlet       1006   0.000771  4         
..cIoGreenlet  2512   0.000659  2         
..cIoGreenlet  2515   0.000638  2         
..cIoGreenlet  1213   0.000636  2         
..cIoGreenlet  1940   0.000620  2         
..cIoGreenlet  1938   0.000611  2         
..cIoGreenlet  1211   0.000609  2         
..cIoGreenlet  2529   0.000608  2         
..cIoGreenlet  1941   0.000603  2         
..cIoGreenlet  1212   0.000598  2         
..cIoGreenlet  1936   0.000598  2         
..cIoGreenlet  1198   0.000588  2         
..cIoGreenlet  1020   0.000582  2         
..cIoGreenlet  1939   0.000568  2         
..cIoGreenlet  2519   0.000567  2         
..cIoGreenlet  2516   0.000553  2         
greenlet       1005   0.000551  5         
..cIoGreenlet  2889   0.000548  2         
..cIoGreenlet  2655   0.000541  2         
..cIoGreenlet  2517   0.000540  2         
..cIoGreenlet  2518   0.000524  2         
..cIoGreenlet  1647   0.000518  2         
..cIoGreenlet  2530   0.000517  2         
..cIoGreenlet  1235   0.000516  2         
..cIoGreenlet  1403   0.000514  2         
..cIoGreenlet  1011   0.000512  2         
..cIoGreenlet  1986   0.000510  2         
..cIoGreenlet  1625   0.000509  2         
..cIoGreenlet  2547   0.000509  2         
..cIoGreenlet  2003   0.000507  2         
..cIoGreenlet  2501   0.000502  2         
..cIoGreenlet  1043   0.000501  2         
..cIoGreenlet  1013   0.000499  2         
..cIoGreenlet  2535   0.000497  2         
..cIoGreenlet  2439   0.000496  2         
..cIoGreenlet  2943   0.000493  2         
..cIoGreenlet  1270   0.000492  2         
..cIoGreenlet  2532   0.000491  2         
..cIoGreenlet  2349   0.000491  2         
..cIoGreenlet  1214   0.000490  2         
..cIoGreenlet  1427   0.000490  2         
..cIoGreenlet  2534   0.000487  2         
..cIoGreenlet  2673   0.000486  2         
..cIoGreenlet  2531   0.000486  2         
..cIoGreenlet  2533   0.000485  2         
..cIoGreenlet  2925   0.000485  2         
..cIoGreenlet  2835   0.000485  2         
..cIoGreenlet  2536   0.000485  2         
..cIoGreenlet  1268   0.000482  2         
..cIoGreenlet  2457   0.000481  2         
..cIoGreenlet  2871   0.000481  2         
..cIoGreenlet  2021   0.000480  2         
..cIoGreenlet  2836   0.000479  2         
..cIoGreenlet  820    0.000476  2         
..cIoGreenlet  2330   0.000475  2         
..cIoGreenlet  1259   0.000475  2         
..cIoGreenlet  1955   0.000475  2         
..cIoGreenlet  2493   0.000473  2         
..cIoGreenlet  2691   0.000473  2         
..cIoGreenlet  1187   0.000472  2         
..cIoGreenlet  2550   0.000470  2         
..cIoGreenlet  2537   0.000469  2         
..cIoGreenlet  1283   0.000468  2         
..cIoGreenlet  1219   0.000468  2         
..cIoGreenlet  2799   0.000468  2         
..cIoGreenlet  1999   0.000468  2         
..cIoGreenlet  1985   0.000467  2         
..cIoGreenlet  1471   0.000466  2         
..cIoGreenlet  1379   0.000466  2         
..cIoGreenlet  1669   0.000465  2         
..cIoGreenlet  2329   0.000464  2         
..cIoGreenlet  1691   0.000464  2         
..cIoGreenlet  2583   0.000463  2         
..cIoGreenlet  1977   0.000463  2         
..cIoGreenlet  2367   0.000463  2         
..cIoGreenlet  2745   0.000461  2         
..cIoGreenlet  2421   0.000461  2         
..cIoGreenlet  1537   0.000461  2         
..cIoGreenlet  1735   0.000460  2         
..cIoGreenlet  2907   0.000460  2         
..cIoGreenlet  2601   0.000459  2         
..cIoGreenlet  2656   0.000459  2         
..cIoGreenlet  2961   0.000459  2         
..cIoGreenlet  2817   0.000459  2         
..cIoGreenlet  2475   0.000458  2         
..cIoGreenlet  1933   0.000458  2         
..cIoGreenlet  1220   0.000458  2         
..cIoGreenlet  2853   0.000458  2         
..cIoGreenlet  1331   0.000458  2         
..cIoGreenlet  1163   0.000458  2         
..cIoGreenlet  1493   0.000458  2         
..cIoGreenlet  2619   0.000457  2         
..cIoGreenlet  2043   0.000457  2         
..cIoGreenlet  2065   0.000457  2         
..cIoGreenlet  1307   0.000457  2         
..cIoGreenlet  1823   0.000456  2         
..cIoGreenlet  1942   0.000456  2         
..cIoGreenlet  1779   0.000454  2         
..cIoGreenlet  2087   0.000454  2         
..cIoGreenlet  1541   0.000454  2         
..cIoGreenlet  1559   0.000454  2         
..cIoGreenlet  2109   0.000454  2         
..cIoGreenlet  1984   0.000453  2         
..cIoGreenlet  1889   0.000453  2         
..cIoGreenlet  1515   0.000453  2         
...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment