Repository: avenga/couper
Pull request #481 (2022-04-12 16:52:25)

Synced json start
#433 introduced a regression related to jwks url backends which prevents Couper to start on jwks backend errors.

---
<details>
    <summary>Reviewer checklist</summary>
    <ul>
        <li>Read PR description: a summary about the changes is required</li>
        <li>Changelog updated</li>
        <li>Documentation: docs/{Reference, Cli, ...}, Docker and cli help/usage</li>
        <li>Pulled branch, manually tested</li>
        <li>Verified requirements are met</li>
        <li>Reviewed the code</li>
        <li>Reviewed the related tests</li>
    </ul>
</details>



Patch:
diff --git a/accesscontrol/jwk/jwks.go b/accesscontrol/jwk/jwks.go
index abeaec90..b59f4467 100644
--- a/accesscontrol/jwk/jwks.go
+++ b/accesscontrol/jwk/jwks.go
@@ -47,12 +47,6 @@ func NewJWKS(uri string, ttl string, transport http.RoundTripper) (*JWKS, error)
 
 	jwks := &JWKS{}
 	jwks.syncedJSON, err = jsn.NewSyncedJSON(file, "jwks_url", uri, transport, "jwks", timetolive, jwks)
-	if err != nil {
-		return nil, err
-	}
-
-	_, err = jwks.Data("") // obtain any initial fetch errors
-
 	return jwks, err
 }
 
diff --git a/json/synced_json.go b/json/synced_json.go
index fd3afb72..4042a89b 100644
--- a/json/synced_json.go
+++ b/json/synced_json.go
@@ -65,6 +65,7 @@ func (s *SyncedJSON) sync(ctx context.Context) {
 		expired = time.After(s.ttl)
 	}
 
+	backoff := time.Second
 	for {
 		select {
 		case <-ctx.Done():
@@ -72,10 +73,14 @@ func (s *SyncedJSON) sync(ctx context.Context) {
 		case <-expired:
 			err = s.fetch()
 			if err != nil {
-				time.Sleep(time.Second * 2)
+				time.Sleep(backoff)
+				if backoff < time.Minute {
+					backoff *= 2
+				}
 				continue
 			}
 			expired = time.After(s.ttl)
+			backoff = time.Second
 		case r := <-s.dataRequest:
 			r <- &dataRequest{
 				err: err,


Test patch:
diff --git a/accesscontrol/jwt_test.go b/accesscontrol/jwt_test.go
index 08374105..a1fc148e 100644
--- a/accesscontrol/jwt_test.go
+++ b/accesscontrol/jwt_test.go
@@ -12,12 +12,12 @@ import (
 	"reflect"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/dgrijalva/jwt-go/v4"
 	"github.com/hashicorp/hcl/v2"
 	"github.com/hashicorp/hcl/v2/hcltest"
 	"github.com/sirupsen/logrus"
-	logrustest "github.com/sirupsen/logrus/hooks/test"
 	"github.com/zclconf/go-cty/cty"
 
 	ac "github.com/avenga/couper/accesscontrol"
@@ -816,7 +816,7 @@ func TestJwtConfig(t *testing.T) {
 			  }
 			}
 			`,
-			`backend error: anonymous_5_8_jwks_url: connecting to anonymous_5_8_jwks_url "no-back.end:80" failed: dial tcp: lookup no-back.end`,
+			`backend error: anonymous_5_8_jwks_url: connecting to anonymous_5_8_jwks_url "no-back.end:80" failed: dial tcp: lookup no-back.end: no such host`,
 		},
 		{
 			"signature_algorithm + jwks_url",
@@ -892,10 +892,12 @@ func TestJwtConfig(t *testing.T) {
 		},
 	}
 
-	log, _ := logrustest.NewNullLogger()
+	log, hook := test.NewLogger()
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(subT *testing.T) {
+			hook.Reset()
+
 			conf, err := configload.LoadBytes([]byte(tt.hcl), "couper.hcl")
 			if conf != nil {
 				logger := log.WithContext(context.TODO())
@@ -906,20 +908,33 @@ func TestJwtConfig(t *testing.T) {
 				_, err = runtime.NewServerConfiguration(conf, logger, cache.New(logger, tmpStoreCh))
 			}
 
-			var errMsg = ""
+			var errMsg, expectedError string
 			if err != nil {
 				if _, ok := err.(errors.GoError); ok {
 					errMsg = err.(errors.GoError).LogError()
 				} else {
 					errMsg = err.Error()
 				}
+				if tt.error != "" {
+					expectedError = "configuration error: myac: " + tt.error
+				}
+			} else {
+				expectedError = tt.error
 			}
 
 			if tt.error == "" && errMsg == "" {
 				return
 			}
 
-			expectedError := "configuration error: myac: " + tt.error
+			time.Sleep(time.Second / 2) // sync routine start
+
+			for _, e := range hook.AllEntries() {
+				if e.Level != logrus.ErrorLevel {
+					continue
+				}
+				errMsg = e.Message
+				break
+			}
 
 			if !strings.HasPrefix(errMsg, expectedError) {
 				subT.Errorf("%q: Unexpected configuration error:\n\tWant: %q\n\tGot:  %q", tt.name, expectedError, errMsg)
diff --git a/server/http_integration_test.go b/server/http_integration_test.go
index b5ff8552..193043bb 100644
--- a/server/http_integration_test.go
+++ b/server/http_integration_test.go
@@ -3452,6 +3452,7 @@ func TestJWTAccessControl(t *testing.T) {
 		{"local RSA JWKS without kid", "/jwks/rsa", http.Header{"Authorization": []string{"Bearer eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOjEyMzQ1Njc4OTB9.V9skZUql-mHqwOzVdzamqAOWSx8fjEA-6py0nfxLRSl7h1bQvqUCWMZUAkMJK6RuJ3y5YAr8ZBXZsh4rwABp_3hitQitMXnV6nr5qfzVDE9-mdS4--Bj46-JlkHacNcK24qlnn_EXGJlzCj6VFgjObSy6geaTY9iDVF6EzjZkxc1H75XRlNYAMu-0KCGfKdte0qASeBKrWnoFNEpnXZ_jhqRRNVkaSBj7_HPXD6oPqKBQf6Jh6fGgdz6q4KNL-t-Qa2_eKc8tkrYNdTdxco-ufmmLiUQ_MzRAqowHb2LdsFJP9rN2QT8MGjRXqGvkCd0EsLfqAeCPkTXs1kN8LGlvw"}}, "", http.StatusForbidden, "", `access control error: JWKS: token is unverifiable: Keyfunc returned an error`},
 		{"local RSA JWKS with unsupported kid", "/jwks/rsa", http.Header{"Authorization": []string{"Bearer eyJraWQiOiJyczI1Ni11bnN1cHBvcnRlZCIsImFsZyI6IlJTMjU2IiwidHlwIjoiSldUIn0.eyJzdWIiOjEyMzQ1Njc4OTB9.wx1MkMgJhh6gnOvvrnnkRpEUDe-0KpKWw9ZIfDVHtGkuL46AktBgfbaW1ttB78wWrIW9OPfpLqKwkPizwfShoXKF9qN-6TlhPSWIUh0_kBHEj7H4u45YZXH1Ha-r9kGzly1PmLx7gzxUqRpqYnwo0TzZSEr_a8rpfWaC0ZJl3CKARormeF3tzW_ARHnGUqck4VjPfX50Ot6B5nool6qmsCQLLmDECIKBDzZicqdeWH7JPvRZx45R5ZHJRQpD3Z2iqVIF177Wj1C8q75Gxj2PXziIVKplmIUrKN-elYj3kBtJkDFneb384FPLuzsQZOR6HQmKXG2nA1WOfsblJSz3FA"}}, "", http.StatusForbidden, "", "access control error: JWKS: token is unverifiable: Keyfunc returned an error"},
 		{"local RSA JWKS with non-parsable cert", "/jwks/rsa", http.Header{"Authorization": []string{"Bearer eyJraWQiOiJyczI1Ni13cm9uZy1jZXJ0IiwiYWxnIjoiUlMyNTYiLCJ0eXAiOiJKV1QifQ.eyJzdWIiOjEyMzQ1Njc4OTB9.n--6mjzfnPKbaYAquBK3v6gsbmvEofSprk3jwWGSKPdDt2VpVOe8ZNtGhJj_3f1h86-wg-gEQT5GhJmsI47X9MJ70j74dqhXUF6w4782OljstP955whuSM9hJAIvUw_WV1sqtkiESA-CZiNJIBydL5YzV2nO3gfEYdy9EdMJ2ykGLRBajRxhShxsfaZykFKvvWpy1LbUc-gfRZ4q8Hs9B7b_9RGdbpRwBtwiqPPzhjC5O86vk7ZoiG9Gq7pg52yEkLqdN4a5QkfP8nNeTTMAsqPQL1-1TAC7rIGekoUtoINRR-cewPpZ_E7JVxXvBVvPe3gX_2NzGtXkLg5QDt6RzQ"}}, "", http.StatusForbidden, "", "access control error: JWKS: token is unverifiable: Keyfunc returned an error"},
+		{"local RSA JWKS not found", "/jwks/rsa/not_found", http.Header{"Authorization": []string{"Bearer " + rsaToken}}, "", http.StatusForbidden, "", "access control error: JWKS_not_found: token is unverifiable: Keyfunc returned an error"},
 		{"local RSA JWKS", "/jwks/rsa", http.Header{"Authorization": []string{"Bearer " + rsaToken}}, "", http.StatusOK, "", ""},
 		{"local RSA JWKS with scope", "/jwks/rsa/scope", http.Header{"Authorization": []string{"Bearer eyJhbGciOiJSUzI1NiIsImtpZCI6InJzMjU2IiwidHlwIjoiSldUIn0.eyJzdWIiOjEyMzQ1Njc4OTAsInNjb3BlIjpbImZvbyIsImJhciJdfQ.IFqIF_9ELXl3A-oy52G0Sg5f34ah3araOxFboskEw110nXdb_-UuxCnG0naFVFje7xvNrGbJgVAbBRX1v1I_to4BR8RzvIh2hi5IgBmqclIYsYbVWlEhsvjBhFR2b90Rz0APUdfgHp-nvgLB13jxm8f4TRr4ZDnvUQdZp3vI5PMj9optEmlZvexkNLDQLrBvoGCfVHodZyPQMLNVKp0TXWksPT-bw0E7Lq1GeYe2eU0GwHx8fugo2-v44dfCp0RXYYG6bI_Z-U3KZpvdj05n2_UDgTJFFm4c5i9UjILvlO73QJpMNi5eBjerm2alTisSCoiCtfgIgVsM8yHoomgarg"}}, "", http.StatusOK, `["foo","bar"]`, ""},
 		{"remote RSA JWKS x5c", "/jwks/rsa/remote", http.Header{"Authorization": []string{"Bearer " + rsaToken}}, "", http.StatusOK, "", ""},
diff --git a/server/testdata/integration/config/03_couper.hcl b/server/testdata/integration/config/03_couper.hcl
index 0ba67000..e4208bbd 100644
--- a/server/testdata/integration/config/03_couper.hcl
+++ b/server/testdata/integration/config/03_couper.hcl
@@ -236,6 +236,16 @@ server "acs" {
     }
   }
 
+  endpoint "/jwks/rsa/not_found" {
+    disable_access_control = ["ba1"]
+    access_control = ["JWKS_not_found"]
+    response {
+      headers = {
+        x-jwt-sub = request.context.JWKS_not_found.sub
+      }
+    }
+  }
+
   endpoint "/jwks/rsa/remote" {
     disable_access_control = ["ba1"]
     access_control = ["JWKSRemote"]
@@ -344,46 +354,60 @@ definitions {
         -----END PUBLIC KEY-----
     EOF
   }
+
   jwt "ECDSATokenWrongAlgorithm" {
     signature_algorithm = "ES384"
     key_file = "../files/certificate-ecdsa.pem"
   }
+
   jwt "JWKS" {
     jwks_url = "file:../files/jwks.json"
   }
+
   jwt "JWKS_scope" {
     jwks_url = "file:../files/jwks.json"
     beta_permissions_claim = "scope"
   }
+
   jwt "JWKSRemote" {
     jwks_url = "${env.COUPER_TEST_BACKEND_ADDR}/jwks.json"
   }
 
+  jwt "JWKS_not_found" {
+    header = "Authorization"
+    jwks_url = "${env.COUPER_TEST_BACKEND_ADDR}/not.found"
+  }
+
   jwt "JWKSBackend" {
     jwks_url = "${env.COUPER_TEST_BACKEND_ADDR}/jwks.json"
     backend {
       origin = env.COUPER_TEST_BACKEND_ADDR
     }
   }
+
   jwt "JWKSBackendRef" {
     jwks_url = "${env.COUPER_TEST_BACKEND_ADDR}/jwks.json"
     backend = "jwks"
   }
+
   jwt "JWT_token_value_query" {
     token_value = request.query.token[0]
     signature_algorithm = "HS256"
     key = "y0urS3cretT08eU5edF0rC0uPerInThe3xamp1e"
     beta_permissions_claim = "scope"
   }
+
   jwt "JWT_token_value_body" {
     token_value = request.json_body.token
     signature_algorithm = "HS256"
     key = "y0urS3cretT08eU5edF0rC0uPerInThe3xamp1e"
     beta_permissions_claim = "scope"
   }
+
   backend "jwks" {
     origin = env.COUPER_TEST_BACKEND_ADDR
   }
+
   backend "test" {
     origin = env.COUPER_TEST_BACKEND_ADDR
     path = "/anything"