client-go/test: warning handler with contextual logging

The default handler now uses contextual logging. Instead of

     warnings.go:106] warning 1

it now logs the caller of client-go and uses structured, contextual
logging

     main.go:100] "Warning" message="warning 1"

Users of client-go have the choice whether the handler that they provide uses
the traditional API (no API break!) or contextual logging.
This commit is contained in:
Patrick Ohly 2024-09-02 17:51:01 +02:00
parent bd55d18c75
commit 48fb886325
8 changed files with 343 additions and 61 deletions

View File

@ -101,7 +101,7 @@ type RESTClient struct {
// warningHandler is shared among all requests created by this client. // warningHandler is shared among all requests created by this client.
// If not set, defaultWarningHandler is used. // If not set, defaultWarningHandler is used.
warningHandler WarningHandler warningHandler WarningHandlerWithContext
// Set specific behavior of the client. If not set http.DefaultClient will be used. // Set specific behavior of the client. If not set http.DefaultClient will be used.
Client *http.Client Client *http.Client

View File

@ -129,10 +129,23 @@ type Config struct {
RateLimiter flowcontrol.RateLimiter RateLimiter flowcontrol.RateLimiter
// WarningHandler handles warnings in server responses. // WarningHandler handles warnings in server responses.
// If not set, the default warning handler is used. // If this and WarningHandlerWithContext are not set, the
// See documentation for SetDefaultWarningHandler() for details. // default warning handler is used. If both are set,
// WarningHandlerWithContext is used.
//
// See documentation for [SetDefaultWarningHandler] for details.
//
//logcheck:context // WarningHandlerWithContext should be used instead of WarningHandler in code which supports contextual logging.
WarningHandler WarningHandler WarningHandler WarningHandler
// WarningHandlerWithContext handles warnings in server responses.
// If this and WarningHandler are not set, the
// default warning handler is used. If both are set,
// WarningHandlerWithContext is used.
//
// See documentation for [SetDefaultWarningHandler] for details.
WarningHandlerWithContext WarningHandlerWithContext
// The maximum length of time to wait before giving up on a server request. A value of zero means no timeout. // The maximum length of time to wait before giving up on a server request. A value of zero means no timeout.
Timeout time.Duration Timeout time.Duration
@ -381,12 +394,27 @@ func RESTClientForConfigAndClient(config *Config, httpClient *http.Client) (*RES
} }
restClient, err := NewRESTClient(baseURL, versionedAPIPath, clientContent, rateLimiter, httpClient) restClient, err := NewRESTClient(baseURL, versionedAPIPath, clientContent, rateLimiter, httpClient)
if err == nil && config.WarningHandler != nil { maybeSetWarningHandler(restClient, config.WarningHandler, config.WarningHandlerWithContext)
restClient.warningHandler = config.WarningHandler
}
return restClient, err return restClient, err
} }
// maybeSetWarningHandler sets the handlerWithContext if non-nil,
// otherwise the handler with a wrapper if non-nil,
// and does nothing if both are nil.
//
// May be called for a nil client.
func maybeSetWarningHandler(c *RESTClient, handler WarningHandler, handlerWithContext WarningHandlerWithContext) {
if c == nil {
return
}
switch {
case handlerWithContext != nil:
c.warningHandler = handlerWithContext
case handler != nil:
c.warningHandler = warningLoggerNopContext{l: handler}
}
}
// UnversionedRESTClientFor is the same as RESTClientFor, except that it allows // UnversionedRESTClientFor is the same as RESTClientFor, except that it allows
// the config.Version to be empty. // the config.Version to be empty.
func UnversionedRESTClientFor(config *Config) (*RESTClient, error) { func UnversionedRESTClientFor(config *Config) (*RESTClient, error) {
@ -448,9 +476,7 @@ func UnversionedRESTClientForConfigAndClient(config *Config, httpClient *http.Cl
} }
restClient, err := NewRESTClient(baseURL, versionedAPIPath, clientContent, rateLimiter, httpClient) restClient, err := NewRESTClient(baseURL, versionedAPIPath, clientContent, rateLimiter, httpClient)
if err == nil && config.WarningHandler != nil { maybeSetWarningHandler(restClient, config.WarningHandler, config.WarningHandlerWithContext)
restClient.warningHandler = config.WarningHandler
}
return restClient, err return restClient, err
} }
@ -616,15 +642,16 @@ func AnonymousClientConfig(config *Config) *Config {
CAData: config.TLSClientConfig.CAData, CAData: config.TLSClientConfig.CAData,
NextProtos: config.TLSClientConfig.NextProtos, NextProtos: config.TLSClientConfig.NextProtos,
}, },
RateLimiter: config.RateLimiter, RateLimiter: config.RateLimiter,
WarningHandler: config.WarningHandler, WarningHandler: config.WarningHandler,
UserAgent: config.UserAgent, WarningHandlerWithContext: config.WarningHandlerWithContext,
DisableCompression: config.DisableCompression, UserAgent: config.UserAgent,
QPS: config.QPS, DisableCompression: config.DisableCompression,
Burst: config.Burst, QPS: config.QPS,
Timeout: config.Timeout, Burst: config.Burst,
Dial: config.Dial, Timeout: config.Timeout,
Proxy: config.Proxy, Dial: config.Dial,
Proxy: config.Proxy,
} }
} }
@ -658,17 +685,18 @@ func CopyConfig(config *Config) *Config {
CAData: config.TLSClientConfig.CAData, CAData: config.TLSClientConfig.CAData,
NextProtos: config.TLSClientConfig.NextProtos, NextProtos: config.TLSClientConfig.NextProtos,
}, },
UserAgent: config.UserAgent, UserAgent: config.UserAgent,
DisableCompression: config.DisableCompression, DisableCompression: config.DisableCompression,
Transport: config.Transport, Transport: config.Transport,
WrapTransport: config.WrapTransport, WrapTransport: config.WrapTransport,
QPS: config.QPS, QPS: config.QPS,
Burst: config.Burst, Burst: config.Burst,
RateLimiter: config.RateLimiter, RateLimiter: config.RateLimiter,
WarningHandler: config.WarningHandler, WarningHandler: config.WarningHandler,
Timeout: config.Timeout, WarningHandlerWithContext: config.WarningHandlerWithContext,
Dial: config.Dial, Timeout: config.Timeout,
Proxy: config.Proxy, Dial: config.Dial,
Proxy: config.Proxy,
} }
if config.ExecProvider != nil && config.ExecProvider.Config != nil { if config.ExecProvider != nil && config.ExecProvider.Config != nil {
c.ExecProvider.Config = config.ExecProvider.Config.DeepCopyObject() c.ExecProvider.Config = config.ExecProvider.Config.DeepCopyObject()

View File

@ -41,6 +41,7 @@ import (
"github.com/google/go-cmp/cmp" "github.com/google/go-cmp/cmp"
fuzz "github.com/google/gofuzz" fuzz "github.com/google/gofuzz"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
) )
func TestIsConfigTransportTLS(t *testing.T) { func TestIsConfigTransportTLS(t *testing.T) {
@ -266,6 +267,19 @@ type fakeWarningHandler struct{}
func (f fakeWarningHandler) HandleWarningHeader(code int, agent string, message string) {} func (f fakeWarningHandler) HandleWarningHeader(code int, agent string, message string) {}
type fakeWarningHandlerWithLogging struct {
messages []string
}
func (f *fakeWarningHandlerWithLogging) HandleWarningHeader(code int, agent string, message string) {
f.messages = append(f.messages, message)
}
type fakeWarningHandlerWithContext struct{}
func (f fakeWarningHandlerWithContext) HandleWarningHeaderWithContext(ctx context.Context, code int, agent string, message string) {
}
type fakeNegotiatedSerializer struct{} type fakeNegotiatedSerializer struct{}
func (n *fakeNegotiatedSerializer) SupportedMediaTypes() []runtime.SerializerInfo { func (n *fakeNegotiatedSerializer) SupportedMediaTypes() []runtime.SerializerInfo {
@ -330,6 +344,9 @@ func TestAnonymousAuthConfig(t *testing.T) {
func(h *WarningHandler, f fuzz.Continue) { func(h *WarningHandler, f fuzz.Continue) {
*h = &fakeWarningHandler{} *h = &fakeWarningHandler{}
}, },
func(h *WarningHandlerWithContext, f fuzz.Continue) {
*h = &fakeWarningHandlerWithContext{}
},
// Authentication does not require fuzzer // Authentication does not require fuzzer
func(r *AuthProviderConfigPersister, f fuzz.Continue) {}, func(r *AuthProviderConfigPersister, f fuzz.Continue) {},
func(r *clientcmdapi.AuthProviderConfig, f fuzz.Continue) { func(r *clientcmdapi.AuthProviderConfig, f fuzz.Continue) {
@ -428,6 +445,9 @@ func TestCopyConfig(t *testing.T) {
func(h *WarningHandler, f fuzz.Continue) { func(h *WarningHandler, f fuzz.Continue) {
*h = &fakeWarningHandler{} *h = &fakeWarningHandler{}
}, },
func(h *WarningHandlerWithContext, f fuzz.Continue) {
*h = &fakeWarningHandlerWithContext{}
},
func(r *AuthProviderConfigPersister, f fuzz.Continue) { func(r *AuthProviderConfigPersister, f fuzz.Continue) {
*r = fakeAuthProviderConfigPersister{} *r = fakeAuthProviderConfigPersister{}
}, },
@ -619,25 +639,69 @@ func TestConfigSprint(t *testing.T) {
KeyData: []byte("fake key"), KeyData: []byte("fake key"),
NextProtos: []string{"h2", "http/1.1"}, NextProtos: []string{"h2", "http/1.1"},
}, },
UserAgent: "gobot", UserAgent: "gobot",
Transport: &fakeRoundTripper{}, Transport: &fakeRoundTripper{},
WrapTransport: fakeWrapperFunc, WrapTransport: fakeWrapperFunc,
QPS: 1, QPS: 1,
Burst: 2, Burst: 2,
RateLimiter: &fakeLimiter{}, RateLimiter: &fakeLimiter{},
WarningHandler: fakeWarningHandler{}, WarningHandler: fakeWarningHandler{},
Timeout: 3 * time.Second, WarningHandlerWithContext: fakeWarningHandlerWithContext{},
Dial: fakeDialFunc, Timeout: 3 * time.Second,
Proxy: fakeProxyFunc, Dial: fakeDialFunc,
Proxy: fakeProxyFunc,
} }
want := fmt.Sprintf( want := fmt.Sprintf(
`&rest.Config{Host:"localhost:8080", APIPath:"v1", ContentConfig:rest.ContentConfig{AcceptContentTypes:"application/json", ContentType:"application/json", GroupVersion:(*schema.GroupVersion)(nil), NegotiatedSerializer:runtime.NegotiatedSerializer(nil)}, Username:"gopher", Password:"--- REDACTED ---", BearerToken:"--- REDACTED ---", BearerTokenFile:"", Impersonate:rest.ImpersonationConfig{UserName:"gopher2", UID:"uid123", Groups:[]string(nil), Extra:map[string][]string(nil)}, AuthProvider:api.AuthProviderConfig{Name: "gopher", Config: map[string]string{--- REDACTED ---}}, AuthConfigPersister:rest.AuthProviderConfigPersister(--- REDACTED ---), ExecProvider:api.ExecConfig{Command: "sudo", Args: []string{"--- REDACTED ---"}, Env: []ExecEnvVar{--- REDACTED ---}, APIVersion: "", ProvideClusterInfo: true, Config: runtime.Object(--- REDACTED ---), StdinUnavailable: false}, TLSClientConfig:rest.sanitizedTLSClientConfig{Insecure:false, ServerName:"", CertFile:"a.crt", KeyFile:"a.key", CAFile:"", CertData:[]uint8{0x2d, 0x2d, 0x2d, 0x20, 0x54, 0x52, 0x55, 0x4e, 0x43, 0x41, 0x54, 0x45, 0x44, 0x20, 0x2d, 0x2d, 0x2d}, KeyData:[]uint8{0x2d, 0x2d, 0x2d, 0x20, 0x52, 0x45, 0x44, 0x41, 0x43, 0x54, 0x45, 0x44, 0x20, 0x2d, 0x2d, 0x2d}, CAData:[]uint8(nil), NextProtos:[]string{"h2", "http/1.1"}}, UserAgent:"gobot", DisableCompression:false, Transport:(*rest.fakeRoundTripper)(%p), WrapTransport:(transport.WrapperFunc)(%p), QPS:1, Burst:2, RateLimiter:(*rest.fakeLimiter)(%p), WarningHandler:rest.fakeWarningHandler{}, Timeout:3000000000, Dial:(func(context.Context, string, string) (net.Conn, error))(%p), Proxy:(func(*http.Request) (*url.URL, error))(%p)}`, `&rest.Config{Host:"localhost:8080", APIPath:"v1", ContentConfig:rest.ContentConfig{AcceptContentTypes:"application/json", ContentType:"application/json", GroupVersion:(*schema.GroupVersion)(nil), NegotiatedSerializer:runtime.NegotiatedSerializer(nil)}, Username:"gopher", Password:"--- REDACTED ---", BearerToken:"--- REDACTED ---", BearerTokenFile:"", Impersonate:rest.ImpersonationConfig{UserName:"gopher2", UID:"uid123", Groups:[]string(nil), Extra:map[string][]string(nil)}, AuthProvider:api.AuthProviderConfig{Name: "gopher", Config: map[string]string{--- REDACTED ---}}, AuthConfigPersister:rest.AuthProviderConfigPersister(--- REDACTED ---), ExecProvider:api.ExecConfig{Command: "sudo", Args: []string{"--- REDACTED ---"}, Env: []ExecEnvVar{--- REDACTED ---}, APIVersion: "", ProvideClusterInfo: true, Config: runtime.Object(--- REDACTED ---), StdinUnavailable: false}, TLSClientConfig:rest.sanitizedTLSClientConfig{Insecure:false, ServerName:"", CertFile:"a.crt", KeyFile:"a.key", CAFile:"", CertData:[]uint8{0x2d, 0x2d, 0x2d, 0x20, 0x54, 0x52, 0x55, 0x4e, 0x43, 0x41, 0x54, 0x45, 0x44, 0x20, 0x2d, 0x2d, 0x2d}, KeyData:[]uint8{0x2d, 0x2d, 0x2d, 0x20, 0x52, 0x45, 0x44, 0x41, 0x43, 0x54, 0x45, 0x44, 0x20, 0x2d, 0x2d, 0x2d}, CAData:[]uint8(nil), NextProtos:[]string{"h2", "http/1.1"}}, UserAgent:"gobot", DisableCompression:false, Transport:(*rest.fakeRoundTripper)(%p), WrapTransport:(transport.WrapperFunc)(%p), QPS:1, Burst:2, RateLimiter:(*rest.fakeLimiter)(%p), WarningHandler:rest.fakeWarningHandler{}, WarningHandlerWithContext:rest.fakeWarningHandlerWithContext{}, Timeout:3000000000, Dial:(func(context.Context, string, string) (net.Conn, error))(%p), Proxy:(func(*http.Request) (*url.URL, error))(%p)}`,
c.Transport, fakeWrapperFunc, c.RateLimiter, fakeDialFunc, fakeProxyFunc, c.Transport, fakeWrapperFunc, c.RateLimiter, fakeDialFunc, fakeProxyFunc,
) )
for _, f := range []string{"%s", "%v", "%+v", "%#v"} { for _, f := range []string{"%s", "%v", "%+v", "%#v"} {
if got := fmt.Sprintf(f, c); want != got { if got := fmt.Sprintf(f, c); want != got {
t.Errorf("fmt.Sprintf(%q, c)\ngot: %q\nwant: %q", f, got, want) t.Errorf("fmt.Sprintf(%q, c)\ngot: %q\nwant: %q\ndiff: %s", f, got, want, cmp.Diff(want, got))
} }
} }
} }
func TestConfigWarningHandler(t *testing.T) {
config := &Config{}
config.GroupVersion = &schema.GroupVersion{}
config.NegotiatedSerializer = &fakeNegotiatedSerializer{}
handlerNoContext := &fakeWarningHandler{}
handlerWithContext := &fakeWarningHandlerWithContext{}
t.Run("none", func(t *testing.T) {
client, err := RESTClientForConfigAndClient(config, nil)
require.NoError(t, err)
assert.Nil(t, client.warningHandler)
})
t.Run("no-context", func(t *testing.T) {
config := CopyConfig(config)
handler := &fakeWarningHandlerWithLogging{}
config.WarningHandler = handler
client, err := RESTClientForConfigAndClient(config, nil)
require.NoError(t, err)
client.warningHandler.HandleWarningHeaderWithContext(context.Background(), 0, "", "message")
assert.Equal(t, []string{"message"}, handler.messages)
})
t.Run("with-context", func(t *testing.T) {
config := CopyConfig(config)
config.WarningHandlerWithContext = handlerWithContext
client, err := RESTClientForConfigAndClient(config, nil)
require.NoError(t, err)
assert.Equal(t, handlerWithContext, client.warningHandler)
})
t.Run("both", func(t *testing.T) {
config := CopyConfig(config)
config.WarningHandler = handlerNoContext
config.WarningHandlerWithContext = handlerWithContext
client, err := RESTClientForConfigAndClient(config, nil)
require.NoError(t, err)
assert.NotNil(t, client.warningHandler)
assert.Equal(t, handlerWithContext, client.warningHandler)
})
}

View File

@ -242,6 +242,9 @@ func TestConfigToExecClusterRoundtrip(t *testing.T) {
func(h *WarningHandler, f fuzz.Continue) { func(h *WarningHandler, f fuzz.Continue) {
*h = &fakeWarningHandler{} *h = &fakeWarningHandler{}
}, },
func(h *WarningHandlerWithContext, f fuzz.Continue) {
*h = &fakeWarningHandlerWithContext{}
},
// Authentication does not require fuzzer // Authentication does not require fuzzer
func(r *AuthProviderConfigPersister, f fuzz.Continue) {}, func(r *AuthProviderConfigPersister, f fuzz.Continue) {},
func(r *clientcmdapi.AuthProviderConfig, f fuzz.Continue) { func(r *clientcmdapi.AuthProviderConfig, f fuzz.Continue) {
@ -289,6 +292,7 @@ func TestConfigToExecClusterRoundtrip(t *testing.T) {
expected.Burst = 0 expected.Burst = 0
expected.RateLimiter = nil expected.RateLimiter = nil
expected.WarningHandler = nil expected.WarningHandler = nil
expected.WarningHandlerWithContext = nil
expected.Timeout = 0 expected.Timeout = 0
expected.Dial = nil expected.Dial = nil

View File

@ -103,7 +103,7 @@ type Request struct {
contentConfig ClientContentConfig contentConfig ClientContentConfig
contentTypeNotSet bool contentTypeNotSet bool
warningHandler WarningHandler warningHandler WarningHandlerWithContext
rateLimiter flowcontrol.RateLimiter rateLimiter flowcontrol.RateLimiter
backoff BackoffManager backoff BackoffManager
@ -271,8 +271,21 @@ func (r *Request) BackOff(manager BackoffManager) *Request {
} }
// WarningHandler sets the handler this client uses when warning headers are encountered. // WarningHandler sets the handler this client uses when warning headers are encountered.
// If set to nil, this client will use the default warning handler (see SetDefaultWarningHandler). // If set to nil, this client will use the default warning handler (see [SetDefaultWarningHandler]).
//
//logcheck:context // WarningHandlerWithContext should be used instead of WarningHandler in code which supports contextual logging.
func (r *Request) WarningHandler(handler WarningHandler) *Request { func (r *Request) WarningHandler(handler WarningHandler) *Request {
if handler == nil {
r.warningHandler = nil
return r
}
r.warningHandler = warningLoggerNopContext{l: handler}
return r
}
// WarningHandlerWithContext sets the handler this client uses when warning headers are encountered.
// If set to nil, this client will use the default warning handler (see [SetDefaultWarningHandlerWithContext]).
func (r *Request) WarningHandlerWithContext(handler WarningHandlerWithContext) *Request {
r.warningHandler = handler r.warningHandler = handler
return r return r
} }
@ -776,7 +789,7 @@ func (r *Request) watchInternal(ctx context.Context) (watch.Interface, runtime.D
resp, err := client.Do(req) resp, err := client.Do(req)
retry.After(ctx, r, resp, err) retry.After(ctx, r, resp, err)
if err == nil && resp.StatusCode == http.StatusOK { if err == nil && resp.StatusCode == http.StatusOK {
return r.newStreamWatcher(resp) return r.newStreamWatcher(ctx, resp)
} }
done, transformErr := func() (bool, error) { done, transformErr := func() (bool, error) {
@ -969,7 +982,7 @@ func (r *Request) handleWatchList(ctx context.Context, w watch.Interface, negoti
} }
} }
func (r *Request) newStreamWatcher(resp *http.Response) (watch.Interface, runtime.Decoder, error) { func (r *Request) newStreamWatcher(ctx context.Context, resp *http.Response) (watch.Interface, runtime.Decoder, error) {
contentType := resp.Header.Get("Content-Type") contentType := resp.Header.Get("Content-Type")
mediaType, params, err := mime.ParseMediaType(contentType) mediaType, params, err := mime.ParseMediaType(contentType)
if err != nil { if err != nil {
@ -980,7 +993,7 @@ func (r *Request) newStreamWatcher(resp *http.Response) (watch.Interface, runtim
return nil, nil, err return nil, nil, err
} }
handleWarnings(resp.Header, r.warningHandler) handleWarnings(ctx, resp.Header, r.warningHandler)
frameReader := framer.NewFrameReader(resp.Body) frameReader := framer.NewFrameReader(resp.Body)
watchEventDecoder := streaming.NewDecoder(frameReader, streamingSerializer) watchEventDecoder := streaming.NewDecoder(frameReader, streamingSerializer)
@ -1067,7 +1080,7 @@ func (r *Request) Stream(ctx context.Context) (io.ReadCloser, error) {
switch { switch {
case (resp.StatusCode >= 200) && (resp.StatusCode < 300): case (resp.StatusCode >= 200) && (resp.StatusCode < 300):
handleWarnings(resp.Header, r.warningHandler) handleWarnings(ctx, resp.Header, r.warningHandler)
return resp.Body, nil return resp.Body, nil
default: default:
@ -1365,7 +1378,7 @@ func (r *Request) transformResponse(ctx context.Context, resp *http.Response, re
body: body, body: body,
contentType: contentType, contentType: contentType,
statusCode: resp.StatusCode, statusCode: resp.StatusCode,
warnings: handleWarnings(resp.Header, r.warningHandler), warnings: handleWarnings(ctx, resp.Header, r.warningHandler),
} }
} }
} }
@ -1384,7 +1397,7 @@ func (r *Request) transformResponse(ctx context.Context, resp *http.Response, re
statusCode: resp.StatusCode, statusCode: resp.StatusCode,
decoder: decoder, decoder: decoder,
err: err, err: err,
warnings: handleWarnings(resp.Header, r.warningHandler), warnings: handleWarnings(ctx, resp.Header, r.warningHandler),
} }
} }
@ -1393,7 +1406,7 @@ func (r *Request) transformResponse(ctx context.Context, resp *http.Response, re
contentType: contentType, contentType: contentType,
statusCode: resp.StatusCode, statusCode: resp.StatusCode,
decoder: decoder, decoder: decoder,
warnings: handleWarnings(resp.Header, r.warningHandler), warnings: handleWarnings(ctx, resp.Header, r.warningHandler),
} }
} }

View File

@ -4066,15 +4066,24 @@ func TestRequestLogging(t *testing.T) {
testcases := map[string]struct { testcases := map[string]struct {
v int v int
body any body any
response *http.Response
expectedOutput string expectedOutput string
}{ }{
"no-output": { "no-output": {
v: 7, v: 7,
body: []byte("ping"), body: []byte("ping"),
response: &http.Response{
StatusCode: http.StatusOK,
Body: io.NopCloser(strings.NewReader("pong")),
},
}, },
"output": { "output": {
v: 8, v: 8,
body: []byte("ping"), body: []byte("ping"),
response: &http.Response{
StatusCode: http.StatusOK,
Body: io.NopCloser(strings.NewReader("pong")),
},
expectedOutput: `<location>] "Request Body" logger="TestLogger" body="ping" expectedOutput: `<location>] "Request Body" logger="TestLogger" body="ping"
<location>] "Response Body" logger="TestLogger" body="pong" <location>] "Response Body" logger="TestLogger" body="pong"
`, `,
@ -4082,6 +4091,10 @@ func TestRequestLogging(t *testing.T) {
"io-reader": { "io-reader": {
v: 8, v: 8,
body: strings.NewReader("ping"), body: strings.NewReader("ping"),
response: &http.Response{
StatusCode: http.StatusOK,
Body: io.NopCloser(strings.NewReader("pong")),
},
// Cannot log the request body! // Cannot log the request body!
expectedOutput: `<location>] "Response Body" logger="TestLogger" body="pong" expectedOutput: `<location>] "Response Body" logger="TestLogger" body="pong"
`, `,
@ -4089,10 +4102,34 @@ func TestRequestLogging(t *testing.T) {
"truncate": { "truncate": {
v: 8, v: 8,
body: []byte(strings.Repeat("a", 2000)), body: []byte(strings.Repeat("a", 2000)),
response: &http.Response{
StatusCode: http.StatusOK,
Body: io.NopCloser(strings.NewReader("pong")),
},
expectedOutput: fmt.Sprintf(`<location>] "Request Body" logger="TestLogger" body="%s [truncated 976 chars]" expectedOutput: fmt.Sprintf(`<location>] "Request Body" logger="TestLogger" body="%s [truncated 976 chars]"
<location>] "Response Body" logger="TestLogger" body="pong" <location>] "Response Body" logger="TestLogger" body="pong"
`, strings.Repeat("a", 1024)), `, strings.Repeat("a", 1024)),
}, },
"warnings": {
v: 8,
body: []byte("ping"),
response: &http.Response{
StatusCode: http.StatusOK,
Header: http.Header{
"Warning": []string{
`299 request-test "warning 1"`,
`299 request-test-2 "warning 2"`,
`300 request-test-3 "ignore code 300"`,
},
},
Body: io.NopCloser(strings.NewReader("pong")),
},
expectedOutput: `<location>] "Request Body" logger="TestLogger" body="ping"
<location>] "Response Body" logger="TestLogger" body="pong"
warnings.go] "Warning: warning 1" logger="TestLogger"
warnings.go] "Warning: warning 2" logger="TestLogger"
`,
},
} }
for name, tc := range testcases { for name, tc := range testcases {
@ -4106,12 +4143,10 @@ func TestRequestLogging(t *testing.T) {
var fs flag.FlagSet var fs flag.FlagSet
klog.InitFlags(&fs) klog.InitFlags(&fs)
require.NoError(t, fs.Set("v", fmt.Sprintf("%d", tc.v)), "set verbosity") require.NoError(t, fs.Set("v", fmt.Sprintf("%d", tc.v)), "set verbosity")
require.NoError(t, fs.Set("one_output", "true"), "set one_output")
client := clientForFunc(func(req *http.Request) (*http.Response, error) { client := clientForFunc(func(req *http.Request) (*http.Response, error) {
return &http.Response{ return tc.response, nil
StatusCode: http.StatusOK,
Body: io.NopCloser(strings.NewReader("pong")),
}, nil
}) })
req := NewRequestWithClient(nil, "", defaultContentConfig(), client). req := NewRequestWithClient(nil, "", defaultContentConfig(), client).
@ -4128,11 +4163,49 @@ func TestRequestLogging(t *testing.T) {
// Compare log output: // Compare log output:
// - strip date/time/pid from each line (fixed length header) // - strip date/time/pid from each line (fixed length header)
// - replace <location> with the actual call location // - replace <location> with the actual call location
// - strip line number from warnings.go (might change)
state.Restore() state.Restore()
expectedOutput := strings.ReplaceAll(tc.expectedOutput, "<location>", fmt.Sprintf("%s:%d", path.Base(file), line+1)) expectedOutput := strings.ReplaceAll(tc.expectedOutput, "<location>", fmt.Sprintf("%s:%d", path.Base(file), line+1))
actualOutput := buffer.String() actualOutput := buffer.String()
actualOutput = regexp.MustCompile(`(?m)^.{30}`).ReplaceAllString(actualOutput, "") actualOutput = regexp.MustCompile(`(?m)^.{30}`).ReplaceAllString(actualOutput, "")
actualOutput = regexp.MustCompile(`(?m)^warnings\.go:\d+`).ReplaceAllString(actualOutput, "warnings.go")
assert.Equal(t, expectedOutput, actualOutput) assert.Equal(t, expectedOutput, actualOutput)
}) })
} }
} }
func TestRequestWarningHandler(t *testing.T) {
t.Run("no-context", func(t *testing.T) {
request := &Request{}
handler := &fakeWarningHandlerWithLogging{}
//nolint:logcheck
assert.Equal(t, request, request.WarningHandler(handler))
assert.NotNil(t, request.warningHandler)
request.warningHandler.HandleWarningHeaderWithContext(context.Background(), 0, "", "message")
assert.Equal(t, []string{"message"}, handler.messages)
})
t.Run("with-context", func(t *testing.T) {
request := &Request{}
handler := &fakeWarningHandlerWithContext{}
assert.Equal(t, request, request.WarningHandlerWithContext(handler))
assert.Equal(t, request.warningHandler, handler)
})
t.Run("nil-no-context", func(t *testing.T) {
request := &Request{
warningHandler: &fakeWarningHandlerWithContext{},
}
//nolint:logcheck
assert.Equal(t, request, request.WarningHandler(nil))
assert.Nil(t, request.warningHandler)
})
t.Run("nil-with-context", func(t *testing.T) {
request := &Request{
warningHandler: &fakeWarningHandlerWithContext{},
}
assert.Equal(t, request, request.WarningHandlerWithContext(nil))
assert.Nil(t, request.warningHandler)
})
}

View File

@ -17,6 +17,7 @@ limitations under the License.
package rest package rest
import ( import (
"context"
"fmt" "fmt"
"io" "io"
"net/http" "net/http"
@ -33,8 +34,15 @@ type WarningHandler interface {
HandleWarningHeader(code int, agent string, text string) HandleWarningHeader(code int, agent string, text string)
} }
// WarningHandlerWithContext is an interface for handling warning headers with
// support for contextual logging.
type WarningHandlerWithContext interface {
// HandleWarningHeaderWithContext is called with the warn code, agent, and text when a warning header is countered.
HandleWarningHeaderWithContext(ctx context.Context, code int, agent string, text string)
}
var ( var (
defaultWarningHandler WarningHandler = WarningLogger{} defaultWarningHandler WarningHandlerWithContext = WarningLogger{}
defaultWarningHandlerLock sync.RWMutex defaultWarningHandlerLock sync.RWMutex
) )
@ -43,33 +51,68 @@ var (
// - NoWarnings suppresses warnings. // - NoWarnings suppresses warnings.
// - WarningLogger logs warnings. // - WarningLogger logs warnings.
// - NewWarningWriter() outputs warnings to the provided writer. // - NewWarningWriter() outputs warnings to the provided writer.
//
// logcheck:context // SetDefaultWarningHandlerWithContext should be used instead of SetDefaultWarningHandler in code which supports contextual logging.
func SetDefaultWarningHandler(l WarningHandler) { func SetDefaultWarningHandler(l WarningHandler) {
if l == nil {
SetDefaultWarningHandlerWithContext(nil)
return
}
SetDefaultWarningHandlerWithContext(warningLoggerNopContext{l: l})
}
// SetDefaultWarningHandlerWithContext is a variant of [SetDefaultWarningHandler] which supports contextual logging.
func SetDefaultWarningHandlerWithContext(l WarningHandlerWithContext) {
defaultWarningHandlerLock.Lock() defaultWarningHandlerLock.Lock()
defer defaultWarningHandlerLock.Unlock() defer defaultWarningHandlerLock.Unlock()
defaultWarningHandler = l defaultWarningHandler = l
} }
func getDefaultWarningHandler() WarningHandler {
func getDefaultWarningHandler() WarningHandlerWithContext {
defaultWarningHandlerLock.RLock() defaultWarningHandlerLock.RLock()
defer defaultWarningHandlerLock.RUnlock() defer defaultWarningHandlerLock.RUnlock()
l := defaultWarningHandler l := defaultWarningHandler
return l return l
} }
// NoWarnings is an implementation of WarningHandler that suppresses warnings. type warningLoggerNopContext struct {
l WarningHandler
}
func (w warningLoggerNopContext) HandleWarningHeaderWithContext(_ context.Context, code int, agent string, message string) {
w.l.HandleWarningHeader(code, agent, message)
}
// NoWarnings is an implementation of [WarningHandler] and [WarningHandlerWithContext] that suppresses warnings.
type NoWarnings struct{} type NoWarnings struct{}
func (NoWarnings) HandleWarningHeader(code int, agent string, message string) {} func (NoWarnings) HandleWarningHeader(code int, agent string, message string) {}
func (NoWarnings) HandleWarningHeaderWithContext(ctx context.Context, code int, agent string, message string) {
}
// WarningLogger is an implementation of WarningHandler that logs code 299 warnings var _ WarningHandler = NoWarnings{}
var _ WarningHandlerWithContext = NoWarnings{}
// WarningLogger is an implementation of [WarningHandler] and [WarningHandlerWithContext] that logs code 299 warnings
type WarningLogger struct{} type WarningLogger struct{}
func (WarningLogger) HandleWarningHeader(code int, agent string, message string) { func (WarningLogger) HandleWarningHeader(code int, agent string, message string) {
if code != 299 || len(message) == 0 { if code != 299 || len(message) == 0 {
return return
} }
klog.Warning(message) klog.Background().Info("Warning: " + message)
} }
func (WarningLogger) HandleWarningHeaderWithContext(ctx context.Context, code int, agent string, message string) {
if code != 299 || len(message) == 0 {
return
}
klog.FromContext(ctx).Info("Warning: " + message)
}
var _ WarningHandler = WarningLogger{}
var _ WarningHandlerWithContext = WarningLogger{}
type warningWriter struct { type warningWriter struct {
// out is the writer to output warnings to // out is the writer to output warnings to
out io.Writer out io.Writer
@ -134,14 +177,14 @@ func (w *warningWriter) WarningCount() int {
return w.writtenCount return w.writtenCount
} }
func handleWarnings(headers http.Header, handler WarningHandler) []net.WarningHeader { func handleWarnings(ctx context.Context, headers http.Header, handler WarningHandlerWithContext) []net.WarningHeader {
if handler == nil { if handler == nil {
handler = getDefaultWarningHandler() handler = getDefaultWarningHandler()
} }
warnings, _ := net.ParseWarningHeaders(headers["Warning"]) warnings, _ := net.ParseWarningHeaders(headers["Warning"])
for _, warning := range warnings { for _, warning := range warnings {
handler.HandleWarningHeader(warning.Code, warning.Agent, warning.Text) handler.HandleWarningHeaderWithContext(ctx, warning.Code, warning.Agent, warning.Text)
} }
return warnings return warnings
} }

View File

@ -0,0 +1,57 @@
/*
Copyright 2024 The Kubernetes Authors.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/
package rest
import (
"context"
"testing"
"github.com/stretchr/testify/assert"
)
func TestDefaultWarningHandler(t *testing.T) {
t.Run("default", func(t *testing.T) {
assert.IsType(t, WarningHandlerWithContext(WarningLogger{}), getDefaultWarningHandler())
})
deferRestore := func(t *testing.T) {
handler := getDefaultWarningHandler()
t.Cleanup(func() {
SetDefaultWarningHandlerWithContext(handler)
})
}
t.Run("no-context", func(t *testing.T) {
deferRestore(t)
handler := &fakeWarningHandlerWithLogging{}
//nolint:logcheck
SetDefaultWarningHandler(handler)
getDefaultWarningHandler().HandleWarningHeaderWithContext(context.Background(), 0, "", "message")
assert.Equal(t, []string{"message"}, handler.messages)
SetDefaultWarningHandler(nil)
assert.Nil(t, getDefaultWarningHandler())
})
t.Run("with-context", func(t *testing.T) {
deferRestore(t)
handler := &fakeWarningHandlerWithContext{}
SetDefaultWarningHandlerWithContext(handler)
assert.Equal(t, handler, getDefaultWarningHandler())
SetDefaultWarningHandlerWithContext(nil)
assert.Nil(t, getDefaultWarningHandler())
})
}