Tempo Traces - Search showing inconsistent results

gw2auth · June 16, 2023, 12:54am

I have successfully sent some traces to tempo using oltp.
When using the Explore page with tempo as a datasource, my traces only show up under specific conditions.

I’m using these TraceQL queries:

{} // all
{span.http.route = "/api/v2/ping"} // specific

When using relative ranges, for example now-3h to now, only the most recent traces (past ~30min) show up as a result (the configured limit is NOT exhausted).

However, I know there are more traces to be found in this timerange.

When searching with an absolute range of the past 3h (i.e. 2023-06-16 00:00:00 to 2023-06-16 03:00:00), I get the same traces as with the relative range (only the recent ones).

When searching with an absolute range more specific to the traces I’m looking for (but still within the past 3h, i.e. 2023-06-16 01:00:00 to 2023-06-16 01:59:59), I can find the traces I’m looking for.

I’m using Grafana Cloud.

Edit (next day)

I’m coming back today, when looking for traces in the past 24h I see no results:

But when I specify I smaller absolute timerange I see results:

Edit 2

With some more exploration, it seems to be related to “finished” days. For example, when using an absolute range from 2023-06-14 00:00:00 to 2023-06-15 23:59:59, I can find all traces (up to the configured search limit) within those days, but when including the current (not-finished) day in the timerange, I end up with only the recent results (currently, none, since I didn’t send any traces today)

Edit 3

It very much looks like this is related to “hot” data.´

Whenever the timerange includes the most recent 30min (i.e. with any relative range), I only find data that was produced in the past 30min.

When manually excluding the most recent 30min (by using an absolute range), I can find all traces for the configured timerange.

For example:

it is 2023-06-17 00:17:00 in my timezone right now
I didn’t send any traces in the past 30min
searching for now-7d to now yields no results (assumption: it seems to search only in the “hot” data, because the timerange includes the “hot” data)
searching for 2023-06-10 00:17:00 to 2023-06-17 00:17:00 yields no results (assumption: it seems to search only in the “hot” data, because the timerange includes the “hot” data)
searching for 2023-06-10 00:17:00 to 2023-06-16 23:46:00 yields matching traces for the configured timerange (assumption: it seems to search only in the “cold” data, because the timerange doesn’t include the “hot” data)

Edit 4

I’m not sure if I found the correct place, but according to this:

github.com

grafana/tempo/blob/main/modules/querier/http.go#L114


      
          	ctx, cancel := context.WithDeadline(r.Context(), time.Now().Add(q.cfg.Search.QueryTimeout))
          	defer cancel()
          
          	span, ctx := opentracing.StartSpanFromContext(ctx, "Querier.SearchHandler")
          	defer span.Finish()
          
          	span.SetTag("requestURI", r.RequestURI)
          	span.SetTag("isSearchBlock", isSearchBlock)
          
          	var resp *tempopb.SearchResponse
          	if !isSearchBlock {
          		req, err := api.ParseSearchRequest(r)
          		if err != nil {
          			http.Error(w, err.Error(), http.StatusBadRequest)
          			return
          		}
          
          		span.SetTag("SearchRequest", req.String())
          
          		resp, err = q.SearchRecent(ctx, req)
          		if err != nil {

It seems like the search goes always either to SearchRecent (which searches at the ingester directly) or to SearchBlock, but never to both.

This would explain the behavior I see.

Is this a known bug or limitation?

gw2auth · June 24, 2023, 10:25pm

I have reported the issue here Search looks only into recent data if the configured timerange includes recent data, but does not search beyond · Issue #2565 · grafana/tempo · GitHub and a fix has been merged. Waiting for the fix to be available in Grafana Cloud.