Skip to content

Commit

Permalink
feat: add logging to gapics
Browse files Browse the repository at this point in the history
As a follow up to this PR we will need to add a little logging
support in the gax REST streaming helper. For now we should add
this with minimal changes but in the future we may want to feed
that helper more information to have richer logs. This is a very
small amount of RPCs that use this code path today.
  • Loading branch information
codyoss committed Sep 18, 2024
1 parent f8a560e commit 8ec48b2
Show file tree
Hide file tree
Showing 39 changed files with 127 additions and 13 deletions.
32 changes: 24 additions & 8 deletions internal/gengapic/client_init_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -414,6 +414,9 @@ func TestClientInit(t *testing.T) {
{Name: "iampb", Path: "cloud.google.com/go/iam/apiv1/iampb"}: true,
{Name: "locationpb", Path: "google.golang.org/genproto/googleapis/cloud/location"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog/cloggrpc"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 6,
},
Expand All @@ -436,6 +439,8 @@ func TestClientInit(t *testing.T) {
{Name: "iampb", Path: "cloud.google.com/go/iam/apiv1/iampb"}: true,
{Name: "locationpb", Path: "google.golang.org/genproto/googleapis/cloud/location"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 6,
},
Expand All @@ -453,6 +458,9 @@ func TestClientInit(t *testing.T) {
{Name: "gtransport", Path: "google.golang.org/api/transport/grpc"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Name: "httptransport", Path: "google.golang.org/api/transport/http"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog/cloggrpc"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 1,
},
Expand All @@ -469,9 +477,12 @@ func TestClientInit(t *testing.T) {
{Name: "longrunningpb", Path: "cloud.google.com/go/longrunning/autogen/longrunningpb"}: true,
{Name: "lroauto", Path: "cloud.google.com/go/longrunning/autogen"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Path: "context"}: true,
{Path: "google.golang.org/api/option"}: true,
{Path: "google.golang.org/grpc"}: true,
{Path: "context"}: true,
{Path: "google.golang.org/api/option"}: true,
{Path: "google.golang.org/grpc"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog/cloggrpc"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 6,
},
Expand All @@ -484,11 +495,14 @@ func TestClientInit(t *testing.T) {
{Name: "gtransport", Path: "google.golang.org/api/transport/grpc"}: true,
{Name: "httptransport", Path: "google.golang.org/api/transport/http"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Path: "context"}: true,
{Path: "google.golang.org/api/option"}: true,
{Path: "google.golang.org/api/option/internaloption"}: true,
{Path: "google.golang.org/grpc"}: true,
{Path: "net/http"}: true,
{Path: "context"}: true,
{Path: "google.golang.org/api/option"}: true,
{Path: "google.golang.org/api/option/internaloption"}: true,
{Path: "google.golang.org/grpc"}: true,
{Path: "net/http"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog/cloggrpc"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 1,
},
Expand All @@ -506,6 +520,8 @@ func TestClientInit(t *testing.T) {
{Path: "net/http"}: true,
{Name: "httptransport", Path: "google.golang.org/api/transport/http"}: true,
{Name: "mypackagepb", Path: "github.com/googleapis/mypackage"}: true,
{Path: "github.com/googleapis/gax-go/v2/clog"}: true,
{Path: "log/slog"}: true,
},
wantNumSnps: 1,
setExt: func() (protoreflect.ExtensionType, interface{}) {
Expand Down
2 changes: 2 additions & 0 deletions internal/gengapic/doc_file.go
Original file line number Diff line number Diff line change
Expand Up @@ -133,6 +133,8 @@ func (g *generator) genDocFile(year int, scopes []string, serv *descriptorpb.Ser
p(")")
p("")

p("const serviceName = %q", g.serviceConfig.GetName())

p("// For more information on implementing a client constructor hook, see")
p("// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.")
p("type clientHookParams struct{}")
Expand Down
9 changes: 9 additions & 0 deletions internal/gengapic/gengrpc.go
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,9 @@ func (g *generator) unaryGRPCCall(servName string, m *descriptorpb.MethodDescrip
p("var resp *%s", retTyp)
p("err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" resp, err = %s", g.grpcStubCall(m))
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", cloggrpc.ProtoMessageResponse(req))`, m.GetName())
p(" return err")
p("}, opts...)")
p("if err != nil {")
Expand Down Expand Up @@ -147,7 +149,9 @@ func (g *generator) emptyUnaryGRPCCall(servName string, m *descriptorpb.MethodDe
g.appendCallOpts(m)
p("err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" _, err = %s", g.grpcStubCall(m))
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api empty response", "serviceName", serviceName, "rpcName", %q)`, m.GetName())
p(" return err")
p("}, opts...)")
p("return err")
Expand Down Expand Up @@ -295,10 +299,15 @@ func (g *generator) grpcClientInit(serv *descriptorpb.ServiceDescriptorProto, se

p("// The x-goog-* metadata to be sent with each request.")
p("xGoogHeaders []string")
p("")
p("logger *slog.Logger")

p("}")
p("")

g.imports[pbinfo.ImportSpec{Path: "log/slog"}] = true
g.imports[pbinfo.ImportSpec{Path: "github.com/googleapis/gax-go/v2/clog"}] = true
g.imports[pbinfo.ImportSpec{Path: "github.com/googleapis/gax-go/v2/clog/cloggrpc"}] = true
g.imports[pbinfo.ImportSpec{Path: "google.golang.org/grpc"}] = true
g.imports[imp] = true

Expand Down
29 changes: 24 additions & 5 deletions internal/gengapic/genrest.go
Original file line number Diff line number Diff line change
Expand Up @@ -91,10 +91,14 @@ func (g *generator) restClientInit(serv *descriptorpb.ServiceDescriptorProto, se
p("")
p(" // Points back to the CallOptions field of the containing %sClient", servName)
p(" CallOptions **%sCallOptions", servName)
p("")
p(" logger *slog.Logger")
p("}")
p("")
g.restClientUtilities(serv, servName, hasRPCForLRO)

g.imports[pbinfo.ImportSpec{Path: "log/slog"}] = true
g.imports[pbinfo.ImportSpec{Path: "github.com/googleapis/gax-go/v2/clog"}] = true
g.imports[pbinfo.ImportSpec{Path: "net/http"}] = true
g.imports[pbinfo.ImportSpec{Name: "httptransport", Path: "google.golang.org/api/transport/http"}] = true
g.imports[pbinfo.ImportSpec{Path: "google.golang.org/api/option/internaloption"}] = true
Expand Down Expand Up @@ -617,7 +621,7 @@ func (g *generator) serverStreamRESTCall(servName string, s *descriptorpb.Servic
// rest-client method
p("func (c *%s) %s(ctx context.Context, req *%s.%s, opts ...gax.CallOption) (%s.%s_%sClient, error) {",
lowcaseServName, m.GetName(), inSpec.Name, inType.GetName(), servSpec.Name, s.GetName(), m.GetName())
body := "nil"
body, logBody := "nil", "nil"
verb := strings.ToUpper(info.verb)

// Marshal body for HTTP methods that take a body.
Expand All @@ -638,6 +642,7 @@ func (g *generator) serverStreamRESTCall(servName string, s *descriptorpb.Servic
p("")

body = "bytes.NewReader(jsonReq)"
logBody = "jsonReq"
g.imports[pbinfo.ImportSpec{Path: "bytes"}] = true
g.imports[pbinfo.ImportSpec{Path: "google.golang.org/protobuf/encoding/protojson"}] = true
}
Expand All @@ -658,6 +663,7 @@ func (g *generator) serverStreamRESTCall(servName string, s *descriptorpb.Servic
p(" httpReq = httpReq.WithContext(ctx)")
p(" httpReq.Header = headers")
p("")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", clog.HTTPRequest(httpReq, %s))`, m.GetName(), logBody)
p(" httpRsp, err := c.httpClient.Do(httpReq)")
p(" if err != nil{")
p(" return err")
Expand Down Expand Up @@ -800,10 +806,12 @@ func (g *generator) pagingRESTCall(servName string, m *descriptorpb.MethodDescri
p("it := &%s{}", pt.iterTypeName)
p("req = proto.Clone(req).(*%s.%s)", inSpec.Name, inType.GetName())

maybeReqBytes := "nil"
maybeReqBytes, logBody := "nil", "nil"

if info.body != "" {
g.protoJSONMarshaler()
maybeReqBytes = "bytes.NewReader(jsonReq)"
logBody = "jsonReq"
g.imports[pbinfo.ImportSpec{Path: "bytes"}] = true
}

Expand Down Expand Up @@ -835,6 +843,7 @@ func (g *generator) pagingRESTCall(servName string, m *descriptorpb.MethodDescri
// TODO: Should this http.Request use WithContext?
p(" httpReq.Header = headers")
p("")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", clog.HTTPRequest(httpReq, %s))`, m.GetName(), logBody)
p(" httpRsp, err := c.httpClient.Do(httpReq)")
p(" if err != nil{")
p(` return err`)
Expand All @@ -849,6 +858,7 @@ func (g *generator) pagingRESTCall(servName string, m *descriptorpb.MethodDescri
p(" if err != nil {")
p(` return err`)
p(" }")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", clog.HTTPResponse(httpRsp, buf))`, m.GetName())
p("")
p(" if err := unm.Unmarshal(buf, resp); err != nil {")
p(" return err")
Expand Down Expand Up @@ -916,7 +926,7 @@ func (g *generator) lroRESTCall(servName string, m *descriptorpb.MethodDescripto
// TODO(noahdietz): handle deadlines?
// TODO(noahdietz): handle calloptions

body := "nil"
body, logBody := "nil", "nil"
verb := strings.ToUpper(info.verb)

// Marshal body for HTTP methods that take a body.
Expand All @@ -937,6 +947,7 @@ func (g *generator) lroRESTCall(servName string, m *descriptorpb.MethodDescripto
p("")

body = "bytes.NewReader(jsonReq)"
logBody = "jsonReq"
g.imports[pbinfo.ImportSpec{Path: "bytes"}] = true
}

Expand All @@ -957,6 +968,7 @@ func (g *generator) lroRESTCall(servName string, m *descriptorpb.MethodDescripto
p(" httpReq = httpReq.WithContext(ctx)")
p(" httpReq.Header = headers")
p("")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", clog.HTTPRequest(httpReq, %s))`, m.GetName(), logBody)
p(" httpRsp, err := c.httpClient.Do(httpReq)")
p(" if err != nil{")
p(" return err")
Expand All @@ -966,6 +978,7 @@ func (g *generator) lroRESTCall(servName string, m *descriptorpb.MethodDescripto
p(" if err = googleapi.CheckResponse(httpRsp); err != nil {")
p(" return err")
p(" }")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", clog.HTTPResponse(httpRsp, buf))`, m.GetName())
p("")
p(" buf, err := io.ReadAll(httpRsp.Body)")
p(" if err != nil {")
Expand Down Expand Up @@ -1023,7 +1036,7 @@ func (g *generator) emptyUnaryRESTCall(servName string, m *descriptorpb.MethodDe
// TODO(dovs): handle deadlines
// TODO(dovs): handle call options

body := "nil"
body, logBody := "nil", "nil"
verb := strings.ToUpper(info.verb)

// Marshal body for HTTP methods that take a body.
Expand All @@ -1044,6 +1057,7 @@ func (g *generator) emptyUnaryRESTCall(servName string, m *descriptorpb.MethodDe
p("}")
p("")
body = "bytes.NewReader(jsonReq)"
logBody = "jsonReq"
g.imports[pbinfo.ImportSpec{Path: "bytes"}] = true
g.imports[pbinfo.ImportSpec{Path: "google.golang.org/protobuf/encoding/protojson"}] = true
}
Expand All @@ -1063,11 +1077,13 @@ func (g *generator) emptyUnaryRESTCall(servName string, m *descriptorpb.MethodDe
p(" httpReq = httpReq.WithContext(ctx)")
p(" httpReq.Header = headers")
p("")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", clog.HTTPRequest(httpReq, %s))`, m.GetName(), logBody)
p(" httpRsp, err := c.httpClient.Do(httpReq)")
p(" if err != nil{")
p(" return err")
p(" }")
p(" defer httpRsp.Body.Close()")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", clog.HTTPResponse(httpRsp, nil))`, m.GetName())
p("")
p(" // Returns nil if there is no error, otherwise wraps")
p(" // the response code and body into a non-nil error")
Expand Down Expand Up @@ -1117,7 +1133,7 @@ func (g *generator) unaryRESTCall(servName string, m *descriptorpb.MethodDescrip
// TODO(dovs): handle deadlines?
// TODO(dovs): handle calloptions

body := "nil"
body, logBody := "nil", "nil"
verb := strings.ToUpper(info.verb)

// Marshal body for HTTP methods that take a body.
Expand All @@ -1139,6 +1155,7 @@ func (g *generator) unaryRESTCall(servName string, m *descriptorpb.MethodDescrip
p("")

body = "bytes.NewReader(jsonReq)"
logBody = "jsonReq"
g.imports[pbinfo.ImportSpec{Path: "bytes"}] = true
g.imports[pbinfo.ImportSpec{Path: "google.golang.org/protobuf/encoding/protojson"}] = true

Expand Down Expand Up @@ -1166,6 +1183,7 @@ func (g *generator) unaryRESTCall(servName string, m *descriptorpb.MethodDescrip
p(" httpReq = httpReq.WithContext(ctx)")
p(" httpReq.Header = headers")
p("")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", clog.HTTPRequest(httpReq, %s))`, m.GetName(), logBody)
p(" httpRsp, err := c.httpClient.Do(httpReq)")
p(" if err != nil{")
p(" return err")
Expand All @@ -1180,6 +1198,7 @@ func (g *generator) unaryRESTCall(servName string, m *descriptorpb.MethodDescrip
p(" if err != nil {")
p(" return err")
p(" }")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", clog.HTTPResponse(httpRsp, buf))`, m.GetName())
p("")
if isHTTPBodyMessage {
p("resp.Data = buf")
Expand Down
2 changes: 2 additions & 0 deletions internal/gengapic/lro.go
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,9 @@ func (g *generator) lroCall(servName string, m *descriptorpb.MethodDescriptorPro
p(" var resp *%s.%s", outSpec.Name, outType.GetName())
p(" err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" resp, err = %s", g.grpcStubCall(m))
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", cloggrpc.ProtoMessageResponse(req))`, m.GetName())
p(" return err")
p(" }, opts...)")
p(" if err != nil {")
Expand Down
2 changes: 2 additions & 0 deletions internal/gengapic/paging.go
Original file line number Diff line number Diff line change
Expand Up @@ -392,7 +392,9 @@ func (g *generator) pagingCall(servName string, m *descriptorpb.MethodDescriptor
g.internalFetchSetup(outType, outSpec, pageSize, tok)
p(" err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" resp, err = %s", g.grpcStubCall(m))
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", cloggrpc.ProtoMessageResponse(req))`, m.GetName())
p(" return err")
p(" }, opts...)")
p(" if err != nil {")
Expand Down
4 changes: 4 additions & 0 deletions internal/gengapic/stream.go
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,9 @@ func (g *generator) noRequestStreamCall(servName string, s *descriptorpb.Service

p(" err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" resp, err = c.%s.%s(ctx, settings.GRPC...)", grpcClientField(servName), m.GetName())
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", cloggrpc.ProtoMessageResponse(req))`, m.GetName())
p(" return err")
p(" }, opts...)")
p(" if err != nil {")
Expand Down Expand Up @@ -83,7 +85,9 @@ func (g *generator) serverStreamCall(servName string, s *descriptorpb.ServiceDes
p(" var resp %s", retTyp)
p("err := gax.Invoke(ctx, func(ctx context.Context, settings gax.CallSettings) error {")
p(" var err error")
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api request", "serviceName", serviceName, "rpcName", %q, "request", cloggrpc.ProtoMessageRequest(ctx, req))`, m.GetName())
p(" resp, err = %s", g.grpcStubCall(m))
p(` c.logger.Log(ctx, clog.DynamicLevel(), "api response", "serviceName", serviceName, "rpcName", %q, "response", cloggrpc.ProtoMessageResponse(req))`, m.GetName())
p(" return err")
p("}, opts...)")
p("if err != nil {")
Expand Down
2 changes: 2 additions & 0 deletions internal/gengapic/testdata/custom_op_init.want
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,8 @@ type restClient struct {

// Points back to the CallOptions field of the containing Client
CallOptions **CallOptions

logger *slog.Logger
}

// NewRESTClient creates a new foo rest client.
Expand Down
4 changes: 4 additions & 0 deletions internal/gengapic/testdata/deprecated_client_init.want
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,8 @@ type gRPCClient struct {

// The x-goog-* metadata to be sent with each request.
xGoogHeaders []string

logger *slog.Logger
}

// NewClient creates a new foo client based on gRPC.
Expand Down Expand Up @@ -139,6 +141,8 @@ type restClient struct {

// Points back to the CallOptions field of the containing Client
CallOptions **CallOptions

logger *slog.Logger
}

// NewRESTClient creates a new foo rest client.
Expand Down
1 change: 1 addition & 0 deletions internal/gengapic/testdata/doc_file.want
Original file line number Diff line number Diff line change
Expand Up @@ -99,6 +99,7 @@ import (
"google.golang.org/api/option"
)

const serviceName = "secretmanager.googleapis.com"
// For more information on implementing a client constructor hook, see
// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.
type clientHookParams struct{}
Expand Down
1 change: 1 addition & 0 deletions internal/gengapic/testdata/doc_file_alpha.want
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,7 @@ import (
"google.golang.org/api/option"
)

const serviceName = "secretmanager.googleapis.com"
// For more information on implementing a client constructor hook, see
// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.
type clientHookParams struct{}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,7 @@ import (
"google.golang.org/api/option"
)

const serviceName = "secretmanager.googleapis.com"
// For more information on implementing a client constructor hook, see
// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.
type clientHookParams struct{}
Expand Down
1 change: 1 addition & 0 deletions internal/gengapic/testdata/doc_file_beta.want
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,7 @@ import (
"google.golang.org/api/option"
)

const serviceName = "secretmanager.googleapis.com"
// For more information on implementing a client constructor hook, see
// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.
type clientHookParams struct{}
Expand Down
1 change: 1 addition & 0 deletions internal/gengapic/testdata/doc_file_beta_emptyservice.want
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,7 @@ import (
"google.golang.org/api/option"
)

const serviceName = "secretmanager.googleapis.com"
// For more information on implementing a client constructor hook, see
// https://github.com/googleapis/google-cloud-go/wiki/Customizing-constructors.
type clientHookParams struct{}
Expand Down
Loading

0 comments on commit 8ec48b2

Please sign in to comment.