Caching disabled in sqlalchemy queries

[mekanix]

There is a significant regression in speed and it's probably due to cache not being used. In ormar PR switching to SQLAlchemy2 there is a noticeable degradation in speed, and the recommendation was to check SQLAlchemy's caching. I came up with this to test for caching being disabled

env TEST_DATABASE_URLS="sqlite+aiosqlite:////tmp/db.sqlite" pytest -s tests/test_databases.py::test_queries
================================================================================================================================================= test session starts ==================================================================================================================================================
platform freebsd15 -- Python 3.9.18, pytest-7.4.4, pluggy-1.4.0
codspeed: 2.2.1 (callgraph: not supported)
benchmark: 4.0.0 (defaults: timer=time.perf_counter disable_gc=False min_rounds=5 min_time=0.000005 max_time=1.0 calibration_precision=10 warmup=False warmup_iterations=100000)
rootdir: /usr/home/meka/repos/databases
plugins: benchmark-4.0.0, cov-4.1.0, asyncio-0.21.1, anyio-4.3.0, codspeed-2.2.1, Faker-24.7.1
asyncio: mode=strict
collected 1 item

tests/test_databases.py 2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine BEGIN (implicit)
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("notes")
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("articles")
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("events")
2024-04-10 01:00:45,045 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("daily_schedule")
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("tshirt_size")
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info("tshirt_size")
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("session")
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info("session")
2024-04-10 01:00:45,046 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("custom_date")
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info("custom_date")
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine PRAGMA main.table_info("prices")
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info("prices")
2024-04-10 01:00:45,047 INFO sqlalchemy.engine.Engine [raw sql] ()
2024-04-10 01:00:45,048 INFO sqlalchemy.engine.Engine
CREATE TABLE tshirt_size (
	id INTEGER NOT NULL,
	size VARCHAR(6),
	color VARCHAR(6),
	PRIMARY KEY (id)
)


2024-04-10 01:00:45,048 INFO sqlalchemy.engine.Engine [no key 0.00008s] ()
2024-04-10 01:00:45,055 INFO sqlalchemy.engine.Engine
CREATE TABLE session (
	id INTEGER NOT NULL,
	data JSON,
	PRIMARY KEY (id)
)


2024-04-10 01:00:45,055 INFO sqlalchemy.engine.Engine [no key 0.00014s] ()
2024-04-10 01:00:45,062 INFO sqlalchemy.engine.Engine
CREATE TABLE custom_date (
	id INTEGER NOT NULL,
	title VARCHAR(100),
	published INTEGER,
	PRIMARY KEY (id)
)


2024-04-10 01:00:45,062 INFO sqlalchemy.engine.Engine [no key 0.00012s] ()
2024-04-10 01:00:45,068 INFO sqlalchemy.engine.Engine
CREATE TABLE prices (
	id INTEGER NOT NULL,
	price NUMERIC(30, 20),
	PRIMARY KEY (id)
)


2024-04-10 01:00:45,068 INFO sqlalchemy.engine.Engine [no key 0.00010s] ()
2024-04-10 01:00:45,074 INFO sqlalchemy.engine.Engine COMMIT

The no key part indicates that the caching is disabled, as per official docs. I still don't know where that no key comes from, but I do hope you can help me narrow it down.

[zanieb]

Thanks for the report!

cc @tarsil