Tanzu Application PlatformのContourをOpenTelemetryでTracingするメモ

️⚠️ 本記事の内容はVMwareによってサポートされていません。記事の内容で生じた問題については自己責任で対応し、 VMwareサポート窓口には問い合わせないでください。

Tanzu Application PlatformのIngress Controllerとして使われているContourは1.25からTracingがサポートされています。 TAP 1.7はContour 1.25を使用しているので、この機能を利用できます。

ContourではOpenTelemetry (OTLP)によるTracingのみがサポートされています。今回はOTLPプロトコルをサポートしているTracingバックエンドとしてTempoを使用します。また、TempoのUIとしてGrafanaを使用します。

まずは次の構成を作ります。

Tempoのインストール
Grafanaのインストール
ContourのTracing
アプリからTraceを送信
Open Telemetry Collectorの導入
Open Telemetry Agentによる自動計測
Span Attributeの追加

Tempoのインストール

Tempoはhelmでインストールします。

helm repo add grafana https://grafana.github.io/helm-charts

helm upgrade tempo \
  -n tempo \
  grafana/tempo \
  --set tempo.receivers.zipkin=null \
  --create-namespace \
  --install \
  --wait

Podを確認します。

$ kubectl get pod -n tempo
NAME      READY   STATUS    RESTARTS   AGE
tempo-0   1/1     Running   0          9s

Grafanaのインストール

TempoはUIを持たないので、UIとしてGrafanaをインストールします。Grafanaもhelmでインストールします。

ドメイン名とCluster Issuer名は環境に合わせて変えてください。

cat <<EOF > helm-values.yaml
---
adminUser: grafana
adminPassword: grafana
testFramework:
  enabled: false
ingress:
  enabled: true
  hosts:
  - grafana.tapv-huge-hornet.tapsandbox.com
  tls:
  - hosts:
    - grafana.tapv-huge-hornet.tapsandbox.com
    secretName: grafana-tls
  annotations:
    cert-manager.io/cluster-issuer: tap-ingress-selfsigned
datasources:
  datasources.yaml:
    apiVersion: 1
    datasources:
    - name: Tempo
      uid: grafana-traces
      type: tempo
      access: proxy
      orgId: 1
      url: http://tempo.tempo.svc.cluster.local:3100
      editable: true
---
EOF

helm upgrade grafana \
  -n grafana \
  grafana/grafana \
  -f helm-values.yaml \
  --create-namespace \
  --install \
  --wait

podとingressを確認します。

$ kubectl get pod,ing -n grafana
NAME                           READY   STATUS    RESTARTS   AGE
pod/grafana-7cb85d6cfc-qp2j8   1/1     Running   0          2m36s

NAME                                CLASS    HOSTS                                     ADDRESS         PORTS     AGE
ingress.networking.k8s.io/grafana   <none>   grafana.tapv-huge-hornet.tapsandbox.com   35.238.162.93   80, 443   2m36s

GrafanaのURLにアクセスします。ユーザー名とパスワードともにgrafanaです。

ExploreでTempoのデータソースを選択します。まだデータはありません。

ContourのTracing

Contourのドキュメントにしたがって、次のExtensionServiceリソースを作成します。

cat <<EOF > tempo-extension.yaml
---
apiVersion: projectcontour.io/v1alpha1
kind: ExtensionService
metadata:
  name: tempo
  namespace: tempo
spec:
  protocol: h2c
  services:
  - name: tempo
    port: 4317
---
EOF

kubectl apply -f tempo-extension.yaml

Contourのconfigファイルにtracingの設定が含まれるようにtap-values.yamlに以下の設定を追加します。ここではEnvoyのアクセスログをJSONフォーマットに変え、かつtraceparentフィールドが含まれるように設定します。

# ...
contour:
  contour:
    configFileContents:
      tracing:
        includePodDetail: true
        extensionService: tempo/tempo
        serviceName: contour
      accesslog-format: json
      json-fields:
      - "@timestamp"
      - "authority"
      - "bytes_received"
      - "bytes_sent"
      - "traceparent=%REQ(TRACEPARENT)%" # <--
      - "duration"
      - "method"
      - "path"
      - "protocol"
      - "referer=%REQ(REFERER)%"
      - "request_id"
      - "requested_server_name"
      - "response_code"
      - "upstream_cluster"
      - "user_agent"
      - "x_forwarded_for"
# ...

TAPを更新します。

tanzu package installed update tap -n tap-install --values-file tap-values.yaml

Contourの再起動を明示的にしないとこの設定が反映されないみたいです。

kubectl delete pod -n tanzu-system-ingress -l app=contour --force

次のコマンドでEnvoyのアクセスログを確認します。

kubectl logs -n tanzu-system-ingress -l app=envoy -c envoy -f

TAP上のアプリにアクセスすると、次のようなJSONログを確認できます。

{"referer":null,"duration":38,"upstream_cluster":"apps_rest-service-00004_80","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36","bytes_sent":60,"protocol":"HTTP/2","x_forwarded_for":"192.168.3.1","requested_server_name":"rest-service-apps.tapv-huge-hornet.tapsandbox.com","path":"/greeting","traceparent":"00-7a352f8ac8b545bce79e439cbe595687-dbd8a641798bfa4d-01","@timestamp":"2024-01-25T09:34:43.018Z","method":"GET","request_id":"aeff3400-fed7-9e1f-bf39-de29ee7b7078","authority":"rest-service-apps.tapv-huge-hornet.tapsandbox.com","bytes_received":0,"response_code":200}

traceparentフィールドに00-7a352f8ac8b545bce79e439cbe595687-dbd8a641798bfa4d-01が設定されていることがわかります。これはW3C Tracing Contextのフォーマットです。 7a352f8ac8b545bce79e439cbe595687がTrace IDです。

GrafanaのExploreからTrace IDでTraceを検索します。Contourレベルで計測されたアクセスログ相当のTraceが確認できます。

Trace一覧も取得できます。

アプリからTraceを送信

今度はTrace Contextをアプリに伝播し、アプリ側でもTracingを行い、TraceをTempoに送ります。

アプリには https://github.com/categolj/blog-api を使用します。このアプリはMicrometer TracingでTracingを行っています。本稿執筆時点では、このアプリはTracingのプロトコルにZipkinを使用しているので、Tempoの9411ポートにTraceを送るように環境変数MANAGEMENT_ZIPKIN_TRACING_ENDPOINTを設定します。

次のコマンドでアプリをデプロイします。PostgreSQLが必要なため、Bitnami ServiceでPostgreSQLインスタンスを作成します。

tanzu service class-claim create blog-db --class postgresql-unmanaged --parameter storageGB=1 -n demo

tanzu apps workload apply blog-api \
  --app blog-api \
  --git-repo https://github.com/categolj/blog-api \
  --git-branch main \
  --type web \
  --annotation autoscaling.knative.dev/minScale=1 \
  --label apps.tanzu.vmware.com/has-tests=true \
  --service-ref blog-db=services.apps.tanzu.vmware.com/v1alpha1:ClassClaim:blog-db \
  --build-env BP_JVM_VERSION=17 \
  --env MANAGEMENT_ZIPKIN_TRACING_ENDPOINT=http://tempo.tempo.svc.cluster.local:9411 \
  -n apps

アプリにリクエストを送ります。

curl -s https://blog-api-apps.tapv-huge-hornet.tapsandbox.com/entries/template.md > template.md
curl -s -u admin:changeme -XPUT https://blog-api-apps.tapv-huge-hornet.tapsandbox.com/entries/2 -H "Content-Type: text/markdown" -d "$(cat template.md)"
curl -s https://blog-api-apps.tapv-huge-hornet.tapsandbox.com/entries/2 | jq .

Envoyのアクセスログには次のようなログが出力されます。

{"@timestamp":"2024-01-25T10:06:37.820Z","authority":"blog-api-apps.tapv-huge-hornet.tapsandbox.com","bytes_received":197,"requested_server_name":"blog-api-apps.tapv-huge-hornet.tapsandbox.com","path":"/entries/2","user_agent":"curl/8.1.2","upstream_cluster":"apps_blog-api-00002_80","response_code":200,"traceparent":"00-98a0891be5a08d923da6feebb2aab04f-8ef8b9f68a8ee1b2-01","bytes_sent":412,"x_forwarded_for":"10.0.1.8","method":"PUT","referer":null,"duration":967,"request_id":"2c9cc4c5-e2c7-90f6-8680-8eeab7fbdaf2","protocol":"HTTP/2"}

このリクエストのTrace IDは98a0891be5a08d923da6feebb2aab04fであることがわかります。

GrafanaでこのTraceの情報を見ます。今度はContourだけでなく、アプリ側のSpanも含まれていることがわかります。

Spanの詳細を見ると、実行されているSQLも確認できます。

ContourのTracingを有効にしたことで、Envoyのアクセスログを起点とし、簡単にアプリのTraceデータを見ることができるようになりました。

ところで、GrafanaでTempoのTraceデータ一覧を見ていると、次のようなTrace (Grafana自体へのアクセスに対するTrace) がたくさん出てきます。 ContourレベルでTracingを行っているので、Envoyを経由した全てのリクエストが対象になります。場合によってはNoisyなデータになるので、これをFilterしたいです。

SpanのFilteringはTempoではおそらくできない、あるいはできたとしてもTempo独自のノウハウになってしまいます。ここではTraceバックエンドを差し替えることを念頭に、ベンダーニュートラルなOpen Telemetry Collectorを間に挟み、CollectorレベルでSpanをFilterします。

Open Telemetry Collectorの導入

Open Telemetry Collectorを導入して、EnvoyからのTrace送信先をOpen Telemetry Collectorに変えます。Open Telemetry CollectorがSpanをFilteringした後にTempoへデータを送信します。アプリのTrace送信先もOpen Telemetry Collectorに変更できますが、ここではContourの設定のみ変更します。

Open Telemetry CollectorをKubernetes上にインストールするのにOpen Telemetry Operatorを使用します。

Open Telemetry Operatorは次のコマンドでインストールできます。

kubectl apply -f https://github.com/open-telemetry/opentelemetry-operator/releases/latest/download/opentelemetry-operator.yaml

ここではOpen Telemetry Operator 0.92.1を使用しました。特定のバージョンを指定してインストールする場合は、次のコマンドを使用してください。

kubectl apply -f https://github.com/open-telemetry/opentelemetry-operator/releases/download/v0.92.1/opentelemetry-operator.yaml

Podを確認します。

$ kubectl get pod -n opentelemetry-operator-system
NAME                                                         READY   STATUS    RESTARTS   AGE
opentelemetry-operator-controller-manager-5fb8cbf79b-8xlkl   2/2     Running   0          104m

Open Telemetry Operatorを使うとOpenTelemetryCollectorリソースを使ってOpen Telemetry Collectorをインストールできます。

次のようにOpenTelemetryCollectorリソースを作成します。OTLPで受け付けて、SpanのFilterを行ったあと、OTLPでTempoにデータを送信するTraceパイプラインを定義しました。

cat <<'EOF' > otelcol.yaml
---
apiVersion: opentelemetry.io/v1alpha1
kind: OpenTelemetryCollector
metadata:
  name: otel
  namespace: opentelemetry
spec:
  config: |
    receivers:
      otlp:
        protocols:
          grpc: {}
          http: {}
    processors:
      filter:
        # https://github.com/open-telemetry/opentelemetry-collector-contrib/tree/main/processor/filterprocessor
        error_mode: ignore
        traces:
          span:
          - IsMatch(attributes["upstream_cluster"], "grafana/.*")
          - IsMatch(attributes["upstream_cluster"], "tap-gui/.*")
          - IsMatch(attributes["upstream_cluster"], "appsso/.*")
          - IsMatch(attributes["http.url"], "https://grafana.*")
      batch:
        send_batch_size: 10000
        timeout: 10s
    exporters: 
      otlp/tempo:
        endpoint: http://tempo.tempo.svc.cluster.local:4317
        tls:
          insecure: true
    service:
      pipelines:
        traces:
          receivers:
          - otlp
          processors:
          - filter
          - batch
          exporters:
          - otlp/tempo
---
EOF

kubectl create namespace opentelemetry
kubectl apply -f otelcol.yaml

OpenTelemetryCollector, Pod, Serviceリソースを確認します。

$ kubectl get otelcol,pod,svc -n opentelemetry
NAME                                           MODE         VERSION   READY   AGE   IMAGE                                                                                    MANAGEMENT
opentelemetrycollector.opentelemetry.io/otel   deployment   0.92.0    1/1     6s    ghcr.io/open-telemetry/opentelemetry-collector-releases/opentelemetry-collector:0.92.0   managed

NAME                                  READY   STATUS    RESTARTS   AGE
pod/otel-collector-75fb5c8dc5-kssmp   1/1     Running   0          5s

NAME                                TYPE        CLUSTER-IP       EXTERNAL-IP   PORT(S)             AGE
service/otel-collector              ClusterIP   192.168.73.127   <none>        4317/TCP,4318/TCP   7s
service/otel-collector-headless     ClusterIP   None             <none>        4317/TCP,4318/TCP   7s
service/otel-collector-monitoring   ClusterIP   192.168.68.138   <none>        8888/TCP            7s

ContourのTrace設定をTempoからOpen Telemetry Collectorに変更します。

cat <<EOF > otelcol-extension.yaml
---
apiVersion: projectcontour.io/v1alpha1
kind: ExtensionService
metadata:
  name: otel-collector
  namespace: opentelemetry
spec:
  protocol: h2c
  services:
  - name: otel-collector
    port: 4317
---
EOF

kubectl apply -f otelcol-extension.yaml

tap-values.yamlも合わせて変更します。

contour:
  contour:
    configFileContents:
      tracing:
        includePodDetail: true
        extensionService: opentelemetry/otel-collector #! <---
        serviceName: contour

TAPを更新します。

tanzu package installed update tap -n tap-install --values-file tap-values.yaml

Contourの再起動します。

kubectl delete pod -n tanzu-system-ingress -l app=contour --force

これでSpanのFilteringにより、NoisyなTraceをTempoに送らないようにできます。

Open Telemetry Agentによる自動計測

先ほどデプロイしたアプリはMicrometer Tracingによるライブラリレベルでの計測が行われていました。場合によっては、アプリに手を入れずにTraceを計測したいこともあるでしょう。その場合にはソースコードを変えることなく、Open Telemetry Agentを使った計測を行うことができます。

次の図のようにアプリにAgentを組み込み、AgentがTracingを行い、CollectorにTraceを送信するようにします。

Open Telemetry Operatorを使用するとOpen Telemetry Agentの自動計測を行うことができます。コンテナにagentを自動で追加してくれます。

次のInstrumentationリソースを作成します。

cat <<EOF > instrumentation.yaml
---
apiVersion: opentelemetry.io/v1alpha1
kind: Instrumentation
metadata:
  name: default
  namespace: opentelemetry
spec:
  exporter:
    endpoint: http://otel-collector.opentelemetry.svc.cluster.local:4317
  propagators:
  - tracecontext
  - baggage
  sampler:
   type: parentbased_traceidratio
   argument: "1.0"
---
EOF

kubectl apply -f instrumentation.yaml

Instrumentationリソースを確認します。

$ kubectl get instrumentation -n opentelemetry
NAME      AGE   ENDPOINT                                                     SAMPLER                    SAMPLER ARG
default   8s    http://otel-collector.opentelemetry.svc.cluster.local:4317   parentbased_traceidratio   1.0

ここではMicrometerを使用していないJavaアプリとして https://github.com/making/rest-service を使用します。

次のコマンドでこのアプリをデプロイします。instrumentation.opentelemetry.io/inject-javaアノテーションにopentelemetry/default (Instrumentationのnamespac/Instrumentationの名前)を設定することで自動でagentを追加できます。

tanzu apps workload apply rest-service \
  --app rest-service \
  --git-repo https://github.com/making/rest-service \
  --git-branch main \
  --type web \
  --label apps.tanzu.vmware.com/has-tests=true \
  --annotation autoscaling.knative.dev/minScale=1 \
  --annotation instrumentation.opentelemetry.io/inject-java=opentelemetry/default \
  --build-env BP_JVM_VERSION=17 \
  -n apps

アプリのログを追跡します。

tanzu apps workload tail rest-service --namespace apps --timestamp --since 10m --component run

起動時に次のようなログが出力されれば、agentが追加され、起動したことがわかります。

rest-service-00005-deployment-757f998ddc-gvp64[workload] 2024-01-26T16:36:38.131807287+09:00 Picked up JAVA_TOOL_OPTIONS: -Dmanagement.endpoint.health.probes.add-additional-paths="true" -Dmanagement.health.probes.enabled="true" -Dserver.port="8080" -Dserver.shutdown.grace-period="24s" -javaagent:/otel-auto-instrumentation-java/javaagent.jar -Djava.security.properties=/layers/tanzu-buildpacks_bellsoft-liberica/java-security-properties/java-security.properties -XX:+ExitOnOutOfMemoryError -XX:ActiveProcessorCount=2 -XX:MaxDirectMemorySize=10M -Xmx6414426K -XX:MaxMetaspaceSize=103345K -XX:ReservedCodeCacheSize=240M -Xss1M -XX:+UnlockDiagnosticVMOptions -XX:NativeMemoryTracking=summary -XX:+PrintNMTStatistics -Dorg.springframework.cloud.bindings.boot.enable=true
rest-service-00005-deployment-757f998ddc-gvp64[workload] 2024-01-26T16:36:38.329771913+09:00 OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
rest-service-00005-deployment-757f998ddc-gvp64[workload] 2024-01-26T16:36:38.588003672+09:00 [otel.javaagent 2024-01-26 07:36:38:586 +0000] [main] INFO io.opentelemetry.javaagent.tooling.VersionLogger - opentelemetry-javaagent - version: 1.32.0

アプリにいくつかリクエストを送るとGrafanaで次のようなTraceを確認できます。

ServiceがcontourなTraceの詳細を一つ確認すると、アプリのSpanが含まれていることがわかります。

ℹ️ 同様にNode.jsアプリのTracingも行えます。この場合、アノテーション名はinstrumentation.opentelemetry.io/inject-nodejsです。
tanzu apps workload apply hello-nodejs \
  --app hello-nodejs \
  --git-repo https://github.com/making/hello-nodejs \
  --git-branch master \
  --type web \
  --label apps.tanzu.vmware.com/has-tests=true \
  --annotation autoscaling.knative.dev/minScale=1 \
  --annotation instrumentation.opentelemetry.io/inject-nodejs=opentelemetry/default \
  -n apps
次のようなTraceを見ることができます。なぜか送信されるまで時間がかかりました。

さて、KubernetesによるProbeのTraceがNoisyなので、filterの条件に次を追加します。

        traces:
          span:
          # ...
          - attributes["http.route"] == "/livez"
          - attributes["http.route"] == "/readyz"
          - attributes["user_agent.original"] == "kube-probe//"
          - attributes["user_agent"] == "Knative-Ingress-Probe"
          - name == "OperationHandler.handle"

Collectorを更新します。

kubectl apply -f otelcol.yaml

他にもNoisyなデータがあれば、FilterしていくとGrafanaが見やすくなります。

Span Attributeの追加

Tempoには複数のクラスタからのTraceが送信されうるので、どのクラスタからきたSpanなのかがわかるようにCollectorレベルで一括でSpan Attributeを追加します。

次の設定を追加します。

    processors:
      # ...
      attributes:
        actions:
        - key: cluster
          value: tap-sandbox
          action: upsert
    # ...
    service:
      pipelines:
        traces:
          receivers:
          - otlp
          processors:
          - filter
          - attributes # <--
          - batch
          exporters:
          - otlp/tempo

Collectorを更新します。

kubectl apply -f otelcol.yaml

新規のデータにはSpan Attributeにclusterが追加されていることが確認できます。

Span Attributeでの検索も可能です。

Tanzu Application PlatformのContourでTraceを有効にすることでいろいろな観測ができそうです。

IK.AM