Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion docs/pages/deployment/server_options.rst
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@
http.clientipheader X-Forwarded-For 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.
http.log metadata What to log about HTTP requests. Options are 'nothing', 'metadata' (log request method, URI, IP and response code), and 'metadata-and-body' (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.cache.maxbytes 10485760 HTTP client maximum size of the response cache in bytes. If 0, the HTTP client does not cache responses.
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.
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
Expand Down Expand Up @@ -70,5 +71,5 @@
tracing.servicename Service name reported to the tracing backend. Defaults to 'nuts-node'.
**policy**
policy.directory ./config/policy Directory to read policy files from. Policy files are JSON files that contain a scope to PresentationDefinition mapping.
policy.authzen.endpoint Base URL of the AuthZen PDP endpoint. Required when any credential profile uses scope_policy 'dynamic'.
policy.authzen.endpoint Base URL of the AuthZen PDP endpoint. Required when any credential profile uses scope_policy 'dynamic'; the node refuses to start if such a profile is configured but this flag is empty.
======================================== =================================================================================================================================================================================================================================================================================================================================================================================================================================================================== ============================================================================================================================================================================================================================================================================================================================================
10 changes: 7 additions & 3 deletions http/client/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -81,15 +81,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.
Expand Down
48 changes: 44 additions & 4 deletions http/client/client_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
Expand Down Expand Up @@ -81,7 +83,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)
})
})
Expand Down Expand Up @@ -215,14 +217,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)
})
}

Expand All @@ -245,6 +249,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")
}
118 changes: 118 additions & 0 deletions http/client/requestlogger.go
Original file line number Diff line number Diff line change
@@ -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 <https://www.gnu.org/licenses/>.
*
*/

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
}
Loading
Loading