feat(compute/metadata): add debug logging (googleapis#11078)

compute/metadata/go.mod

@@ -2,4 +2,7 @@ module cloud.google.com/go/compute/metadata
 
 go 1.21
 
-require golang.org/x/sys v0.28.0
+require (
+	github.com/google/go-cmp v0.6.0
+	golang.org/x/sys v0.28.0
+)

compute/metadata/go.sum

@@ -1,2 +1,4 @@
+github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
+github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
 golang.org/x/sys v0.28.0 h1:Fksou7UEQUWlKvIdsqzJmUmCX3cZuD2+P3XyyzwMhlA=
 golang.org/x/sys v0.28.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=

compute/metadata/log.go

@@ -0,0 +1,149 @@
+// Copyright 2024 Google LLC
+//
+// 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 metadata
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"fmt"
+	"log/slog"
+	"net/http"
+	"strings"
+)
+
+// Code below this point is copied from github.com/googleapis/gax-go/v2/internallog
+// to avoid the dependency. The compute/metadata module is used by too many
+// non-client library modules that can't justify the dependency.
+
+// The handler returned if logging is not enabled.
+type noOpHandler struct{}
+
+func (h noOpHandler) Enabled(_ context.Context, _ slog.Level) bool {
+	return false
+}
+
+func (h noOpHandler) Handle(_ context.Context, _ slog.Record) error {
+	return nil
+}
+
+func (h noOpHandler) WithAttrs(_ []slog.Attr) slog.Handler {
+	return h
+}
+
+func (h noOpHandler) WithGroup(_ string) slog.Handler {
+	return h
+}
+
+// httpRequest returns a lazily evaluated [slog.LogValuer] for a
+// [http.Request] and the associated body.
+func httpRequest(req *http.Request, body []byte) slog.LogValuer {
+	return &request{
+		req:     req,
+		payload: body,
+	}
+}
+
+type request struct {
+	req     *http.Request
+	payload []byte
+}
+
+func (r *request) LogValue() slog.Value {
+	if r == nil || r.req == nil {
+		return slog.Value{}
+	}
+	var groupValueAttrs []slog.Attr
+	groupValueAttrs = append(groupValueAttrs, slog.String("method", r.req.Method))
+	groupValueAttrs = append(groupValueAttrs, slog.String("url", r.req.URL.String()))
+
+	var headerAttr []slog.Attr
+	for k, val := range r.req.Header {
+		headerAttr = append(headerAttr, slog.String(k, strings.Join(val, ",")))
+	}
+	if len(headerAttr) > 0 {
+		groupValueAttrs = append(groupValueAttrs, slog.Any("headers", headerAttr))
+	}
+
+	if len(r.payload) > 0 {
+		if attr, ok := processPayload(r.payload); ok {
+			groupValueAttrs = append(groupValueAttrs, attr)
+		}
+	}
+	return slog.GroupValue(groupValueAttrs...)
+}
+
+// httpResponse returns a lazily evaluated [slog.LogValuer] for a
+// [http.Response] and the associated body.
+func httpResponse(resp *http.Response, body []byte) slog.LogValuer {
+	return &response{
+		resp:    resp,
+		payload: body,
+	}
+}
+
+type response struct {
+	resp    *http.Response
+	payload []byte
+}
+
+func (r *response) LogValue() slog.Value {
+	if r == nil {
+		return slog.Value{}
+	}
+	var groupValueAttrs []slog.Attr
+	groupValueAttrs = append(groupValueAttrs, slog.String("status", fmt.Sprint(r.resp.StatusCode)))
+
+	var headerAttr []slog.Attr
+	for k, val := range r.resp.Header {
+		headerAttr = append(headerAttr, slog.String(k, strings.Join(val, ",")))
+	}
+	if len(headerAttr) > 0 {
+		groupValueAttrs = append(groupValueAttrs, slog.Any("headers", headerAttr))
+	}
+
+	if len(r.payload) > 0 {
+		if attr, ok := processPayload(r.payload); ok {
+			groupValueAttrs = append(groupValueAttrs, attr)
+		}
+	}
+	return slog.GroupValue(groupValueAttrs...)
+}
+
+func processPayload(payload []byte) (slog.Attr, bool) {
+	peekChar := payload[0]
+	if peekChar == '{' {
+		// JSON object
+		var m map[string]any
+		if err := json.Unmarshal(payload, &m); err == nil {
+			return slog.Any("payload", m), true
+		}
+	} else if peekChar == '[' {
+		// JSON array
+		var m []any
+		if err := json.Unmarshal(payload, &m); err == nil {
+			return slog.Any("payload", m), true
+		}
+	} else {
+		// Everything else
+		buf := &bytes.Buffer{}
+		if err := json.Compact(buf, payload); err != nil {
+			// Write raw payload incase of error
+			buf.Write(payload)
+		}
+		return slog.String("payload", buf.String()), true
+	}
+	return slog.Attr{}, false
+}

compute/metadata/log_test.go

@@ -0,0 +1,137 @@
+// Copyright 2024 Google LLC
+//
+// 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 metadata
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"flag"
+	"io"
+	"log/slog"
+	"net/http"
+	"os"
+	"path/filepath"
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+)
+
+var updateGolden = flag.Bool("update-golden", false, "update golden files")
+
+// To update conformance tests in this package run `go test -update_golden`
+func TestMain(m *testing.M) {
+	flag.Parse()
+	os.Exit(m.Run())
+}
+
+func TestLog_httpRequest(t *testing.T) {
+	golden := "httpRequest.log"
+	logger, f := setupLogger(t, golden)
+	ctx := context.Background()
+	request, err := http.NewRequest(http.MethodPost, "https://example.com/computeMetadata/v1/instance/service-accounts/default/token", nil)
+	if err != nil {
+		t.Fatal(err)
+	}
+	request.Header.Add("foo", "bar")
+	logger.DebugContext(ctx, "msg", "request", httpRequest(request, nil))
+	f.Close()
+	diffTest(t, f.Name(), golden)
+}
+
+func TestLog_httpResponse(t *testing.T) {
+	golden := "httpResponse.log"
+	logger, f := setupLogger(t, golden)
+	ctx := context.Background()
+	body := []byte(`{"access_token":"token","expires_in":600,"token_type":"Bearer"}`)
+	response := &http.Response{
+		StatusCode: 200,
+		Header:     http.Header{"Foo": []string{"bar"}},
+		Body:       io.NopCloser(bytes.NewReader(body)),
+	}
+	logger.DebugContext(ctx, "msg", "response", httpResponse(response, body))
+	f.Close()
+	diffTest(t, f.Name(), golden)
+}
+
+func setupLogger(t *testing.T, golden string) (*slog.Logger, *os.File) {
+	t.Helper()
+	f, err := os.CreateTemp(t.TempDir(), golden)
+	if err != nil {
+		t.Fatal(err)
+	}
+	logger := slog.New(slog.NewJSONHandler(f, &slog.HandlerOptions{
+		Level: slog.LevelDebug,
+	}))
+	return logger, f
+}
+
+// diffTest is a test helper, testing got against contents of a goldenFile.
+func diffTest(t *testing.T, tempFile, goldenFile string) {
+	rawGot, err := os.ReadFile(tempFile)
+	if err != nil {
+		t.Fatal(err)
+	}
+	t.Helper()
+	if *updateGolden {
+		got := removeLogVariance(t, rawGot)
+		if err := os.WriteFile(filepath.Join("testdata", goldenFile), got, os.ModePerm); err != nil {
+			t.Fatal(err)
+		}
+		return
+	}
+
+	want, err := os.ReadFile(filepath.Join("testdata", goldenFile))
+	if err != nil {
+		t.Fatal(err)
+	}
+	got := removeLogVariance(t, rawGot)
+
+	if diff := cmp.Diff(want, got); diff != "" {
+		t.Errorf("mismatch(-want, +got): %s", diff)
+	}
+}
+
+// removeLogVariance removes parts of log lines that may differ between runs
+// and/or machines.
+func removeLogVariance(t *testing.T, in []byte) []byte {
+	if len(in) == 0 {
+		return in
+	}
+	bs := bytes.Split(in, []byte("\n"))
+	for i, b := range bs {
+		if len(b) == 0 {
+			continue
+		}
+		m := map[string]any{}
+		if err := json.Unmarshal(b, &m); err != nil {
+			t.Fatal(err)
+		}
+		delete(m, "time")
+		if sl, ok := m["sourceLocation"].(map[string]any); ok {
+			delete(sl, "file")
+			// So that if test cases move around in this file they don't cause
+			// failures
+			delete(sl, "line")
+		}
+		b2, err := json.Marshal(m)
+		if err != nil {
+			t.Fatal(err)
+		}
+		t.Logf("%s", b2)
+		bs[i] = b2
+	}
+	return bytes.Join(bs, []byte("\n"))
+}