Skip to content

Commit 83661fa

Browse files
authored
feat(remote): add LoggingTransport for slog-based HTTP debug logging (#1190)
## What Adds `LoggingTransport` and `NewLoggingTransport(inner http.RoundTripper, logger *slog.Logger) *LoggingTransport` in `registry/remote`: - Wraps an `http.RoundTripper` and logs every request/response pair at `slog.LevelDebug`. - Defaults: `inner=http.DefaultTransport`, `logger=slog.Default()`. - Scrubs sensitive headers (`Authorization`, `Set-Cookie`) from logs. - Clips response bodies at 16 KiB. - A package-level `atomic.Uint64` counter assigns each pair a sequential ID so request/response lines can be correlated across concurrent operations (oras-go does parallel blob fetches, so log lines interleave). ## Why Part of the v3 PR-by-PR breakdown (**PR 8: `feat/remote-transport-utils`**), reduced scope: - `warning.go` / `warning_test.go` (also part of prs.md PR 8) are **already merged** to `upstream/main`. - The `internal/ioutil` clean-up-temp-file fix (the other prs.md PR 8 piece) is already proposed in open PR #1185 (`fix(ioutil): clean up temp file on Ingest error`), so it's excluded here. This PR ships only the genuinely new, standalone piece: the LoggingTransport. ## Test plan - [x] `go build -mod=mod ./registry/remote/...` - [x] `go test -mod=mod ./registry/remote/` — passes (`ok ... 21.025s`) - [x] `go test -mod=mod -run LoggingTransport -v` — `TestNewLoggingTransport_Defaults`, `TestLoggingTransport_RoundTrip`, `TestLoggingTransport_RoundTrip_Error` all PASS Signed-off-by: Terry Howe <terrylhowe@gmail.com>
1 parent 2c0bf91 commit 83661fa

2 files changed

Lines changed: 381 additions & 0 deletions

File tree

Lines changed: 185 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,185 @@
1+
/*
2+
Copyright The ORAS Authors.
3+
Licensed under the Apache License, Version 2.0 (the "License");
4+
you may not use this file except in compliance with the License.
5+
You may obtain a copy of the License at
6+
7+
http://www.apache.org/licenses/LICENSE-2.0
8+
9+
Unless required by applicable law or agreed to in writing, software
10+
distributed under the License is distributed on an "AS IS" BASIS,
11+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
See the License for the specific language governing permissions and
13+
limitations under the License.
14+
*/
15+
16+
package remote
17+
18+
import (
19+
"bytes"
20+
"fmt"
21+
"io"
22+
"log/slog"
23+
"mime"
24+
"net/http"
25+
"strings"
26+
"sync/atomic"
27+
)
28+
29+
// sensitiveHeaders is the set of headers whose values are scrubbed from logs.
30+
var sensitiveHeaders = []string{
31+
"Authorization",
32+
"Set-Cookie",
33+
}
34+
35+
// loggingPayloadSizeLimit is the maximum number of response body bytes printed.
36+
const loggingPayloadSizeLimit int64 = 16 * 1024 // 16 KiB
37+
38+
// requestCounter assigns a unique sequential ID to each logged
39+
// request/response pair. Because oras-go performs concurrent HTTP requests
40+
// (e.g. parallel blob fetches), the ID lets callers correlate a request log
41+
// line with its corresponding response log line when output is interleaved.
42+
var requestCounter atomic.Uint64
43+
44+
// LoggingTransport is an http.RoundTripper that logs every request and its
45+
// response at slog.LevelDebug. It is safe for concurrent use.
46+
//
47+
// Usage:
48+
//
49+
// reg := remote.NewRegistry("example.com")
50+
// reg.Client = &auth.Client{
51+
// Client: &http.Client{
52+
// Transport: remote.NewLoggingTransport(http.DefaultTransport, nil),
53+
// },
54+
// }
55+
type LoggingTransport struct {
56+
inner http.RoundTripper
57+
logger *slog.Logger
58+
}
59+
60+
// NewLoggingTransport wraps inner with request/response debug logging.
61+
// If logger is nil, slog.Default() is used. If inner is nil,
62+
// http.DefaultTransport is used.
63+
func NewLoggingTransport(inner http.RoundTripper, logger *slog.Logger) *LoggingTransport {
64+
if inner == nil {
65+
inner = http.DefaultTransport
66+
}
67+
if logger == nil {
68+
logger = slog.Default()
69+
}
70+
return &LoggingTransport{inner: inner, logger: logger}
71+
}
72+
73+
// RoundTrip implements http.RoundTripper, logging the request and response.
74+
func (t *LoggingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
75+
id := requestCounter.Add(1) - 1
76+
77+
t.logger.Debug(req.Method,
78+
"id", id,
79+
"url", req.URL,
80+
"header", formatHeaders(req.Header),
81+
)
82+
83+
resp, err := t.inner.RoundTrip(req)
84+
if err != nil {
85+
t.logger.Debug("Response",
86+
"id", id,
87+
"error", err,
88+
)
89+
return resp, err
90+
}
91+
92+
t.logger.Debug("Response",
93+
"id", id,
94+
"status", resp.Status,
95+
"header", formatHeaders(resp.Header),
96+
"body", formatResponseBody(resp),
97+
)
98+
return resp, nil
99+
}
100+
101+
// formatHeaders returns a human-readable representation of the headers with
102+
// sensitive values (Authorization, Set-Cookie) replaced by "*****".
103+
func formatHeaders(header http.Header) string {
104+
if len(header) == 0 {
105+
return " Empty header"
106+
}
107+
var parts []string
108+
for k, v := range header {
109+
val := strings.Join(v, ", ")
110+
for _, sensitive := range sensitiveHeaders {
111+
if strings.EqualFold(k, sensitive) {
112+
val = "*****"
113+
break
114+
}
115+
}
116+
parts = append(parts, fmt.Sprintf(" %q: %q", k, val))
117+
}
118+
return strings.Join(parts, "\n")
119+
}
120+
121+
// formatResponseBody reads up to loggingPayloadSizeLimit bytes from the
122+
// response body and returns them as a string, then restores resp.Body so
123+
// subsequent reads by the caller see the full body. Non-printable content
124+
// types and bodies containing potential credentials are not printed.
125+
func formatResponseBody(resp *http.Response) string {
126+
if resp.Body == nil || resp.Body == http.NoBody {
127+
return " No response body"
128+
}
129+
130+
contentType := resp.Header.Get("Content-Type")
131+
if contentType == "" {
132+
return " Response body without content type not printed"
133+
}
134+
if !isLoggableContentType(contentType) {
135+
return fmt.Sprintf(" Response body of content type %q not printed", contentType)
136+
}
137+
138+
// Read up to the limit into buf, then restore resp.Body by prepending
139+
// the already-read bytes ahead of the remaining body.
140+
var buf bytes.Buffer
141+
if _, err := io.CopyN(&buf, resp.Body, loggingPayloadSizeLimit+1); err != nil && err != io.EOF {
142+
return fmt.Sprintf(" Error reading response body: %v", err)
143+
}
144+
145+
// Restore: callers see buf contents followed by any unread remainder.
146+
remaining := resp.Body
147+
resp.Body = struct {
148+
io.Reader
149+
io.Closer
150+
}{
151+
Reader: io.MultiReader(bytes.NewReader(buf.Bytes()), remaining),
152+
Closer: remaining,
153+
}
154+
155+
body := buf.String()
156+
if len(body) == 0 {
157+
return " Response body is empty"
158+
}
159+
if containsCredentialFields(body) {
160+
return " Response body redacted (potential credentials)"
161+
}
162+
if int64(len(body)) > loggingPayloadSizeLimit {
163+
return body[:loggingPayloadSizeLimit] + "\n...(truncated)"
164+
}
165+
return body
166+
}
167+
168+
// isLoggableContentType returns true for JSON and plain-text content types.
169+
func isLoggableContentType(contentType string) bool {
170+
mediaType, _, err := mime.ParseMediaType(contentType)
171+
if err != nil {
172+
return false
173+
}
174+
switch mediaType {
175+
case "application/json", "text/plain", "text/html":
176+
return true
177+
}
178+
return strings.HasSuffix(mediaType, "+json")
179+
}
180+
181+
// containsCredentialFields returns true if the body appears to contain
182+
// authentication tokens that should not be logged.
183+
func containsCredentialFields(body string) bool {
184+
return strings.Contains(body, `"token"`) || strings.Contains(body, `"access_token"`)
185+
}
Lines changed: 196 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,196 @@
1+
/*
2+
Copyright The ORAS Authors.
3+
Licensed under the Apache License, Version 2.0 (the "License");
4+
you may not use this file except in compliance with the License.
5+
You may obtain a copy of the License at
6+
7+
http://www.apache.org/licenses/LICENSE-2.0
8+
9+
Unless required by applicable law or agreed to in writing, software
10+
distributed under the License is distributed on an "AS IS" BASIS,
11+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
See the License for the specific language governing permissions and
13+
limitations under the License.
14+
*/
15+
16+
package remote
17+
18+
import (
19+
"io"
20+
"log/slog"
21+
"net/http"
22+
"net/http/httptest"
23+
"strings"
24+
"testing"
25+
)
26+
27+
// roundTripFunc is an http.RoundTripper backed by a function.
28+
type roundTripFunc func(*http.Request) (*http.Response, error)
29+
30+
func (f roundTripFunc) RoundTrip(req *http.Request) (*http.Response, error) { return f(req) }
31+
32+
func TestNewLoggingTransport_Defaults(t *testing.T) {
33+
lt := NewLoggingTransport(nil, nil)
34+
if lt.inner == nil {
35+
t.Error("inner should default to http.DefaultTransport")
36+
}
37+
if lt.logger == nil {
38+
t.Error("logger should default to slog.Default()")
39+
}
40+
}
41+
42+
func TestLoggingTransport_RoundTrip(t *testing.T) {
43+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
44+
w.Header().Set("Content-Type", "application/json")
45+
w.WriteHeader(http.StatusOK)
46+
w.Write([]byte(`{"status":"ok"}`))
47+
}))
48+
defer srv.Close()
49+
50+
lt := NewLoggingTransport(http.DefaultTransport, slog.Default())
51+
req, _ := http.NewRequest(http.MethodGet, srv.URL, nil)
52+
resp, err := lt.RoundTrip(req)
53+
if err != nil {
54+
t.Fatalf("RoundTrip() error = %v", err)
55+
}
56+
defer resp.Body.Close()
57+
58+
// Body must still be readable after LoggingTransport consumed it for logging.
59+
body, err := io.ReadAll(resp.Body)
60+
if err != nil {
61+
t.Fatalf("ReadAll() error = %v", err)
62+
}
63+
if string(body) != `{"status":"ok"}` {
64+
t.Errorf("body = %q, want %q", body, `{"status":"ok"}`)
65+
}
66+
}
67+
68+
func TestLoggingTransport_RoundTrip_Error(t *testing.T) {
69+
wantErr := io.ErrUnexpectedEOF
70+
inner := roundTripFunc(func(*http.Request) (*http.Response, error) {
71+
return nil, wantErr
72+
})
73+
lt := NewLoggingTransport(inner, slog.Default())
74+
req, _ := http.NewRequest(http.MethodGet, "http://example.com", nil)
75+
_, err := lt.RoundTrip(req)
76+
if err != wantErr {
77+
t.Errorf("RoundTrip() error = %v, want %v", err, wantErr)
78+
}
79+
}
80+
81+
func TestFormatHeaders_Scrubbing(t *testing.T) {
82+
h := http.Header{
83+
"Authorization": {"Bearer secret"},
84+
"Content-Type": {"application/json"},
85+
"Set-Cookie": {"session=abc"},
86+
}
87+
out := formatHeaders(h)
88+
if strings.Contains(out, "secret") {
89+
t.Error("Authorization value should be scrubbed")
90+
}
91+
if strings.Contains(out, "session=abc") {
92+
t.Error("Set-Cookie value should be scrubbed")
93+
}
94+
if !strings.Contains(out, "Content-Type") {
95+
t.Error("Content-Type should be present")
96+
}
97+
}
98+
99+
func TestFormatHeaders_Empty(t *testing.T) {
100+
out := formatHeaders(http.Header{})
101+
if !strings.Contains(out, "Empty") {
102+
t.Errorf("expected empty header message, got %q", out)
103+
}
104+
}
105+
106+
func TestFormatResponseBody_NoBody(t *testing.T) {
107+
resp := &http.Response{Body: http.NoBody}
108+
out := formatResponseBody(resp)
109+
if !strings.Contains(out, "No response body") {
110+
t.Errorf("got %q", out)
111+
}
112+
}
113+
114+
func TestFormatResponseBody_NonPrintable(t *testing.T) {
115+
resp := &http.Response{
116+
Header: http.Header{"Content-Type": {"application/octet-stream"}},
117+
Body: io.NopCloser(strings.NewReader("binary")),
118+
}
119+
out := formatResponseBody(resp)
120+
if !strings.Contains(out, "not printed") {
121+
t.Errorf("got %q", out)
122+
}
123+
}
124+
125+
func TestFormatResponseBody_CredentialRedaction(t *testing.T) {
126+
resp := &http.Response{
127+
Header: http.Header{"Content-Type": {"application/json"}},
128+
Body: io.NopCloser(strings.NewReader(`{"token":"secret"}`)),
129+
}
130+
out := formatResponseBody(resp)
131+
if !strings.Contains(out, "redacted") {
132+
t.Errorf("got %q", out)
133+
}
134+
}
135+
136+
func TestFormatResponseBody_BodyRestored(t *testing.T) {
137+
payload := `{"foo":"bar"}`
138+
resp := &http.Response{
139+
Header: http.Header{"Content-Type": {"application/json"}},
140+
Body: io.NopCloser(strings.NewReader(payload)),
141+
}
142+
formatResponseBody(resp)
143+
144+
// Body must be intact after formatResponseBody reads it.
145+
got, err := io.ReadAll(resp.Body)
146+
if err != nil {
147+
t.Fatalf("ReadAll after formatResponseBody: %v", err)
148+
}
149+
if string(got) != payload {
150+
t.Errorf("body after logging = %q, want %q", got, payload)
151+
}
152+
}
153+
154+
func TestFormatResponseBody_Truncated(t *testing.T) {
155+
large := strings.Repeat("a", int(loggingPayloadSizeLimit)+100)
156+
resp := &http.Response{
157+
Header: http.Header{"Content-Type": {"text/plain"}},
158+
Body: io.NopCloser(strings.NewReader(large)),
159+
}
160+
out := formatResponseBody(resp)
161+
if !strings.Contains(out, "truncated") {
162+
t.Errorf("expected truncation notice, got %q", out[:50])
163+
}
164+
}
165+
166+
func TestIsLoggableContentType(t *testing.T) {
167+
tests := []struct {
168+
ct string
169+
want bool
170+
}{
171+
{"application/json", true},
172+
{"application/json; charset=utf-8", true},
173+
{"application/vnd.oci.image.manifest.v1+json", true},
174+
{"text/plain", true},
175+
{"text/html", true},
176+
{"application/octet-stream", false},
177+
{"", false},
178+
}
179+
for _, tt := range tests {
180+
if got := isLoggableContentType(tt.ct); got != tt.want {
181+
t.Errorf("isLoggableContentType(%q) = %v, want %v", tt.ct, got, tt.want)
182+
}
183+
}
184+
}
185+
186+
func TestContainsCredentialFields(t *testing.T) {
187+
if !containsCredentialFields(`{"token":"x"}`) {
188+
t.Error(`expected true for "token"`)
189+
}
190+
if !containsCredentialFields(`{"access_token":"x"}`) {
191+
t.Error(`expected true for "access_token"`)
192+
}
193+
if containsCredentialFields(`{"status":"ok"}`) {
194+
t.Error("expected false for non-credential body")
195+
}
196+
}

0 commit comments

Comments
 (0)