fix(http): fall back to metadata logging in strictmode

docs/pages/deployment/configuration.rst

@@ -93,6 +93,7 @@ As a general safety precaution ``auth.contractvalidators`` ignores the ``dummy``
 requesting an access token from another node on ``/n2n/auth/v1/accesstoken`` does not return any error details,
 ``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),
 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.

docs/pages/release_notes.rst

@@ -14,6 +14,7 @@ Unreleased
 * #4233: ``request-credential`` API gains an optional ``credential_request_params`` JSON object overlaid on top of the OpenID4VCI Credential Request body sent to the issuer. Lets the wallet talk to issuers that accept additional fields, or to override the credential request entirely.
 
 ## Security
+* #4440: In strictmode, ``http.log: metadata-and-body`` is no longer honored: the node resets it to ``metadata`` at startup and logs a warning. Full body logging wrote OAuth token endpoint request and response bodies (client assertions, VP tokens, authorization codes and issued access tokens) to the log at Info severity. Non-strictmode deployments are unaffected. By @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4440
 * #4421: Stop reflecting fetched HTTP response bodies in API responses. The OAuth2 and OpenID4VCI callback handlers no longer place a remote endpoint's response body or error text into the returned ``error_description``, the did:web resolver no longer returns the fetched document body in its parse error, and the Discovery Service client no longer includes the remote server's error response in errors returned through the discovery APIs. Such content is now logged (truncated) for diagnostics instead. Static context such as the endpoint that failed is retained. By @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4421
 * #4420: Harden the strict-mode HTTP client against SSRF. In strict mode the client now refuses at connect time to reach non-public addresses (loopback, private/RFC1918, unique local, link-local and unspecified), checked against the resolved IP so DNS-rebinding cannot bypass it, and refuses to follow a redirect that downgrades from HTTPS to HTTP. Cloud provider metadata endpoints are always blocked, following the OWASP SSRF prevention cheat sheet. Deployments that legitimately reach a private address for an internal flow (such as an internal credential offering or OAuth user flow) can permit specific ranges with ``http.client.allowedinternalcidrs``; publicly routable ranges that are internal-only can additionally be blocked with ``http.client.deniedcidrs``, which takes precedence. Reported by @raysabee, fixed by @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4420
 

http/cmd/cmd.go

@@ -34,7 +34,7 @@ func FlagSet() *pflag.FlagSet {
 	flags.String("http.internal.auth.type", string(defs.Internal.Auth.Type), fmt.Sprintf("Whether to enable authentication for /internal endpoints, specify '%s' for bearer token mode or '%s' for legacy bearer token mode.", http.BearerTokenAuthV2, http.BearerTokenAuth))
 	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). When debug vebosity is set the authorization headers are also logged when the request is fully logged.", http.LogNothingLevel, http.LogMetadataLevel, http.LogMetadataAndBodyLevel))
+	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.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.")

http/engine.go

@@ -94,6 +94,13 @@ 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.applyTracingMiddleware(h.server)
 	h.applyRateLimiterMiddleware(h.server, serverConfig)
 	h.applyLoggerMiddleware(h.server, []string{MetricsPath, StatusPath, HealthPath}, h.config.Log)

http/engine_test.go

@@ -365,8 +365,10 @@ func TestEngine_LoggingMiddleware(t *testing.T) {
 		engine := New(noop, nil)
 		engine.config = createTestConfig()
 		engine.config.Log = LogMetadataAndBodyLevel
+		serverConfig := core.NewServerConfig()
+		serverConfig.Strictmode = false
 
-		err := engine.Configure(*core.NewServerConfig())
+		err := engine.Configure(*serverConfig)
 		require.NoError(t, err)
 		engine.Router().POST("/", func(c echo.Context) error {
 			return c.JSON(200, "hello, world")
@@ -385,6 +387,48 @@ func TestEngine_LoggingMiddleware(t *testing.T) {
 			assert.Contains(t, output.String(), `HTTP response body: \"hello, world\"`)
 		})
 	})
+	t.Run("bodyLogger is disabled in strict mode", func(t *testing.T) {
+		// Configure sets the package-global client strict mode flag; restore it afterwards.
+		oldStrictMode := client.StrictMode
+		t.Cleanup(func() { client.StrictMode = oldStrictMode })
+		warnOutput := new(bytes.Buffer)
+		logrus.StandardLogger().AddHook(&writer.Hook{
+			Writer:    warnOutput,
+			LogLevels: []logrus.Level{logrus.WarnLevel},
+		})
+		engine := New(noop, nil)
+		engine.config = createTestConfig()
+		engine.config.Log = LogMetadataAndBodyLevel
+		serverConfig := core.NewServerConfig()
+		serverConfig.Strictmode = true
+
+		err := engine.Configure(*serverConfig)
+		require.NoError(t, err)
+		engine.Router().POST("/", func(c echo.Context) error {
+			return c.JSON(200, "very-secret-response")
+		})
+
+		err = engine.Start()
+		require.NoError(t, err)
+		defer engine.Shutdown()
+
+		assertServerStarted(t, engine.config.Internal.Address)
+
+		output.Reset()
+		response, err := http.Post("http://"+engine.config.Public.Address, "application/json", bytes.NewReader([]byte(`{"assertion": "very-secret-request"}`)))
+		require.NoError(t, err)
+		require.Equal(t, http.StatusOK, response.StatusCode)
+
+		logs := output.String()
+		// Metadata logging must still work: a request log entry with the response status.
+		assert.Contains(t, logs, `msg="HTTP request"`)
+		assert.Contains(t, logs, "status=200")
+		// Neither the request nor the response body content may reach the log.
+		assert.NotContains(t, logs, "very-secret-request")
+		assert.NotContains(t, logs, "very-secret-response")
+		assert.Equal(t, LogLevel(LogMetadataLevel), engine.config.Log)
+		assert.Contains(t, warnOutput.String(), "Body logging (http.log=metadata-and-body) is not allowed in strictmode, falling back to metadata")
+	})
 }
 
 func assertServerStarted(t *testing.T, address string) {