Log errors when write fails, not 200; requires Go 1.13

[gouthamve]

See discussion here: cortexproject/cortex#2483 (comment)

Requires projects to use Go 1.13 and above

Signed-off-by: Goutham Veeramachaneni gouthamve@gmail.com

[bboreham]

how do they appear in metrics and tracing, after this change?

[bboreham]

Also: test?

[pracucci]

I personally find this code quite tricky. I would be more comfortable if, before merging this, we would have a proof that this code + reverting Cortex PR #2483 would work as expected.

[gouthamve]

Added a test and also incorporated the feedback.

how do they appear in metrics and tracing, after this change?

It would be the same behavior as before unfortunately. resp.StatusCode == 200 even if a write errors. We only modified the logging middleware and tbh, I am not sure how to catch this in tracing/metrics.

[gouthamve]

Tested this by vendoring it into Cortex and reverting cortexproject/cortex#2483

Before:

2020-05-12 16:14:31.381381 I | http: superfluous response.WriteHeader call from github.com/opentracing-contrib/go-stdlib/nethttp.(*statusCodeTracker).WriteHeader (status-code-tracker.go:19)
level=warn ts=2020-05-12T15:14:31.381571716Z caller=logging.go:49 traceID=1bce8fc8c1a57be7 msg="GET /api/v1/query?query=up[10000m]&start=1557759455&step=126144 (500) 729.261961ms Response: \"write tcp 127.0.0.1:9091->127.0.0.1:54276: write: broken pipe\\n\" ws: false; Accept: */*; User-Agent: curl/7.70.0; "

After:

level=warn ts=2020-05-12T15:13:17.161683485Z caller=logging.go:51 traceID=604b1b0b5218a0e7 msg="GET /api/v1/query?query=up[10000m]&start=1557759455&step=126144 728.757586ms, error: write tcp 127.0.0.1:9091->127.0.0.1:54270: write: broken pipe ws: false; Accept: */*; User-Agent: curl/7.70.0; "

The new log is more accurate (the status code in this case is not 500), and also doesn't log the duplicate header write golang error.