HTTP response code, `err` returned by request handlers, and middlewares

[sio4]

From the definition of buffalo Handler: https://pkg.go.dev/github.com/gobuffalo/buffalo#Handler

It is the responsibility of the Handler to handle the request/response correctly.

This statement also includes the responsibility of setting the HTTP response status correctly. However, sometimes we could omit to set the response code and just returns with nil or non-nil err which indicates the request was successfully completed (could be 200 by default) or failed (could be 500 by default). In this case, the buffalo.Response will not be configured completely, and it could make some confusion on middlewares and the result of what middlewares do.

One effect of this issue is gobuffalo/buffalo-pop#19

In this case, the handler did its database job correctly but just returned nil without the setting response. As a result, even though the response to the client became 200 (since the returned error is nil) but the pop middleware detected it as a failure and the database rollback happened.

Another issue affected by this behavior is https://gophers.slack.com/archives/C3MSAFD40/p1658983223965079

(Coping from the original description):

Hello! Question regarding something I've noticed when logging via the app error handlers, e.g. app.ErrorHandlers[http.StatusInternalServerError] = someFunc. I noticed that the log status gets set to 0 if the response has has not yet been written with the relevant status code prior to execution of the Error Handler callback. Here is a log item:

time="2022-07-28T04:32:02Z" level=error msg="An internal error occurred: unhealthy" content_type=application/json duration="17.711µs" human_size="0 B" method=GET params="{}" path=/v2/health/ request_id=86619d31654c9c78b952-06d343033a282f7ef78e size=0 status=0

The error handling itself is behaving as I would expect, and it is executing my custom error function as desired. I am then writing the appropriate status code to the response and the client sees it as a 500 error. However, because the log is setting a status of 0, my log aggregators pick this up with EMERGENCY level logging... which is not desirable. I verified that writing the response error to the response body before the error gets handled by app.ErrorHandlers sets the status code of the log appropriately. In the above example, it would be status=500.

(for the reference) My answer to this issue was:

<...> Let's start with the output of buffalo task middleware from my test project:

$ buffalo task middleware
-> http://127.0.0.1:3000/
	github.com/gobuffalo/buffalo.*App.defaultErrorMiddleware
	github.com/gobuffalo/buffalo.*App.PanicHandler
	github.com/gobuffalo/buffalo.RequestLoggerFunc
	github.com/gobuffalo/mw-forcessl.Middleware.func1
	github.com/gobuffalo/mw-paramlogger.ParameterLogger
	github.com/gobuffalo/mw-csrf.glob..func1
	github.com/gobuffalo/buffalo-pop/v3/pop/popmw.Transaction.func2
	github.com/gobuffalo/mw-i18n/v2.*Translator.Middleware.func1

This application is just a vanilla scaffolded app with buffalo new coke ... and this middleware stack is the default. The first three middlewares are configured by default and the others are configured from the scaffolded actions/app.go. If my request handler is invoked with this stack, the control travels through them, reaches to the handler, and travels back to the root of the stack.
In your case, when the handler returns with non-nil err but had not been set response, the control reaches back to the ParameterLogger first and it logs the exact status without altering the response or something, so the status will remain as 0 when it reached to the defaultErrorMiddleware. In this defaultErrorMiddleware, the middleware function sets HTTP status as 500 if the response has no specific one, so your error handler for 500 will be picked for error handling correctly but still the original status will remain as 0 (even though the error handler was called with the first argument 500. So this symptom is expected from the perspective of the middleware stack, and the logger did its own job which is representing the exact situation with log output.
The current definition of the buffalo request handler stated this behavior as the following:
It is the responsibility of the Handler to handle the request/response correctly.
So basically you need to set a correct response code from your handler. However, I understand sometimes it is annoying, inconvenient to set it on all handlers, could be a duplication of code, or even not possible in some cases. One possible solution is adding a "status correction" middleware at the top of the middleware stack so the status can be set just after the handler returns. Doing that within the buffalo could be nice but it will hurt the flexibility of the user's own configuration, so I don't think that could be the best solution.
I am researching on this though, but I feel like the solution could be to document this behavior more clearly.

[sio4]

We need to consider the following two things.

• add a clear description of this behavior in the documentation so developers can understand it more clearly.
• consider implementing status fixer as a last/default middleware by default so that we can make sure the response code will not be 0, but in a flexible way.

[github-actions]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days.