Hijack before WriteHeader to avoid issues with middleware and Gin

[prologic]

I tried to upgrade to your library in one of my projects msgbus in this commit but unfortunately ran into some issues and had to revert

It would appear that the interaction between Logging and GZIP MIddleware is not playing nicely, whereas the old gorilla/websocket library was handling this fine.

Basic error I'm seeing is:

2022/03/27 02:23:54 http: response.WriteHeader on hijacked connection from github.com/unrolled/logger.(*customResponseWriter).WriteHeader (logger.go:108)

Can we fix this somehow so that your library plays nicely with middleware that wraps it potentially?

[nhooyr]

I'd have to see your gzip middleware to be sure but I suspect the issue is that the gzip middleware is buffering WriteHeader to check whether it's worth gzipping and/or sniff the response's content type but then not calling WriteHeader before Hijack if there was a buffered WriteHeader.

But then the gzip middleware knows there was a WriteHeader that needs to be flushed when the handler chain errors out (as no response was sent to the client) and so it calls WriteHeader but the connection was hijacked and so you then see the above error.

The reason Gorilla worked is that it hijacks before writing the upgrade response and so there is no WriteHeader that's buffered.

To fix, change the gzip response writer's Hijack to call WriteHeader first if there is one buffered.

As for why I opted to write the upgrade response with the net/http response writer, it's far simpler.

Compare Gorilla's code to my library:

• gorilla: https://github.com/gorilla/websocket/blob/69d0eb9187b6dead8fe84b2423518475e5cc535c/server.go#L219
• nhooyr:

  websocket/accept.go

  Line 110 in 8dee580

  w.Header().Set("Upgrade", "websocket")

But perhaps it's a good idea to add a Flush right before the Hijack to handle these kinds of response writers. But I suspect few gzip response writer's implement Flush correctly.

For example, the popular nytime's Go gzip response writer does not: https://github.com/nytimes/gziphandler/blob/2f8bb1d30d9d69c8e0c3714da5a9917125a87769/gzip.go#L250

[prologic]

@nhooyr This happens with unrolled/logger too if you want to take a look at that. I commonly use the following setup in a lot of my projects, and the above basically prevents me from fully migrating t oyour library server-side (have only done so client-side so far):

...
	router := NewRouter()
	router.Use(Middleware(func(next httprouter.Handle) httprouter.Handle {
		return func(w http.ResponseWriter, r *http.Request, p httprouter.Params) {
			w.Header().Set("Access-Control-Allow-Origin", "*")
			w.Header().Set("Access-Control-Allow-Headers", "*")
			next(w, r, p)
		}
	}))

	api := NewAPI(router, config, db)

	csrfHandler := nosurf.New(router)
	csrfHandler.ExemptGlob("/api/v1/*")
	csrfHandler.ExemptGlob("/.well-known/*")
	csrfHandler.ExemptGlob("/inbox/*")

	routes.AddRoutes()
	server := &Server{
		bind:   bind,
		config: config,
		router: router,

		server: &http.Server{
			Addr: bind,
			Handler: logger.New(logger.Options{
				Prefix:               "saltyd",
				RemoteAddressHeaders: []string{"X-Forwarded-For"},
			}).Handler(gziphandler.GzipHandler(
				csrfHandler,
			),
			),
		},
...

Of course this varies a bit from project to project but you get the idea.

[prologic]

To fix, change the gzip response writer's Hijack to call WriteHeader first if there is one buffered.

Hmmm I would have go essentially go fork a bunch of "middleware" libraries and "make them my own". I'm okay with that 👌 If this is the correct thing to do?

[prologic]

But perhaps it's a good idea to add a Flush right before the Hijack to handle these kinds of response writers. But I suspect few gzip response writer's implement Flush correctly.

It's actually surprisingly hard to find good Middleware that actualy works correctly and doesn't suck 😅

[nhooyr]

@prologic In the example above, if you remove the gzip handler entirely, does the issue still occur with just unrolled/logger?

I know the error message seems to indicate that the error is in unrolled/logger but if my understanding is correct, it's a red herring.

[prologic]

@prologic In the example above, if you remove the gzip handler entirely, does the issue still occur with just unrolled/logger?

Yes. It occurs with both. I've already done the necessary pulling bits out to see wtf was going on 😅

I know the error message seems to indicate that the error is in unrolled/logger but if my understanding is correct, it's a red herring.

I think it's just because of the order of the wrapping handlers? (middleware)

[nhooyr]

Hmm, I'm not sure how the error could arise with just unrolled/logger.

Can you add a debug.PrintStack() call here in unrolled/logger? And then post the stack right before the error message here. Should be helpful.

[prologic]

Sure I'll try and poke around and get back to you 👌

[nhooyr]

Friendly reminder re the above.

[nhooyr]

I'll just change my library to hijack first like Gorilla.