Repository navigation
Memory leak when using command_timeout #830
Description
- asyncpg version: 0.24
- PostgreSQL version: 13, 12
- Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
the issue with a local PostgreSQL install?: - Python version: 3.9.5
- Platform: windows, linux
- Do you use pgbouncer?: no
- Did you install asyncpg with pip?: yes
- If you built asyncpg locally, which version of Cython did you use?: no
- Can the issue be reproduced under both asyncio and
uvloop?:
This was initially reported on sqlalchemy by @mvbrn here sqlalchemy/sqlalchemy#7058 and followed up at sqlalchemy/sqlalchemy#7059, but we can reproduce the issue without using sqlalchemy.
Here is the test I'm running:
import asyncio
import gc
import tracemalloc
import asyncpg
DB_URL_PG = "postgresql://scott:tiger@127.0.0.1:5432/test"
async def job(wait_for=0.01):
# just do some dummy stuff
conn = await asyncpg.connect(DB_URL_PG, command_timeout=60 * 1000)
await conn.execute(f"select 1;")
await conn.execute(f"select pg_sleep({wait_for});")
await conn.close()
async def run():
tracemalloc.start()
snapshot1 = tracemalloc.take_snapshot()
num_rounds = 100
num_jobs = 10
for _ in range(num_rounds):
await asyncio.gather(*(job() for i in range(num_jobs)))
print(_)
snapshot2 = tracemalloc.take_snapshot()
top_stats = snapshot2.compare_to(snapshot1, "lineno")
print("[ Top 10 differences ]")
for stat in top_stats[:10]:
print(stat)
print("Running garbage collection")
gc.collect()
print("Stats after collection")
snapshot2 = tracemalloc.take_snapshot()
top_stats = snapshot2.compare_to(snapshot1, "lineno")
print("[ Top 10 differences after gc ]")
for stat in top_stats[:10]:
print(stat)
top_stats = snapshot2.statistics("lineno")
print("[ Top 10 - FINAL stats ]")
for stat in top_stats[:10]:
print(stat)
if __name__ == "__main__":
asyncio.run(run())Running uses quite a bit of ram an the final print, on windows is something like
[ Top 10 differences ]
\lib\asyncio\windows_events.py:449: size=31.3 MiB (+31.3 MiB), count=1001 (+1001), average=32.0 KiB
\lib\asyncio\proactor_events.py:269: size=1776 KiB (+1776 KiB), count=22002 (+22002), average=83 B
\lib\site-packages\asyncpg\connect_utils.py:705: size=1773 KiB (+1773 KiB), count=16756 (+16756), average=108 B
\lib\asyncio\locks.py:174: size=711 KiB (+711 KiB), count=4000 (+4000), average=182 B
\lib\asyncio\windows_events.py:812: size=649 KiB (+649 KiB), count=2001 (+2001), average=332 B
\lib\asyncio\events.py:80: size=588 KiB (+588 KiB), count=1050 (+1050), average=573 B
\lib\asyncio\base_events.py:1890: size=577 KiB (+577 KiB), count=1000 (+1000), average=591 B
\lib\asyncio\windows_events.py:457: size=552 KiB (+552 KiB), count=6036 (+6036), average=94 B
\lib\asyncio\windows_events.py:434: size=299 KiB (+299 KiB), count=500 (+500), average=613 B
\lib\asyncio\base_events.py:596: size=297 KiB (+297 KiB), count=500 (+500), average=608 B
Removing the command_timeout no noticeable leak is observed:
[ Top 10 differences ]
\lib\asyncio\windows_events.py:449: size=645 KiB (+645 KiB), count=21 (+21), average=30.7 KiB
<string>:1: size=96.0 KiB (+96.0 KiB), count=1023 (+1023), average=96 B
\lib\site-packages\asyncpg\connect_utils.py:705: size=37.6 KiB (+37.6 KiB), count=339 (+339), average=114 B
\lib\asyncio\proactor_events.py:269: size=36.1 KiB (+36.1 KiB), count=441 (+441), average=84 B
\lib\asyncio\events.py:80: size=22.3 KiB (+22.3 KiB), count=53 (+53), average=432 B
\lib\asyncio\base_events.py:1890: size=19.7 KiB (+19.7 KiB), count=30 (+30), average=672 B
\lib\asyncio\windows_events.py:812: size=16.6 KiB (+16.6 KiB), count=44 (+44), average=387 B
\lib\asyncio\base_events.py:1854: size=11.1 KiB (+11.1 KiB), count=17 (+17), average=670 B
\lib\asyncio\windows_events.py:457: size=10.9 KiB (+10.9 KiB), count=120 (+120), average=93 B
\lib\asyncio\locks.py:174: size=10.1 KiB (+10.1 KiB), count=72 (+72), average=144 B
Reacted by 0xD09CD196D188D0B0 and Yevhen Ts.
Activity
elprans commentedon Sep 21, 2021
This seems to be a windows proactor bug in asyncio. I can't reproduce the leak on Linux.
CaselIT commentedon Sep 21, 2021
@zzzeek was reproducing it also on linux. Could you share the details?
@elprans which version of python you used on linux?
Make sure timeout callbacks always get cleaned up
elprans commentedon Sep 21, 2021
Actually, I think I found the leak. See #831
CaselIT commentedon Sep 21, 2021
Thanks for looking into it.
I cannot immediately test it on windows since I don't have all the cython build chain installed, sorry.
If you can produce a wheel without much hassle, I can test it.
zzzeek commentedon Sep 21, 2021
this does reproduce for me on linux, running fedora 34.
0xD09CD196D188D0B0 commentedon Sep 22, 2021
Same for Ubuntu 20.04
Make sure timeout callbacks always get cleaned up (#831)