Skip to content

Commit 9ce9d86

Browse files
NurayAhmadovaNurayAhmadova
committed
[TT-14494] improve error logging for JWKS URL handling
1 parent 6b7d1da commit 9ce9d86

4 files changed

Lines changed: 140 additions & 6 deletions

File tree

‎gateway/log_helpers.go‎

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,11 @@
11
package gateway
22

33
import (
4+
"encoding/json"
5+
"errors"
46
"net/http"
7+
"net/url"
8+
"strings"
59

610
"github.com/sirupsen/logrus"
711

@@ -65,3 +69,26 @@ func (gw *Gateway) getExplicitLogEntryForRequest(logger *logrus.Entry, path stri
6569
}
6670
return logger.WithFields(fields)
6771
}
72+
73+
func (gw *Gateway) logJWKError(logger *logrus.Entry, jwkURL string, err error) {
74+
if err == nil {
75+
return
76+
}
77+
78+
// invalid content (JSON errors)
79+
var syntaxErr *json.SyntaxError
80+
var unmarshalErr *json.UnmarshalTypeError
81+
if errors.As(err, &syntaxErr) || errors.As(err, &unmarshalErr) || strings.Contains(err.Error(), "invalid character") {
82+
logger.WithError(err).Errorf("Invalid JWKS retrieved from endpoint: %s", jwkURL)
83+
return
84+
}
85+
86+
// network/URL errors (DNS, TCP, Refused)
87+
var urlErr *url.Error
88+
if errors.As(err, &urlErr) || strings.Contains(err.Error(), "dial tcp") || strings.Contains(err.Error(), "no such host") || strings.Contains(err.Error(), "connection refused") {
89+
logger.WithError(err).Errorf("JWKS endpoint resolution failed: invalid or unreachable host %s", jwkURL)
90+
return
91+
}
92+
93+
logger.WithError(err).Errorf("Failed to fetch or decode JWKs from %s", jwkURL)
94+
}

‎gateway/log_helpers_test.go‎

Lines changed: 99 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,15 @@
11
package gateway
22

33
import (
4+
"encoding/json"
5+
"errors"
46
"net/http/httptest"
7+
"net/url"
58
"testing"
69

710
"github.com/sirupsen/logrus"
11+
"github.com/sirupsen/logrus/hooks/test"
12+
"github.com/stretchr/testify/assert"
813
)
914

1015
func TestGetLogEntryForRequest(t *testing.T) {
@@ -135,3 +140,97 @@ func TestGetLogEntryForRequest(t *testing.T) {
135140
}
136141
}
137142
}
143+
144+
func TestGatewayLogJWKError(t *testing.T) {
145+
// Setup logrus hook to capture logs
146+
logger, hook := test.NewNullLogger()
147+
entry := logrus.NewEntry(logger)
148+
149+
// We only need a minimal Gateway struct since logJWKError doesn't access Gateway fields
150+
gw := &Gateway{}
151+
testURL := "https://idp.example.com/jwks"
152+
153+
tests := []struct {
154+
name string
155+
err error
156+
expectedLog string
157+
shouldLog bool
158+
}{
159+
{
160+
name: "No error (nil)",
161+
err: nil,
162+
shouldLog: false,
163+
},
164+
{
165+
name: "JSON Syntax Error",
166+
err: &json.SyntaxError{},
167+
expectedLog: "Invalid JWKS retrieved from endpoint: " + testURL,
168+
shouldLog: true,
169+
},
170+
{
171+
name: "JSON Unmarshal Type Error",
172+
err: &json.UnmarshalTypeError{},
173+
expectedLog: "Invalid JWKS retrieved from endpoint: " + testURL,
174+
shouldLog: true,
175+
},
176+
{
177+
name: "String error containing 'invalid character'",
178+
err: errors.New("invalid character 'x' looking for beginning of value"),
179+
expectedLog: "Invalid JWKS retrieved from endpoint: " + testURL,
180+
shouldLog: true,
181+
},
182+
{
183+
name: "URL Error type",
184+
err: &url.Error{Op: "Get", URL: testURL, Err: errors.New("timeout")},
185+
expectedLog: "JWKS endpoint resolution failed: invalid or unreachable host " + testURL,
186+
shouldLog: true,
187+
},
188+
{
189+
name: "String error containing 'dial tcp'",
190+
err: errors.New("dial tcp: lookup failed"),
191+
expectedLog: "JWKS endpoint resolution failed: invalid or unreachable host " + testURL,
192+
shouldLog: true,
193+
},
194+
{
195+
name: "String error containing 'no such host'",
196+
err: errors.New("Get: no such host"),
197+
expectedLog: "JWKS endpoint resolution failed: invalid or unreachable host " + testURL,
198+
shouldLog: true,
199+
},
200+
{
201+
name: "String error containing 'connection refused'",
202+
err: errors.New("connect: connection refused"),
203+
expectedLog: "JWKS endpoint resolution failed: invalid or unreachable host " + testURL,
204+
shouldLog: true,
205+
},
206+
{
207+
name: "Generic/Fallback Error",
208+
err: errors.New("unknown internal server error"),
209+
expectedLog: "Failed to fetch or decode JWKs from " + testURL,
210+
shouldLog: true,
211+
},
212+
}
213+
214+
for _, tc := range tests {
215+
t.Run(tc.name, func(t *testing.T) {
216+
hook.Reset()
217+
218+
gw.logJWKError(entry, testURL, tc.err)
219+
220+
if !tc.shouldLog {
221+
assert.Empty(t, hook.Entries)
222+
return
223+
}
224+
225+
// Verify log was written
226+
assert.Len(t, hook.Entries, 1)
227+
assert.Equal(t, logrus.ErrorLevel, hook.LastEntry().Level)
228+
229+
// Verify message matches ticket requirements
230+
assert.Equal(t, tc.expectedLog, hook.LastEntry().Message)
231+
232+
// Verify the original error is attached
233+
assert.Equal(t, tc.err, hook.LastEntry().Data["error"])
234+
})
235+
}
236+
}

‎gateway/mw_external_oauth.go‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -182,11 +182,13 @@ func (k *ExternalOAuthMiddleware) getSecretFromJWKURL(url string, kid interface{
182182
// Fallback to original method if client factory fails
183183
k.Logger().Debug("[ExternalServices] Falling back to legacy JWK client due to factory error")
184184
if jwkSet, err = getJWK(url, k.Gw.GetConfig().JWTSSLInsecureSkipVerify); err != nil {
185+
k.Gw.logJWKError(k.Logger(), url, err)
185186
return nil, err
186187
}
187188
} else {
188189
k.Logger().Debugf("[ExternalServices] Using external services JWK client to fetch: %s", url)
189190
if jwkSet, err = getJWKWithClient(url, client); err != nil {
191+
k.Gw.logJWKError(k.Logger(), url, err)
190192
return nil, err
191193
}
192194
}
@@ -215,6 +217,7 @@ func (k *ExternalOAuthMiddleware) getSecretFromJWKOrConfig(kid interface{}, jwtV
215217

216218
decodedSource, err := base64.StdEncoding.DecodeString(jwtValidation.Source)
217219
if err != nil {
220+
k.Logger().WithError(err).Errorf("JWKS source decode failed: %s is not a base64 string", jwtValidation.Source)
218221
return nil, err
219222
}
220223

‎gateway/mw_jwt.go‎

Lines changed: 11 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -97,7 +97,7 @@ func (k *JWTMiddleware) Init() {
9797
}
9898

9999
if err != nil {
100-
k.Logger().WithError(err).Infof("Failed to fetch or decode JWKs from %s", jwk.URL)
100+
k.Gw.logJWKError(k.Logger(), jwk.URL, err)
101101
continue
102102
}
103103

@@ -180,14 +180,14 @@ func (k *JWTMiddleware) legacyGetSecretFromURL(url, kid, keyType string) (interf
180180
if !found {
181181
resp, err := client.Get(url)
182182
if err != nil {
183-
k.Logger().WithError(err).Error("Failed to get resource URL")
183+
k.Logger().WithError(err).Errorf("JWKS endpoint resolution failed: invalid or unreachable host %s", url)
184184
return nil, err
185185
}
186186
defer resp.Body.Close()
187187

188188
// Decode it
189189
if err := json.NewDecoder(resp.Body).Decode(&jwkSet); err != nil {
190-
k.Logger().WithError(err).Error("Failed to decode body JWK")
190+
k.Logger().WithError(err).Errorf("Invalid JWKS retrieved from endpoint: %s", url)
191191
return nil, err
192192
}
193193

@@ -242,6 +242,7 @@ func (k *JWTMiddleware) getSecretFromURL(url string, kidVal interface{}, keyType
242242

243243
decodedURL, err := base64.StdEncoding.DecodeString(cachedAPIDef.JWTSource)
244244
if err != nil {
245+
k.Logger().WithError(err).Errorf("JWKS source decode failed: %s is not a base64 string", cachedAPIDef.JWTSource)
245246
return nil, err
246247
}
247248

@@ -269,14 +270,17 @@ func (k *JWTMiddleware) getSecretFromURL(url string, kidVal interface{}, keyType
269270
client, clientErr := clientFactory.CreateJWKClient()
270271
if clientErr == nil {
271272
if jwkSet, err = getJWKWithClient(url, client); err != nil {
272-
k.Logger().WithError(err).Info("Failed to decode JWKs body with factory client. Trying x5c PEM fallback.")
273+
k.Gw.logJWKError(k.Logger(), url, err)
274+
k.Logger().Info("Failed to decode JWKs body with factory client. Trying x5c PEM fallback.")
273275
}
274276
}
275277

276278
// Fallback to original method if factory fails or JWK fetch fails
277279
if clientErr != nil || err != nil {
278280
if jwkSet, err = GetJWK(url, k.Gw.GetConfig().JWTSSLInsecureSkipVerify); err != nil {
279-
k.Logger().WithError(err).Info("Failed to decode JWKs body. Trying x5c PEM fallback.")
281+
// CHANGED: Call shared helper
282+
k.Gw.logJWKError(k.Logger(), url, err)
283+
k.Logger().Info("Failed to decode JWKs body. Trying x5c PEM fallback.")
280284

281285
key, legacyError := k.legacyGetSecretFromURL(url, kid, keyType)
282286
if legacyError == nil {
@@ -341,6 +345,7 @@ func (k *JWTMiddleware) getSecretToVerifySignature(r *http.Request, token *jwt.T
341345
// If not, return the actual value
342346
decodedCert, err := base64.StdEncoding.DecodeString(config.JWTSource)
343347
if err != nil {
348+
k.Logger().WithError(err).Errorf("JWKS source decode failed: %s is not a base64 string", config.JWTSource)
344349
return nil, err
345350
}
346351

@@ -452,7 +457,7 @@ func (k *JWTMiddleware) getSecretFromMultipleJWKURIs(jwkURIs []apidef.JWK, kidVa
452457
}
453458

454459
if err != nil {
455-
k.Logger().WithError(err).Infof("Failed to fetch or decode JWKs from %s", jwk.URL)
460+
k.Gw.logJWKError(k.Logger(), jwk.URL, err)
456461
fallbackJWKURIs = append(fallbackJWKURIs, jwk)
457462
continue
458463
}

0 commit comments

Comments
 (0)