diff --git a/docs/pages/deployment/configuration.rst b/docs/pages/deployment/configuration.rst index 1c4d652ff2..66cead569d 100644 --- a/docs/pages/deployment/configuration.rst +++ b/docs/pages/deployment/configuration.rst @@ -94,6 +94,7 @@ requesting an access token from another node on ``/n2n/auth/v1/accesstoken`` doe ``auth.accesstokenlifespan`` is always 60 seconds, json-ld context can only be downloaded from trusted domains configured in ``jsonld.contexts.remoteallowlist``, ``http.log=metadata-and-body`` is not allowed and is changed to ``metadata`` at startup (request and response bodies on the OAuth endpoints contain credentials, which must not be written to logs), +``http.client.log=metadata-and-body`` is not allowed and is changed to ``metadata`` at startup (request and response bodies on outgoing HTTP calls can contain credentials, which must not be written to logs), and the ``internalratelimiter`` is always on. Interacting with remote Nuts nodes requires HTTPS: it will refuse to connect to plain HTTP endpoints when in strict mode. diff --git a/docs/pages/deployment/server_options.rst b/docs/pages/deployment/server_options.rst index 8a3aa6591d..db89a27d62 100755 --- a/docs/pages/deployment/server_options.rst +++ b/docs/pages/deployment/server_options.rst @@ -38,6 +38,7 @@ http.cache.maxbytes 10485760 HTTP client maximum size of the response cache in bytes. If 0, the HTTP client does not cache responses. http.client.allowedinternalcidrs [] IP ranges (CIDR notation, e.g. 10.0.0.0/8) exempted from the strict-mode SSRF guard, which otherwise blocks outbound requests to non-public networks. Use to permit internal flows that legitimately target a private address, such as an internal credential offering or an internal OAuth user flow. Leave empty to block all non-public addresses. http.client.deniedcidrs [] IP ranges (CIDR notation) that outbound HTTP requests must never target in strict mode, in addition to the built-in blocked ranges (non-public addresses and cloud metadata endpoints). Use for publicly routable ranges that are internal-only in your infrastructure. Takes precedence over http.client.allowedinternalcidrs. + http.client.log nothing What to log about outgoing HTTP requests made by the node. Options are 'nothing', 'metadata' (log request/response method, URI, status and headers), and 'metadata-and-body' (also log the request/response body). Sensitive headers (e.g. Authorization) are masked. In strictmode, 'metadata-and-body' is not allowed and is changed to 'metadata' at startup. http.internal.address 127.0.0.1:8081 Address and port the server will be listening to for internal-facing endpoints. http.internal.auth.audience Expected audience for JWT tokens (default: hostname) http.internal.auth.authorizedkeyspath Path to an authorized_keys file for trusted JWT signers diff --git a/http/client/client.go b/http/client/client.go index cb4e347ce3..5aba8cfac9 100644 --- a/http/client/client.go +++ b/http/client/client.go @@ -113,15 +113,19 @@ func New(timeout time.Duration) *StrictHTTPClient { } } -// getTransport wraps the given transport with OpenTelemetry instrumentation if tracing is enabled. +// getTransport wraps the given transport with request/response logging and OpenTelemetry +// instrumentation (if tracing is enabled). func getTransport(base http.RoundTripper) http.RoundTripper { + // Always install the logging transport so logging can be enabled after the client is created: + // whether to log is decided per request (see loggingTransport), not when the client is created. + transport := http.RoundTripper(&loggingTransport{base: base}) if tracing.Enabled() { - return otelhttp.NewTransport(base, + return otelhttp.NewTransport(transport, otelhttp.WithSpanNameFormatter(httpSpanName), otelhttp.WithTracerProvider(tracing.GetTracerProvider()), ) } - return base + return transport } // NewWithCache creates a new HTTP client with the given timeout. diff --git a/http/client/client_test.go b/http/client/client_test.go index 19ee707436..c145c4c92d 100644 --- a/http/client/client_test.go +++ b/http/client/client_test.go @@ -30,6 +30,8 @@ import ( "time" "github.com/nuts-foundation/nuts-node/tracing" + "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus/hooks/test" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -83,7 +85,7 @@ func TestStrictHTTPClient(t *testing.T) { client := NewWithTLSConfig(time.Second, &tls.Config{ InsecureSkipVerify: true, }) - ts := client.client.Transport.(*http.Transport) + ts := client.client.Transport.(*loggingTransport).base.(*http.Transport) assert.True(t, ts.TLSClientConfig.InsecureSkipVerify) }) }) @@ -349,14 +351,16 @@ func TestGetTransport(t *testing.T) { assert.NotEqual(t, SafeHttpTransport, transport) }) - t.Run("returns base transport when tracing disabled", func(t *testing.T) { + t.Run("wraps base in logging transport when tracing disabled", func(t *testing.T) { original := tracing.Enabled() tracing.SetEnabled(false) t.Cleanup(func() { tracing.SetEnabled(original) }) transport := getTransport(SafeHttpTransport) - assert.Equal(t, SafeHttpTransport, transport) + logging, ok := transport.(*loggingTransport) + require.True(t, ok) + assert.Equal(t, SafeHttpTransport, logging.base) }) } @@ -379,6 +383,42 @@ func TestNew(t *testing.T) { client := New(time.Second) - assert.Equal(t, SafeHttpTransport, client.client.Transport) + logging, ok := client.client.Transport.(*loggingTransport) + require.True(t, ok) + assert.Equal(t, SafeHttpTransport, logging.base) }) } + +func TestLogging_enabledAfterClientCreation(t *testing.T) { + // Clients are created before the HTTP engine enables logging, so logging must take effect + // for clients that already exist when LogRequests is set. + originalTracing := tracing.Enabled() + tracing.SetEnabled(false) + t.Cleanup(func() { tracing.SetEnabled(originalTracing) }) + t.Cleanup(func() { LogRequests = false }) + StrictMode = false + LogRequests = false + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusOK) + })) + t.Cleanup(server.Close) + + // Create the client first, while logging is still disabled. + httpClient := New(time.Second) + + // Now enable logging, as the HTTP engine does later during startup. + hook := test.NewLocal(logrus.StandardLogger()) + LogRequests = true + + httpRequest, _ := http.NewRequest(http.MethodGet, server.URL, nil) + _, err := httpClient.Do(httpRequest) + + require.NoError(t, err) + messages := make([]string, 0, len(hook.AllEntries())) + for _, entry := range hook.AllEntries() { + messages = append(messages, entry.Message) + } + assert.Contains(t, messages, "HTTP client request", "logging should apply to clients created before it was enabled") + assert.Contains(t, messages, "HTTP client response") +} diff --git a/http/client/requestlogger.go b/http/client/requestlogger.go new file mode 100644 index 0000000000..ad8ec54272 --- /dev/null +++ b/http/client/requestlogger.go @@ -0,0 +1,118 @@ +/* + * Copyright (C) 2024 Nuts community + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + * + */ + +package client + +import ( + "bytes" + "io" + "net/http" + + "github.com/nuts-foundation/nuts-node/http/log" + "github.com/sirupsen/logrus" +) + +// These flags control logging of outgoing HTTP requests and responses. They are read at request time +// (not when a client is created), because clients are often created before the HTTP engine configures +// logging: the HTTP engine is configured last, while other engines create their HTTP clients earlier. +var ( + // LogRequests enables logging of outgoing request and response metadata (method, URI, status, headers). + LogRequests bool + // LogRequestBodies additionally logs request and response bodies. It has no effect unless LogRequests is set. + LogRequestBodies bool +) + +// maskedHeaders are HTTP headers whose values are replaced with a placeholder when logging, +// to avoid leaking credentials into the logs. +var maskedHeaders = map[string]struct{}{ + "Authorization": {}, + "Proxy-Authorization": {}, +} + +const maskedHeaderValue = "[MASKED]" + +// loggingTransport logs outgoing HTTP requests and their responses, according to LogRequests and +// LogRequestBodies. It is installed on every client created by this package; whether anything is +// logged is decided per request. +type loggingTransport struct { + base http.RoundTripper +} + +func (l *loggingTransport) RoundTrip(request *http.Request) (*http.Response, error) { + if !LogRequests { + return l.base.RoundTrip(request) + } + logger := log.Logger() + + logger.WithFields(logrus.Fields{ + "method": request.Method, + "uri": request.URL.String(), + "headers": maskHeaders(request.Header), + }).Info("HTTP client request") + + if LogRequestBodies && request.Body != nil && log.IsLoggableContentType(request.Header.Get("Content-Type")) { + body, err := io.ReadAll(request.Body) + _ = request.Body.Close() + if err != nil { + return nil, err + } + request.Body = io.NopCloser(bytes.NewReader(body)) + logger.Infof("HTTP client request body: %s", string(body)) + } + + response, err := l.base.RoundTrip(request) + if err != nil { + logger.WithFields(logrus.Fields{ + "method": request.Method, + "uri": request.URL.String(), + }).WithError(err).Info("HTTP client request failed") + return nil, err + } + + logger.WithFields(logrus.Fields{ + "method": request.Method, + "uri": request.URL.String(), + "status": response.StatusCode, + "headers": maskHeaders(response.Header), + }).Info("HTTP client response") + + if LogRequestBodies && response.Body != nil && log.IsLoggableContentType(response.Header.Get("Content-Type")) { + body, err := io.ReadAll(response.Body) + _ = response.Body.Close() + if err != nil { + return nil, err + } + response.Body = io.NopCloser(bytes.NewReader(body)) + logger.Infof("HTTP client response body: %s", string(body)) + } + + return response, nil +} + +// maskHeaders returns a copy of the given headers with the values of sensitive headers masked. +func maskHeaders(header http.Header) http.Header { + masked := make(http.Header, len(header)) + for name, values := range header { + if _, ok := maskedHeaders[http.CanonicalHeaderKey(name)]; ok { + masked[name] = []string{maskedHeaderValue} + continue + } + masked[name] = values + } + return masked +} diff --git a/http/client/requestlogger_test.go b/http/client/requestlogger_test.go new file mode 100644 index 0000000000..023cd8c854 --- /dev/null +++ b/http/client/requestlogger_test.go @@ -0,0 +1,191 @@ +/* + * Copyright (C) 2024 Nuts community + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + * + */ + +package client + +import ( + "errors" + "io" + "net/http" + "strings" + "testing" + + "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus/hooks/test" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// roundTripperFunc adapts a function to an http.RoundTripper. +type roundTripperFunc func(*http.Request) (*http.Response, error) + +func (f roundTripperFunc) RoundTrip(r *http.Request) (*http.Response, error) { + return f(r) +} + +func TestLoggingTransport(t *testing.T) { + hook := test.NewLocal(logrus.StandardLogger()) + t.Cleanup(func() { LogRequests = false; LogRequestBodies = false }) + + newRequest := func(t *testing.T, body string) *http.Request { + req, err := http.NewRequest(http.MethodPost, "https://example.com/foo", strings.NewReader(body)) + require.NoError(t, err) + req.Header.Set("Content-Type", "application/json") + return req + } + jsonResponse := func(body string) *http.Response { + header := http.Header{} + header.Set("Content-Type", "application/json") + return &http.Response{ + StatusCode: http.StatusOK, + Header: header, + Body: io.NopCloser(strings.NewReader(body)), + } + } + + t.Run("disabled: nothing is logged", func(t *testing.T) { + hook.Reset() + LogRequests = false + LogRequestBodies = false + sut := &loggingTransport{base: roundTripperFunc(func(_ *http.Request) (*http.Response, error) { + return jsonResponse(`{"hello":"world"}`), nil + })} + + _, err := sut.RoundTrip(newRequest(t, `{"foo":"bar"}`)) + + require.NoError(t, err) + assert.Empty(t, hook.AllEntries()) + }) + + t.Run("metadata only", func(t *testing.T) { + hook.Reset() + LogRequests = true + LogRequestBodies = false + sut := &loggingTransport{base: roundTripperFunc(func(_ *http.Request) (*http.Response, error) { + return jsonResponse(`{"hello":"world"}`), nil + })} + + response, err := sut.RoundTrip(newRequest(t, `{"foo":"bar"}`)) + + require.NoError(t, err) + // Body is left intact for the caller + responseBody, _ := io.ReadAll(response.Body) + assert.Equal(t, `{"hello":"world"}`, string(responseBody)) + // Request and response metadata (incl. headers) is logged, but no bodies + entries := hook.AllEntries() + require.Len(t, entries, 2) + assert.Equal(t, "HTTP client request", entries[0].Message) + assert.Equal(t, http.MethodPost, entries[0].Data["method"]) + assert.Equal(t, "https://example.com/foo", entries[0].Data["uri"]) + assert.Contains(t, entries[0].Data, "headers") + assert.Equal(t, "HTTP client response", entries[1].Message) + assert.Equal(t, http.StatusOK, entries[1].Data["status"]) + assert.Contains(t, entries[1].Data, "headers") + }) + + t.Run("metadata and body", func(t *testing.T) { + hook.Reset() + LogRequests = true + LogRequestBodies = true + var sentBody string + sut := &loggingTransport{base: roundTripperFunc(func(r *http.Request) (*http.Response, error) { + // Request body must still be readable by the actual transport + b, _ := io.ReadAll(r.Body) + sentBody = string(b) + return jsonResponse(`{"hello":"world"}`), nil + })} + + response, err := sut.RoundTrip(newRequest(t, `{"foo":"bar"}`)) + + require.NoError(t, err) + assert.Equal(t, `{"foo":"bar"}`, sentBody) + responseBody, _ := io.ReadAll(response.Body) + assert.Equal(t, `{"hello":"world"}`, string(responseBody)) + entries := hook.AllEntries() + require.Len(t, entries, 4) + assert.Equal(t, "HTTP client request", entries[0].Message) + assert.Contains(t, entries[0].Data, "headers") + assert.Equal(t, "HTTP client request body: {\"foo\":\"bar\"}", entries[1].Message) + assert.Equal(t, "HTTP client response", entries[2].Message) + assert.Equal(t, "HTTP client response body: {\"hello\":\"world\"}", entries[3].Message) + }) + + t.Run("masks sensitive headers", func(t *testing.T) { + hook.Reset() + LogRequests = true + LogRequestBodies = false + sut := &loggingTransport{base: roundTripperFunc(func(_ *http.Request) (*http.Response, error) { + header := http.Header{} + header.Set("Content-Type", "application/json") + header.Set("WWW-Authenticate", "Bearer realm=\"example\"") + return &http.Response{StatusCode: http.StatusUnauthorized, Header: header, Body: io.NopCloser(strings.NewReader("{}"))}, nil + })} + req := newRequest(t, "{}") + req.Header.Set("Authorization", "Bearer super-secret-token") + + _, err := sut.RoundTrip(req) + + require.NoError(t, err) + entries := hook.AllEntries() + requestHeaders := entries[0].Data["headers"].(http.Header) + assert.Equal(t, []string{"[MASKED]"}, requestHeaders["Authorization"]) + assert.Equal(t, "application/json", requestHeaders.Get("Content-Type")) + // Response WWW-Authenticate is a challenge, not a credential, so it is not masked. + responseHeaders := entries[1].Data["headers"].(http.Header) + assert.Equal(t, "Bearer realm=\"example\"", responseHeaders.Get("WWW-Authenticate")) + }) + + t.Run("body not logged for non-loggable content type", func(t *testing.T) { + hook.Reset() + LogRequests = true + LogRequestBodies = true + sut := &loggingTransport{base: roundTripperFunc(func(_ *http.Request) (*http.Response, error) { + header := http.Header{} + header.Set("Content-Type", "application/octet-stream") + return &http.Response{StatusCode: http.StatusOK, Header: header, Body: io.NopCloser(strings.NewReader("binary"))}, nil + })} + req := newRequest(t, "binary") + req.Header.Set("Content-Type", "application/octet-stream") + + _, err := sut.RoundTrip(req) + + require.NoError(t, err) + // Only metadata is logged + entries := hook.AllEntries() + require.Len(t, entries, 2) + assert.Equal(t, "HTTP client request", entries[0].Message) + assert.Equal(t, "HTTP client response", entries[1].Message) + }) + + t.Run("transport error is logged and returned", func(t *testing.T) { + hook.Reset() + LogRequests = true + LogRequestBodies = false + sut := &loggingTransport{base: roundTripperFunc(func(_ *http.Request) (*http.Response, error) { + return nil, errors.New("connection refused") + })} + + _, err := sut.RoundTrip(newRequest(t, "")) + + require.Error(t, err) + entries := hook.AllEntries() + require.Len(t, entries, 2) + assert.Equal(t, "HTTP client request", entries[0].Message) + assert.Equal(t, "HTTP client request failed", entries[1].Message) + }) +} diff --git a/http/cmd/cmd.go b/http/cmd/cmd.go index d2d0ce4154..c88677d584 100644 --- a/http/cmd/cmd.go +++ b/http/cmd/cmd.go @@ -20,6 +20,7 @@ package cmd import ( "fmt" + "github.com/nuts-foundation/nuts-node/http" "github.com/spf13/pflag" ) @@ -35,6 +36,7 @@ func FlagSet() *pflag.FlagSet { flags.String("http.internal.auth.audience", defs.Internal.Auth.Audience, "Expected audience for JWT tokens (default: hostname)") flags.String("http.internal.auth.authorizedkeyspath", defs.Internal.Auth.AuthorizedKeysPath, "Path to an authorized_keys file for trusted JWT signers") flags.String("http.log", string(defs.Log), fmt.Sprintf("What to log about HTTP requests. Options are '%s', '%s' (log request method, URI, IP and response code), and '%s' (log the request and response body, in addition to the metadata). In strictmode, '%s' is not allowed and is changed to '%s' at startup. When debug vebosity is set the authorization headers are also logged when the request is fully logged.", http.LogNothingLevel, http.LogMetadataLevel, http.LogMetadataAndBodyLevel, http.LogMetadataAndBodyLevel, http.LogMetadataLevel)) + flags.String("http.client.log", string(defs.Client.Log), fmt.Sprintf("What to log about outgoing HTTP requests made by the node. Options are '%s', '%s' (log request/response method, URI, status and headers), and '%s' (also log the request/response body). Sensitive headers (e.g. Authorization) are masked. In strictmode, '%s' is not allowed and is changed to '%s' at startup.", http.LogNothingLevel, http.LogMetadataLevel, http.LogMetadataAndBodyLevel, http.LogMetadataAndBodyLevel, http.LogMetadataLevel)) flags.String("http.clientipheader", defs.ClientIPHeaderName, "Case-sensitive HTTP Header that contains the client IP used for audit logs. For the X-Forwarded-For header only link-local, loopback, and private IPs are excluded. Switch to X-Real-IP or a custom header if you see your own proxy/infra in the logs.") flags.Int("http.cache.maxbytes", defs.ResponseCacheSize, "HTTP client maximum size of the response cache in bytes. If 0, the HTTP client does not cache responses.") flags.StringSlice("http.client.allowedinternalcidrs", defs.Client.AllowedInternalCIDRs, "IP ranges (CIDR notation, e.g. 10.0.0.0/8) exempted from the strict-mode SSRF guard, which otherwise blocks outbound requests to non-public networks. Use to permit internal flows that legitimately target a private address, such as an internal credential offering or an internal OAuth user flow. Leave empty to block all non-public addresses.") diff --git a/http/config.go b/http/config.go index 8b4657c1f7..d530ea5018 100644 --- a/http/config.go +++ b/http/config.go @@ -22,6 +22,9 @@ package http func DefaultConfig() Config { return Config{ Log: LogMetadataLevel, + Client: ClientConfig{ + Log: LogNothingLevel, + }, Internal: InternalConfig{ Address: "127.0.0.1:8081", }, @@ -37,9 +40,9 @@ func DefaultConfig() Config { type Config struct { // Log specifies what should be logged of HTTP requests. Log LogLevel `koanf:"log"` + Client ClientConfig `koanf:"client"` Public PublicConfig `koanf:"public"` Internal InternalConfig `koanf:"internal"` - Client ClientConfig `koanf:"client"` // ResponseCacheSize is the maximum number of bytes cached by HTTP clients. ResponseCacheSize int `koanf:"cache.maxbytes"` ClientIPHeaderName string `koanf:"clientipheader"` @@ -47,6 +50,8 @@ type Config struct { // ClientConfig contains the configuration for outbound HTTP clients. type ClientConfig struct { + // Log specifies what should be logged of outgoing HTTP requests. + Log LogLevel `koanf:"log"` // AllowedInternalCIDRs lists IP ranges in CIDR notation (e.g. "10.0.0.0/8") exempted from the // strict-mode SSRF guard, which otherwise blocks outbound requests to non-public networks. Use // to permit internal flows that legitimately target a private address, such as an internal diff --git a/http/engine.go b/http/engine.go index d0527908f0..cd30e1817e 100644 --- a/http/engine.go +++ b/http/engine.go @@ -94,12 +94,7 @@ func (h *Engine) Configure(serverConfig core.ServerConfig) error { return err } - if serverConfig.Strictmode && h.config.Log == LogMetadataAndBodyLevel { - // Request/response bodies contain credentials: the OAuth token endpoint's client_assertion, - // VP tokens, authorization codes and issued access tokens. - log.Logger().Warn("Body logging (http.log=metadata-and-body) is not allowed in strictmode, falling back to metadata") - h.config.Log = LogMetadataLevel - } + h.config.Log = enforceNoBodyLoggingInStrictmode(serverConfig.Strictmode, "http.log", h.config.Log) h.applyTracingMiddleware(h.server) h.applyRateLimiterMiddleware(h.server, serverConfig) @@ -115,6 +110,15 @@ func (h *Engine) configureClient(serverConfig core.ServerConfig) error { if err := client.SetDeniedCIDRs(h.config.Client.DeniedCIDRs); err != nil { return err } + h.config.Client.Log = enforceNoBodyLoggingInStrictmode(serverConfig.Strictmode, "http.client.log", h.config.Client.Log) + // Configure logging of outgoing HTTP requests/responses. + switch h.config.Client.Log { + case LogMetadataLevel: + client.LogRequests = true + case LogMetadataAndBodyLevel: + client.LogRequests = true + client.LogRequestBodies = true + } // Configure the HTTP caching client, if enabled. Set it to http.DefaultTransport so it can be used by any subsystem. if h.config.ResponseCacheSize > 0 { client.DefaultCachingTransport = client.NewCachingTransport(client.SafeHttpTransport, h.config.ResponseCacheSize) @@ -122,6 +126,19 @@ func (h *Engine) configureClient(serverConfig core.ServerConfig) error { return nil } +// enforceNoBodyLoggingInStrictmode downgrades level from metadata-and-body to metadata in strict +// mode, with a warning. Request/response bodies on the OAuth endpoints (both incoming, e.g. +// http.log, and outgoing, e.g. http.client.log) carry credentials: client_assertion, VP tokens, +// authorization codes and issued access tokens. Those are exactly the loggable content types, so +// full body logging must not be possible on a strictmode node. +func enforceNoBodyLoggingInStrictmode(strictmode bool, flagName string, level LogLevel) LogLevel { + if strictmode && level == LogMetadataAndBodyLevel { + log.Logger().Warnf("Body logging (%s=metadata-and-body) is not allowed in strictmode, falling back to metadata", flagName) + return LogMetadataLevel + } + return level +} + func (h *Engine) applyTracingMiddleware(echoServer core.EchoRouter) { // Only apply tracing middleware if tracing is enabled if !tracing.Enabled() { diff --git a/http/engine_test.go b/http/engine_test.go index 7bb1536c9f..bfcf27b4dc 100644 --- a/http/engine_test.go +++ b/http/engine_test.go @@ -300,6 +300,56 @@ func TestEngine_Configure(t *testing.T) { }) } +func TestEngine_configureClient(t *testing.T) { + reset := func() { client.LogRequests = false; client.LogRequestBodies = false } + t.Run("logging disabled by default", func(t *testing.T) { + reset() + t.Cleanup(reset) + engine := New(func() {}, nil) + + engine.configureClient(*core.NewServerConfig()) + + assert.False(t, client.LogRequests) + assert.False(t, client.LogRequestBodies) + }) + t.Run("metadata logs requests but not bodies", func(t *testing.T) { + reset() + t.Cleanup(reset) + engine := New(func() {}, nil) + engine.config.Client.Log = LogMetadataLevel + + engine.configureClient(*core.NewServerConfig()) + + assert.True(t, client.LogRequests) + assert.False(t, client.LogRequestBodies) + }) + t.Run("metadata-and-body logs requests and bodies", func(t *testing.T) { + reset() + t.Cleanup(reset) + engine := New(func() {}, nil) + engine.config.Client.Log = LogMetadataAndBodyLevel + + serverConfig := core.NewServerConfig() + serverConfig.Strictmode = false + engine.configureClient(*serverConfig) + + assert.True(t, client.LogRequests) + assert.True(t, client.LogRequestBodies) + }) + t.Run("metadata-and-body falls back to metadata in strictmode", func(t *testing.T) { + reset() + t.Cleanup(reset) + engine := New(func() {}, nil) + engine.config.Client.Log = LogMetadataAndBodyLevel + + engine.configureClient(*core.NewServerConfig()) + + assert.True(t, client.LogRequests) + assert.False(t, client.LogRequestBodies) + assert.Equal(t, LogLevel(LogMetadataLevel), engine.config.Client.Log) + }) +} + func TestEngine_LoggingMiddleware(t *testing.T) { output := new(bytes.Buffer) logrus.StandardLogger().AddHook(&writer.Hook{ diff --git a/http/log/contenttype.go b/http/log/contenttype.go new file mode 100644 index 0000000000..e199b5f1fc --- /dev/null +++ b/http/log/contenttype.go @@ -0,0 +1,35 @@ +/* + * Copyright (C) 2024 Nuts community + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + * + */ + +package log + +import "mime" + +// IsLoggableContentType returns true for content types whose body is safe and useful to log as text. +// It is the single source of truth for both client- and server-side HTTP body logging. +func IsLoggableContentType(contentType string) bool { + mediaType, _, _ := mime.ParseMediaType(contentType) + switch mediaType { + case "application/json", + "application/did+json", + "application/vc+json", + "application/x-www-form-urlencoded": + return true + } + return false +} diff --git a/http/requestlogger.go b/http/requestlogger.go index 9a30299b27..c35573d41c 100644 --- a/http/requestlogger.go +++ b/http/requestlogger.go @@ -22,8 +22,8 @@ import ( "github.com/labstack/echo/v4" "github.com/labstack/echo/v4/middleware" "github.com/nuts-foundation/nuts-node/core" + "github.com/nuts-foundation/nuts-node/http/log" "github.com/sirupsen/logrus" - "mime" ) // requestLoggerMiddleware returns middleware that logs metadata of HTTP requests. @@ -65,30 +65,15 @@ func bodyLoggerMiddleware(skipper middleware.Skipper, logger *logrus.Entry) echo return middleware.BodyDumpWithConfig(middleware.BodyDumpConfig{ Handler: func(e echo.Context, request []byte, response []byte) { requestContentType := e.Request().Header.Get("Content-Type") - if isLoggableContentType(requestContentType) { + if log.IsLoggableContentType(requestContentType) { logger.Infof("HTTP request body: %s", string(request)) } responseContentType := e.Response().Header().Get("Content-Type") - if isLoggableContentType(responseContentType) { + if log.IsLoggableContentType(responseContentType) { logger.Infof("HTTP response body: %s", string(response)) } }, Skipper: skipper, }) } - -func isLoggableContentType(contentType string) bool { - mediaType, _, _ := mime.ParseMediaType(contentType) - switch mediaType { - case "application/json": - fallthrough - case "application/did+json": - fallthrough - case "application/vc+json": - fallthrough - case "application/x-www-form-urlencoded": - return true - } - return false -}