Skip to content

minor: add projectionTrace query context for diagnosing projection match failures #19613

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
cecemei wants to merge 3 commits into
base: master
Choose a base branch
from
+44 −3
Open

minor: add projectionTrace query context for diagnosing projection match failures #19613

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
fcf30d2
proj
cecemei Jun 22, 2026
56ee61f
comment
cecemei Jun 22, 2026
2e0ca4a
debug
cecemei Jun 23, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions processing/src/main/java/org/apache/druid/query/QueryContexts.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,7 @@ public class QueryContexts
public static final String NO_PROJECTIONS = "noProjections";
public static final String FORCE_PROJECTION = "forceProjections";
public static final String USE_PROJECTION = "useProjection";
public static final String PROJECTION_TRACE = "projectionTrace";

@clintropolis clintropolis Jun 22, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i wonder if instead of adding a new flag if this should just check ENABLE_DEBUG context flag

@cecemei cecemei Jun 22, 2026 •
edited
Loading

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i've thought about that as well, but decided not because debug=true already triggers a lot of things at once, e.x SQL planner rule, CalciteRulesManager in particular is very noisy when it logs planner rules. It'd be very noisy if someone is just trying to understand why a projection isn't matching.

@clintropolis clintropolis Jun 23, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yea, i considered the noise briefly too, but then said to myself it was ok though because the noisy SQL logs are all on the broker, while these logs are only going to be on the historicals and realtime servers, per segment.

If you really want to add a new flag, i still think we should also do this logging if debug is set, so that way someone wanting "all the logs" doesn't have to set a bunch of different flags, so the logTrace method could check either projectionTrace or debug

@cecemei cecemei Jun 23, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good point, i added the logging if debug is set


// Unique identifier for the query, that is used to map the global shared resources (specifically merge buffers) to the
// query's runtime
Expand Down
46 changes: 43 additions & 3 deletions processing/src/main/java/org/apache/druid/segment/projections/Projections.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,8 @@
import org.apache.druid.java.util.common.granularity.Granularities;
import org.apache.druid.java.util.common.granularity.Granularity;
import org.apache.druid.java.util.common.granularity.PeriodGranularity;
import org.apache.druid.java.util.common.logger.Logger;
import org.apache.druid.query.QueryContext;
import org.apache.druid.query.QueryContexts;
import org.apache.druid.query.aggregation.AggregatorFactory;
import org.apache.druid.query.aggregation.FilteredAggregatorFactory;
Expand Down Expand Up @@ -67,6 +69,17 @@

public class Projections
{
private static final Logger log = new Logger(Projections.class);

private static void logTrace(QueryContext context, String format, Object... args)

@clintropolis clintropolis Jun 22, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why not just pass the CursorBuildSpec into this method? it looks like all of the callers are getting it from there anyway

@cecemei cecemei Jun 22, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

a narrower input param would be more declarative? yes all callers are getting it from CursorBuildSpec.

@clintropolis clintropolis Jun 23, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i guess it was just jarring to see logTrace(queryCursorBuildSpec.getQueryContext()... like 20 times in the same file with all the stuff sourced from a CursorBuildSpec.

{
if (context.getBoolean(QueryContexts.PROJECTION_TRACE, false) || context.isDebug()) {
log.info(format, args);
} else {
log.debug(format, args);
}
}

public static final String BASE_TABLE_PROJECTION_NAME = "__base";

private static final String CLUSTER_GROUP_PREFIX = BASE_TABLE_PROJECTION_NAME + "$";
Expand Down Expand Up @@ -161,35 +174,48 @@ public static ProjectionMatch matchAggregateProjection(
)
{
if (!queryCursorBuildSpec.isCompatibleOrdering(projection.getOrderingWithTimeColumnSubstitution())) {
logTrace(
queryCursorBuildSpec.getQueryContext(),
"matchAggregateProjection: projection [%s] rejected — incompatible ordering, query wants %s but projection provides %s",
projection.getName(),
queryCursorBuildSpec.getPreferredOrdering(),
projection.getOrderingWithTimeColumnSubstitution()
);
return null;
}
if (CollectionUtils.isNullOrEmpty(queryCursorBuildSpec.getPhysicalColumns())) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — no physical columns in query", projection.getName());
return null;
}

if (isUnalignedInterval(projection, queryCursorBuildSpec, dataInterval)) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — unaligned interval", projection.getName());
return null;
}
ProjectionMatchBuilder matchBuilder = new ProjectionMatchBuilder();

// match virtual columns first, which will populate the 'remapColumns' of the match builder
matchBuilder = matchQueryVirtualColumns(projection, queryCursorBuildSpec, physicalColumnChecker, matchBuilder);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — virtual column mismatch", projection.getName());

@clintropolis clintropolis Jun 22, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this and some of these other top level logs seem kind of redundant since the methods they call also log when returning nulls, but i guess we sort of need these here though because otherwise i'm not sure its obvious which caller of which match method was the failing one.

This is probably ok for now since its just logs, but in the future we might consider collecting these failure reasons instead of logging them when they happen so that we can produce more concise messaging.

@cecemei cecemei Jun 22, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we could consider collecting failure reasons when forceProjection or useProjection is set in the future, and maybe add it as a system flag.

even though many messages are added here, only 1-2 lines would be logged so it should not be too verbose.

@clintropolis clintropolis Jun 23, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yea, i think its fine for now, though 'only 1-2 lines' is per projection, per segment of the query, so its going to be pretty verbose anywhere that is touching more than a few segments if there are any projections at all.

@cecemei cecemei Jun 23, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yea it would be suboptimal if logging for a lot of segments, maybe could be helpful in the case when only several segments out of all are missing proper projections, it gives some amount of visibility and operatibility to projection at least.

return null;
}

matchBuilder = matchFilter(projection, queryCursorBuildSpec, physicalColumnChecker, matchBuilder);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — filter mismatch", projection.getName());
return null;
}

matchBuilder = matchGrouping(projection, queryCursorBuildSpec, physicalColumnChecker, matchBuilder);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — grouping mismatch", projection.getName());
return null;
}

matchBuilder = matchAggregators(projection, queryCursorBuildSpec, physicalColumnChecker, matchBuilder);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregateProjection: projection [%s] rejected — aggregator mismatch", projection.getName());
return null;
}

Expand All @@ -213,6 +239,7 @@ public static ProjectionMatchBuilder matchQueryVirtualColumns(
matchBuilder
);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchQueryVirtualColumns: projection [%s] rejected — virtual column [%s] could not be matched", projection.getName(), vc.getOutputName());
return null;
}
}
Expand All @@ -231,14 +258,14 @@ public static ProjectionMatchBuilder matchFilter(
if (projection.getFilter() != null) {
final Filter queryFilter = queryCursorBuildSpec.getFilter();
if (queryFilter != null) {
final Set<String> originalRequired = queryFilter.getRequiredColumns();
// try to rewrite the query filter into a projection filter, if the rewrite is valid, we can proceed
final Filter projectionFilter = projection.getFilter().toOptimizedFilter(false);
final Filter remappedQueryFilter = remapFilterToProjection(matchBuilder, queryFilter);

final Filter rewritten = ProjectionFilterMatch.rewriteFilter(projectionFilter, remappedQueryFilter);
// if the filter does not contain the projection filter, we cannot match this projection
if (rewritten == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchFilter: projection [%s] rejected — query filter does not contain the projection filter", projection.getName());
return null;
}
//noinspection ObjectEquality
Expand All @@ -251,6 +278,7 @@ public static ProjectionMatchBuilder matchFilter(
}
} else {
// projection has a filter, but the query doesn't, no good
logTrace(queryCursorBuildSpec.getQueryContext(), "matchFilter: projection [%s] rejected — projection has a filter but query does not", projection.getName());
return null;
}
} else {
Expand All @@ -269,6 +297,7 @@ public static ProjectionMatchBuilder matchFilter(
matchBuilder
);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchFilter: projection [%s] rejected — required filter column [%s] not available on projection", projection.getName(), queryColumn);
return null;
}
}
Expand Down Expand Up @@ -296,14 +325,17 @@ public static ProjectionMatchBuilder matchGrouping(
matchBuilder
);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchGrouping: projection [%s] rejected — grouping column [%s] not available on projection", projection.getName(), queryColumn);
return null;
}
// a query grouping column must also be defined as a projection grouping column
if (projection.isInvalidGrouping(queryColumn)) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchGrouping: projection [%s] rejected — column [%s] is not a grouping column on the projection", projection.getName(), queryColumn);
return null;
}
// even if remapped
if (projection.isInvalidGrouping(matchBuilder.getRemapValue(queryColumn))) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchGrouping: projection [%s] rejected — remapped column [%s] is not a grouping column on the projection", projection.getName(), matchBuilder.getRemapValue(queryColumn));
return null;
}
}
Expand Down Expand Up @@ -354,6 +386,7 @@ public static ProjectionMatchBuilder matchAggregators(
matchBuilder
);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregators: projection [%s] rejected — filtered aggregator [%s] requires column [%s] not available on projection", projection.getName(), queryAgg.getName(), column);
return null;
}
}
Expand All @@ -375,6 +408,7 @@ public static ProjectionMatchBuilder matchAggregators(
if (allMatch) {
return matchBuilder;
}
logTrace(queryCursorBuildSpec.getQueryContext(), "matchAggregators: projection [%s] rejected — one or more query aggregators could not be matched to a projection aggregator", projection.getName());
return null;
}

Expand Down Expand Up @@ -422,7 +456,7 @@ public static ProjectionMatchBuilder matchRequiredColumn(
);
}

return matchQueryPhysicalColumn(column, projection, physicalColumnChecker, matchBuilder);
return matchQueryPhysicalColumn(column, projection, physicalColumnChecker, matchBuilder, queryCursorBuildSpec.getQueryContext());
}

@Nullable
Expand Down Expand Up @@ -482,12 +516,14 @@ public static ProjectionMatchBuilder matchQueryVirtualColumn(
// 1. virtual gran is NONE, and projection gran is not
// 2. projection gran is ALL, and virtual gran is not
// 3. both are period granularities, but projection gran can't be mapped to virtual gran, e.x. PT2H can't be mapped to PT1H
logTrace(queryCursorBuildSpec.getQueryContext(), "matchQueryVirtualColumn: projection [%s] rejected — virtual column [%s] granularity [%s] is incompatible with projection granularity [%s]", projection.getName(), queryVirtualColumn.getOutputName(), virtualGranularity, projection.getEffectiveGranularity());
return null;
} else {
// we can't decide query granularity for the virtual column with __time, requires none granularity to be safe
if (Granularities.NONE.equals(projection.getEffectiveGranularity())) {
return matchBuilder.addReferencedPhysicalColumn(ColumnHolder.TIME_COLUMN_NAME);
}
logTrace(queryCursorBuildSpec.getQueryContext(), "matchQueryVirtualColumn: projection [%s] rejected — virtual column [%s] uses __time but projection granularity [%s] is not NONE", projection.getName(), queryVirtualColumn.getOutputName(), projection.getEffectiveGranularity());
return null;
}
} else {
Expand All @@ -500,6 +536,7 @@ public static ProjectionMatchBuilder matchQueryVirtualColumn(
matchBuilder
);
if (matchBuilder == null) {
logTrace(queryCursorBuildSpec.getQueryContext(), "matchQueryVirtualColumn: projection [%s] rejected — virtual column [%s] requires input [%s] not available on projection", projection.getName(), queryVirtualColumn.getOutputName(), required);
return null;
}
}
Expand All @@ -512,19 +549,22 @@ public static ProjectionMatchBuilder matchQueryPhysicalColumn(
String column,
AggregateProjectionSchema projection,
PhysicalColumnChecker physicalColumnChecker,
ProjectionMatchBuilder matchBuilder
ProjectionMatchBuilder matchBuilder,
QueryContext context
)
{
// if we need __time as a physical column, the projection must be grouping on __time directly
if (ColumnHolder.TIME_COLUMN_NAME.equals(column)) {
if (ColumnHolder.TIME_COLUMN_NAME.equals(projection.getTimeColumnName())) {
return matchBuilder.addReferencedPhysicalColumn(ColumnHolder.TIME_COLUMN_NAME);
}
logTrace(context, "matchQueryPhysicalColumn: projection [%s] rejected — query requires __time as a physical column but projection does not group on __time", projection.getName());
return null;
}
if (physicalColumnChecker.check(projection.getName(), column)) {
return matchBuilder.addReferencedPhysicalColumn(column);
}
logTrace(context, "matchQueryPhysicalColumn: projection [%s] rejected — column [%s] is not available on projection", projection.getName(), column);
return null;
}

Expand Down
Loading