http: superfluous response.WriteHeader call from RespWriterWrapper

[syscl]

Component(s)

No response

What happened?

Description

2024/09/11 04:00:15 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)

Steps to Reproduce

/otel/config.yaml:

receivers:
  otlp:
    protocols:
      grpc:
      http:
        cors:
          allowed_origins:
            - "http://*"
            - "https://*"

  hostmetrics:
    collection_interval: 10s
    scrapers:
      paging:
        metrics:
          system.paging.utilization:
            enabled: true
      cpu:
        metrics:
          system.cpu.utilization:
            enabled: true
      disk:
      filesystem:
        metrics:
          system.filesystem.utilization:
            enabled: true

processors:
  batch:
  resource:
    attributes:
      - key: hello.world
        value: myname
        action: insert

exporters:
  otlphttp/metrics:
    endpoint: "https://api.honeycomb.io"
    headers:
      "x-honeycomb-team": <example-team>
      "x-honeycomb-dataset": <example-dataset>

connectors:
  spanmetrics:

service:
  pipelines:
    metrics:
      receivers: [otlp, spanmetrics]
      processors: [batch, resource]
      exporters: [otlphttp/metrics]

    traces:
      receivers: [otlp]
      processors: [batch, resource]
      exporters: [spanmetrics]

Dockerfile:

FROM otel/opentelemetry-collector-contrib:0.109.0

WORKDIR /otel

COPY config/otel-config.yaml /otel/config.yaml

EXPOSE 4317 4318 55679 8888 5318

CMD ["--config", "/otel/config.yaml", "--feature-gates", "-component.UseLocalHostAsDefaultHost"]

Expected Result

No

2024/09/11 09:35:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)
2024/09/11 09:36:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)

Actual Result

The superfluous span across the collector logs

Collector version

0.109.0

Environment information

Environment

OS: On both k8s's and macOS 14.6.1's docker engine, both happens. I use docker image otel/opentelemetry-collector-contrib:0.109.0
Compiler(if manually compiled): (e.g., "go 14.2") no complier using

OpenTelemetry Collector configuration

No response

Log output

2024/09/11 09:35:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)
2024/09/11 09:36:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)
2024/09/11 09:37:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)
2024/09/11 09:38:31 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)

Additional context

verison before 0.109.0 works as expected. Tested on 0.105.0 till 0.108.0, works as expected.

[bacherfl]

This seems to have been fixed in open-telemetry/opentelemetry-go-contrib#6074

[syscl]

thanks for the information @bacherfl , it seems the release of contrib is still 109

[pitoniak32]

Hello, I just wanted to report that we are also seeing this log spam using image: otel/opentelemetry-collector-contrib:0.109.0-amd64

receivers:
  otlp:
    protocols:
      http:
        endpoint: 0.0.0.0:4318
      grpc:
        endpoint: 0.0.0.0:4317
exporters:
  datadog:
    api:
      site: $${env:DD_SITE}
      key: $${env:DD_API_KEY}
    traces:
      trace_buffer: 1000
  debug:
processors:
  batch:
    send_batch_size: 8192
    send_batch_max_size: 0
    timeout: 200ms
  memory_limiter:
    check_interval: 1s
    limit_percentage: 75
    spike_limit_percentage: 20
extensions:
  health_check:
    endpoint: 0.0.0.0:13133
service:
  extensions: [health_check]
  pipelines:
    traces:
      receivers: [otlp]
      processors: [resource, memory_limiter, batch]
      exporters: [datadog, debug]

We are seeing the following log spammed. It happens when datadog exporter is removed, but less frequently.

opentelemetry-collector 2024/09/20 15:17:16 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)
opentelemetry-collector 2024/09/20 15:17:27 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)

[atoulme]

Closing this as fixed per 0.110.0.