fix(querier): resolve $N trace_id variable before trace-summary short-circuit
The llmobs span views parameterize the trace_id predicate as `trace_id = $N` and carry the real id in the request Variables map. narrowWindowByTraceID reads the filter EXPRESSION via ExtractTraceIDsFromFilter, so it got back the literal "$N", looked that up in distributed_trace_summary, found nothing, and — for SignalTraces — short-circuited the whole span query to empty. Every trace-detail observations/traces query returned zero rows fleet-wide even though the spans existed (verified live: trace 9aa37a28...4406a held its gen_ai span the whole time). Resolve $N/$name placeholders against q.variables before the trace_summary lookup (mirroring the where-clause visitor). An unresolved placeholder skips the optimization (runs the fully-substituted main query) instead of short-circuiting. Inline literals keep the fast path. Regression: TestNarrowWindowParameterizedTraceID (bound placeholder narrows, not short-circuits; unbound placeholder skips, not short-circuits) + TestResolveTraceIDVars.
This commit is contained in:
Hanzo AI
@@ -278,6 +278,19 @@ func (q *builderQuery[T]) narrowWindowByTraceID(ctx context.Context, fromMS, toM
|
||||
return fromMS, toMS, true, ""
|
||||
}
|
||||
|
||||
// The trace_id predicate may be a bound `$N` variable placeholder rather than an
|
||||
// inline literal — the span views parameterize `trace_id = $N` and carry the real
|
||||
// id in the request Variables map, so ExtractTraceIDsFromFilter (which reads the
|
||||
// expression TEXT) hands back the literal "$N". Resolve those placeholders against
|
||||
// the bound variables before the trace_summary lookup. When a placeholder has no
|
||||
// bound value we cannot key the optimization on a real id, so SKIP the optimization
|
||||
// and let the fully-substituted main query run — never short-circuit to empty on a
|
||||
// literal "$N" that no trace can match.
|
||||
traceIDs, resolved := q.resolveTraceIDVars(traceIDs)
|
||||
if !resolved {
|
||||
return fromMS, toMS, true, ""
|
||||
}
|
||||
|
||||
finder := telemetrytraces.NewTraceTimeRangeFinder(q.telemetryStore)
|
||||
traceStart, traceEnd, exists, err := finder.GetTraceTimeRangeMulti(ctx, traceIDs)
|
||||
if err != nil {
|
||||
@@ -330,6 +343,65 @@ func (q *builderQuery[T]) narrowWindowByTraceID(ctx context.Context, fromMS, toM
|
||||
return fromMS, toMS, true, ""
|
||||
}
|
||||
|
||||
// resolveTraceIDVars replaces any `$N` / `$name` placeholder among the extracted
|
||||
// trace_ids with its bound variable value, mirroring the where-clause visitor's
|
||||
// lookup (try the raw token, then the `$`-stripped key). Inline literals (no `$`
|
||||
// prefix) pass through unchanged, preserving the fast path. It returns ok=false when
|
||||
// a placeholder has no matching variable or a non-scalar/empty value — the signal for
|
||||
// the caller to skip the trace_id time-range optimization rather than look up a
|
||||
// literal "$N" in trace_summary (which matches nothing and short-circuits to empty).
|
||||
func (q *builderQuery[T]) resolveTraceIDVars(traceIDs []string) ([]string, bool) {
|
||||
out := make([]string, 0, len(traceIDs))
|
||||
for _, id := range traceIDs {
|
||||
if !strings.HasPrefix(id, "$") {
|
||||
out = append(out, id)
|
||||
continue
|
||||
}
|
||||
item, ok := q.variables[id]
|
||||
if !ok {
|
||||
item, ok = q.variables[strings.TrimPrefix(id, "$")]
|
||||
}
|
||||
if !ok {
|
||||
return nil, false
|
||||
}
|
||||
vals, ok := traceIDVarStrings(item.Value)
|
||||
if !ok {
|
||||
return nil, false
|
||||
}
|
||||
out = append(out, vals...)
|
||||
}
|
||||
return out, len(out) > 0
|
||||
}
|
||||
|
||||
// traceIDVarStrings coerces a bound variable value into one or more non-empty
|
||||
// trace_id strings. A single string or a homogeneous list of non-empty strings is
|
||||
// accepted; anything else (empty string, empty list, non-string element) yields
|
||||
// ok=false so the caller skips the optimization instead of keying it on garbage.
|
||||
func traceIDVarStrings(v any) ([]string, bool) {
|
||||
switch x := v.(type) {
|
||||
case string:
|
||||
return []string{x}, x != ""
|
||||
case []string:
|
||||
for _, s := range x {
|
||||
if s == "" {
|
||||
return nil, false
|
||||
}
|
||||
}
|
||||
return x, len(x) > 0
|
||||
case []any:
|
||||
out := make([]string, 0, len(x))
|
||||
for _, e := range x {
|
||||
s, ok := e.(string)
|
||||
if !ok || s == "" {
|
||||
return nil, false
|
||||
}
|
||||
out = append(out, s)
|
||||
}
|
||||
return out, len(out) > 0
|
||||
}
|
||||
return nil, false
|
||||
}
|
||||
|
||||
// emptyResultFor returns an empty result payload appropriate for the given kind.
|
||||
func emptyResultFor(kind qbtypes.RequestType, queryName string) *qbtypes.Result {
|
||||
var value any
|
||||
|
||||
@@ -0,0 +1,149 @@
|
||||
package querier
|
||||
|
||||
import (
|
||||
"context"
|
||||
"io"
|
||||
"log/slog"
|
||||
"testing"
|
||||
|
||||
sqlmock "github.com/DATA-DOG/go-sqlmock"
|
||||
dsmock "github.com/hanzo-ds/mock"
|
||||
"github.com/hanzoai/o11y/pkg/telemetrystore"
|
||||
"github.com/hanzoai/o11y/pkg/telemetrystore/telemetrystoretest"
|
||||
qbtypes "github.com/hanzoai/o11y/pkg/types/querybuildertypes/querybuildertypesv5"
|
||||
"github.com/hanzoai/o11y/pkg/types/telemetrytypes"
|
||||
"github.com/stretchr/testify/assert"
|
||||
"github.com/stretchr/testify/require"
|
||||
)
|
||||
|
||||
// realTraceID is the live trace 9aa37a283590028516f27b45e3a4406a whose single
|
||||
// gen_ai span (org=hanzo, model enso-flash, 211 tokens, $0.01) proved the read leg
|
||||
// held the row all along — the detail view rendered "no observations" purely because
|
||||
// the trace_id filter was a `$N` placeholder the trace-summary optimizer never
|
||||
// resolved, short-circuiting the span query to empty before it ran.
|
||||
const realTraceID = "9aa37a283590028516f27b45e3a4406a"
|
||||
|
||||
// llmobsDetailFilter is exactly what impllmobs.genAIFilter emits for an
|
||||
// observations/traces DETAIL request: org bound as $1, trace_id bound as $2.
|
||||
const llmobsDetailFilter = "gen_ai.system EXISTS AND gen_ai.hanzo.org_id = $1 AND trace_id = $2"
|
||||
|
||||
func discardLogger() *slog.Logger { return slog.New(slog.NewTextHandler(io.Discard, nil)) }
|
||||
|
||||
func newTraceStore(t *testing.T) *telemetrystoretest.Provider {
|
||||
t.Helper()
|
||||
return telemetrystoretest.New(telemetrystore.Config{}, sqlmock.QueryMatcherRegexp)
|
||||
}
|
||||
|
||||
// TestNarrowWindowParameterizedTraceID is the regression test for the fleet-wide
|
||||
// "trace shows, no observations" bug. The llmobs span views parameterize the
|
||||
// trace_id predicate as `trace_id = $2` and carry the real id in the request
|
||||
// Variables map; narrowWindowByTraceID reads the filter TEXT, so before the fix it
|
||||
// looked up the literal "$2" in distributed_trace_summary, found nothing, and — for
|
||||
// SignalTraces — short-circuited the whole span query to empty (overlap=false).
|
||||
func TestNarrowWindowParameterizedTraceID(t *testing.T) {
|
||||
// The trace's nanosecond bounds; narrowWindowByTraceID pads by 1s and clamps the
|
||||
// ms window to them.
|
||||
const startNano = int64(1_700_000_000_000_000_000)
|
||||
const endNano = int64(1_700_000_001_200_000_000)
|
||||
fromMS := uint64(1_699_999_990_000)
|
||||
toMS := uint64(1_700_000_010_000)
|
||||
|
||||
summaryCols := []dsmock.ColumnType{
|
||||
{Name: "count", Type: "UInt64"},
|
||||
{Name: "start", Type: "Int64"},
|
||||
{Name: "end", Type: "Int64"},
|
||||
}
|
||||
|
||||
// A bound placeholder resolves to the real id, so the trace_summary lookup runs,
|
||||
// finds the trace, and the window is clamped to its bounds — the query is NOT
|
||||
// short-circuited. (Both org=$1 and trace_id=$2 are bound, as in production.)
|
||||
t.Run("bound placeholder runs the lookup and narrows the window", func(t *testing.T) {
|
||||
store := newTraceStore(t)
|
||||
store.Mock().ExpectQueryRow(`distributed_trace_summary`).
|
||||
WillReturnRow(dsmock.NewRow(summaryCols, []any{uint64(1), startNano, endNano}))
|
||||
|
||||
q := &builderQuery[qbtypes.TraceAggregation]{
|
||||
logger: discardLogger(),
|
||||
telemetryStore: store,
|
||||
spec: qbtypes.QueryBuilderQuery[qbtypes.TraceAggregation]{
|
||||
Signal: telemetrytypes.SignalTraces,
|
||||
Filter: &qbtypes.Filter{Expression: llmobsDetailFilter},
|
||||
},
|
||||
variables: map[string]qbtypes.VariableItem{
|
||||
"1": {Type: qbtypes.DynamicVariableType, Value: "hanzo"},
|
||||
"2": {Type: qbtypes.DynamicVariableType, Value: realTraceID},
|
||||
},
|
||||
}
|
||||
|
||||
gotFrom, gotTo, overlap, warning := q.narrowWindowByTraceID(context.Background(), fromMS, toMS)
|
||||
|
||||
require.True(t, overlap, "a resolvable parameterized trace_id must NOT short-circuit the span query")
|
||||
assert.Empty(t, warning)
|
||||
assert.Equal(t, uint64((startNano-1_000_000_000)/1_000_000), gotFrom, "from clamped to trace start")
|
||||
assert.Equal(t, uint64((endNano+1_000_000_000)/1_000_000), gotTo, "to clamped to trace end")
|
||||
require.NoError(t, store.Mock().ExpectationsWereMet(), "trace_summary lookup must run for a bound trace_id")
|
||||
})
|
||||
|
||||
// An UNBOUND `$N` placeholder cannot be resolved to a concrete id. The fix skips
|
||||
// the optimization entirely (overlap=true → the fully-substituted main query
|
||||
// runs). Fail-before: the old code extracts the literal "$2", queries
|
||||
// trace_summary (count=0 here) and short-circuits to empty (overlap=false) — this
|
||||
// assertion fails. Pass-after: the lookup is skipped, so overlap=true and the mock
|
||||
// is never called.
|
||||
t.Run("unbound placeholder skips the optimization instead of short-circuiting", func(t *testing.T) {
|
||||
store := newTraceStore(t)
|
||||
// Only the pre-fix path reaches this; it simulates "$2" not existing in
|
||||
// trace_summary. We deliberately do NOT assert ExpectationsWereMet, since the
|
||||
// fixed path skips the query.
|
||||
store.Mock().ExpectQueryRow(`distributed_trace_summary`).
|
||||
WillReturnRow(dsmock.NewRow(summaryCols, []any{uint64(0), int64(0), int64(0)}))
|
||||
|
||||
q := &builderQuery[qbtypes.TraceAggregation]{
|
||||
logger: discardLogger(),
|
||||
telemetryStore: store,
|
||||
spec: qbtypes.QueryBuilderQuery[qbtypes.TraceAggregation]{
|
||||
Signal: telemetrytypes.SignalTraces,
|
||||
Filter: &qbtypes.Filter{Expression: llmobsDetailFilter},
|
||||
},
|
||||
variables: map[string]qbtypes.VariableItem{}, // trace_id $2 is NOT bound
|
||||
}
|
||||
|
||||
_, _, overlap, _ := q.narrowWindowByTraceID(context.Background(), fromMS, toMS)
|
||||
require.True(t, overlap, "an unresolved $N placeholder must skip the optimization, never short-circuit to empty")
|
||||
})
|
||||
}
|
||||
|
||||
// TestResolveTraceIDVars covers the placeholder-resolution helper directly: this is
|
||||
// the seam the whole bug turned on — the extractor hands back "$2", and this resolves
|
||||
// it against the bound variables into the real id that reaches trace_summary.
|
||||
func TestResolveTraceIDVars(t *testing.T) {
|
||||
vars := map[string]qbtypes.VariableItem{
|
||||
"2": {Type: qbtypes.DynamicVariableType, Value: realTraceID},
|
||||
"tid": {Type: qbtypes.DynamicVariableType, Value: "abc123"},
|
||||
"ids": {Type: qbtypes.DynamicVariableType, Value: []any{"a1", "b2"}},
|
||||
}
|
||||
q := &builderQuery[qbtypes.TraceAggregation]{variables: vars}
|
||||
|
||||
tests := []struct {
|
||||
name string
|
||||
in []string
|
||||
want []string
|
||||
resolved bool
|
||||
}{
|
||||
{name: "positional placeholder resolves to real id", in: []string{"$2"}, want: []string{realTraceID}, resolved: true},
|
||||
{name: "named placeholder resolves", in: []string{"$tid"}, want: []string{"abc123"}, resolved: true},
|
||||
{name: "list placeholder expands", in: []string{"$ids"}, want: []string{"a1", "b2"}, resolved: true},
|
||||
{name: "inline literal passes through", in: []string{"deadbeef"}, want: []string{"deadbeef"}, resolved: true},
|
||||
{name: "mixed literal and placeholder", in: []string{"lit", "$2"}, want: []string{"lit", realTraceID}, resolved: true},
|
||||
{name: "unbound placeholder skips optimization", in: []string{"$9"}, want: nil, resolved: false},
|
||||
}
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
got, ok := q.resolveTraceIDVars(tt.in)
|
||||
assert.Equal(t, tt.resolved, ok)
|
||||
if tt.resolved {
|
||||
assert.Equal(t, tt.want, got)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user