Surface GCP SDK HTTP wire logs at V(5)

Inject an option.WithLogger slog logger bridged to the zap sink via
logr.ToSlogHandler with a V(1) shift, so the SDK's Debug-level
"api request"/"api response" records (URL, headers, full payloads)
appear only at --zap-log-level=5. Startup warning when active, since
raw insert payloads include cloud-init user-data. Note WithLogger
overrides GOOGLE_SDK_GO_LOGGING_LEVEL for this client.

Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
2026-08-11 18:39:37 +02:00
parent 4619c352c0
commit ed59a4c384
3 changed files with 105 additions and 1 deletions

View File

@@ -0,0 +1,37 @@
# Execution: GCP HTTP wire logging at V(5)
Plan: `docs/plans/2026-08-11-1838-gcp-http-wire-logging-v5.md`
- [x] Step 1 — `wireLogger` + `option.WithLogger` wiring in `internal/provider/gcp/gcp.go`
- [x] Step 2 — Tests (`TestWireLogger_gatesAtV5`, `TestWireLogger_infoLandsAtV1`)
- [ ] Step 3 — Live verification at `--zap-log-level=5` (user, on cluster)
- [ ] Step 4 — CHANGELOG entry (after live confirmation; batch with the two
earlier pending entries: GCP V-logging, version stamp)
## Steps 12
Went exactly as planned — the whole feature is ~10 lines of production code
because both halves already existed: the compute SDK logs full HTTP
request/response records at slog Debug to an injectable logger, and
`logr.ToSlogHandler` does the slog→logr bridging. The only real design
content is the level shift (`base.V(1)` + slog-Debug's +4 = V(5)) and the
startup warning line when V(5) is active (raw payloads include cloud-init
user-data, which the curated V(2) logging deliberately hides).
Worth noting for future readers:
- `option.WithLogger` **disables** `GOOGLE_SDK_GO_LOGGING_LEVEL` for this
client (documented SDK precedence) — `--zap-log-level` is now the only knob
for GCP wire logs.
- The V(5) check in `New` runs once at startup; that is sound because the zap
level is fixed by flags at process start.
- Added `TestWireLogger_infoLandsAtV1` beyond the plan's table — it pins the
shift arithmetic from the other side (slog Info → V(1)), so a future logr
mapping change would fail loudly.
Verified with:
```bash
go test -race ./internal/provider/gcp/
go build ./... && go test ./...
```

View File

@@ -9,6 +9,7 @@ package gcp
import (
"context"
"fmt"
"log/slog"
"strings"
"time"
@@ -16,6 +17,7 @@ import (
"cloud.google.com/go/compute/apiv1/computepb"
"github.com/go-logr/logr"
"google.golang.org/api/iterator"
"google.golang.org/api/option"
"google.golang.org/protobuf/proto"
logf "sigs.k8s.io/controller-runtime/pkg/log"
@@ -83,12 +85,28 @@ type Provider struct {
api instancesAPI
}
// wireLogger returns the slog logger handed to the SDK: its Debug-level
// "api request"/"api response" records (slog Debug = +4 on the logr
// scale) land at V(5) on top of the base's V(1) shift.
func wireLogger(base logr.Logger) *slog.Logger {
return slog.New(logr.ToSlogHandler(base.V(1)))
}
// New builds a Provider using Application Default Credentials (workload
// identity in-cluster, gcloud ADC locally — no key-file plumbing).
// Deliberately untested: it dials real Google endpoints; everything below
// it is exercised through newWithAPI.
//
// The injected wire logger surfaces the SDK's raw HTTP request/response
// records at V(5); note option.WithLogger overrides the SDK's own
// GOOGLE_SDK_GO_LOGGING_LEVEL env var, so --zap-log-level is the only knob.
func New(ctx context.Context, pc provider.ProviderConfig) (provider.Provider, error) {
client, err := compute.NewInstancesRESTClient(ctx)
base := logf.Log.WithName("gcp").WithName("http")
if base.V(5).Enabled() {
logf.Log.WithName("gcp").Info(
"GCP HTTP wire logging active — request payloads include cloud-init user-data")
}
client, err := compute.NewInstancesRESTClient(ctx, option.WithLogger(wireLogger(base)))
if err != nil {
return nil, fmt.Errorf("creating GCP instances client: %w", err)
}

View File

@@ -397,6 +397,55 @@ func TestLogging_verbosityTiers(t *testing.T) {
}
}
func TestWireLogger_gatesAtV5(t *testing.T) {
t.Parallel()
tests := []struct {
name string
verbosity int
wantDebug bool
}{
{name: "v5 shows wire records", verbosity: 5, wantDebug: true},
{name: "v4 hides wire records", verbosity: 4, wantDebug: false},
{name: "v2 hides wire records", verbosity: 2, wantDebug: false},
}
for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
t.Parallel()
lines := &[]string{}
base := funcr.New(func(prefix, args string) {
*lines = append(*lines, prefix+" "+args)
}, funcr.Options{Verbosity: tc.verbosity})
slogger := wireLogger(base)
slogger.Debug("api request", "rpcName", "Insert")
joined := strings.Join(*lines, "\n")
if got := strings.Contains(joined, "api request"); got != tc.wantDebug {
t.Errorf("Debug record visible = %v, want %v; output:\n%s", got, tc.wantDebug, joined)
}
if tc.wantDebug && !strings.Contains(joined, "rpcName") {
t.Errorf("wire record lost its attrs:\n%s", joined)
}
})
}
}
func TestWireLogger_infoLandsAtV1(t *testing.T) {
t.Parallel()
lines := &[]string{}
base := funcr.New(func(prefix, args string) {
*lines = append(*lines, prefix+" "+args)
}, funcr.Options{Verbosity: 1})
wireLogger(base).Info("hello")
if joined := strings.Join(*lines, "\n"); !strings.Contains(joined, "hello") {
t.Errorf("slog Info should land at V(1) and be visible at verbosity 1; output:\n%s", joined)
}
}
func TestLogging_apiErrorKeepsHTTPDetail(t *testing.T) {
t.Parallel()
ctx, lines := captureContext(1)