From 284089683e3fb7fc67f9dca4ac945362be3ced32 Mon Sep 17 00:00:00 2001 From: Marcel Ludwig Date: Wed, 18 Aug 2021 08:46:09 +0200 Subject: [PATCH 1/5] Add context based log hook to use entry.WithContext add missing uid field for now --- eval/buffer.go | 4 ++++ eval/context.go | 2 ++ internal/test/log.go | 2 ++ logging/context_hook.go | 26 ++++++++++++++++++++++++++ main.go | 1 + 5 files changed, 35 insertions(+) create mode 100644 logging/context_hook.go diff --git a/eval/buffer.go b/eval/buffer.go index 9c5beb7b3..d3202cfde 100644 --- a/eval/buffer.go +++ b/eval/buffer.go @@ -34,6 +34,10 @@ func (i BufferOption) GoString() string { func MustBuffer(body hcl.Body) BufferOption { result := BufferNone + if body == nil { + return result + } + attrs, err := body.JustAttributes() if err != nil { return result diff --git a/eval/context.go b/eval/context.go index b397160b6..52d5ceb89 100644 --- a/eval/context.go +++ b/eval/context.go @@ -185,6 +185,7 @@ func (c *Context) WithBeresps(beresps ...*http.Response) *Context { if n, ok := bereq.Context().Value(request.RoundTripName).(string); ok { name = n } + p := bereq.URL.Port() if p == "" { if bereq.URL.Scheme == "https" { @@ -194,6 +195,7 @@ func (c *Context) WithBeresps(beresps ...*http.Response) *Context { } } port, _ := strconv.ParseInt(p, 10, 64) + body, jsonBody := parseReqBody(bereq) bereqs[name] = cty.ObjectVal(ContextMap{ Method: cty.StringVal(bereq.Method), diff --git a/internal/test/log.go b/internal/test/log.go index 8f84a02db..69aa89011 100644 --- a/internal/test/log.go +++ b/internal/test/log.go @@ -7,12 +7,14 @@ import ( logrustest "github.com/sirupsen/logrus/hooks/test" "github.com/avenga/couper/errors" + "github.com/avenga/couper/logging" ) func NewLogger() (*logrus.Logger, *logrustest.Hook) { log := logrus.New() log.Out = io.Discard log.AddHook(&errors.LogHook{}) + log.AddHook(&logging.ContextHook{}) hook := logrustest.NewLocal(log) return log, hook } diff --git a/logging/context_hook.go b/logging/context_hook.go new file mode 100644 index 000000000..4f4374d1d --- /dev/null +++ b/logging/context_hook.go @@ -0,0 +1,26 @@ +package logging + +import ( + "github.com/sirupsen/logrus" + + "github.com/avenga/couper/config/request" +) + +var _ logrus.Hook = &ContextHook{} + +type ContextHook struct { +} + +func (c ContextHook) Levels() []logrus.Level { + return logrus.AllLevels +} + +func (c ContextHook) Fire(entry *logrus.Entry) error { + _, exist := entry.Data["uid"] + if entry.Context != nil && !exist { + if uid := entry.Context.Value(request.UID); uid != nil { + entry.Data["uid"] = uid + } + } + return nil +} diff --git a/main.go b/main.go index 382b37073..fa1855d4e 100644 --- a/main.go +++ b/main.go @@ -197,6 +197,7 @@ func newLogger(format string, pretty bool) *logrus.Entry { logger.Out = os.Stdout logger.AddHook(&errors.LogHook{}) + logger.AddHook(&logging.ContextHook{}) if testHook != nil { logger.AddHook(testHook) From c6b9d0294375e6a9109dcafbb4d6fca654dd2d58 Mon Sep 17 00:00:00 2001 From: Marcel Ludwig Date: Wed, 18 Aug 2021 08:54:44 +0200 Subject: [PATCH 2/5] handle gzip.Reader (new)error With this initialization the gzip header will be read. This could throw an invalid header error. In combination with content-length a follow up error while writing to the client (CL != Body) is not helpful at all. --- handler/transport/backend.go | 35 ++++++++++++++++++++++++++++------- 1 file changed, 28 insertions(+), 7 deletions(-) diff --git a/handler/transport/backend.go b/handler/transport/backend.go index 04d225c92..89a6a1464 100644 --- a/handler/transport/backend.go +++ b/handler/transport/backend.go @@ -1,9 +1,11 @@ package transport import ( + "bytes" "compress/gzip" "context" "encoding/base64" + "io" "net/http" "net/url" "strings" @@ -115,7 +117,9 @@ func (b *Backend) RoundTrip(req *http.Request) (*http.Response, error) { return nil, err } - setGzipReader(beresp) + if err = setGzipReader(beresp); err != nil { + b.upstreamLog.LogEntry().WithContext(req.Context()).WithError(err).Error() + } if !isProxyReq { removeConnectionHeaders(req.Header) @@ -310,13 +314,30 @@ func setUserAgent(outreq *http.Request) { } } -func setGzipReader(beresp *http.Response) { - if strings.ToLower(beresp.Header.Get(writer.ContentEncodingHeader)) == writer.GzipName { - if src, err := gzip.NewReader(beresp.Body); err == nil { - beresp.Header.Del(writer.ContentEncodingHeader) - beresp.Body = eval.NewReadCloser(src, beresp.Body) - } +// setGzipReader will set the gzip.Reader for Content-Encoding gzip. +// Invalid header reads will reset the response.Body and return the related error. +func setGzipReader(beresp *http.Response) error { + if strings.ToLower(beresp.Header.Get(writer.ContentEncodingHeader)) != writer.GzipName { + return nil + } + + buf := &bytes.Buffer{} + _, err := buf.ReadFrom(beresp.Body) // TODO: may be optimized with limitReader etc. + if err != nil { + return errors.Backend.With(err) } + b := buf.Bytes() + + var src io.Reader + src, err = gzip.NewReader(buf) + if err != nil { + src = bytes.NewBuffer(b) + err = errors.Backend.With(err).Message("body reset") + } + + beresp.Header.Del(writer.ContentEncodingHeader) + beresp.Body = eval.NewReadCloser(src, beresp.Body) + return err } // removeConnectionHeaders removes hop-by-hop headers listed in the "Connection" header of h. From f88426ec1d8337759f567b6ee0ab26f55b76d002 Mon Sep 17 00:00:00 2001 From: Marcel Ludwig Date: Wed, 18 Aug 2021 09:16:05 +0200 Subject: [PATCH 3/5] Add statusCode fallback to responseWriter Handle worst case scenario to prevent a panic thrown by http package --- server/writer/response.go | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/server/writer/response.go b/server/writer/response.go index 36b81f1af..ea2933c26 100644 --- a/server/writer/response.go +++ b/server/writer/response.go @@ -9,6 +9,7 @@ import ( "net/textproto" "strconv" + "github.com/avenga/couper/errors" "github.com/avenga/couper/eval" "github.com/avenga/couper/logging" "github.com/hashicorp/hcl/v2" @@ -122,7 +123,13 @@ func (r *Response) WriteHeader(statusCode int) { r.configureHeader() r.applyModifier() - r.rw.WriteHeader(statusCode) + + if statusCode == 0 { + r.rw.Header().Set(errors.HeaderErrorCode, errors.Server.Error()) + r.rw.WriteHeader(errors.Server.HTTPStatus()) + } else { + r.rw.WriteHeader(statusCode) + } r.statusWritten = true r.statusCode = statusCode } From 56609ccfa11e704fa05713bb4f56cc352aa4544c Mon Sep 17 00:00:00 2001 From: Marcel Ludwig Date: Wed, 18 Aug 2021 09:24:59 +0200 Subject: [PATCH 4/5] Add faulty default response test reduce png bytes, fmt check --- handler/endpoint_test.go | 90 +++++++++++++++++++++++++++++++++++++++- 1 file changed, 89 insertions(+), 1 deletion(-) diff --git a/handler/endpoint_test.go b/handler/endpoint_test.go index d1cb8f625..4326ebf11 100644 --- a/handler/endpoint_test.go +++ b/handler/endpoint_test.go @@ -13,6 +13,7 @@ import ( "github.com/hashicorp/hcl/v2/hclsimple" logrustest "github.com/sirupsen/logrus/hooks/test" + "github.com/avenga/couper/config/request" "github.com/avenga/couper/errors" "github.com/avenga/couper/eval" "github.com/avenga/couper/handler" @@ -20,6 +21,7 @@ import ( "github.com/avenga/couper/handler/transport" "github.com/avenga/couper/internal/test" "github.com/avenga/couper/server/writer" + "github.com/sirupsen/logrus" ) func TestEndpoint_RoundTrip_Eval(t *testing.T) { @@ -242,7 +244,7 @@ func TestEndpoint_RoundTripContext_Variables_json_body(t *testing.T) { } } -// TestProxy_SetRoundtripContext_Null_Eval tests the handling with non existing references or cty.Null evaluations. +// TestProxy_SetRoundtripContext_Null_Eval tests the handling with non-existing references or cty.Null evaluations. func TestEndpoint_RoundTripContext_Null_Eval(t *testing.T) { helper := test.New(t) @@ -364,3 +366,89 @@ func TestEndpoint_RoundTripContext_Null_Eval(t *testing.T) { } } + +type mockProducerResult struct { + rt http.RoundTripper +} + +func (m *mockProducerResult) Produce(_ context.Context, r *http.Request, results chan<- *producer.Result) { + if m == nil || m.rt == nil { + close(results) + return + } + + res, err := m.rt.RoundTrip(r) + results <- &producer.Result{ + RoundTripName: "default", + Beresp: res, + Err: err, + } + close(results) +} + +func TestEndpoint_ServeHTTP_FaultyDefaultResponse(t *testing.T) { + log, hook := test.NewLogger() + + origin := httptest.NewServer(http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) { + png := []byte(`�PNG + + +IHDRH0=���gAMA�� �a pHYs���B��tEXtSoftwarePaint.NET v3.5.100�r�pIDAThC��� �0 ���b!K�$�������1x={+��^��h +�)��6���z�Qj�h +�)��0�N4��FS�7l�5��"Ma4��F�=q���ь�FS�7l|�Ұ��nW�i�0IEND�B`) + + rw.Header().Set("Content-Encoding", "gzip") // wrong + rw.Header().Set("Content-Type", "text/html") // wrong + rw.Header().Set("Cache-Control", "no-cache, no-store, max-age=0") + + _, err := rw.Write(png) + if err != nil { + t.Error(err) + } + })) + defer origin.Close() + + rt := transport.NewBackend( + test.NewRemainContext("origin", origin.URL), &transport.Config{}, + &transport.BackendOptions{}, log.WithContext(context.Background())) + + mockProducer := &mockProducerResult{rt} + + ep := handler.NewEndpoint(&handler.EndpointOptions{ + Context: hcl.EmptyBody(), + Error: errors.DefaultJSON, + Requests: mockProducer, + Proxies: &mockProducerResult{}, + }, log.WithContext(context.Background()), nil) + + ctx := context.Background() + req := httptest.NewRequest(http.MethodGet, "http://", nil).WithContext(ctx) + ctx = eval.NewContext(nil, nil).WithClientRequest(req) + ctx = context.WithValue(ctx, request.UID, "test123") + + rec := transport.NewRecorder() + rw := writer.NewResponseWriter(rec, "") + ep.ServeHTTP(rw, req.Clone(ctx)) + res, err := rec.Response(req) + if err != nil { + t.Error(err) + } + if res.StatusCode == 0 { + t.Errorf("Fatal error: response status is zero") + if res.Header.Get("Couper-Error") != "internal server error" { + t.Errorf("Expected internal server error, got: %s", res.Header.Get("Couper-Error")) + } + } else if res.StatusCode != http.StatusOK { + t.Errorf("Expected status ok, got: %v", res.StatusCode) + } + + for _, e := range hook.AllEntries() { + if e.Level != logrus.ErrorLevel { + continue + } + if e.Message != "backend error: body reset: gzip: invalid header" { + t.Errorf("Unexpected error message: %s", e.Message) + } + } + +} From 19a03487954e6b1815c71b661ce51de91426f254 Mon Sep 17 00:00:00 2001 From: Marcel Ludwig Date: Thu, 19 Aug 2021 08:06:32 +0200 Subject: [PATCH 5/5] Add changelog entries PR #291 --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1f8af108f..f78ca810f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -25,6 +25,8 @@ Unreleased changes are available as `avenga/couper:edge` container. * Documentation of [`request.query.`](./docs/REFERENCE.md#request) ([#278](https://github.com/avenga/couper/pull/278)) * Missing access log on some error cases ([#267](https://github.com/avenga/couper/issues/267)) * Panic during backend origin / url usage with previous parse error ([#206](https://github.com/avenga/couper/issues/206)) + * Missing error handling for backend gzip header reads ([#291](https://github.com/avenga/couper/pull/291)) + * ResponseWriter fallback for possible statusCode 0 writes ([#291](https://github.com/avenga/couper/pull/291)) * [**Beta**](./docs/BETA.md) * OAuth2 Authorization Code Grant Flow: [`beta_oauth2 {}` block](./docs/REFERENCE.md#oauth2-ac-block-beta); [`beta_oauth_authorization_url()`](./docs/REFERENCE.md#functions) and [`beta_oauth_verifier()`](./docs/REFERENCE.md#functions) ([#247](https://github.com/avenga/couper/pull/247))