search

open-telemetry / opentelemetry-go-instrumentation

OpenTelemetry Auto Instrumentation using eBPF
https://opentelemetry.io
Apache License 2.0
481 stars 73 forks source link

offset not found: golang.org/x/net/http2.MetaHeadersFrame:Fields #511

Open andrew-lozoya opened 9 months ago

andrew-lozoya commented 9 months ago

Describe the bug

Following the provided emojivote

I was able to successfully sidecar inject the application using release v.0.7.0 however v0.8.0 creates errors while loading probes.

Environment

To Reproduce

Steps to reproduce the behavior:

---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: emoji
  namespace: emojivoto
  labels:
    app.kubernetes.io/name: emoji
    app.kubernetes.io/part-of: emojivoto
    app.kubernetes.io/version: v11
spec:
  replicas: 1
  selector:
    matchLabels:
      app: emoji-svc
      version: v11
  template:
    metadata:
      labels:
        app: emoji-svc
        version: v11
    spec:
      serviceAccountName: emoji
      shareProcessNamespace: true
      terminationGracePeriodSeconds: 0
      containers:
        - env:
            - name: GRPC_PORT
              value: "8080"
            - name: PROM_PORT
              value: "8801"
          image: docker.l5d.io/buoyantio/emojivoto-emoji-svc:v11
          name: emoji-svc
          ports:
            - containerPort: 8080
              name: grpc
            - containerPort: 8801
              name: prom
          resources:
            requests:
              cpu: 100m
        - name: emojivoto-emoji-instrumentation
          image: ghcr.io/open-telemetry/opentelemetry-go-instrumentation/autoinstrumentation-go:v0.8.0-alpha
          imagePullPolicy: IfNotPresent
          env:
            - name: OTEL_GO_AUTO_TARGET_EXE
              value: /usr/local/bin/emojivoto-emoji-svc
            - name: OTEL_EXPORTER_OTLP_ENDPOINT
              value: "http://jaeger:4318"
            - name: OTEL_SERVICE_NAME
              value: "emojivoto-emoji"
          securityContext:
            runAsUser: 0
            privileged: true
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: voting
  namespace: emojivoto
  labels:
    app.kubernetes.io/name: voting
    app.kubernetes.io/part-of: emojivoto
    app.kubernetes.io/version: v11
spec:
  replicas: 1
  selector:
    matchLabels:
      app: voting-svc
      version: v11
  template:
    metadata:
      labels:
        app: voting-svc
        version: v11
    spec:
      serviceAccountName: voting
      shareProcessNamespace: true
      terminationGracePeriodSeconds: 0
      containers:
        - env:
            - name: GRPC_PORT
              value: "8080"
            - name: PROM_PORT
              value: "8801"
          image: docker.l5d.io/buoyantio/emojivoto-voting-svc:v11
          name: voting-svc
          ports:
            - containerPort: 8080
              name: grpc
            - containerPort: 8801
              name: prom
          resources:
            requests:
              cpu: 100m
        - name: emojivoto-voting-instrumentation
          image: ghcr.io/open-telemetry/opentelemetry-go-instrumentation/autoinstrumentation-go:v0.8.0-alpha
          imagePullPolicy: IfNotPresent
          env:
            - name: OTEL_GO_AUTO_TARGET_EXE
              value: /usr/local/bin/emojivoto-voting-svc
            - name: OTEL_EXPORTER_OTLP_ENDPOINT
              value: "http://jaeger:4318"
            - name: OTEL_SERVICE_NAME
              value: "emojivoto-voting"
          securityContext:
            runAsUser: 0
            privileged: true`
---            
apiVersion: apps/v1
kind: Deployment
metadata:
  name: web
  namespace: emojivoto
  labels:
    app.kubernetes.io/name: web
    app.kubernetes.io/part-of: emojivoto
    app.kubernetes.io/version: v11
spec:
  replicas: 1
  selector:
    matchLabels:
      app: web-svc
      version: v11
  template:
    metadata:
      labels:
        app: web-svc
        version: v11
    spec:
      serviceAccountName: web
      shareProcessNamespace: true
      terminationGracePeriodSeconds: 0
      containers:
        - env:
            - name: WEB_PORT
              value: "8080"
            - name: EMOJISVC_HOST
              value: emoji-svc.emojivoto:8080
            - name: VOTINGSVC_HOST
              value: voting-svc.emojivoto:8080
            - name: INDEX_BUNDLE
              value: dist/index_bundle.js
          image: docker.l5d.io/buoyantio/emojivoto-web:v11
          name: web-svc
          ports:
            - containerPort: 8080
              name: http
          resources:
            requests:
              cpu: 100m
        - name: emojivoto-web-instrumentation
          image: ghcr.io/open-telemetry/opentelemetry-go-instrumentation/autoinstrumentation-go:v0.8.0-alpha
          imagePullPolicy: IfNotPresent
          env:
            - name: OTEL_GO_AUTO_TARGET_EXE
              value: /usr/local/bin/emojivoto-web
            - name: OTEL_EXPORTER_OTLP_ENDPOINT
              value: "http://jaeger:4318"
            - name: OTEL_SERVICE_NAME
              value: "emojivoto-web"
          securityContext:
            runAsUser: 0
            privileged: true

Expected behavior

2023-11-17T18:50:27.346832840Z {"level":"info","ts":1700247027.3465803,"logger":"go.opentelemetry.io/auto","caller":"cli/main.go:91","msg":"building OpenTelemetry Go instrumentation ..."}
2023-11-17T18:50:29.347330470Z {"level":"info","ts":1700247029.3471537,"logger":"Instrumentation.Analyzer","caller":"process/discover.go:69","msg":"found process","pid":13}
2023-11-17T18:50:29.357294906Z {"level":"info","ts":1700247029.3570986,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"net/http.HandlerFunc.ServeHTTP","Offset":2870464,"ReturnOffsets":[2870541]}}
2023-11-17T18:50:29.357351970Z {"level":"info","ts":1700247029.3571725,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"google.golang.org/grpc/internal/transport.(*loopyWriter).headerHandler","Offset":4205024,"ReturnOffsets":[4205271,4205453,4205517,4205613,4205756,4206035]}}
2023-11-17T18:50:29.357358634Z {"level":"info","ts":1700247029.357185,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"google.golang.org/grpc/internal/transport.(*http2Client).NewStream","Offset":4253888,"ReturnOffsets":[4255323,4255381,4255485,4255529,4255590,4256372,4256560]}}
2023-11-17T18:50:29.357361170Z {"level":"info","ts":1700247029.3571932,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"google.golang.org/grpc/internal/transport.(*http2Server).operateHeaders","Offset":4281184,"ReturnOffsets":[4281618,4282576,4282811,4283044,4284085,4285805]}}
2023-11-17T18:50:29.357365074Z {"level":"info","ts":1700247029.3572009,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"google.golang.org/grpc.(*ClientConn).Invoke","Offset":4742592,"ReturnOffsets":[4742898,4743068]}}
2023-11-17T18:50:29.357516293Z {"level":"info","ts":1700247029.3572083,"logger":"Instrumentation.Analyzer","caller":"process/analyze.go:98","msg":"found function","function_name":{"Name":"google.golang.org/grpc.(*Server).handleStream","Offset":4841536,"ReturnOffsets":[4842201,4843609,4844418,4844715,4844820]}}
2023-11-17T18:50:29.357530858Z {"level":"info","ts":1700247029.3573382,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":13}
2023-11-17T18:50:29.357537349Z {"level":"info","ts":1700247029.3574083,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":14}
2023-11-17T18:50:29.357540439Z {"level":"info","ts":1700247029.357443,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":15}
2023-11-17T18:50:29.357543234Z {"level":"info","ts":1700247029.3574812,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":16}
2023-11-17T18:50:29.357695179Z {"level":"info","ts":1700247029.3575728,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":17}
2023-11-17T18:50:29.357721642Z {"level":"info","ts":1700247029.3576093,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":18}
2023-11-17T18:50:29.357724807Z {"level":"info","ts":1700247029.3576345,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":19}
2023-11-17T18:50:29.357733663Z {"level":"info","ts":1700247029.3576634,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:133","msg":"attach successfully","tid":20}
2023-11-17T18:50:29.357921111Z {"level":"info","ts":1700247029.3578427,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:234","msg":"Detected linux kernel version","version":"5.10.0"}
2023-11-17T18:50:29.358077267Z {"level":"info","ts":1700247029.3580172,"logger":"Instrumentation.Allocate.TracedProgram","caller":"ptrace/ptrace_linux.go:246","msg":"mlock ret","ret":0}
2023-11-17T18:50:29.358083492Z {"level":"info","ts":1700247029.3580403,"logger":"Instrumentation.Allocate","caller":"process/allocate.go:64","msg":"Detaching from process","pid":13}
2023-11-17T18:50:29.358218442Z {"level":"info","ts":1700247029.3581402,"logger":"Instrumentation.Allocate","caller":"process/allocate.go:43","msg":"mmaped remote memory","start_addr":"7F68E488F000","end_addr":"7F68E489F000"}
2023-11-17T18:50:29.359023099Z {"level":"info","ts":1700247029.3581622,"logger":"Instrumentation","caller":"app/instrumentation.go:132","msg":"target process analysis completed","pid":13,"go_version":"1.15.0","dependencies":{"command-line-arguments":null,"contrib.go.opencensus.io/exporter/ocagent":"0.6.0","github.com/beorn7/perks":"1.0.1","github.com/buoyantio/emojivoto":null,"github.com/census-instrumentation/opencensus-proto":"0.2.1","github.com/cespare/xxhash/v2":"2.1.1","github.com/golang/groupcache":"0.0.0-20200121045136-8c9f03a8e57e","github.com/golang/protobuf":"1.4.0","github.com/grpc-ecosystem/go-grpc-prometheus":"1.2.0","github.com/grpc-ecosystem/grpc-gateway":"1.14.4","github.com/matttproud/golang_protobuf_extensions":"1.0.1","github.com/prometheus/client_golang":"1.6.0","github.com/prometheus/client_model":"0.2.0","github.com/prometheus/common":"0.9.1","github.com/prometheus/procfs":"0.0.11","go.opencensus.io":"0.22.3","golang.org/x/net":"0.0.0-20200425230154-ff2c4b7c35a0","golang.org/x/sync":"0.0.0-20200317015054-43a5402ce75a","golang.org/x/sys":"0.0.0-20200430082407-1f5687305801","golang.org/x/text":"0.3.2","google.golang.org/api":"0.22.0","google.golang.org/genproto":"0.0.0-20200430143042-b979b6f78d84","google.golang.org/grpc":"1.29.1","google.golang.org/protobuf":"1.21.0","std":"1.15.0"},"total_functions_found":6}
2023-11-17T18:50:29.359034151Z {"level":"info","ts":1700247029.3585973,"logger":"go.opentelemetry.io/auto","caller":"cli/main.go:98","msg":"starting instrumentation..."}
2023-11-17T18:50:29.359038279Z {"level":"info","ts":1700247029.3587976,"logger":"Instrumentation.Manager","caller":"instrumentation/manager.go:178","msg":"Mounting bpffs","allocations_details":{"StartAddr":140088487505920,"EndAddr":140088487571456}}
2023-11-17T18:50:29.376407535Z {"level":"info","ts":1700247029.37623,"logger":"Instrumentation.Manager","caller":"instrumentation/manager.go:163","msg":"loading probes","name":"google.golang.org/grpc"}
2023-11-17T18:50:29.513209571Z {"level":"info","ts":1700247029.513062,"logger":"Instrumentation.Manager","caller":"instrumentation/manager.go:163","msg":"loading probes","name":"google.golang.org/grpc/server"}
2023-11-17T18:50:29.514912152Z {"level":"error","ts":1700247029.5147672,"logger":"Instrumentation.Manager","caller":"instrumentation/manager.go:166","msg":"error while loading probes, cleaning up","name":"google.golang.org/grpc/server","error":"offset not found: golang.org/x/net/http2.MetaHeadersFrame:Fields (0.0.0-20200425230154-ff2c4b7c35a0)\noffset not found: golang.org/x/net/http2.FrameHeader:StreamID (0.0.0-20200425230154-ff2c4b7c35a0)","stacktrace":"go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).load\n\t/app/internal/pkg/instrumentation/manager.go:166\ngo.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).Run\n\t/app/internal/pkg/instrumentation/manager.go:121\ngo.opentelemetry.io/auto.(*Instrumentation).Run\n\t/app/instrumentation.go:150\nmain.main\n\t/app/cli/main.go:99\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:267"}
2023-11-17T18:50:29.632802862Z {"level":"info","ts":1700247029.6326632,"logger":"Instrumentation.Manager","caller":"instrumentation/manager.go:191","msg":"Cleaning bpffs"}
2023-11-17T18:50:29.633019729Z {"level":"error","ts":1700247029.632901,"logger":"go.opentelemetry.io/auto","caller":"cli/main.go:100","msg":"instrumentation crashed","error":"offset not found: golang.org/x/net/http2.MetaHeadersFrame:Fields (0.0.0-20200425230154-ff2c4b7c35a0)\noffset not found: golang.org/x/net/http2.FrameHeader:StreamID (0.0.0-20200425230154-ff2c4b7c35a0)","stacktrace":"main.main\n\t/app/cli/main.go:100\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:267"}
2023-11-17T18:52:57.464886Z    Stream closed EOF for default/voting-7884ff8d98-xfnwx (opentelemetry-auto-instrumentation)

Additional context

This only happens when using v0.8.0 if i downgrade to v0.7.0 i have no issues

RonFed commented 9 months ago

https://github.com/open-telemetry/opentelemetry-go-instrumentation/pull/503 should resolve this (merged after the v0.8.0 release).