JSON-LD: time out remote context fetches and remember failures

docs/pages/deployment/verifiable-credentials.rst

@@ -53,6 +53,8 @@ Fetching & Caching
 ^^^^^^^^^^^^^^^^^^
 
 During startup of the node, remote contexts are fetched and cached. If the contents of a remote context changes, the node must be restarted in order for these changes to have effect. Only remote context listed in the `remoteallowlist` are fetched.
+When strict mode is disabled, the node also fetches contexts that are not on the `remoteallowlist` from the internet, when a credential it processes refers to them. Use strict mode outside of development.
+A remote context fetch fails after 5 seconds. A context that failed to load is not fetched again for 5 minutes: credentials referring to it fail immediately during that time, and are retried later.
 Local mappings can be used to pin a version of a context, so no unseen changes can be made. Working with local mappings is also useful for developing purposes when the remote context is older or non-existent. When you work with local mappings, make sure all nodes involved in the use-case have the same custom context configured.
 
 Searching and indexing

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.
 
 ## Minor fixes/changes
+* #4615: JSON-LD: fetching a remote context now times out after 5 seconds, and a context that failed to load is not fetched again for 5 minutes. Previously the fetch had no timeout: in non-strict mode a context server that never answered stopped network synchronization at the first credential referring to it, without logging an error. Remote contexts are now fetched with the node's HTTP client, so the strict-mode URL checks apply and the node identifies with its own User-Agent. By @reinkrul in https://github.com/nuts-foundation/nuts-node/pull/4617
 * Network: a peer that rejects an outbound connection with ``already connected`` is now retried with exponential backoff instead of every 1 to 5 seconds. By @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4467
 * Network: the default of ``network.maxbackoff`` is lowered from ``24h`` to ``1h``. The backoff is persisted across restarts and only reset when a peer's NutsComm address changes, so a peer that was unreachable for a few days could previously go unattempted for up to a day after it came back. By @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4467
 * Network: failed connection attempts are now logged at debug level instead of warning level. A warning is logged once, on the attempt that reaches ``network.maxbackoff``, so an unreachable peer no longer repeats the same warning on every retry. By @stevenvegt in https://github.com/nuts-foundation/nuts-node/pull/4467

jsonld/ldutils.go

@@ -24,13 +24,25 @@ import (
 	"errors"
 	"fmt"
 	ssi "github.com/nuts-foundation/go-did"
+	"github.com/nuts-foundation/nuts-node/v6/http/client"
 	"github.com/nuts-foundation/nuts-node/v6/jsonld/log"
 	"github.com/nuts-foundation/nuts-node/v6/vcr/assets"
 	"github.com/piprate/json-gold/ld"
 	"io/fs"
+	"net/http"
 	"net/url"
+	"sync"
+	"time"
 )
 
+// remoteContextTimeout bounds a single fetch of a remote JSON-LD context document.
+// Contexts are fetched while processing network transactions, so a server that never answers must not block that processing.
+var remoteContextTimeout = 5 * time.Second
+
+// remoteContextFailureTTL is how long a failed remote context fetch is remembered.
+// During that time, loads of the same URL fail immediately with the original error instead of fetching again.
+var remoteContextFailureTTL = 5 * time.Minute
+
 // ContextsConfig contains config for json-ld document loader
 type ContextsConfig struct {
 	// RemoteAllowList A list with urls as string which are allowed to request
@@ -193,9 +205,11 @@ func NewContextLoader(allowUnlistedExternalCalls bool, contexts ContextsConfig)
 		ld.NewCachingDocumentLoader(
 			// Handle all embedded file system files
 			NewEmbeddedFSDocumentLoader(assets.Assets,
-				// Last in the chain is the defaultLoader which can resolve
-				// local files and remote (via http) context documents
-				ld.NewDefaultDocumentLoader(nil))))
+				// Remember failed remote fetches, so a dead context server costs one timeout instead of one per document
+				newFailureCachingLoader(remoteContextFailureTTL,
+					// Last in the chain is the defaultLoader which can resolve
+					// local files and remote (via http) context documents
+					ld.NewDefaultDocumentLoader(newRemoteContextHTTPClient())))))
 
 	// If unlisted calls are not allowed, filter all calls to the defaultLoader
 	if !allowUnlistedExternalCalls {
@@ -219,6 +233,87 @@ func NewContextLoader(allowUnlistedExternalCalls bool, contexts ContextsConfig)
 	return loader, nil
 }
 
+// newRemoteContextHTTPClient returns the HTTP client used to fetch remote JSON-LD contexts.
+// json-gold needs a *http.Client, so the node's strict HTTP client (timeout, SSRF guard, URL checks, response size limit)
+// is wrapped as its transport.
+func newRemoteContextHTTPClient() *http.Client {
+	return &http.Client{Transport: strictClientTransport{client: client.New(remoteContextTimeout)}}
+}
+
+// strictClientTransport adapts a client.StrictHTTPClient to http.RoundTripper.
+// The strict client follows redirects itself, so the outer http.Client receives the final response.
+type strictClientTransport struct {
+	client *client.StrictHTTPClient
+}
+
+func (s strictClientTransport) RoundTrip(request *http.Request) (*http.Response, error) {
+	// RoundTrip must not modify the request, but the strict client sets the User-Agent header.
+	return s.client.Do(request.Clone(request.Context()))
+}
+
+type failedLoad struct {
+	err   error
+	until time.Time
+}
+
+// failureCachingLoader remembers failed loads per URL for a fixed time, and returns the remembered error without
+// calling the next loader during that time. Successful loads are not cached here (see ld.NewCachingDocumentLoader).
+type failureCachingLoader struct {
+	ttl        time.Duration
+	nextLoader ld.DocumentLoader
+	mutex      sync.Mutex
+	failures   map[string]failedLoad
+}
+
+func newFailureCachingLoader(ttl time.Duration, nextLoader ld.DocumentLoader) *failureCachingLoader {
+	return &failureCachingLoader{
+		ttl:        ttl,
+		nextLoader: nextLoader,
+		failures:   map[string]failedLoad{},
+	}
+}
+
+// LoadDocument returns the remembered error if loading u failed less than ttl ago, otherwise it calls the next loader.
+func (f *failureCachingLoader) LoadDocument(u string) (*ld.RemoteDocument, error) {
+	if err := f.recentFailure(u); err != nil {
+		log.Logger().Debugf("Not fetching JSON-LD context, it failed recently (url=%s)", u)
+		return nil, err
+	}
+	document, err := f.nextLoader.LoadDocument(u)
+	if err != nil {
+		f.recordFailure(u, err)
+		log.Logger().WithError(err).Warnf("Failed to load JSON-LD context, not retrying for %s (url=%s)", f.ttl, u)
+	}
+	return document, err
+}
+
+func (f *failureCachingLoader) recentFailure(u string) error {
+	f.mutex.Lock()
+	defer f.mutex.Unlock()
+	failure, ok := f.failures[u]
+	if !ok {
+		return nil
+	}
+	if time.Now().After(failure.until) {
+		delete(f.failures, u)
+		return nil
+	}
+	return failure.err
+}
+
+func (f *failureCachingLoader) recordFailure(u string, err error) {
+	f.mutex.Lock()
+	defer f.mutex.Unlock()
+	now := time.Now()
+	// Prune expired entries, so the map stays bounded by the number of URLs that failed within the last ttl.
+	for failedURL, failure := range f.failures {
+		if now.After(failure.until) {
+			delete(f.failures, failedURL)
+		}
+	}
+	f.failures[u] = failedLoad{err: err, until: now.Add(f.ttl)}
+}
+
 // LDUtil package a set of often used JSON-LD operations for re-usability.
 type LDUtil struct {
 	LDDocumentLoader ld.DocumentLoader

jsonld/ldutils_test.go

@@ -24,11 +24,15 @@ import (
 	"fmt"
 	"net/http"
 	"net/http/httptest"
+	"sync/atomic"
 	"testing"
+	"time"
 
 	ssi "github.com/nuts-foundation/go-did"
+	"github.com/nuts-foundation/nuts-node/v6/core"
 	"github.com/piprate/json-gold/ld"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 //go:embed test/*
@@ -273,3 +277,126 @@ func Test_filteredDocumentLoader(t *testing.T) {
 		assert.False(t, mockLoader.Called)
 	})
 }
+
+func TestNewContextLoader_RemoteContexts(t *testing.T) {
+	t.Run("fails when the server does not answer within the timeout", func(t *testing.T) {
+		timeout := remoteContextTimeout
+		remoteContextTimeout = 100 * time.Millisecond
+		defer func() { remoteContextTimeout = timeout }()
+		srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			// never answer, until the client gives up
+			<-r.Context().Done()
+		}))
+		defer srv.Close()
+		loader, err := NewContextLoader(true, DefaultContextConfig())
+		require.NoError(t, err)
+
+		start := time.Now()
+		_, err = loader.LoadDocument(srv.URL + "/context.jsonld")
+
+		var jsonLDError *ld.JsonLdError
+		require.ErrorAs(t, err, &jsonLDError)
+		assert.Equal(t, ld.LoadingDocumentFailed, jsonLDError.Code)
+		assert.Less(t, time.Since(start), 5*time.Second)
+	})
+	t.Run("does not fetch a context again after it failed", func(t *testing.T) {
+		var requests atomic.Int32
+		srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			requests.Add(1)
+			w.WriteHeader(http.StatusNotFound)
+		}))
+		defer srv.Close()
+		loader, err := NewContextLoader(true, DefaultContextConfig())
+		require.NoError(t, err)
+
+		_, err1 := loader.LoadDocument(srv.URL + "/context.jsonld")
+		_, err2 := loader.LoadDocument(srv.URL + "/context.jsonld")
+
+		require.Error(t, err1)
+		assert.Same(t, err1, err2)
+		assert.Equal(t, int32(1), requests.Load())
+	})
+	t.Run("identifies as the Nuts node", func(t *testing.T) {
+		var userAgent string
+		srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			userAgent = r.UserAgent()
+			w.Header().Set("Content-Type", "application/ld+json")
+			_, _ = w.Write([]byte(`{"@context":{}}`))
+		}))
+		defer srv.Close()
+		loader, err := NewContextLoader(true, DefaultContextConfig())
+		require.NoError(t, err)
+
+		_, err = loader.LoadDocument(srv.URL + "/context.jsonld")
+
+		require.NoError(t, err)
+		assert.Equal(t, core.UserAgent(), userAgent)
+	})
+}
+
+type countingLoader struct {
+	calls int
+	err   error
+}
+
+func (c *countingLoader) LoadDocument(u string) (*ld.RemoteDocument, error) {
+	c.calls++
+	if c.err != nil {
+		return nil, c.err
+	}
+	return &ld.RemoteDocument{DocumentURL: u}, nil
+}
+
+func Test_failureCachingLoader(t *testing.T) {
+	const contextURL = "https://example.com/context.jsonld"
+	t.Run("returns the remembered error without calling the next loader", func(t *testing.T) {
+		next := &countingLoader{err: ld.NewJsonLdError(ld.LoadingDocumentFailed, "boom")}
+		sut := newFailureCachingLoader(time.Minute, next)
+
+		_, err1 := sut.LoadDocument(contextURL)
+		_, err2 := sut.LoadDocument(contextURL)
+
+		assert.Same(t, err1, err2)
+		assert.Equal(t, 1, next.calls)
+	})
+	t.Run("calls the next loader again after the failure expired", func(t *testing.T) {
+		next := &countingLoader{err: ld.NewJsonLdError(ld.LoadingDocumentFailed, "boom")}
+		sut := newFailureCachingLoader(time.Minute, next)
+		_, _ = sut.LoadDocument(contextURL)
+		sut.failures[contextURL] = failedLoad{err: next.err, until: time.Now().Add(-time.Second)}
+
+		_, _ = sut.LoadDocument(contextURL)
+
+		assert.Equal(t, 2, next.calls)
+	})
+	t.Run("does not remember successful loads", func(t *testing.T) {
+		next := &countingLoader{}
+		sut := newFailureCachingLoader(time.Minute, next)
+
+		_, err1 := sut.LoadDocument(contextURL)
+		_, err2 := sut.LoadDocument(contextURL)
+
+		assert.NoError(t, err1)
+		assert.NoError(t, err2)
+		assert.Equal(t, 2, next.calls)
+	})
+	t.Run("remembers failures per URL", func(t *testing.T) {
+		next := &countingLoader{err: ld.NewJsonLdError(ld.LoadingDocumentFailed, "boom")}
+		sut := newFailureCachingLoader(time.Minute, next)
+
+		_, _ = sut.LoadDocument(contextURL)
+		_, _ = sut.LoadDocument("https://example.com/other.jsonld")
+
+		assert.Equal(t, 2, next.calls)
+	})
+	t.Run("prunes expired failures when recording a new one", func(t *testing.T) {
+		next := &countingLoader{err: ld.NewJsonLdError(ld.LoadingDocumentFailed, "boom")}
+		sut := newFailureCachingLoader(time.Minute, next)
+		sut.failures["https://example.com/expired.jsonld"] = failedLoad{err: next.err, until: time.Now().Add(-time.Second)}
+
+		_, _ = sut.LoadDocument(contextURL)
+
+		assert.Len(t, sut.failures, 1)
+		assert.Contains(t, sut.failures, contextURL)
+	})
+}