cc @cmgoffena13
Environment
- sqlmesh 0.227.1 (code paths below are unchanged on
main, 0.236.1), sqlglot 27.28.1
- Python 3.13, BigQuery engine, ~2,400 promoted snapshots per environment
concurrent_tasks: 16 (raising it to 64 changed nothing)
Symptom
sqlmesh plan --include-unmodified <dev_env> spends 40–50 minutes in "Updating virtual layer" for ~2,400 views.
BigQuery INFORMATION_SCHEMA.JOBS shows every job finishing in 1–2 s with no errors, no queueing and long idle stretches, i.e. the warehouse is not the bottleneck. Thread dumps (py-spy) show the promotion workers busy in pure Python. Because dev environments never partially promote (Environment.can_partially_promote requires name == 'prod'), every dev plan pays this for the whole environment.
Root causes (per promoted view)
-
Property rendering re-normalizes the entire view mapping, twice per render.
_promote_snapshot renders session_properties and virtual_properties with table_mapping = to_view_mapping(<all env snapshots>) (N entries). ExpressionRenderer.render → _render resolves this_model unconditionally through _resolve_table, which calls exp.replace_tables(table, {**mapping, **table_mapping}), then _resolve_tables calls exp.replace_tables again on the rendered expression. sqlglot's replace_tables normalizes every mapping key with normalize_table_name (a full parse_one) on every call. Result: ~4N table-name parses per view for two property expressions that contain no table reference at all (label arrays), so a promotion of N views costs O(N²) parses. Profile: 58,580 normalize_table_name calls for 20 renders at N=1,464 (99% of the render time); a static literal property costs the same as a macro call, so this is not macro evaluation.
(sqlmesh/core/renderer.py _render/_resolve_table/_resolve_tables, sqlmesh/core/model/definition.py _render_properties, sqlmesh/core/snapshot/evaluator.py _promote_snapshot)
-
to_table_mapping over all environment snapshots, twice per view.
PromotableStrategy.promote passes snapshots=<all env snapshots> to render_virtual_properties; _resolve_tables and _resolve_table each call to_table_mapping(snapshots.values(), deployability_index), i.e. Snapshot.table_name() (parse + SQL generation) for every snapshot in the environment, per view. Note this only shows up with versioned snapshots (to_table_mapping skips version is None), so a profile on a freshly loaded Context misses it.
(sqlmesh/core/snapshot/evaluator.py PromotableStrategy.promote, sqlmesh/core/snapshot/definition.py to_table_mapping)
-
sqlglot: the lazy dialect loader takes a lock on every import.
sqlglot/dialects/__init__.py resolves from sqlglot.dialects import Dialect through a module __getattr__ that acquires an RLock and calls importlib.import_module each time; the attribute is never cached into the module namespace. Expression.sql() and Parser.__init__ both do that import, so one to_table_mapping build performs ~16,000 locked calls (N=1,338). With 9–16 promotion threads this becomes a lock convoy: one build takes 85 ms single-threaded and ~2 s per thread with 9 threads on Linux; on macOS the run appeared frozen for many minutes at 92% (all workers sampled inside __getattr__), and Ctrl-C printed "Aborted!" without exiting because the non-daemon workers were mid-call.
-
Smaller item on the same path: _promote_snapshot rebuilds snapshot_by_name = {s.name: s for s in snapshots.values()} for every view (O(N) per view, 70–120 ms here) just for render_on_virtual_update.
More threads won't help
All of the above is CPU work under the GIL. Measured per-view Python cost: 330 ms at 1 thread, 707 ms at 4 threads (contention makes it slower). The BigQuery I/O it hides is ~3 s per view and would parallelize fine.
Verification of the diagnosis
Two process-local memoizations, applied from a module imported at startup, took the same 2,391-view promotion from ~50 min to 3 min 37 s with byte-identical DDL:
normalize_table_name memoized for str inputs (key: name, dialect string, dialect normalization strategy): property render 248 ms → 4.8 ms per view;to_table_mapping memoized on (deployability index fields, snapshot ids/versions) and Dialect bound as a real attribute of sqlglot.dialects: mapping build 85 ms (2,016 ms at 9 threads) → 0.5 ms, zero locked calls.
Fingerprints unchanged; renders of self-referencing models identical across evaluating/creating × deployable/dev; identical output across 14 dialect settings.
Reproduction
Any project with ~1,000+ models: sqlmesh plan --include-unmodified <new_dev_env> on a warehouse where DDL is fast, then py-spy dump on the process during "Updating virtual layer" (frames: render_virtual_properties → _resolve_tables → _to_table_mapping → table_name → … → sqlglot/dialects/__init__.py __getattr__) or cProfile model.render_virtual_properties(...) with a full table_mapping and versioned snapshots (replace_tables → normalize_table_name → parse_one dominates).
cc @cmgoffena13
Environment
main, 0.236.1), sqlglot 27.28.1concurrent_tasks: 16(raising it to 64 changed nothing)Symptom
sqlmesh plan --include-unmodified <dev_env>spends 40–50 minutes in "Updating virtual layer" for ~2,400 views.BigQuery
INFORMATION_SCHEMA.JOBSshows every job finishing in 1–2 s with no errors, no queueing and long idle stretches, i.e. the warehouse is not the bottleneck. Thread dumps (py-spy) show the promotion workers busy in pure Python. Because dev environments never partially promote (Environment.can_partially_promoterequiresname == 'prod'), every dev plan pays this for the whole environment.Root causes (per promoted view)
Property rendering re-normalizes the entire view mapping, twice per render.
_promote_snapshotrenderssession_propertiesandvirtual_propertieswithtable_mapping = to_view_mapping(<all env snapshots>)(N entries).ExpressionRenderer.render→_renderresolvesthis_modelunconditionally through_resolve_table, which callsexp.replace_tables(table, {**mapping, **table_mapping}), then_resolve_tablescallsexp.replace_tablesagain on the rendered expression. sqlglot'sreplace_tablesnormalizes every mapping key withnormalize_table_name(a fullparse_one) on every call. Result: ~4N table-name parses per view for two property expressions that contain no table reference at all (label arrays), so a promotion of N views costs O(N²) parses. Profile: 58,580normalize_table_namecalls for 20 renders at N=1,464 (99% of the render time); a static literal property costs the same as a macro call, so this is not macro evaluation.(
sqlmesh/core/renderer.py_render/_resolve_table/_resolve_tables,sqlmesh/core/model/definition.py_render_properties,sqlmesh/core/snapshot/evaluator.py_promote_snapshot)to_table_mappingover all environment snapshots, twice per view.PromotableStrategy.promotepassessnapshots=<all env snapshots>torender_virtual_properties;_resolve_tablesand_resolve_tableeach callto_table_mapping(snapshots.values(), deployability_index), i.e.Snapshot.table_name()(parse + SQL generation) for every snapshot in the environment, per view. Note this only shows up with versioned snapshots (to_table_mappingskipsversion is None), so a profile on a freshly loaded Context misses it.(
sqlmesh/core/snapshot/evaluator.pyPromotableStrategy.promote,sqlmesh/core/snapshot/definition.pyto_table_mapping)sqlglot: the lazy dialect loader takes a lock on every import.
sqlglot/dialects/__init__.pyresolvesfrom sqlglot.dialects import Dialectthrough a module__getattr__that acquires an RLock and callsimportlib.import_moduleeach time; the attribute is never cached into the module namespace.Expression.sql()andParser.__init__both do that import, so oneto_table_mappingbuild performs ~16,000 locked calls (N=1,338). With 9–16 promotion threads this becomes a lock convoy: one build takes 85 ms single-threaded and ~2 s per thread with 9 threads on Linux; on macOS the run appeared frozen for many minutes at 92% (all workers sampled inside__getattr__), and Ctrl-C printed "Aborted!" without exiting because the non-daemon workers were mid-call.Smaller item on the same path:
_promote_snapshotrebuildssnapshot_by_name = {s.name: s for s in snapshots.values()}for every view (O(N) per view, 70–120 ms here) just forrender_on_virtual_update.More threads won't help
All of the above is CPU work under the GIL. Measured per-view Python cost: 330 ms at 1 thread, 707 ms at 4 threads (contention makes it slower). The BigQuery I/O it hides is ~3 s per view and would parallelize fine.
Verification of the diagnosis
Two process-local memoizations, applied from a module imported at startup, took the same 2,391-view promotion from ~50 min to 3 min 37 s with byte-identical DDL:
normalize_table_namememoized for str inputs (key: name, dialect string, dialect normalization strategy): property render 248 ms → 4.8 ms per view;to_table_mappingmemoized on (deployability index fields, snapshot ids/versions) andDialectbound as a real attribute ofsqlglot.dialects: mapping build 85 ms (2,016 ms at 9 threads) → 0.5 ms, zero locked calls.Fingerprints unchanged; renders of self-referencing models identical across evaluating/creating × deployable/dev; identical output across 14 dialect settings.
Reproduction
Any project with ~1,000+ models:
sqlmesh plan --include-unmodified <new_dev_env>on a warehouse where DDL is fast, thenpy-spy dumpon the process during "Updating virtual layer" (frames:render_virtual_properties → _resolve_tables → _to_table_mapping → table_name → … → sqlglot/dialects/__init__.py __getattr__) or cProfilemodel.render_virtual_properties(...)with a fulltable_mappingand versioned snapshots (replace_tables → normalize_table_name → parse_onedominates).