[Bug]: Jaeger Query Tags Search Causes Nested Search Error

[stephaje]

What happened?

When searching for tags in the UI, a "failed to create query: [nested] failed to find nested object under path [tags]" error is thrown by jaeger's query. I would think ignore_unmapped would be used here to prevent this error, but it isn't in the query.

Steps to reproduce

1. Use collector with the following configuration:

es.use-ilm: False
es.index-date-separator: .
es.server-urls: <intake nodes>
es.tags-as-fields.all: True
collector.zipkin.host-port: 9411
es.max-span-age: 744h0m0s
es.use-aliases: True
es.create-index-templates: False
es.username: "jaeger"
es.password: <pw>

2. Use query with the following configuration:

query.max-clock-skew-adjustment: 300s
es.index-date-separator: .
es.server-urls: https://<cluster LB>:9200
es.tags-as-fields.all: True
es.use-ilm: False
es.max-span-age: 744h0m0s //tried with smaller values as well
es.use-aliases: True
es.tls.skip-host-verify: True
es.create-index-templates: False
es.username: "jaeger"
es.password: <pw>

3. Ingest spans
4. Attempt to search for any tags
5. See error

Expected behavior

I expect the nested error to be ignored and the search to work.

Relevant log output

{"level":"debug","ts":1662507212.5653389,"caller":"zapgrpc/zapgrpc.go:129","msg":"POST /jaeger-span-read/_search?ignore_unavailable=true&rest_total_hits_as_int=true HTTP/1.1\r\nHost: <host>:9200\r\nUser-Agent: elastic/6.2.37 (linux-amd64)\r\nTransfer-Encoding: chunked\r\nAccept: application/json\r\nAuthorization: Basic <>\r\nContent-Type: application/json\r\nAccept-Encoding: gzip\r\n\r\n400\r\n{\"aggregations\":{\"traceIDs\":{\"aggregations\":{\"startTime\":{\"max\":{\"field\":\"startTime\"}}},\"terms\":{\"field\":\"traceID\",\"order\":[{\"startTime\":\"desc\"}],\"size\":20}}},\"query\":{\"bool\":{\"must\":[{\"range\":{\"startTimeMillis\":{\"from\":1662503612261,\"include_lower\":true,\"include_upper\":true,\"to\":1662507212261}}},{\"match\":{\"process.serviceName\":{\"query\":\"<Service> Client\"}}},{\"bool\":{\"should\":[{\"bool\":{\"must\":{\"regexp\":{\"tag.screen_height\":{\"value\":\"1080\"}}}}},{\"bool\":{\"must\":{\"regexp\":{\"process.tag.screen_height\":{\"value\":\"1080\"}}}}},{\"nested\":{\"path\":\"tags\",\"query\":{\"bool\":{\"must\":[{\"match\":{\"tags.key\":{\"query\":\"screen_height\"}}},{\"regexp\":{\"tags.value\":{\"value\":\"1080\"}}}]}}}},{\"nested\":{\"path\":\"process.tags\",\"query\":{\"bool\":{\"must\":[{\"match\":{\"process.tags.key\":{\"query\":\"screen_height\"}}},{\"regexp\":{\"process.tags.value\":{\"value\":\"1080\"}}}]}}}},{\"nested\":{\"path\":\"logs.fields\",\"query\":{\"bool\":{\"must\":[{\"match\":{\"logs.fields.key\":{\"query\":\"screen_height\"}}},{\"regexp\":{\"logs.fields.value\":{\"value\":\"1080\"}}}]}}}}]}}]}},\"size\":0}\r\n0\r\n\r\n\n"}
{"level":"debug","ts":1662507212.573889,"caller":"zapgrpc/zapgrpc.go:129","msg":"HTTP/1.1 400 Bad Request\r\nContent-Length: 905\r\nConnection: keep-alive\r\nContent-Type: application/json; charset=UTF-8\r\nDate: Tue, 06 Sep 2022 23:33:32 GMT\r\nX-Elastic-Product: Elasticsearch\r\n\r\n{\"error\":{\"root_cause\":[{\"type\":\"query_shard_exception\",\"reason\":\"failed to create query: [nested] failed to find nested object under path [tags]\",\"index_uuid\":\"3_fWA2cPSgiezCxBAi55fw\",\"index\":\"jaeger-span-write-<metadata>\"}],\"type\":\"search_phase_execution_exception\",\"reason\":\"all shards failed\",\"phase\":\"query\",\"grouped\":true,\"failed_shards\":[{\"shard\":0,\"index\":\"jaeger-span-write-<metadata>\",\"node\":\"D2OukQsjT_yWLVGhSZMUwg\",\"reason\":{\"type\":\"query_shard_exception\",\"reason\":\"failed to create query: [nested] failed to find nested object under path [tags]\",\"index_uuid\":\"3_fWA2cPSgiezCxBAi55fw\",\"index\":\"jaeger-span-write-<metadata>\",\"caused_by\":{\"type\":\"illegal_state_exception\",\"reason\":\"[nested] failed to find nested object under path [tags]\"}}}]},\"status\":400}\n"}
{"level":"error","ts":1662507212.5740166,"caller":"app/http_handler.go:487","msg":"HTTP handler, Internal Server Error","error":"search services failed: elastic: Error 400 (Bad Request): all shards failed [type=search_phase_execution_exception]","stacktrace":"github.com/jaegertracing/jaeger/cmd/query/app.(*APIHandler).handleError\n\tgithub.com/jaegertracing/jaeger/cmd/query/app/http_handler.go:487\ngithub.com/jaegertracing/jaeger/cmd/query/app.(*APIHandler).search\n\tgithub.com/jaegertracing/jaeger/cmd/query/app/http_handler.go:236\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2046\ngithub.com/opentracing-contrib/go-stdlib/nethttp.MiddlewareFunc.func5\n\tgithub.com/opentracing-contrib/go-stdlib@v1.0.0/nethttp/server.go:154\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2046\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2046\ngithub.com/gorilla/mux.(*Router).ServeHTTP\n\tgithub.com/gorilla/mux@v1.8.0/mux.go:210\ngithub.com/jaegertracing/jaeger/cmd/query/app.additionalHeadersHandler.func1\n\tgithub.com/jaegertracing/jaeger/cmd/query/app/additional_headers_handler.go:28\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2046\ngithub.com/gorilla/handlers.CompressHandlerLevel.func1\n\tgithub.com/gorilla/handlers@v1.5.1/compress.go:141\nnet/http.HandlerFunc.ServeHTTP\n\tnet/http/server.go:2046\ngithub.com/gorilla/handlers.recoveryHandler.ServeHTTP\n\tgithub.com/gorilla/handlers@v1.5.1/recovery.go:78\nnet/http.serverHandler.ServeHTTP\n\tnet/http/server.go:2878\nnet/http.(*conn).serve\n\tnet/http/server.go:1929"}

Screenshot

No response

Additional context

{
  "_index": "jaeger-span-write-<metadata>",
  "_type": "_doc",
  "_id": "P3AGFYMBB_hNjC7OD2UC",
  "_version": 1,
  "_score": 1,
  "_source": {
    "traceID": "4563888ef57951d46bbf8c77c41d2cf7",
    "spanID": "0000017af27bfe5b",
    "flags": 2,
    "operationName": "ojButton Click",
    "references": [],
    "startTime": 1662504984000000,
    "startTimeMillis": 1662504984000,
    "duration": 1185000,
    "tags": [],
    "tag": {
      ...
      "screen_height": "1080",
      "screen_orientationType": "landscape-primary",
      "screen_width": "1920" ...
    },
    "logs": [],
    "process": {
      "serviceName": "<Service> Client",
      "tags": []
    }
  }
}

Jaeger backend version

v1.26

SDK

No response

Pipeline

Java -> Jaeger Collector (zipkin format via :9411) -> Intake ELK cluster -> CCR -> Query ELK Cluster -> Jaeger Query/UI

Stogage backend

Elasticsearch 7.16.3

Operating system

Oracle Linux Server 7.9

Deployment model

No response

Deployment configs

No response

[stephaje]

I've tried upgrading to v1.36 and this issue still exists. Adding a nested mapping for tags fixes the issue, but since we don't use this part of the document, it should be optional.

[pmuls99]

Hi @yurishkuro , I am interested in resolving this issue. I have some doubts regarding the issue.

1. I tried to replicate the issue with jaeger-all-in-one image running with ES as backend and HOTROD as the instrumented application. I set ES_TAGS_AS_FIELDS=True, which sent all the tags to the tag object and the nested object tags was empty. I tried querying the tags from the UI and didnt face any such issue.
2. Correct me if I am wrong,the part of the code where the query is being built for tags is

   jaeger/plugin/storage/es/spanstore/reader.go

   Line 669 in ab6732b

   func (s *SpanReader) buildTagQuery(k string, v string) elastic.Query {

   . This part can be changed to check if tags is empty and not build the query for nested tags. But I am not able to figure out what might be causing the error. Because as far as I understand the other settings should not alter the functioning of the tag query. Could you please give me advice for moving forward in resolving this issue.

[yurishkuro]

I am not sure of the validity of this ticket. The JSON example clearly shows "tags": [], so why would ES say the field is not found?

[pmuls99]

So from what I understand from our code and issues of similar kind, we are sending an empty object(

jaeger/plugin/storage/es/spanstore/dbmodel/from_domain.go

Line 88 in 369219c

func (fd FromDomain) convertKeyValuesString(keyValues model.KeyValues) ([]KeyValue, map[string]interface{}) {

) to the tags field if ES_TAGS_AS_FIELDS_ALL=True. And elastic search creates a new document for nested objects and if the object is empty , there is an issue with mapping, Not sure if this is the right explanation for the issue. Although the solution for such issue is including ignore_unmapped = True in our nested query(

jaeger/plugin/storage/es/spanstore/reader.go

Line 690 in 369219c

return elastic.NewNestedQuery(field, tagBoolQuery)

), this is supported by our current ES driver olivere/elastic(olivere/elastic@cec324c). If you are ok with this , I could raise a PR.

[pmuls99]

I am not sure of the validity of this ticket. The JSON example clearly shows "tags": [], so why would ES say the field is not found?

The issue is not finding the nested object under the field right ?

[pmuls99]

So from what I understand from our code and issues of similar kind, we are sending an empty object(

jaeger/plugin/storage/es/spanstore/dbmodel/from_domain.go

Line 88 in 369219c

func (fd FromDomain) convertKeyValuesString(keyValues model.KeyValues) ([]KeyValue, map[string]interface{}) {

) to the tags field if ES_TAGS_AS_FIELDS_ALL=True. And elastic search creates a new document for nested objects and if the object is empty , there is an issue with mapping, Not sure if this is the right explanation for the issue. Although the solution for such issue is including ignore_unmapped = True in our nested query(

jaeger/plugin/storage/es/spanstore/reader.go

Line 690 in 369219c

return elastic.NewNestedQuery(field, tagBoolQuery)

), this is supported by our current ES driver olivere/elastic(olivere/elastic@cec324c). If you are ok with this , I could raise a PR.

Whats your take on this @yurishkuro ?

[yurishkuro]

I don't have a take. The issue needs to be reproduced, but the error does not match the JSON snippet which does have tags: [], so how can it cause an error failed to find nested object under path: tags?

[stephaje]

I am not sure of the validity of this ticket. The JSON example clearly shows "tags": [], so why would ES say the field is not found?

The document having tags and the tags field being mapped to a nested object are completely separate from one another. Because I was leveraging es.tags-as-fields.all, the tags field is never populated with values other than the empty object. Additionally because of es.create-index-templates: False, the field was unmapped by our mapping configuration. I believe mapping the tags field should be optional given that it can be completely unused.

The error is because the query from the UI requires the tags field to be mapped. It would not be required if the query is constructed with the ignore_unmapped flag.

[yurishkuro]

I agree that the query logic right now always tries to look into both formats. It could account for es.tags-as-fields.all flag and not query tags: [] at all.

[pmuls99]

So @yurishkuro , we can either have the ignore_unmapped flag or just stop sending the nested query request if Tags field is empty. Which one do you prefer? Why(just for understanding)

[yurishkuro]

if we know from config settings that this field is never going to be populated, there is no reason to include it in the query. I don't know what ignore_unmapped flag does exactly, using it could have some unintended consequences.

[pmuls99]

@yurishkuro , Raised a PR #4651 addressing this issue, Can you please take a look!