Error logs coming for http: superfluous response.WriteHeader call when using otelhttp handler

[vipul-rawat]

Description

A clear and concise description of what the bug is.

In the latest release the call to request.Write() is setting the response headers to http.StatusOK without checking if the WriteHeader is already called, this is causing issues when trying to set Status Codes and then trying to Write to the response.

Environment

• OS: darwin
• Architecture: arm64
• Go Version: go 1.22
• otelhttp version: v0.54.0

Steps To Reproduce

1. Using this code ...

package main

import (
	"fmt"

	"gofr.dev/pkg/gofr"
)

func main() {
	a := gofr.New()

	a.GET("/hello", HelloHandler)

	a.Run()
}

func HelloHandler(c *gofr.Context) (interface{}, error) {
	name := c.Param("name")
	if name == "" {
		c.Log("Name came empty")
		name = "World"
	}

	return fmt.Sprintf("Hello %s!", name), nil
}

2. Run ...

go run main.go

curl --location 'localhost:8000/hello'

3. See error ...
   

Expected behavior

The Write() call should check if the wroteHeader is true before calling WriteHeader()

[dmathieu]

I'm unable to reproduce this running your sample example:

WARN [12:04:43] Failed to load config from file: /.env, Err: open /.env: no such file or directory
INFO [12:04:43] Starting metrics server on port: 2121
INFO [12:04:43] Starting server on port: 8000
INFO [12:05:10] Name came empty
INFO [12:05:10] 28adde73d3a4db5359b386841c4099b5 200 345µs GET /hello

Also, based on stacktrace in the screenshot you're providing, it would appear the superfluous call to WriteHeader could be from gofr, not us?

[vipul-rawat]

I can reproduce with the following code -

package main

import (
	"net/http"

	"github.com/gorilla/mux"
	"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)

func main() {
	r := mux.NewRouter()

	handler := http.HandlerFunc(func(wr http.ResponseWriter, r *http.Request) {
		wr.WriteHeader(http.StatusCreated)

		_, _ = wr.Write([]byte("Hello World!"))
	})

	// defining a new otelhttp handler
	h := otelhttp.NewHandler(handler, "gofr-router")

	// register a hello route
	r.NewRoute().Methods(http.MethodGet).Path("/hello").Handler(h)

	err := http.ListenAndServe("localhost:8000", r)
	if err != nil {
		panic(err)
	}
}

Output:

2024/08/27 16:33:12 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp/internal/request.(*RespWriterWrapper).writeHeader (resp_writer_wrapper.go:78)

go.mod :

module example

go 1.22.4

require (
	github.com/gorilla/mux v1.8.1
	go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp v0.54.0
)

require (
	github.com/felixge/httpsnoop v1.0.4 // indirect
	github.com/go-logr/logr v1.4.2 // indirect
	github.com/go-logr/stdr v1.2.2 // indirect
	go.opentelemetry.io/otel v1.29.0 // indirect
	go.opentelemetry.io/otel/metric v1.29.0 // indirect
	go.opentelemetry.io/otel/trace v1.29.0 // indirect
)

[mehdy]

This if block has been removed in this PR: c619919#diff-cd9dbf33a4742e5cca53d128ebad2d1e61fdc1b41d4978db6d2a3d6a39c4a522L67-L69

[lambrospetrou]

Hitting this as well #5438 (comment)

[ash2k]

Hitting this too. All those methods that call the real WriteHeader() probably don't need to. They should only check if w.statusCode has been set already, and if not, set it to 200 (without calling the real WriteHeader()). This is simpler and doesn't have any chances of triggering some unexpected behavior in the wrapped response writer. It may too be some sort of wrapper.

[RangelReale]

I'm getting this same error on otelmux (contrib v0.54.0).

2024/09/02 12:45:02 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/github.com/gorilla/mux/otelmux.getRRW.func2.1 (mux.go:104)

go.opentelemetry.io/contrib/instrumentation/github.com/gorilla/mux/otelmux v0.54.0

[dmathieu]

This has been fixed in main, and will be available with the next release.