Jaeger OTEL Ingester/Collector seems not to save spans to elasticsearch (from kafka)

[ning2008wisc]

Problem - Jaeger OTEL Ingester/Collector seems not to save spans to elasticsearch (from kafka)

I set up an Jaeger OTEL Ingester/Collector to consumer spans from kafka, without special processors (e.g. simply use queued_retry), then want to save spans to elasticsearch. Here is the log of Jaeger OTEL Ingester/Collector, after I send some spans from upstream to the subscribed kafka topic (with 2 partitions):

2020-05-18T08:46:33.457Z	INFO	service/service.go:382	Starting Jaeger OpenTelemetry Ingester...	{"Version": "v1.18.0", "GitHash": "75a1d9357a8268ffb447a245388d906073ee7836", "NumCPU": 16}
2020-05-18T08:46:33.457Z	INFO	service/service.go:221	Setting up own telemetry...
2020-05-18T08:46:33.457Z	INFO	service/telemetry.go:94	Serving Prometheus metrics	{"address": "localhost:8888", "legacy_metrics": true, "new_metrics": false, "level": 3, "service.instance.id": ""}
2020-05-18T08:46:33.487Z	INFO	service/service.go:259	Loading configuration...
2020-05-18T08:46:33.500Z	INFO	service/service.go:270	Applying configuration...
2020-05-18T08:46:33.500Z	INFO	service/service.go:291	Starting extensions...
2020-05-18T08:46:33.500Z	INFO	builder/extensions_builder.go:53	Extension is starting...	{"component_kind": "extension", "component_type": "health_check", "component_name": "health_check"}
2020-05-18T08:46:33.500Z	INFO	healthcheckextension/healthcheckextension.go:40	Starting health_check extension	{"component_kind": "extension", "config": {"TypeVal":"health_check","NameVal":"health_check","Port":13133}}
2020-05-18T08:46:33.500Z	INFO	builder/extensions_builder.go:59	Extension started.	{"component_kind": "extension", "component_type": "health_check", "component_name": "health_check"}
2020-05-18T08:46:33.504Z	INFO	config/config.go:173	Elasticsearch detected	{"component_kind": "exporter", "component_type": "jaeger_elasticsearch", "component_name": "jaeger_elasticsearch", "version": 5}
2020-05-18T08:46:33.518Z	INFO	builder/exporters_builder.go:281	Exporter is enabled.	{"component_kind": "exporter", "exporter": "jaeger_elasticsearch"}
2020-05-18T08:46:33.518Z	INFO	service/service.go:306	Starting exporters...
2020-05-18T08:46:33.518Z	INFO	builder/exporters_builder.go:89	Exporter is starting...	{"component_kind": "exporter", "component_type": "jaeger_elasticsearch", "component_name": "jaeger_elasticsearch"}
2020-05-18T08:46:33.518Z	INFO	builder/exporters_builder.go:94	Exporter started.	{"component_kind": "exporter", "component_type": "jaeger_elasticsearch", "component_name": "jaeger_elasticsearch"}
2020-05-18T08:46:33.518Z	INFO	builder/pipelines_builder.go:188	Pipeline is enabled.	{"pipeline_name": "", "pipeline_datatype": "traces"}
2020-05-18T08:46:33.518Z	INFO	service/service.go:319	Starting processors...
2020-05-18T08:46:33.518Z	INFO	builder/pipelines_builder.go:51	Pipeline is starting...	{"pipeline_name": "", "pipeline_datatype": "traces"}
2020-05-18T08:46:33.518Z	INFO	builder/pipelines_builder.go:61	Pipeline is started.	{"pipeline_name": "", "pipeline_datatype": "traces"}
2020-05-18T08:46:33.708Z	INFO	builder/receivers_builder.go:223	Receiver is enabled.	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "datatype": "traces"}
2020-05-18T08:46:33.708Z	INFO	service/service.go:331	Starting receivers...
2020-05-18T08:46:33.708Z	INFO	builder/receivers_builder.go:74	Receiver is starting...	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka"}
2020-05-18T08:46:33.708Z	INFO	builder/receivers_builder.go:79	Receiver started.	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka"}
2020-05-18T08:46:33.708Z	INFO	healthcheck/handler.go:128	Health Check state change	{"component_kind": "extension", "status": "ready"}
2020-05-18T08:46:33.708Z	INFO	service/service.go:233	Everything is ready. Begin running and processing data.
2020-05-18T08:46:33.708Z	INFO	consumer/consumer.go:78	Starting main loop	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka"}
2020-05-18T08:46:36.989Z	INFO	consumer/consumer.go:169	Starting error handler	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 1}
2020-05-18T08:46:36.989Z	INFO	consumer/consumer.go:112	Starting message handler	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 1}
2020-05-18T08:46:36.992Z	INFO	consumer/consumer.go:169	Starting error handler	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 0}
2020-05-18T08:46:36.992Z	INFO	consumer/consumer.go:112	Starting message handler	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 0}
2020-05-18T08:46:54.430Z	INFO	consumer/processor_factory.go:65	Creating new processors	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 0}
2020-05-18T08:46:54.555Z	INFO	consumer/processor_factory.go:65	Creating new processors	{"component_kind": "receiver", "component_type": "jaeger_kafka", "component_name": "jaeger_kafka", "partition": 1}

Here is the partial k8s yaml file for deploy the above OTEL Ingestor/Collector:

      spec:
        containers:
        - image: jaegertracing/jaeger-opentelemetry-ingester
          name: jaeger-collector
          args:
          - --es.num-shards=1
          - --es.num-replicas=0
          - --es.server-urls=http://elasticsearch:9200
          - --collector.zipkin.host-port=9411
          - --config=/config/otel-collector-config.yml
.....
          env:
          - name: LOG_LEVEL
            value: debug
          - name: SPAN_STORAGE_TYPE
            value: elasticsearch
          - name: ES_USERNAME
            value: elastic
          - name: ES_PASSWORD
            value: changeme
......
apiVersion: v1
kind: ConfigMap
metadata:
  name: otel-collector-conf
  labels:
    app: opentelemetry-collector
    component: otel-collector-conf
data:
  otel-collector-config: |
    receivers:
      jaeger_kafka:
        brokers: "<broker_url>:9092"
        topic: jaeger-test
        encoding: protobuf
        client_id: jaeger-collector-client
        group_id: jaeger-collector-consumer

The proof that I reason elasticsearch does not receive the spans from OTEL Ingester/Collector is: I started with a brand new ES cluster (1-node) and if the spans are saved to ES, ES should create a new index, the ES logs should look like:

[2020-05-18T07:50:59,401][INFO ][o.e.c.m.MetaDataCreateIndexService] [761Dk77] [.jaeger-span-05-18] creating index, cause [auto(bulk api)], templates [jaeger], shards [1]/[1], mappings [watch]

However I did not see the above log when (1) using above OTEL Ingestor/Collector, (2) starts a new ES cluster, (3) ingest spans from upstream to Kafka topic

[ning2008wisc]

Also, it seems the flags kafka.consumer.* (e.g. kafka.consumer.topic, kafka.consumer.brokers ) are not recognized by OTEL Ingester/Collector.

However, the flags kafka.producer.* (e.g. kafka.producer.topic, kafka.producer.brokers) are fully recognized.

[pavolloffay]

hi @ning2008wisc thanks for reporting this. About the flags you are right the consumer flags are not being exposed. I will fix that today. However you should be able to configure the component directly in the OTEL config.

Though, I am not sure why the ingester is not writing any data to ES. Rather than relying on the ES logs it's better to have a look at http://elasticsearch:9200 that shows existing indices in the cluster.
You can also try to run the collector with --metrics-new=true and observe metrics if the receivers (Kafka) are getting any spans.

[ning2008wisc]

Thanks @pavolloffay for your inputs.

After using your latest #2251, ES is able to receive/store the spans from OTEL Ingester, and the spans are query-able from Jaeger UI. This is the index created for span:

[2020-05-18T15:09:20,102][INFO ][o.e.c.m.MetaDataCreateIndexService] [761Dk77] [jaeger-span-2020-05-18] creating index, cause [auto(bulk api)], templates [jaeger-span], shards [1]/[0], mappings [_default_, span]

BTW, --metrics-new=true seems not recognized, this is how I use it:

     spec:
        containers:
        - image: jaegertracing/jaeger-opentelemetry-ingester
          name: jaeger-collector
          args:
          - --es.num-shards=1
          - --es.num-replicas=0
          - --es.server-urls=http://elasticsearch:9200
          - --collector.zipkin.host-port=9411
          - --config=/config/otel-collector-config.yml
          - --kafka.consumer.topic=jaeger-test
          - --kafka.consumer.brokers=<some_broker_URL>:9092
         - --metrics-new=true

Here is the log output:

Error: unknown flag: --metrics-new
2020/05/18 15:14:25 Failed to run the service: unknown flag: --metrics-new

Also, if enabling --metrics-new will have the similar effect as verbose logging, that will be also helpful to me to debug more complex cases. Or I will be happy to learn how to turn on verbose logging, e.g. log_level = DEBUG

[pavolloffay]

My bad it is --new-metrics=true -h should print all flags.

Can be this issue closed now?

[ning2008wisc]

@pavolloffay yes, please close it. Thanks a lot for your inputs