Skip to content

TagNode load takes 150s on an analysis with 0 tags - get_tag_counts() isn't short-circuited #1838

Description

@davmlaw

🤖 Written by Claude

A TagNode in prod recorded load_seconds = 149.96 on an analysis with 0 VariantTags. The node's own filter is provably empty, so the load should be milliseconds.

The IN (NULL) SQL is a red herring

The SQL copied off the node's Debug tab shows:

... AND "snpdb_variant"."id" IN (NULL) AND ...

That is a rendering artifact, not what runs. analysis/views/views_node.py:get_node_sql wraps the compile in library/utils/database_utils.py:render_empty_result_set_sql, which monkey-patches In.process_rhs to emit (NULL) for an empty list so the debug tab has something to show. In the real query path Django raises EmptyResultSet for Q(pk__in=[]) and no SQL is sent at all.

Verified on vg-test2 with a real TagNode (node_input=PARENT_TAGGED, mode=THIS_ANALYSIS, no tags in the analysis):

  • n.get_queryset()EmptyResultSet, no query executed
  • qs.aggregate(Count("pk", empty_result_set_value=0)){'total': 0}, connection.queries empty
  • n.get_tag_counts() → 0.012 s

And even if that SQL did run, Postgres folds it:

EXPLAIN ... WHERE (id IN (SELECT ...) OR id IN (SELECT ...)) AND id IN (NULL) ...
Result  (cost=0.00..0.00 rows=0 width=4)
  One-Time Filter: false

So the 150 s is somewhere else in TagNode.load().

Where the time can actually go

load_seconds covers AnalysisNode.load()_load() + node_counts(), and node_counts() calls _get_load_data(), which for TagNode is get_tag_counts() (added in #1820). Two things in there are not gated on the node being provably empty:

1. The tag list query — analysis_varianttag unscoped OR-join

q_configured = Q(tagnodetag__tag_node=self)
tags_qs = Tag.objects.filter(Q(varianttag__analysis=self.analysis) | q_configured)
tag_ids = sorted(tags_qs.distinct().values_list("pk", flat=True))

An OR across two multi-valued joins with DISTINCT. The varianttag__analysis index can't be used to drive it, so the planner is free to walk analysis_varianttag (412k rows at SA Path) — the exact shape we already know to keep as a subquery. This runs on every TagNode load regardless of how many tags the analysis has.

2. get_tag_counts() in TagNodeMode.ALL_TAGS — one allele subquery per live tag

For a global node this is genuinely large, and for a source global node (node_input=TAGGED_VARIANTS) it is unbounded — arg_q_dict = {None: {}}, i.e. the whole 24M-row snpdb_variant table. Captured on vg-test2:

SELECT COUNT(v.id) FILTER (WHERE va.allele_id IN (SELECT allele_id FROM analysis_varianttag U0 LEFT JOIN classification_classification U2 ... AND U0.tag_id IN ('Artefact')) AND va.genome_build_id='GRCh38') AS tag_count_0,
       COUNT(...)  -- one of these per live tag
FROM snpdb_variant v
LEFT JOIN snpdb_variantallele va ON v.id = va.variant_id
WHERE va.allele_id IN (SELECT allele_id FROM analysis_varianttag U0 LEFT JOIN ...)   -- every tagged allele in the DB
  AND va.genome_build_id='GRCh38'

N repeats of a 412k-row subquery, over snpdb_variant ⟕ snpdb_variantallele. The docstring's "restricting to tagged variants first makes this far cheaper than a scan" holds for an analysis-scoped node; for a global one the restriction is every tagged allele in the database.

Suggested fixes

  • Short-circuit get_tag_counts() when the node can't produce rows: if mode == THIS_ANALYSIS and the analysis has no VariantTags, return dict.fromkeys(self.tag_ids, 0) without touching the parent queryset.
  • Make the tag-list query a subquery instead of an OR-join: Tag.objects.filter(Q(pk__in=VariantTag.objects.filter(analysis=...).values("tag_id")) | Q(pk__in=TagNodeTag.objects.filter(tag_node=self).values("tag_id"))).
  • For ALL_TAGS, count from analysis_varianttag (small) intersected with the node's variants, rather than one FILTER subquery per tag over the variant table — and never over {None: {}} (all variants) for a source node.
  • Consider recording the per-phase time in load_seconds (or logging _get_load_data() separately) so a slow load points at the phase.

To confirm on prod

Node id and mode for the 149.96 s load, plus:

python3 manage.py profile_analysis_nodes --analysis <id> --rerun --explain

Activity

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

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions