diff --git a/default_dial_option_server_option_test.go b/default_dial_option_server_option_test.go index 3dc446f58b5a..eecd6b846f28 100644 --- a/default_dial_option_server_option_test.go +++ b/default_dial_option_server_option_test.go @@ -38,7 +38,7 @@ func (s) TestAddExtraDialOptions(t *testing.T) { // Set and check the DialOptions opts := []DialOption{WithTransportCredentials(insecure.NewCredentials()), WithTransportCredentials(insecure.NewCredentials()), WithTransportCredentials(insecure.NewCredentials())} - internal.AddExtraDialOptions.(func(opt ...DialOption))(opts...) + internal.AddGlobalDialOptions.(func(opt ...DialOption))(opts...) for i, opt := range opts { if extraDialOptions[i] != opt { t.Fatalf("Unexpected extra dial option at index %d: %v != %v", i, extraDialOptions[i], opt) @@ -52,7 +52,7 @@ func (s) TestAddExtraDialOptions(t *testing.T) { cc.Close() } - internal.ClearExtraDialOptions() + internal.ClearGlobalDialOptions() if len(extraDialOptions) != 0 { t.Fatalf("Unexpected len of extraDialOptions: %d != 0", len(extraDialOptions)) } @@ -62,7 +62,7 @@ func (s) TestAddExtraServerOptions(t *testing.T) { const maxRecvSize = 998765 // Set and check the ServerOptions opts := []ServerOption{Creds(insecure.NewCredentials()), MaxRecvMsgSize(maxRecvSize)} - internal.AddExtraServerOptions.(func(opt ...ServerOption))(opts...) + internal.AddGlobalServerOptions.(func(opt ...ServerOption))(opts...) for i, opt := range opts { if extraServerOptions[i] != opt { t.Fatalf("Unexpected extra server option at index %d: %v != %v", i, extraServerOptions[i], opt) @@ -75,7 +75,7 @@ func (s) TestAddExtraServerOptions(t *testing.T) { t.Fatalf("Unexpected s.opts.maxReceiveMessageSize: %d != %d", s.opts.maxReceiveMessageSize, maxRecvSize) } - internal.ClearExtraServerOptions() + internal.ClearGlobalServerOptions() if len(extraServerOptions) != 0 { t.Fatalf("Unexpected len of extraServerOptions: %d != 0", len(extraServerOptions)) } diff --git a/dialoptions.go b/dialoptions.go index 60403bc160ec..9372dc322e80 100644 --- a/dialoptions.go +++ b/dialoptions.go @@ -29,6 +29,7 @@ import ( "google.golang.org/grpc/credentials/insecure" "google.golang.org/grpc/internal" internalbackoff "google.golang.org/grpc/internal/backoff" + "google.golang.org/grpc/internal/binarylog" "google.golang.org/grpc/internal/transport" "google.golang.org/grpc/keepalive" "google.golang.org/grpc/resolver" @@ -36,12 +37,13 @@ import ( ) func init() { - internal.AddExtraDialOptions = func(opt ...DialOption) { + internal.AddGlobalDialOptions = func(opt ...DialOption) { extraDialOptions = append(extraDialOptions, opt...) } - internal.ClearExtraDialOptions = func() { + internal.ClearGlobalDialOptions = func() { extraDialOptions = nil } + internal.WithBinaryLogger = withBinaryLogger } // dialOptions configure a Dial call. dialOptions are set by the DialOption @@ -61,6 +63,7 @@ type dialOptions struct { timeout time.Duration scChan <-chan ServiceConfig authority string + binaryLogger binarylog.Logger copts transport.ConnectOptions callOptions []CallOption channelzParentID *channelz.Identifier @@ -401,6 +404,14 @@ func WithStatsHandler(h stats.Handler) DialOption { }) } +// withBinaryLogger returns a DialOption that specifies the binary logger for +// this ClientConn. +func withBinaryLogger(bl binarylog.Logger) DialOption { + return newFuncDialOption(func(o *dialOptions) { + o.binaryLogger = bl + }) +} + // FailOnNonTempDialError returns a DialOption that specifies if gRPC fails on // non-temporary dial errors. If f is true, and dialer returns a non-temporary // error, gRPC will fail the connection to the network address and won't try to diff --git a/gcp/observability/config.go b/gcp/observability/config.go index 1a9f718e81b1..0b6067d8e770 100644 --- a/gcp/observability/config.go +++ b/gcp/observability/config.go @@ -21,6 +21,7 @@ package observability import ( "context" "encoding/json" + "errors" "fmt" "io/ioutil" "os" @@ -28,79 +29,15 @@ import ( gcplogging "cloud.google.com/go/logging" "golang.org/x/oauth2/google" + "google.golang.org/grpc/internal/envconfig" ) const ( - envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY" - envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON" - envProjectID = "GOOGLE_CLOUD_PROJECT" - logFilterPatternRegexpStr = `^([\w./]+)/((?:\w+)|[*])$` + envProjectID = "GOOGLE_CLOUD_PROJECT" + methodStringRegexpStr = `^([\w./]+)/((?:\w+)|[*])$` ) -var logFilterPatternRegexp = regexp.MustCompile(logFilterPatternRegexpStr) - -// logFilter represents a method logging configuration. -type logFilter struct { - // Pattern is a string which can select a group of method names. By - // default, the Pattern is an empty string, matching no methods. - // - // Only "*" Wildcard is accepted for Pattern. A Pattern is in the form - // of / or just a character "*" . - // - // If the Pattern is "*", it specifies the defaults for all the - // services; If the Pattern is /*, it specifies the defaults - // for all methods in the specified service ; If the Pattern is - // */, this is not supported. - // - // Examples: - // - "Foo/Bar" selects only the method "Bar" from service "Foo" - // - "Foo/*" selects all methods from service "Foo" - // - "*" selects all methods from all services. - Pattern string `json:"pattern,omitempty"` - // HeaderBytes is the number of bytes of each header to log. If the size of - // the header is greater than the defined limit, content past the limit will - // be truncated. The default value is 0. - HeaderBytes int32 `json:"header_bytes,omitempty"` - // MessageBytes is the number of bytes of each message to log. If the size - // of the message is greater than the defined limit, content pass the limit - // will be truncated. The default value is 0. - MessageBytes int32 `json:"message_bytes,omitempty"` -} - -// config is configuration for observability behaviors. By default, no -// configuration is required for tracing/metrics/logging to function. This -// config captures the most common knobs for gRPC users. It's always possible to -// override with explicit config in code. -type config struct { - // EnableCloudTrace represents whether the tracing data upload to - // CloudTrace should be enabled or not. - EnableCloudTrace bool `json:"enable_cloud_trace,omitempty"` - // EnableCloudMonitoring represents whether the metrics data upload to - // CloudMonitoring should be enabled or not. - EnableCloudMonitoring bool `json:"enable_cloud_monitoring,omitempty"` - // EnableCloudLogging represents Whether the logging data upload to - // CloudLogging should be enabled or not. - EnableCloudLogging bool `json:"enable_cloud_logging,omitempty"` - // DestinationProjectID is the destination GCP project identifier for the - // uploading log entries. If empty, the gRPC Observability plugin will - // attempt to fetch the project_id from the GCP environment variables, or - // from the default credentials. - DestinationProjectID string `json:"destination_project_id,omitempty"` - // LogFilters is a list of method config. The order matters here - the first - // Pattern which matches the current method will apply the associated config - // options in the logFilter. Any other logFilter that also matches that - // comes later will be ignored. So a logFilter of "*/*" should appear last - // in this list. - LogFilters []logFilter `json:"log_filters,omitempty"` - // GlobalTraceSamplingRate is the global setting that controls the - // probability of a RPC being traced. For example, 0.05 means there is a 5% - // chance for a RPC to be traced, 1.0 means trace every call, 0 means don’t - // start new traces. - GlobalTraceSamplingRate float64 `json:"global_trace_sampling_rate,omitempty"` - // CustomTags a list of custom tags that will be attached to every log - // entry. - CustomTags map[string]string `json:"custom_tags,omitempty"` -} +var methodStringRegexp = regexp.MustCompile(methodStringRegexpStr) // fetchDefaultProjectID fetches the default GCP project id from environment. func fetchDefaultProjectID(ctx context.Context) string { @@ -123,14 +60,34 @@ func fetchDefaultProjectID(ctx context.Context) string { return credentials.ProjectID } -func validateFilters(config *config) error { - for _, filter := range config.LogFilters { - if filter.Pattern == "*" { +func validateLogEventMethod(methods []string, exclude bool) error { + for _, method := range methods { + if method == "*" { + if exclude { + return errors.New("cannot have exclude and a '*' wildcard") + } continue } - match := logFilterPatternRegexp.FindStringSubmatch(filter.Pattern) + match := methodStringRegexp.FindStringSubmatch(method) if match == nil { - return fmt.Errorf("invalid log filter Pattern: %v", filter.Pattern) + return fmt.Errorf("invalid method string: %v", method) + } + } + return nil +} + +func validateLoggingEvents(config *config) error { + if config.CloudLogging == nil { + return nil + } + for _, clientRPCEvent := range config.CloudLogging.ClientRPCEvents { + if err := validateLogEventMethod(clientRPCEvent.Methods, clientRPCEvent.Exclude); err != nil { + return fmt.Errorf("error in clientRPCEvent method: %v", err) + } + } + for _, serverRPCEvent := range config.CloudLogging.ServerRPCEvents { + if err := validateLogEventMethod(serverRPCEvent.Methods, serverRPCEvent.Exclude); err != nil { + return fmt.Errorf("error in serverRPCEvent method: %v", err) } } return nil @@ -144,38 +101,161 @@ func unmarshalAndVerifyConfig(rawJSON json.RawMessage) (*config, error) { if err := json.Unmarshal(rawJSON, &config); err != nil { return nil, fmt.Errorf("error parsing observability config: %v", err) } - if err := validateFilters(&config); err != nil { + if err := validateLoggingEvents(&config); err != nil { return nil, fmt.Errorf("error parsing observability config: %v", err) } - if config.GlobalTraceSamplingRate > 1 || config.GlobalTraceSamplingRate < 0 { - return nil, fmt.Errorf("error parsing observability config: invalid global trace sampling rate %v", config.GlobalTraceSamplingRate) + if config.CloudTrace != nil && (config.CloudTrace.SamplingRate > 1 || config.CloudTrace.SamplingRate < 0) { + return nil, fmt.Errorf("error parsing observability config: invalid cloud trace sampling rate %v", config.CloudTrace.SamplingRate) } logger.Infof("Parsed ObservabilityConfig: %+v", &config) return &config, nil } func parseObservabilityConfig() (*config, error) { - if fileSystemPath := os.Getenv(envObservabilityConfigJSON); fileSystemPath != "" { - content, err := ioutil.ReadFile(fileSystemPath) // TODO: Switch to os.ReadFile once dropped support for go 1.15 + if f := envconfig.ObservabilityConfigFile; f != "" { + if envconfig.ObservabilityConfig != "" { + logger.Warning("Ignoring GRPC_GCP_OBSERVABILITY_CONFIG and using GRPC_GCP_OBSERVABILITY_CONFIG_FILE contents.") + } + content, err := ioutil.ReadFile(f) // TODO: Switch to os.ReadFile once dropped support for go 1.15 if err != nil { - return nil, fmt.Errorf("error reading observability configuration file %q: %v", fileSystemPath, err) + return nil, fmt.Errorf("error reading observability configuration file %q: %v", f, err) } return unmarshalAndVerifyConfig(content) - } else if content := os.Getenv(envObservabilityConfig); content != "" { - return unmarshalAndVerifyConfig([]byte(content)) + } else if envconfig.ObservabilityConfig != "" { + return unmarshalAndVerifyConfig([]byte(envconfig.ObservabilityConfig)) } // If the ENV var doesn't exist, do nothing return nil, nil } func ensureProjectIDInObservabilityConfig(ctx context.Context, config *config) error { - if config.DestinationProjectID == "" { + if config.ProjectID == "" { // Try to fetch the GCP project id projectID := fetchDefaultProjectID(ctx) if projectID == "" { return fmt.Errorf("empty destination project ID") } - config.DestinationProjectID = projectID + config.ProjectID = projectID } return nil } + +type clientRPCEvents struct { + // Methods is a list of strings which can select a group of methods. By + // default, the list is empty, matching no methods. + // + // The value of the method is in the form of /. + // + // "*" is accepted as a wildcard for: + // 1. The method name. If the value is /*, it matches all + // methods in the specified service. + // 2. The whole value of the field which matches any /. + // It’s not supported when Exclude is true. + // 3. The * wildcard cannot be used on the service name independently, + // */ is not supported. + // + // The service name, when specified, must be the fully qualified service + // name, including the package name. + // + // Examples: + // 1."goo.Foo/Bar" selects only the method "Bar" from service "goo.Foo", + // here “goo” is the package name. + // 2."goo.Foo/*" selects all methods from service "goo.Foo" + // 3. "*" selects all methods from all services. + Methods []string `json:"methods,omitempty"` + // Exclude represents whether the methods denoted by Methods should be + // excluded from logging. The default value is false, meaning the methods + // denoted by Methods are included in the logging. If Exclude is true, the + // wildcard `*` cannot be used as value of an entry in Methods. + Exclude bool `json:"exclude,omitempty"` + // MaxMetadataBytes is the maximum number of bytes of each header to log. If + // the size of the metadata is greater than the defined limit, content past + // the limit will be truncated. The default value is 0. + MaxMetadataBytes int `json:"max_metadata_bytes"` + // MaxMessageBytes is the maximum number of bytes of each message to log. If + // the size of the message is greater than the defined limit, content past + // the limit will be truncated. The default value is 0. + MaxMessageBytes int `json:"max_message_bytes"` +} + +type serverRPCEvents struct { + // Methods is a list of strings which can select a group of methods. By + // default, the list is empty, matching no methods. + // + // The value of the method is in the form of /. + // + // "*" is accepted as a wildcard for: + // 1. The method name. If the value is /*, it matches all + // methods in the specified service. + // 2. The whole value of the field which matches any /. + // It’s not supported when Exclude is true. + // 3. The * wildcard cannot be used on the service name independently, + // */ is not supported. + // + // The service name, when specified, must be the fully qualified service + // name, including the package name. + // + // Examples: + // 1."goo.Foo/Bar" selects only the method "Bar" from service "goo.Foo", + // here “goo” is the package name. + // 2."goo.Foo/*" selects all methods from service "goo.Foo" + // 3. "*" selects all methods from all services. + Methods []string `json:"methods,omitempty"` + // Exclude represents whether the methods denoted by Methods should be + // excluded from logging. The default value is false, meaning the methods + // denoted by Methods are included in the logging. If Exclude is true, the + // wildcard `*` cannot be used as value of an entry in Methods. + Exclude bool `json:"exclude,omitempty"` + // MaxMetadataBytes is the maximum number of bytes of each header to log. If + // the size of the metadata is greater than the defined limit, content past + // the limit will be truncated. The default value is 0. + MaxMetadataBytes int `json:"max_metadata_bytes"` + // MaxMessageBytes is the maximum number of bytes of each message to log. If + // the size of the message is greater than the defined limit, content past + // the limit will be truncated. The default value is 0. + MaxMessageBytes int `json:"max_message_bytes"` +} + +type cloudLogging struct { + // ClientRPCEvents represents the configuration for outgoing RPC's from the + // binary. The client_rpc_events configs are evaluated in text order, the + // first one matched is used. If an RPC doesn't match an entry, it will + // continue on to the next entry in the list. + ClientRPCEvents []clientRPCEvents `json:"client_rpc_events,omitempty"` + + // ServerRPCEvents represents the configuration for incoming RPC's to the + // binary. The server_rpc_events configs are evaluated in text order, the + // first one matched is used. If an RPC doesn't match an entry, it will + // continue on to the next entry in the list. + ServerRPCEvents []serverRPCEvents `json:"server_rpc_events,omitempty"` +} + +type cloudMonitoring struct{} + +type cloudTrace struct { + // SamplingRate is the global setting that controls the probability of a RPC + // being traced. For example, 0.05 means there is a 5% chance for a RPC to + // be traced, 1.0 means trace every call, 0 means don’t start new traces. By + // default, the sampling_rate is 0. + SamplingRate float64 `json:"sampling_rate,omitempty"` +} + +type config struct { + // ProjectID is the destination GCP project identifier for uploading log + // entries. If empty, the gRPC Observability plugin will attempt to fetch + // the project_id from the GCP environment variables, or from the default + // credentials. If not found, the observability init functions will return + // an error. + ProjectID string `json:"project_id,omitempty"` + // CloudLogging defines the logging options. If not present, logging is disabled. + CloudLogging *cloudLogging `json:"cloud_logging,omitempty"` + // CloudMonitoring determines whether or not metrics are enabled based on + // whether it is present or not. If present, monitoring will be enabled, if + // not present, monitoring is disabled. + CloudMonitoring *cloudMonitoring `json:"cloud_monitoring,omitempty"` + // CloudTrace defines the tracing options. When present, tracing is enabled + // with default configurations. When absent, the tracing is disabled. + CloudTrace *cloudTrace `json:"cloud_trace,omitempty"` + // Labels are applied to cloud logging, monitoring, and trace. + Labels map[string]string `json:"labels,omitempty"` +} diff --git a/gcp/observability/exporting.go b/gcp/observability/exporting.go index 0c566f4b183c..73eac40b5ed0 100644 --- a/gcp/observability/exporting.go +++ b/gcp/observability/exporting.go @@ -20,12 +20,9 @@ package observability import ( "context" - "encoding/json" "fmt" gcplogging "cloud.google.com/go/logging" - grpclogrecordpb "google.golang.org/grpc/gcp/observability/internal/logging" - "google.golang.org/protobuf/encoding/protojson" ) // loggingExporter is the interface of logging exporter for gRPC Observability. @@ -33,7 +30,7 @@ import ( // now, it exists for testing purposes. type loggingExporter interface { // EmitGrpcLogRecord writes a gRPC LogRecord to cache without blocking. - EmitGrpcLogRecord(*grpclogrecordpb.GrpcLogRecord) + EmitGcpLoggingEntry(entry gcplogging.Entry) // Close flushes all pending data and closes the exporter. Close() error } @@ -44,58 +41,23 @@ type cloudLoggingExporter struct { logger *gcplogging.Logger } -func newCloudLoggingExporter(ctx context.Context, config *config) (*cloudLoggingExporter, error) { - c, err := gcplogging.NewClient(ctx, fmt.Sprintf("projects/%v", config.DestinationProjectID)) +func newCloudLoggingExporter(ctx context.Context, config *config) (loggingExporter, error) { + c, err := gcplogging.NewClient(ctx, fmt.Sprintf("projects/%v", config.ProjectID)) if err != nil { return nil, fmt.Errorf("failed to create cloudLoggingExporter: %v", err) } defer logger.Infof("Successfully created cloudLoggingExporter") - if len(config.CustomTags) != 0 { - logger.Infof("Adding custom tags: %+v", config.CustomTags) + if len(config.Labels) != 0 { + logger.Infof("Adding labels: %+v", config.Labels) } return &cloudLoggingExporter{ - projectID: config.DestinationProjectID, + projectID: config.ProjectID, client: c, - logger: c.Logger("microservices.googleapis.com/observability/grpc", gcplogging.CommonLabels(config.CustomTags)), + logger: c.Logger("microservices.googleapis.com/observability/grpc", gcplogging.CommonLabels(config.Labels)), }, nil } -// mapLogLevelToSeverity maps the gRPC defined log level to Cloud Logging's -// Severity. The canonical definition can be found at -// https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#LogSeverity. -var logLevelToSeverity = map[grpclogrecordpb.GrpcLogRecord_LogLevel]gcplogging.Severity{ - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_UNKNOWN: 0, - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_TRACE: 100, // Cloud Logging doesn't have a trace level, treated as DEBUG. - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_DEBUG: 100, - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_INFO: 200, - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_WARN: 400, - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_ERROR: 500, - grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_CRITICAL: 600, -} - -var protoToJSONOptions = &protojson.MarshalOptions{ - UseProtoNames: true, - UseEnumNumbers: false, -} - -func (cle *cloudLoggingExporter) EmitGrpcLogRecord(l *grpclogrecordpb.GrpcLogRecord) { - // Converts the log record content to a more readable format via protojson. - jsonBytes, err := protoToJSONOptions.Marshal(l) - if err != nil { - logger.Infof("Unable to marshal log record: %v", l) - return - } - var payload map[string]interface{} - err = json.Unmarshal(jsonBytes, &payload) - if err != nil { - logger.Infof("Unable to unmarshal bytes to JSON: %v", jsonBytes) - return - } - entry := gcplogging.Entry{ - Timestamp: l.Timestamp.AsTime(), - Severity: logLevelToSeverity[l.LogLevel], - Payload: payload, - } +func (cle *cloudLoggingExporter) EmitGcpLoggingEntry(entry gcplogging.Entry) { cle.logger.Log(entry) if logger.V(2) { logger.Infof("Uploading event to CloudLogging: %+v", entry) diff --git a/gcp/observability/go.mod b/gcp/observability/go.mod index dcbfdaebb6e3..a164fa48c23c 100644 --- a/gcp/observability/go.mod +++ b/gcp/observability/go.mod @@ -5,12 +5,11 @@ go 1.14 require ( cloud.google.com/go/logging v1.4.2 contrib.go.opencensus.io/exporter/stackdriver v0.13.12 - github.com/golang/protobuf v1.5.2 + github.com/google/go-cmp v0.5.6 github.com/google/uuid v1.3.0 go.opencensus.io v0.23.0 golang.org/x/oauth2 v0.0.0-20211104180415-d3ed0bb246c8 google.golang.org/grpc v1.46.0 - google.golang.org/protobuf v1.27.1 ) // TODO(lidiz) remove the following line when we have a release containing the diff --git a/gcp/observability/internal/logging/logging.pb.go b/gcp/observability/internal/logging/logging.pb.go deleted file mode 100644 index a47c405759b6..000000000000 --- a/gcp/observability/internal/logging/logging.pb.go +++ /dev/null @@ -1,914 +0,0 @@ -// Copyright 2022 The gRPC 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. - -// Code generated by protoc-gen-go. DO NOT EDIT. -// versions: -// protoc-gen-go v1.25.0 -// protoc v3.14.0 -// source: gcp/observability/internal/logging/logging.proto - -package logging - -import ( - proto "github.com/golang/protobuf/proto" - protoreflect "google.golang.org/protobuf/reflect/protoreflect" - protoimpl "google.golang.org/protobuf/runtime/protoimpl" - durationpb "google.golang.org/protobuf/types/known/durationpb" - timestamppb "google.golang.org/protobuf/types/known/timestamppb" - reflect "reflect" - sync "sync" -) - -const ( - // Verify that this generated code is sufficiently up-to-date. - _ = protoimpl.EnforceVersion(20 - protoimpl.MinVersion) - // Verify that runtime/protoimpl is sufficiently up-to-date. - _ = protoimpl.EnforceVersion(protoimpl.MaxVersion - 20) -) - -// This is a compile-time assertion that a sufficiently up-to-date version -// of the legacy proto package is being used. -const _ = proto.ProtoPackageIsVersion4 - -// List of event types -type GrpcLogRecord_EventType int32 - -const ( - // Unknown event type - GrpcLogRecord_GRPC_CALL_UNKNOWN GrpcLogRecord_EventType = 0 - // Header sent from client to server - GrpcLogRecord_GRPC_CALL_REQUEST_HEADER GrpcLogRecord_EventType = 1 - // Header sent from server to client - GrpcLogRecord_GRPC_CALL_RESPONSE_HEADER GrpcLogRecord_EventType = 2 - // Message sent from client to server - GrpcLogRecord_GRPC_CALL_REQUEST_MESSAGE GrpcLogRecord_EventType = 3 - // Message sent from server to client - GrpcLogRecord_GRPC_CALL_RESPONSE_MESSAGE GrpcLogRecord_EventType = 4 - // Trailer indicates the end of the gRPC call - GrpcLogRecord_GRPC_CALL_TRAILER GrpcLogRecord_EventType = 5 - // A signal that client is done sending - GrpcLogRecord_GRPC_CALL_HALF_CLOSE GrpcLogRecord_EventType = 6 - // A signal that the rpc is canceled - GrpcLogRecord_GRPC_CALL_CANCEL GrpcLogRecord_EventType = 7 -) - -// Enum value maps for GrpcLogRecord_EventType. -var ( - GrpcLogRecord_EventType_name = map[int32]string{ - 0: "GRPC_CALL_UNKNOWN", - 1: "GRPC_CALL_REQUEST_HEADER", - 2: "GRPC_CALL_RESPONSE_HEADER", - 3: "GRPC_CALL_REQUEST_MESSAGE", - 4: "GRPC_CALL_RESPONSE_MESSAGE", - 5: "GRPC_CALL_TRAILER", - 6: "GRPC_CALL_HALF_CLOSE", - 7: "GRPC_CALL_CANCEL", - } - GrpcLogRecord_EventType_value = map[string]int32{ - "GRPC_CALL_UNKNOWN": 0, - "GRPC_CALL_REQUEST_HEADER": 1, - "GRPC_CALL_RESPONSE_HEADER": 2, - "GRPC_CALL_REQUEST_MESSAGE": 3, - "GRPC_CALL_RESPONSE_MESSAGE": 4, - "GRPC_CALL_TRAILER": 5, - "GRPC_CALL_HALF_CLOSE": 6, - "GRPC_CALL_CANCEL": 7, - } -) - -func (x GrpcLogRecord_EventType) Enum() *GrpcLogRecord_EventType { - p := new(GrpcLogRecord_EventType) - *p = x - return p -} - -func (x GrpcLogRecord_EventType) String() string { - return protoimpl.X.EnumStringOf(x.Descriptor(), protoreflect.EnumNumber(x)) -} - -func (GrpcLogRecord_EventType) Descriptor() protoreflect.EnumDescriptor { - return file_gcp_observability_internal_logging_logging_proto_enumTypes[0].Descriptor() -} - -func (GrpcLogRecord_EventType) Type() protoreflect.EnumType { - return &file_gcp_observability_internal_logging_logging_proto_enumTypes[0] -} - -func (x GrpcLogRecord_EventType) Number() protoreflect.EnumNumber { - return protoreflect.EnumNumber(x) -} - -// Deprecated: Use GrpcLogRecord_EventType.Descriptor instead. -func (GrpcLogRecord_EventType) EnumDescriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 0} -} - -// The entity that generates the log entry -type GrpcLogRecord_EventLogger int32 - -const ( - GrpcLogRecord_LOGGER_UNKNOWN GrpcLogRecord_EventLogger = 0 - GrpcLogRecord_LOGGER_CLIENT GrpcLogRecord_EventLogger = 1 - GrpcLogRecord_LOGGER_SERVER GrpcLogRecord_EventLogger = 2 -) - -// Enum value maps for GrpcLogRecord_EventLogger. -var ( - GrpcLogRecord_EventLogger_name = map[int32]string{ - 0: "LOGGER_UNKNOWN", - 1: "LOGGER_CLIENT", - 2: "LOGGER_SERVER", - } - GrpcLogRecord_EventLogger_value = map[string]int32{ - "LOGGER_UNKNOWN": 0, - "LOGGER_CLIENT": 1, - "LOGGER_SERVER": 2, - } -) - -func (x GrpcLogRecord_EventLogger) Enum() *GrpcLogRecord_EventLogger { - p := new(GrpcLogRecord_EventLogger) - *p = x - return p -} - -func (x GrpcLogRecord_EventLogger) String() string { - return protoimpl.X.EnumStringOf(x.Descriptor(), protoreflect.EnumNumber(x)) -} - -func (GrpcLogRecord_EventLogger) Descriptor() protoreflect.EnumDescriptor { - return file_gcp_observability_internal_logging_logging_proto_enumTypes[1].Descriptor() -} - -func (GrpcLogRecord_EventLogger) Type() protoreflect.EnumType { - return &file_gcp_observability_internal_logging_logging_proto_enumTypes[1] -} - -func (x GrpcLogRecord_EventLogger) Number() protoreflect.EnumNumber { - return protoreflect.EnumNumber(x) -} - -// Deprecated: Use GrpcLogRecord_EventLogger.Descriptor instead. -func (GrpcLogRecord_EventLogger) EnumDescriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 1} -} - -// The log severity level of the log entry -type GrpcLogRecord_LogLevel int32 - -const ( - GrpcLogRecord_LOG_LEVEL_UNKNOWN GrpcLogRecord_LogLevel = 0 - GrpcLogRecord_LOG_LEVEL_TRACE GrpcLogRecord_LogLevel = 1 - GrpcLogRecord_LOG_LEVEL_DEBUG GrpcLogRecord_LogLevel = 2 - GrpcLogRecord_LOG_LEVEL_INFO GrpcLogRecord_LogLevel = 3 - GrpcLogRecord_LOG_LEVEL_WARN GrpcLogRecord_LogLevel = 4 - GrpcLogRecord_LOG_LEVEL_ERROR GrpcLogRecord_LogLevel = 5 - GrpcLogRecord_LOG_LEVEL_CRITICAL GrpcLogRecord_LogLevel = 6 -) - -// Enum value maps for GrpcLogRecord_LogLevel. -var ( - GrpcLogRecord_LogLevel_name = map[int32]string{ - 0: "LOG_LEVEL_UNKNOWN", - 1: "LOG_LEVEL_TRACE", - 2: "LOG_LEVEL_DEBUG", - 3: "LOG_LEVEL_INFO", - 4: "LOG_LEVEL_WARN", - 5: "LOG_LEVEL_ERROR", - 6: "LOG_LEVEL_CRITICAL", - } - GrpcLogRecord_LogLevel_value = map[string]int32{ - "LOG_LEVEL_UNKNOWN": 0, - "LOG_LEVEL_TRACE": 1, - "LOG_LEVEL_DEBUG": 2, - "LOG_LEVEL_INFO": 3, - "LOG_LEVEL_WARN": 4, - "LOG_LEVEL_ERROR": 5, - "LOG_LEVEL_CRITICAL": 6, - } -) - -func (x GrpcLogRecord_LogLevel) Enum() *GrpcLogRecord_LogLevel { - p := new(GrpcLogRecord_LogLevel) - *p = x - return p -} - -func (x GrpcLogRecord_LogLevel) String() string { - return protoimpl.X.EnumStringOf(x.Descriptor(), protoreflect.EnumNumber(x)) -} - -func (GrpcLogRecord_LogLevel) Descriptor() protoreflect.EnumDescriptor { - return file_gcp_observability_internal_logging_logging_proto_enumTypes[2].Descriptor() -} - -func (GrpcLogRecord_LogLevel) Type() protoreflect.EnumType { - return &file_gcp_observability_internal_logging_logging_proto_enumTypes[2] -} - -func (x GrpcLogRecord_LogLevel) Number() protoreflect.EnumNumber { - return protoreflect.EnumNumber(x) -} - -// Deprecated: Use GrpcLogRecord_LogLevel.Descriptor instead. -func (GrpcLogRecord_LogLevel) EnumDescriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 2} -} - -type GrpcLogRecord_Address_Type int32 - -const ( - GrpcLogRecord_Address_TYPE_UNKNOWN GrpcLogRecord_Address_Type = 0 - GrpcLogRecord_Address_TYPE_IPV4 GrpcLogRecord_Address_Type = 1 // in 1.2.3.4 form - GrpcLogRecord_Address_TYPE_IPV6 GrpcLogRecord_Address_Type = 2 // IPv6 canonical form (RFC5952 section 4) - GrpcLogRecord_Address_TYPE_UNIX GrpcLogRecord_Address_Type = 3 // UDS string -) - -// Enum value maps for GrpcLogRecord_Address_Type. -var ( - GrpcLogRecord_Address_Type_name = map[int32]string{ - 0: "TYPE_UNKNOWN", - 1: "TYPE_IPV4", - 2: "TYPE_IPV6", - 3: "TYPE_UNIX", - } - GrpcLogRecord_Address_Type_value = map[string]int32{ - "TYPE_UNKNOWN": 0, - "TYPE_IPV4": 1, - "TYPE_IPV6": 2, - "TYPE_UNIX": 3, - } -) - -func (x GrpcLogRecord_Address_Type) Enum() *GrpcLogRecord_Address_Type { - p := new(GrpcLogRecord_Address_Type) - *p = x - return p -} - -func (x GrpcLogRecord_Address_Type) String() string { - return protoimpl.X.EnumStringOf(x.Descriptor(), protoreflect.EnumNumber(x)) -} - -func (GrpcLogRecord_Address_Type) Descriptor() protoreflect.EnumDescriptor { - return file_gcp_observability_internal_logging_logging_proto_enumTypes[3].Descriptor() -} - -func (GrpcLogRecord_Address_Type) Type() protoreflect.EnumType { - return &file_gcp_observability_internal_logging_logging_proto_enumTypes[3] -} - -func (x GrpcLogRecord_Address_Type) Number() protoreflect.EnumNumber { - return protoreflect.EnumNumber(x) -} - -// Deprecated: Use GrpcLogRecord_Address_Type.Descriptor instead. -func (GrpcLogRecord_Address_Type) EnumDescriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 2, 0} -} - -type GrpcLogRecord struct { - state protoimpl.MessageState - sizeCache protoimpl.SizeCache - unknownFields protoimpl.UnknownFields - - // The timestamp of the log event - Timestamp *timestamppb.Timestamp `protobuf:"bytes,1,opt,name=timestamp,proto3" json:"timestamp,omitempty"` - // Uniquely identifies a call. The value must not be 0 in order to disambiguate - // from an unset value. - // Each call may have several log entries. They will all have the same rpc_id. - // Nothing is guaranteed about their value other than they are unique across - // different RPCs in the same gRPC process. - RpcId string `protobuf:"bytes,2,opt,name=rpc_id,json=rpcId,proto3" json:"rpc_id,omitempty"` - EventType GrpcLogRecord_EventType `protobuf:"varint,3,opt,name=event_type,json=eventType,proto3,enum=grpc.observability.logging.v1.GrpcLogRecord_EventType" json:"event_type,omitempty"` // one of the above EventType enum - EventLogger GrpcLogRecord_EventLogger `protobuf:"varint,4,opt,name=event_logger,json=eventLogger,proto3,enum=grpc.observability.logging.v1.GrpcLogRecord_EventLogger" json:"event_logger,omitempty"` // one of the above EventLogger enum - // the name of the service - ServiceName string `protobuf:"bytes,5,opt,name=service_name,json=serviceName,proto3" json:"service_name,omitempty"` - // the name of the RPC method - MethodName string `protobuf:"bytes,6,opt,name=method_name,json=methodName,proto3" json:"method_name,omitempty"` - LogLevel GrpcLogRecord_LogLevel `protobuf:"varint,7,opt,name=log_level,json=logLevel,proto3,enum=grpc.observability.logging.v1.GrpcLogRecord_LogLevel" json:"log_level,omitempty"` // one of the above LogLevel enum - // Peer address information. On client side, peer is logged on server - // header event or trailer event (if trailer-only). On server side, peer - // is always logged on the client header event. - PeerAddress *GrpcLogRecord_Address `protobuf:"bytes,8,opt,name=peer_address,json=peerAddress,proto3" json:"peer_address,omitempty"` - // the RPC timeout value - Timeout *durationpb.Duration `protobuf:"bytes,11,opt,name=timeout,proto3" json:"timeout,omitempty"` - // A single process may be used to run multiple virtual servers with - // different identities. - // The authority is the name of such a server identify. It is typically a - // portion of the URI in the form of or :. - Authority string `protobuf:"bytes,12,opt,name=authority,proto3" json:"authority,omitempty"` - // Size of the message or metadata, depending on the event type, - // regardless of whether the full message or metadata is being logged - // (i.e. could be truncated or omitted). - PayloadSize uint32 `protobuf:"varint,13,opt,name=payload_size,json=payloadSize,proto3" json:"payload_size,omitempty"` - // true if message or metadata field is either truncated or omitted due - // to config options - PayloadTruncated bool `protobuf:"varint,14,opt,name=payload_truncated,json=payloadTruncated,proto3" json:"payload_truncated,omitempty"` - // Used by header event or trailer event - Metadata *GrpcLogRecord_Metadata `protobuf:"bytes,15,opt,name=metadata,proto3" json:"metadata,omitempty"` - // The entry sequence ID for this call. The first message has a value of 1, - // to disambiguate from an unset value. The purpose of this field is to - // detect missing entries in environments where durability or ordering is - // not guaranteed. - SequenceId uint64 `protobuf:"varint,16,opt,name=sequence_id,json=sequenceId,proto3" json:"sequence_id,omitempty"` - // Used by message event - Message []byte `protobuf:"bytes,17,opt,name=message,proto3" json:"message,omitempty"` - // The gRPC status code - StatusCode uint32 `protobuf:"varint,18,opt,name=status_code,json=statusCode,proto3" json:"status_code,omitempty"` - // The gRPC status message - StatusMessage string `protobuf:"bytes,19,opt,name=status_message,json=statusMessage,proto3" json:"status_message,omitempty"` - // The value of the grpc-status-details-bin metadata key, if any. - // This is always an encoded google.rpc.Status message - StatusDetails []byte `protobuf:"bytes,20,opt,name=status_details,json=statusDetails,proto3" json:"status_details,omitempty"` -} - -func (x *GrpcLogRecord) Reset() { - *x = GrpcLogRecord{} - if protoimpl.UnsafeEnabled { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[0] - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - ms.StoreMessageInfo(mi) - } -} - -func (x *GrpcLogRecord) String() string { - return protoimpl.X.MessageStringOf(x) -} - -func (*GrpcLogRecord) ProtoMessage() {} - -func (x *GrpcLogRecord) ProtoReflect() protoreflect.Message { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[0] - if protoimpl.UnsafeEnabled && x != nil { - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - if ms.LoadMessageInfo() == nil { - ms.StoreMessageInfo(mi) - } - return ms - } - return mi.MessageOf(x) -} - -// Deprecated: Use GrpcLogRecord.ProtoReflect.Descriptor instead. -func (*GrpcLogRecord) Descriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0} -} - -func (x *GrpcLogRecord) GetTimestamp() *timestamppb.Timestamp { - if x != nil { - return x.Timestamp - } - return nil -} - -func (x *GrpcLogRecord) GetRpcId() string { - if x != nil { - return x.RpcId - } - return "" -} - -func (x *GrpcLogRecord) GetEventType() GrpcLogRecord_EventType { - if x != nil { - return x.EventType - } - return GrpcLogRecord_GRPC_CALL_UNKNOWN -} - -func (x *GrpcLogRecord) GetEventLogger() GrpcLogRecord_EventLogger { - if x != nil { - return x.EventLogger - } - return GrpcLogRecord_LOGGER_UNKNOWN -} - -func (x *GrpcLogRecord) GetServiceName() string { - if x != nil { - return x.ServiceName - } - return "" -} - -func (x *GrpcLogRecord) GetMethodName() string { - if x != nil { - return x.MethodName - } - return "" -} - -func (x *GrpcLogRecord) GetLogLevel() GrpcLogRecord_LogLevel { - if x != nil { - return x.LogLevel - } - return GrpcLogRecord_LOG_LEVEL_UNKNOWN -} - -func (x *GrpcLogRecord) GetPeerAddress() *GrpcLogRecord_Address { - if x != nil { - return x.PeerAddress - } - return nil -} - -func (x *GrpcLogRecord) GetTimeout() *durationpb.Duration { - if x != nil { - return x.Timeout - } - return nil -} - -func (x *GrpcLogRecord) GetAuthority() string { - if x != nil { - return x.Authority - } - return "" -} - -func (x *GrpcLogRecord) GetPayloadSize() uint32 { - if x != nil { - return x.PayloadSize - } - return 0 -} - -func (x *GrpcLogRecord) GetPayloadTruncated() bool { - if x != nil { - return x.PayloadTruncated - } - return false -} - -func (x *GrpcLogRecord) GetMetadata() *GrpcLogRecord_Metadata { - if x != nil { - return x.Metadata - } - return nil -} - -func (x *GrpcLogRecord) GetSequenceId() uint64 { - if x != nil { - return x.SequenceId - } - return 0 -} - -func (x *GrpcLogRecord) GetMessage() []byte { - if x != nil { - return x.Message - } - return nil -} - -func (x *GrpcLogRecord) GetStatusCode() uint32 { - if x != nil { - return x.StatusCode - } - return 0 -} - -func (x *GrpcLogRecord) GetStatusMessage() string { - if x != nil { - return x.StatusMessage - } - return "" -} - -func (x *GrpcLogRecord) GetStatusDetails() []byte { - if x != nil { - return x.StatusDetails - } - return nil -} - -// A list of metadata pairs -type GrpcLogRecord_Metadata struct { - state protoimpl.MessageState - sizeCache protoimpl.SizeCache - unknownFields protoimpl.UnknownFields - - Entry []*GrpcLogRecord_MetadataEntry `protobuf:"bytes,1,rep,name=entry,proto3" json:"entry,omitempty"` -} - -func (x *GrpcLogRecord_Metadata) Reset() { - *x = GrpcLogRecord_Metadata{} - if protoimpl.UnsafeEnabled { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[1] - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - ms.StoreMessageInfo(mi) - } -} - -func (x *GrpcLogRecord_Metadata) String() string { - return protoimpl.X.MessageStringOf(x) -} - -func (*GrpcLogRecord_Metadata) ProtoMessage() {} - -func (x *GrpcLogRecord_Metadata) ProtoReflect() protoreflect.Message { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[1] - if protoimpl.UnsafeEnabled && x != nil { - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - if ms.LoadMessageInfo() == nil { - ms.StoreMessageInfo(mi) - } - return ms - } - return mi.MessageOf(x) -} - -// Deprecated: Use GrpcLogRecord_Metadata.ProtoReflect.Descriptor instead. -func (*GrpcLogRecord_Metadata) Descriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 0} -} - -func (x *GrpcLogRecord_Metadata) GetEntry() []*GrpcLogRecord_MetadataEntry { - if x != nil { - return x.Entry - } - return nil -} - -// One metadata key value pair -type GrpcLogRecord_MetadataEntry struct { - state protoimpl.MessageState - sizeCache protoimpl.SizeCache - unknownFields protoimpl.UnknownFields - - Key string `protobuf:"bytes,1,opt,name=key,proto3" json:"key,omitempty"` - Value []byte `protobuf:"bytes,2,opt,name=value,proto3" json:"value,omitempty"` -} - -func (x *GrpcLogRecord_MetadataEntry) Reset() { - *x = GrpcLogRecord_MetadataEntry{} - if protoimpl.UnsafeEnabled { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[2] - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - ms.StoreMessageInfo(mi) - } -} - -func (x *GrpcLogRecord_MetadataEntry) String() string { - return protoimpl.X.MessageStringOf(x) -} - -func (*GrpcLogRecord_MetadataEntry) ProtoMessage() {} - -func (x *GrpcLogRecord_MetadataEntry) ProtoReflect() protoreflect.Message { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[2] - if protoimpl.UnsafeEnabled && x != nil { - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - if ms.LoadMessageInfo() == nil { - ms.StoreMessageInfo(mi) - } - return ms - } - return mi.MessageOf(x) -} - -// Deprecated: Use GrpcLogRecord_MetadataEntry.ProtoReflect.Descriptor instead. -func (*GrpcLogRecord_MetadataEntry) Descriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 1} -} - -func (x *GrpcLogRecord_MetadataEntry) GetKey() string { - if x != nil { - return x.Key - } - return "" -} - -func (x *GrpcLogRecord_MetadataEntry) GetValue() []byte { - if x != nil { - return x.Value - } - return nil -} - -// Address information -type GrpcLogRecord_Address struct { - state protoimpl.MessageState - sizeCache protoimpl.SizeCache - unknownFields protoimpl.UnknownFields - - Type GrpcLogRecord_Address_Type `protobuf:"varint,1,opt,name=type,proto3,enum=grpc.observability.logging.v1.GrpcLogRecord_Address_Type" json:"type,omitempty"` - Address string `protobuf:"bytes,2,opt,name=address,proto3" json:"address,omitempty"` - // only for TYPE_IPV4 and TYPE_IPV6 - IpPort uint32 `protobuf:"varint,3,opt,name=ip_port,json=ipPort,proto3" json:"ip_port,omitempty"` -} - -func (x *GrpcLogRecord_Address) Reset() { - *x = GrpcLogRecord_Address{} - if protoimpl.UnsafeEnabled { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[3] - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - ms.StoreMessageInfo(mi) - } -} - -func (x *GrpcLogRecord_Address) String() string { - return protoimpl.X.MessageStringOf(x) -} - -func (*GrpcLogRecord_Address) ProtoMessage() {} - -func (x *GrpcLogRecord_Address) ProtoReflect() protoreflect.Message { - mi := &file_gcp_observability_internal_logging_logging_proto_msgTypes[3] - if protoimpl.UnsafeEnabled && x != nil { - ms := protoimpl.X.MessageStateOf(protoimpl.Pointer(x)) - if ms.LoadMessageInfo() == nil { - ms.StoreMessageInfo(mi) - } - return ms - } - return mi.MessageOf(x) -} - -// Deprecated: Use GrpcLogRecord_Address.ProtoReflect.Descriptor instead. -func (*GrpcLogRecord_Address) Descriptor() ([]byte, []int) { - return file_gcp_observability_internal_logging_logging_proto_rawDescGZIP(), []int{0, 2} -} - -func (x *GrpcLogRecord_Address) GetType() GrpcLogRecord_Address_Type { - if x != nil { - return x.Type - } - return GrpcLogRecord_Address_TYPE_UNKNOWN -} - -func (x *GrpcLogRecord_Address) GetAddress() string { - if x != nil { - return x.Address - } - return "" -} - -func (x *GrpcLogRecord_Address) GetIpPort() uint32 { - if x != nil { - return x.IpPort - } - return 0 -} - -var File_gcp_observability_internal_logging_logging_proto protoreflect.FileDescriptor - -var file_gcp_observability_internal_logging_logging_proto_rawDesc = []byte{ - 0x0a, 0x30, 0x67, 0x63, 0x70, 0x2f, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, - 0x69, 0x74, 0x79, 0x2f, 0x69, 0x6e, 0x74, 0x65, 0x72, 0x6e, 0x61, 0x6c, 0x2f, 0x6c, 0x6f, 0x67, - 0x67, 0x69, 0x6e, 0x67, 0x2f, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x70, 0x72, 0x6f, - 0x74, 0x6f, 0x12, 0x1d, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, - 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, - 0x31, 0x1a, 0x1e, 0x67, 0x6f, 0x6f, 0x67, 0x6c, 0x65, 0x2f, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, - 0x75, 0x66, 0x2f, 0x64, 0x75, 0x72, 0x61, 0x74, 0x69, 0x6f, 0x6e, 0x2e, 0x70, 0x72, 0x6f, 0x74, - 0x6f, 0x1a, 0x1f, 0x67, 0x6f, 0x6f, 0x67, 0x6c, 0x65, 0x2f, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, - 0x75, 0x66, 0x2f, 0x74, 0x69, 0x6d, 0x65, 0x73, 0x74, 0x61, 0x6d, 0x70, 0x2e, 0x70, 0x72, 0x6f, - 0x74, 0x6f, 0x22, 0xe5, 0x0d, 0x0a, 0x0d, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, 0x65, - 0x63, 0x6f, 0x72, 0x64, 0x12, 0x38, 0x0a, 0x09, 0x74, 0x69, 0x6d, 0x65, 0x73, 0x74, 0x61, 0x6d, - 0x70, 0x18, 0x01, 0x20, 0x01, 0x28, 0x0b, 0x32, 0x1a, 0x2e, 0x67, 0x6f, 0x6f, 0x67, 0x6c, 0x65, - 0x2e, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, 0x75, 0x66, 0x2e, 0x54, 0x69, 0x6d, 0x65, 0x73, 0x74, - 0x61, 0x6d, 0x70, 0x52, 0x09, 0x74, 0x69, 0x6d, 0x65, 0x73, 0x74, 0x61, 0x6d, 0x70, 0x12, 0x15, - 0x0a, 0x06, 0x72, 0x70, 0x63, 0x5f, 0x69, 0x64, 0x18, 0x02, 0x20, 0x01, 0x28, 0x09, 0x52, 0x05, - 0x72, 0x70, 0x63, 0x49, 0x64, 0x12, 0x55, 0x0a, 0x0a, 0x65, 0x76, 0x65, 0x6e, 0x74, 0x5f, 0x74, - 0x79, 0x70, 0x65, 0x18, 0x03, 0x20, 0x01, 0x28, 0x0e, 0x32, 0x36, 0x2e, 0x67, 0x72, 0x70, 0x63, - 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, - 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, 0x31, 0x2e, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, - 0x67, 0x52, 0x65, 0x63, 0x6f, 0x72, 0x64, 0x2e, 0x45, 0x76, 0x65, 0x6e, 0x74, 0x54, 0x79, 0x70, - 0x65, 0x52, 0x09, 0x65, 0x76, 0x65, 0x6e, 0x74, 0x54, 0x79, 0x70, 0x65, 0x12, 0x5b, 0x0a, 0x0c, - 0x65, 0x76, 0x65, 0x6e, 0x74, 0x5f, 0x6c, 0x6f, 0x67, 0x67, 0x65, 0x72, 0x18, 0x04, 0x20, 0x01, - 0x28, 0x0e, 0x32, 0x38, 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, - 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, - 0x76, 0x31, 0x2e, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, 0x65, 0x63, 0x6f, 0x72, 0x64, - 0x2e, 0x45, 0x76, 0x65, 0x6e, 0x74, 0x4c, 0x6f, 0x67, 0x67, 0x65, 0x72, 0x52, 0x0b, 0x65, 0x76, - 0x65, 0x6e, 0x74, 0x4c, 0x6f, 0x67, 0x67, 0x65, 0x72, 0x12, 0x21, 0x0a, 0x0c, 0x73, 0x65, 0x72, - 0x76, 0x69, 0x63, 0x65, 0x5f, 0x6e, 0x61, 0x6d, 0x65, 0x18, 0x05, 0x20, 0x01, 0x28, 0x09, 0x52, - 0x0b, 0x73, 0x65, 0x72, 0x76, 0x69, 0x63, 0x65, 0x4e, 0x61, 0x6d, 0x65, 0x12, 0x1f, 0x0a, 0x0b, - 0x6d, 0x65, 0x74, 0x68, 0x6f, 0x64, 0x5f, 0x6e, 0x61, 0x6d, 0x65, 0x18, 0x06, 0x20, 0x01, 0x28, - 0x09, 0x52, 0x0a, 0x6d, 0x65, 0x74, 0x68, 0x6f, 0x64, 0x4e, 0x61, 0x6d, 0x65, 0x12, 0x52, 0x0a, - 0x09, 0x6c, 0x6f, 0x67, 0x5f, 0x6c, 0x65, 0x76, 0x65, 0x6c, 0x18, 0x07, 0x20, 0x01, 0x28, 0x0e, - 0x32, 0x35, 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, - 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, 0x31, - 0x2e, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, 0x65, 0x63, 0x6f, 0x72, 0x64, 0x2e, 0x4c, - 0x6f, 0x67, 0x4c, 0x65, 0x76, 0x65, 0x6c, 0x52, 0x08, 0x6c, 0x6f, 0x67, 0x4c, 0x65, 0x76, 0x65, - 0x6c, 0x12, 0x57, 0x0a, 0x0c, 0x70, 0x65, 0x65, 0x72, 0x5f, 0x61, 0x64, 0x64, 0x72, 0x65, 0x73, - 0x73, 0x18, 0x08, 0x20, 0x01, 0x28, 0x0b, 0x32, 0x34, 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, - 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, - 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, 0x31, 0x2e, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, - 0x65, 0x63, 0x6f, 0x72, 0x64, 0x2e, 0x41, 0x64, 0x64, 0x72, 0x65, 0x73, 0x73, 0x52, 0x0b, 0x70, - 0x65, 0x65, 0x72, 0x41, 0x64, 0x64, 0x72, 0x65, 0x73, 0x73, 0x12, 0x33, 0x0a, 0x07, 0x74, 0x69, - 0x6d, 0x65, 0x6f, 0x75, 0x74, 0x18, 0x0b, 0x20, 0x01, 0x28, 0x0b, 0x32, 0x19, 0x2e, 0x67, 0x6f, - 0x6f, 0x67, 0x6c, 0x65, 0x2e, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x62, 0x75, 0x66, 0x2e, 0x44, 0x75, - 0x72, 0x61, 0x74, 0x69, 0x6f, 0x6e, 0x52, 0x07, 0x74, 0x69, 0x6d, 0x65, 0x6f, 0x75, 0x74, 0x12, - 0x1c, 0x0a, 0x09, 0x61, 0x75, 0x74, 0x68, 0x6f, 0x72, 0x69, 0x74, 0x79, 0x18, 0x0c, 0x20, 0x01, - 0x28, 0x09, 0x52, 0x09, 0x61, 0x75, 0x74, 0x68, 0x6f, 0x72, 0x69, 0x74, 0x79, 0x12, 0x21, 0x0a, - 0x0c, 0x70, 0x61, 0x79, 0x6c, 0x6f, 0x61, 0x64, 0x5f, 0x73, 0x69, 0x7a, 0x65, 0x18, 0x0d, 0x20, - 0x01, 0x28, 0x0d, 0x52, 0x0b, 0x70, 0x61, 0x79, 0x6c, 0x6f, 0x61, 0x64, 0x53, 0x69, 0x7a, 0x65, - 0x12, 0x2b, 0x0a, 0x11, 0x70, 0x61, 0x79, 0x6c, 0x6f, 0x61, 0x64, 0x5f, 0x74, 0x72, 0x75, 0x6e, - 0x63, 0x61, 0x74, 0x65, 0x64, 0x18, 0x0e, 0x20, 0x01, 0x28, 0x08, 0x52, 0x10, 0x70, 0x61, 0x79, - 0x6c, 0x6f, 0x61, 0x64, 0x54, 0x72, 0x75, 0x6e, 0x63, 0x61, 0x74, 0x65, 0x64, 0x12, 0x51, 0x0a, - 0x08, 0x6d, 0x65, 0x74, 0x61, 0x64, 0x61, 0x74, 0x61, 0x18, 0x0f, 0x20, 0x01, 0x28, 0x0b, 0x32, - 0x35, 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, - 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, 0x31, 0x2e, - 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, 0x65, 0x63, 0x6f, 0x72, 0x64, 0x2e, 0x4d, 0x65, - 0x74, 0x61, 0x64, 0x61, 0x74, 0x61, 0x52, 0x08, 0x6d, 0x65, 0x74, 0x61, 0x64, 0x61, 0x74, 0x61, - 0x12, 0x1f, 0x0a, 0x0b, 0x73, 0x65, 0x71, 0x75, 0x65, 0x6e, 0x63, 0x65, 0x5f, 0x69, 0x64, 0x18, - 0x10, 0x20, 0x01, 0x28, 0x04, 0x52, 0x0a, 0x73, 0x65, 0x71, 0x75, 0x65, 0x6e, 0x63, 0x65, 0x49, - 0x64, 0x12, 0x18, 0x0a, 0x07, 0x6d, 0x65, 0x73, 0x73, 0x61, 0x67, 0x65, 0x18, 0x11, 0x20, 0x01, - 0x28, 0x0c, 0x52, 0x07, 0x6d, 0x65, 0x73, 0x73, 0x61, 0x67, 0x65, 0x12, 0x1f, 0x0a, 0x0b, 0x73, - 0x74, 0x61, 0x74, 0x75, 0x73, 0x5f, 0x63, 0x6f, 0x64, 0x65, 0x18, 0x12, 0x20, 0x01, 0x28, 0x0d, - 0x52, 0x0a, 0x73, 0x74, 0x61, 0x74, 0x75, 0x73, 0x43, 0x6f, 0x64, 0x65, 0x12, 0x25, 0x0a, 0x0e, - 0x73, 0x74, 0x61, 0x74, 0x75, 0x73, 0x5f, 0x6d, 0x65, 0x73, 0x73, 0x61, 0x67, 0x65, 0x18, 0x13, - 0x20, 0x01, 0x28, 0x09, 0x52, 0x0d, 0x73, 0x74, 0x61, 0x74, 0x75, 0x73, 0x4d, 0x65, 0x73, 0x73, - 0x61, 0x67, 0x65, 0x12, 0x25, 0x0a, 0x0e, 0x73, 0x74, 0x61, 0x74, 0x75, 0x73, 0x5f, 0x64, 0x65, - 0x74, 0x61, 0x69, 0x6c, 0x73, 0x18, 0x14, 0x20, 0x01, 0x28, 0x0c, 0x52, 0x0d, 0x73, 0x74, 0x61, - 0x74, 0x75, 0x73, 0x44, 0x65, 0x74, 0x61, 0x69, 0x6c, 0x73, 0x1a, 0x5c, 0x0a, 0x08, 0x4d, 0x65, - 0x74, 0x61, 0x64, 0x61, 0x74, 0x61, 0x12, 0x50, 0x0a, 0x05, 0x65, 0x6e, 0x74, 0x72, 0x79, 0x18, - 0x01, 0x20, 0x03, 0x28, 0x0b, 0x32, 0x3a, 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, - 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, - 0x6e, 0x67, 0x2e, 0x76, 0x31, 0x2e, 0x47, 0x72, 0x70, 0x63, 0x4c, 0x6f, 0x67, 0x52, 0x65, 0x63, - 0x6f, 0x72, 0x64, 0x2e, 0x4d, 0x65, 0x74, 0x61, 0x64, 0x61, 0x74, 0x61, 0x45, 0x6e, 0x74, 0x72, - 0x79, 0x52, 0x05, 0x65, 0x6e, 0x74, 0x72, 0x79, 0x1a, 0x37, 0x0a, 0x0d, 0x4d, 0x65, 0x74, 0x61, - 0x64, 0x61, 0x74, 0x61, 0x45, 0x6e, 0x74, 0x72, 0x79, 0x12, 0x10, 0x0a, 0x03, 0x6b, 0x65, 0x79, - 0x18, 0x01, 0x20, 0x01, 0x28, 0x09, 0x52, 0x03, 0x6b, 0x65, 0x79, 0x12, 0x14, 0x0a, 0x05, 0x76, - 0x61, 0x6c, 0x75, 0x65, 0x18, 0x02, 0x20, 0x01, 0x28, 0x0c, 0x52, 0x05, 0x76, 0x61, 0x6c, 0x75, - 0x65, 0x1a, 0xd2, 0x01, 0x0a, 0x07, 0x41, 0x64, 0x64, 0x72, 0x65, 0x73, 0x73, 0x12, 0x4d, 0x0a, - 0x04, 0x74, 0x79, 0x70, 0x65, 0x18, 0x01, 0x20, 0x01, 0x28, 0x0e, 0x32, 0x39, 0x2e, 0x67, 0x72, - 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, - 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x2e, 0x76, 0x31, 0x2e, 0x47, 0x72, 0x70, 0x63, - 0x4c, 0x6f, 0x67, 0x52, 0x65, 0x63, 0x6f, 0x72, 0x64, 0x2e, 0x41, 0x64, 0x64, 0x72, 0x65, 0x73, - 0x73, 0x2e, 0x54, 0x79, 0x70, 0x65, 0x52, 0x04, 0x74, 0x79, 0x70, 0x65, 0x12, 0x18, 0x0a, 0x07, - 0x61, 0x64, 0x64, 0x72, 0x65, 0x73, 0x73, 0x18, 0x02, 0x20, 0x01, 0x28, 0x09, 0x52, 0x07, 0x61, - 0x64, 0x64, 0x72, 0x65, 0x73, 0x73, 0x12, 0x17, 0x0a, 0x07, 0x69, 0x70, 0x5f, 0x70, 0x6f, 0x72, - 0x74, 0x18, 0x03, 0x20, 0x01, 0x28, 0x0d, 0x52, 0x06, 0x69, 0x70, 0x50, 0x6f, 0x72, 0x74, 0x22, - 0x45, 0x0a, 0x04, 0x54, 0x79, 0x70, 0x65, 0x12, 0x10, 0x0a, 0x0c, 0x54, 0x59, 0x50, 0x45, 0x5f, - 0x55, 0x4e, 0x4b, 0x4e, 0x4f, 0x57, 0x4e, 0x10, 0x00, 0x12, 0x0d, 0x0a, 0x09, 0x54, 0x59, 0x50, - 0x45, 0x5f, 0x49, 0x50, 0x56, 0x34, 0x10, 0x01, 0x12, 0x0d, 0x0a, 0x09, 0x54, 0x59, 0x50, 0x45, - 0x5f, 0x49, 0x50, 0x56, 0x36, 0x10, 0x02, 0x12, 0x0d, 0x0a, 0x09, 0x54, 0x59, 0x50, 0x45, 0x5f, - 0x55, 0x4e, 0x49, 0x58, 0x10, 0x03, 0x22, 0xe5, 0x01, 0x0a, 0x09, 0x45, 0x76, 0x65, 0x6e, 0x74, - 0x54, 0x79, 0x70, 0x65, 0x12, 0x15, 0x0a, 0x11, 0x47, 0x52, 0x50, 0x43, 0x5f, 0x43, 0x41, 0x4c, - 0x4c, 0x5f, 0x55, 0x4e, 0x4b, 0x4e, 0x4f, 0x57, 0x4e, 0x10, 0x00, 0x12, 0x1c, 0x0a, 0x18, 0x47, - 0x52, 0x50, 0x43, 0x5f, 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x52, 0x45, 0x51, 0x55, 0x45, 0x53, 0x54, - 0x5f, 0x48, 0x45, 0x41, 0x44, 0x45, 0x52, 0x10, 0x01, 0x12, 0x1d, 0x0a, 0x19, 0x47, 0x52, 0x50, - 0x43, 0x5f, 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x52, 0x45, 0x53, 0x50, 0x4f, 0x4e, 0x53, 0x45, 0x5f, - 0x48, 0x45, 0x41, 0x44, 0x45, 0x52, 0x10, 0x02, 0x12, 0x1d, 0x0a, 0x19, 0x47, 0x52, 0x50, 0x43, - 0x5f, 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x52, 0x45, 0x51, 0x55, 0x45, 0x53, 0x54, 0x5f, 0x4d, 0x45, - 0x53, 0x53, 0x41, 0x47, 0x45, 0x10, 0x03, 0x12, 0x1e, 0x0a, 0x1a, 0x47, 0x52, 0x50, 0x43, 0x5f, - 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x52, 0x45, 0x53, 0x50, 0x4f, 0x4e, 0x53, 0x45, 0x5f, 0x4d, 0x45, - 0x53, 0x53, 0x41, 0x47, 0x45, 0x10, 0x04, 0x12, 0x15, 0x0a, 0x11, 0x47, 0x52, 0x50, 0x43, 0x5f, - 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x54, 0x52, 0x41, 0x49, 0x4c, 0x45, 0x52, 0x10, 0x05, 0x12, 0x18, - 0x0a, 0x14, 0x47, 0x52, 0x50, 0x43, 0x5f, 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x48, 0x41, 0x4c, 0x46, - 0x5f, 0x43, 0x4c, 0x4f, 0x53, 0x45, 0x10, 0x06, 0x12, 0x14, 0x0a, 0x10, 0x47, 0x52, 0x50, 0x43, - 0x5f, 0x43, 0x41, 0x4c, 0x4c, 0x5f, 0x43, 0x41, 0x4e, 0x43, 0x45, 0x4c, 0x10, 0x07, 0x22, 0x47, - 0x0a, 0x0b, 0x45, 0x76, 0x65, 0x6e, 0x74, 0x4c, 0x6f, 0x67, 0x67, 0x65, 0x72, 0x12, 0x12, 0x0a, - 0x0e, 0x4c, 0x4f, 0x47, 0x47, 0x45, 0x52, 0x5f, 0x55, 0x4e, 0x4b, 0x4e, 0x4f, 0x57, 0x4e, 0x10, - 0x00, 0x12, 0x11, 0x0a, 0x0d, 0x4c, 0x4f, 0x47, 0x47, 0x45, 0x52, 0x5f, 0x43, 0x4c, 0x49, 0x45, - 0x4e, 0x54, 0x10, 0x01, 0x12, 0x11, 0x0a, 0x0d, 0x4c, 0x4f, 0x47, 0x47, 0x45, 0x52, 0x5f, 0x53, - 0x45, 0x52, 0x56, 0x45, 0x52, 0x10, 0x02, 0x22, 0xa0, 0x01, 0x0a, 0x08, 0x4c, 0x6f, 0x67, 0x4c, - 0x65, 0x76, 0x65, 0x6c, 0x12, 0x15, 0x0a, 0x11, 0x4c, 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, 0x45, - 0x4c, 0x5f, 0x55, 0x4e, 0x4b, 0x4e, 0x4f, 0x57, 0x4e, 0x10, 0x00, 0x12, 0x13, 0x0a, 0x0f, 0x4c, - 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, 0x45, 0x4c, 0x5f, 0x54, 0x52, 0x41, 0x43, 0x45, 0x10, 0x01, - 0x12, 0x13, 0x0a, 0x0f, 0x4c, 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, 0x45, 0x4c, 0x5f, 0x44, 0x45, - 0x42, 0x55, 0x47, 0x10, 0x02, 0x12, 0x12, 0x0a, 0x0e, 0x4c, 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, - 0x45, 0x4c, 0x5f, 0x49, 0x4e, 0x46, 0x4f, 0x10, 0x03, 0x12, 0x12, 0x0a, 0x0e, 0x4c, 0x4f, 0x47, - 0x5f, 0x4c, 0x45, 0x56, 0x45, 0x4c, 0x5f, 0x57, 0x41, 0x52, 0x4e, 0x10, 0x04, 0x12, 0x13, 0x0a, - 0x0f, 0x4c, 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, 0x45, 0x4c, 0x5f, 0x45, 0x52, 0x52, 0x4f, 0x52, - 0x10, 0x05, 0x12, 0x16, 0x0a, 0x12, 0x4c, 0x4f, 0x47, 0x5f, 0x4c, 0x45, 0x56, 0x45, 0x4c, 0x5f, - 0x43, 0x52, 0x49, 0x54, 0x49, 0x43, 0x41, 0x4c, 0x10, 0x06, 0x42, 0x77, 0x0a, 0x1d, 0x69, 0x6f, - 0x2e, 0x67, 0x72, 0x70, 0x63, 0x2e, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, - 0x69, 0x74, 0x79, 0x2e, 0x6c, 0x6f, 0x67, 0x67, 0x69, 0x6e, 0x67, 0x42, 0x19, 0x4f, 0x62, 0x73, - 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, 0x74, 0x79, 0x4c, 0x6f, 0x67, 0x67, 0x69, 0x6e, - 0x67, 0x50, 0x72, 0x6f, 0x74, 0x6f, 0x50, 0x01, 0x5a, 0x39, 0x67, 0x6f, 0x6f, 0x67, 0x6c, 0x65, - 0x2e, 0x67, 0x6f, 0x6c, 0x61, 0x6e, 0x67, 0x2e, 0x6f, 0x72, 0x67, 0x2f, 0x67, 0x72, 0x70, 0x63, - 0x2f, 0x67, 0x63, 0x70, 0x2f, 0x6f, 0x62, 0x73, 0x65, 0x72, 0x76, 0x61, 0x62, 0x69, 0x6c, 0x69, - 0x74, 0x79, 0x2f, 0x69, 0x6e, 0x74, 0x65, 0x72, 0x6e, 0x61, 0x6c, 0x2f, 0x6c, 0x6f, 0x67, 0x67, - 0x69, 0x6e, 0x67, 0x62, 0x06, 0x70, 0x72, 0x6f, 0x74, 0x6f, 0x33, -} - -var ( - file_gcp_observability_internal_logging_logging_proto_rawDescOnce sync.Once - file_gcp_observability_internal_logging_logging_proto_rawDescData = file_gcp_observability_internal_logging_logging_proto_rawDesc -) - -func file_gcp_observability_internal_logging_logging_proto_rawDescGZIP() []byte { - file_gcp_observability_internal_logging_logging_proto_rawDescOnce.Do(func() { - file_gcp_observability_internal_logging_logging_proto_rawDescData = protoimpl.X.CompressGZIP(file_gcp_observability_internal_logging_logging_proto_rawDescData) - }) - return file_gcp_observability_internal_logging_logging_proto_rawDescData -} - -var file_gcp_observability_internal_logging_logging_proto_enumTypes = make([]protoimpl.EnumInfo, 4) -var file_gcp_observability_internal_logging_logging_proto_msgTypes = make([]protoimpl.MessageInfo, 4) -var file_gcp_observability_internal_logging_logging_proto_goTypes = []interface{}{ - (GrpcLogRecord_EventType)(0), // 0: grpc.observability.logging.v1.GrpcLogRecord.EventType - (GrpcLogRecord_EventLogger)(0), // 1: grpc.observability.logging.v1.GrpcLogRecord.EventLogger - (GrpcLogRecord_LogLevel)(0), // 2: grpc.observability.logging.v1.GrpcLogRecord.LogLevel - (GrpcLogRecord_Address_Type)(0), // 3: grpc.observability.logging.v1.GrpcLogRecord.Address.Type - (*GrpcLogRecord)(nil), // 4: grpc.observability.logging.v1.GrpcLogRecord - (*GrpcLogRecord_Metadata)(nil), // 5: grpc.observability.logging.v1.GrpcLogRecord.Metadata - (*GrpcLogRecord_MetadataEntry)(nil), // 6: grpc.observability.logging.v1.GrpcLogRecord.MetadataEntry - (*GrpcLogRecord_Address)(nil), // 7: grpc.observability.logging.v1.GrpcLogRecord.Address - (*timestamppb.Timestamp)(nil), // 8: google.protobuf.Timestamp - (*durationpb.Duration)(nil), // 9: google.protobuf.Duration -} -var file_gcp_observability_internal_logging_logging_proto_depIdxs = []int32{ - 8, // 0: grpc.observability.logging.v1.GrpcLogRecord.timestamp:type_name -> google.protobuf.Timestamp - 0, // 1: grpc.observability.logging.v1.GrpcLogRecord.event_type:type_name -> grpc.observability.logging.v1.GrpcLogRecord.EventType - 1, // 2: grpc.observability.logging.v1.GrpcLogRecord.event_logger:type_name -> grpc.observability.logging.v1.GrpcLogRecord.EventLogger - 2, // 3: grpc.observability.logging.v1.GrpcLogRecord.log_level:type_name -> grpc.observability.logging.v1.GrpcLogRecord.LogLevel - 7, // 4: grpc.observability.logging.v1.GrpcLogRecord.peer_address:type_name -> grpc.observability.logging.v1.GrpcLogRecord.Address - 9, // 5: grpc.observability.logging.v1.GrpcLogRecord.timeout:type_name -> google.protobuf.Duration - 5, // 6: grpc.observability.logging.v1.GrpcLogRecord.metadata:type_name -> grpc.observability.logging.v1.GrpcLogRecord.Metadata - 6, // 7: grpc.observability.logging.v1.GrpcLogRecord.Metadata.entry:type_name -> grpc.observability.logging.v1.GrpcLogRecord.MetadataEntry - 3, // 8: grpc.observability.logging.v1.GrpcLogRecord.Address.type:type_name -> grpc.observability.logging.v1.GrpcLogRecord.Address.Type - 9, // [9:9] is the sub-list for method output_type - 9, // [9:9] is the sub-list for method input_type - 9, // [9:9] is the sub-list for extension type_name - 9, // [9:9] is the sub-list for extension extendee - 0, // [0:9] is the sub-list for field type_name -} - -func init() { file_gcp_observability_internal_logging_logging_proto_init() } -func file_gcp_observability_internal_logging_logging_proto_init() { - if File_gcp_observability_internal_logging_logging_proto != nil { - return - } - if !protoimpl.UnsafeEnabled { - file_gcp_observability_internal_logging_logging_proto_msgTypes[0].Exporter = func(v interface{}, i int) interface{} { - switch v := v.(*GrpcLogRecord); i { - case 0: - return &v.state - case 1: - return &v.sizeCache - case 2: - return &v.unknownFields - default: - return nil - } - } - file_gcp_observability_internal_logging_logging_proto_msgTypes[1].Exporter = func(v interface{}, i int) interface{} { - switch v := v.(*GrpcLogRecord_Metadata); i { - case 0: - return &v.state - case 1: - return &v.sizeCache - case 2: - return &v.unknownFields - default: - return nil - } - } - file_gcp_observability_internal_logging_logging_proto_msgTypes[2].Exporter = func(v interface{}, i int) interface{} { - switch v := v.(*GrpcLogRecord_MetadataEntry); i { - case 0: - return &v.state - case 1: - return &v.sizeCache - case 2: - return &v.unknownFields - default: - return nil - } - } - file_gcp_observability_internal_logging_logging_proto_msgTypes[3].Exporter = func(v interface{}, i int) interface{} { - switch v := v.(*GrpcLogRecord_Address); i { - case 0: - return &v.state - case 1: - return &v.sizeCache - case 2: - return &v.unknownFields - default: - return nil - } - } - } - type x struct{} - out := protoimpl.TypeBuilder{ - File: protoimpl.DescBuilder{ - GoPackagePath: reflect.TypeOf(x{}).PkgPath(), - RawDescriptor: file_gcp_observability_internal_logging_logging_proto_rawDesc, - NumEnums: 4, - NumMessages: 4, - NumExtensions: 0, - NumServices: 0, - }, - GoTypes: file_gcp_observability_internal_logging_logging_proto_goTypes, - DependencyIndexes: file_gcp_observability_internal_logging_logging_proto_depIdxs, - EnumInfos: file_gcp_observability_internal_logging_logging_proto_enumTypes, - MessageInfos: file_gcp_observability_internal_logging_logging_proto_msgTypes, - }.Build() - File_gcp_observability_internal_logging_logging_proto = out.File - file_gcp_observability_internal_logging_logging_proto_rawDesc = nil - file_gcp_observability_internal_logging_logging_proto_goTypes = nil - file_gcp_observability_internal_logging_logging_proto_depIdxs = nil -} diff --git a/gcp/observability/internal/logging/logging.proto b/gcp/observability/internal/logging/logging.proto deleted file mode 100644 index 206d953a9ca8..000000000000 --- a/gcp/observability/internal/logging/logging.proto +++ /dev/null @@ -1,153 +0,0 @@ -// Copyright 2022 The gRPC 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. - -syntax = "proto3"; - -package grpc.observability.logging.v1; - -import "google/protobuf/duration.proto"; -import "google/protobuf/timestamp.proto"; - -option java_package = "io.grpc.observability.logging"; -option java_multiple_files = true; -option java_outer_classname = "ObservabilityLoggingProto"; -option go_package = "google.golang.org/grpc/gcp/observability/internal/logging"; - -message GrpcLogRecord { - // List of event types - enum EventType { - // Unknown event type - GRPC_CALL_UNKNOWN = 0; - // Header sent from client to server - GRPC_CALL_REQUEST_HEADER = 1; - // Header sent from server to client - GRPC_CALL_RESPONSE_HEADER = 2; - // Message sent from client to server - GRPC_CALL_REQUEST_MESSAGE = 3; - // Message sent from server to client - GRPC_CALL_RESPONSE_MESSAGE = 4; - // Trailer indicates the end of the gRPC call - GRPC_CALL_TRAILER = 5; - // A signal that client is done sending - GRPC_CALL_HALF_CLOSE = 6; - // A signal that the rpc is canceled - GRPC_CALL_CANCEL = 7; - } - // The entity that generates the log entry - enum EventLogger { - LOGGER_UNKNOWN = 0; - LOGGER_CLIENT = 1; - LOGGER_SERVER = 2; - } - // The log severity level of the log entry - enum LogLevel { - LOG_LEVEL_UNKNOWN = 0; - LOG_LEVEL_TRACE = 1; - LOG_LEVEL_DEBUG = 2; - LOG_LEVEL_INFO = 3; - LOG_LEVEL_WARN = 4; - LOG_LEVEL_ERROR = 5; - LOG_LEVEL_CRITICAL = 6; - } - - // The timestamp of the log event - google.protobuf.Timestamp timestamp = 1; - - // Uniquely identifies a call. The value must not be 0 in order to disambiguate - // from an unset value. - // Each call may have several log entries. They will all have the same rpc_id. - // Nothing is guaranteed about their value other than they are unique across - // different RPCs in the same gRPC process. - string rpc_id = 2; - - EventType event_type = 3; // one of the above EventType enum - EventLogger event_logger = 4; // one of the above EventLogger enum - - // the name of the service - string service_name = 5; - // the name of the RPC method - string method_name = 6; - - LogLevel log_level = 7; // one of the above LogLevel enum - - // Peer address information. On client side, peer is logged on server - // header event or trailer event (if trailer-only). On server side, peer - // is always logged on the client header event. - Address peer_address = 8; - - // the RPC timeout value - google.protobuf.Duration timeout = 11; - - // A single process may be used to run multiple virtual servers with - // different identities. - // The authority is the name of such a server identify. It is typically a - // portion of the URI in the form of or :. - string authority = 12; - - // Size of the message or metadata, depending on the event type, - // regardless of whether the full message or metadata is being logged - // (i.e. could be truncated or omitted). - uint32 payload_size = 13; - - // true if message or metadata field is either truncated or omitted due - // to config options - bool payload_truncated = 14; - - // Used by header event or trailer event - Metadata metadata = 15; - - // The entry sequence ID for this call. The first message has a value of 1, - // to disambiguate from an unset value. The purpose of this field is to - // detect missing entries in environments where durability or ordering is - // not guaranteed. - uint64 sequence_id = 16; - - // Used by message event - bytes message = 17; - - // The gRPC status code - uint32 status_code = 18; - - // The gRPC status message - string status_message = 19; - - // The value of the grpc-status-details-bin metadata key, if any. - // This is always an encoded google.rpc.Status message - bytes status_details = 20; - - // A list of metadata pairs - message Metadata { - repeated MetadataEntry entry = 1; - } - - // One metadata key value pair - message MetadataEntry { - string key = 1; - bytes value = 2; - } - - // Address information - message Address { - enum Type { - TYPE_UNKNOWN = 0; - TYPE_IPV4 = 1; // in 1.2.3.4 form - TYPE_IPV6 = 2; // IPv6 canonical form (RFC5952 section 4) - TYPE_UNIX = 3; // UDS string - } - Type type = 1; - string address = 2; - // only for TYPE_IPV4 and TYPE_IPV6 - uint32 ip_port = 3; - } -} diff --git a/gcp/observability/logging.go b/gcp/observability/logging.go index 8f93564353cd..dee2656f7b84 100644 --- a/gcp/observability/logging.go +++ b/gcp/observability/logging.go @@ -19,325 +19,441 @@ package observability import ( + "bytes" "context" + "encoding/base64" "fmt" "strings" - "sync/atomic" - "unsafe" + "time" + gcplogging "cloud.google.com/go/logging" "github.com/google/uuid" + + "google.golang.org/grpc" binlogpb "google.golang.org/grpc/binarylog/grpc_binarylog_v1" - grpclogrecordpb "google.golang.org/grpc/gcp/observability/internal/logging" + "google.golang.org/grpc/internal" + "google.golang.org/grpc/internal/binarylog" iblog "google.golang.org/grpc/internal/binarylog" + "google.golang.org/grpc/internal/grpcutil" ) +var lExporter loggingExporter + +var newLoggingExporter = newCloudLoggingExporter + // translateMetadata translates the metadata from Binary Logging format to -// its GrpcLogRecord equivalent. -func translateMetadata(m *binlogpb.Metadata) *grpclogrecordpb.GrpcLogRecord_Metadata { - var res grpclogrecordpb.GrpcLogRecord_Metadata - res.Entry = make([]*grpclogrecordpb.GrpcLogRecord_MetadataEntry, len(m.Entry)) - for i, e := range m.Entry { - res.Entry[i] = &grpclogrecordpb.GrpcLogRecord_MetadataEntry{ - Key: e.Key, - Value: e.Value, +// its GrpcLogEntry equivalent. +func translateMetadata(m *binlogpb.Metadata) map[string]string { + metadata := make(map[string]string) + for _, entry := range m.GetEntry() { + entryKey := entry.GetKey() + var newVal string + if strings.HasSuffix(entryKey, "-bin") { // bin header + newVal = base64.StdEncoding.EncodeToString(entry.GetValue()) + } else { // normal header + newVal = string(entry.GetValue()) } + var oldVal string + var ok bool + if oldVal, ok = metadata[entryKey]; !ok { + metadata[entryKey] = newVal + continue + } + metadata[entryKey] = oldVal + "," + newVal } - return &res + return metadata } -func setPeerIfPresent(binlogEntry *binlogpb.GrpcLogEntry, grpcLogRecord *grpclogrecordpb.GrpcLogRecord) { +func setPeerIfPresent(binlogEntry *binlogpb.GrpcLogEntry, grpcLogEntry *grpcLogEntry) { if binlogEntry.GetPeer() != nil { - grpcLogRecord.PeerAddress = &grpclogrecordpb.GrpcLogRecord_Address{ - Type: grpclogrecordpb.GrpcLogRecord_Address_Type(binlogEntry.Peer.Type), - Address: binlogEntry.Peer.Address, - IpPort: binlogEntry.Peer.IpPort, - } + grpcLogEntry.Peer.Type = addrType(binlogEntry.GetPeer().GetType()) + grpcLogEntry.Peer.Address = binlogEntry.GetPeer().GetAddress() + grpcLogEntry.Peer.IPPort = binlogEntry.GetPeer().GetIpPort() } } -var loggerTypeToEventLogger = map[binlogpb.GrpcLogEntry_Logger]grpclogrecordpb.GrpcLogRecord_EventLogger{ - binlogpb.GrpcLogEntry_LOGGER_UNKNOWN: grpclogrecordpb.GrpcLogRecord_LOGGER_UNKNOWN, - binlogpb.GrpcLogEntry_LOGGER_CLIENT: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - binlogpb.GrpcLogEntry_LOGGER_SERVER: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, +var loggerTypeToEventLogger = map[binlogpb.GrpcLogEntry_Logger]loggerType{ + binlogpb.GrpcLogEntry_LOGGER_UNKNOWN: loggerUnknown, + binlogpb.GrpcLogEntry_LOGGER_CLIENT: loggerClient, + binlogpb.GrpcLogEntry_LOGGER_SERVER: loggerServer, } -type binaryMethodLogger struct { - rpcID, serviceName, methodName string - originalMethodLogger iblog.MethodLogger - childMethodLogger iblog.MethodLogger - exporter loggingExporter -} +type eventType int + +const ( + // eventTypeUnknown is an unknown event type. + eventTypeUnknown eventType = iota + // eventTypeClientHeader is a header sent from client to server. + eventTypeClientHeader + // eventTypeServerHeader is a header sent from server to client. + eventTypeServerHeader + // eventTypeClientMessage is a message sent from client to server. + eventTypeClientMessage + // eventTypeServerMessage is a message sent from server to client. + eventTypeServerMessage + // eventTypeClientHalfClose is a signal that the loggerClient is done sending. + eventTypeClientHalfClose + // eventTypeServerTrailer indicated the end of a gRPC call. + eventTypeServerTrailer + // eventTypeCancel is a signal that the rpc is canceled. + eventTypeCancel +) -func (ml *binaryMethodLogger) Log(c iblog.LogEntryConfig) { - // Invoke the original MethodLogger to maintain backward compatibility - if ml.originalMethodLogger != nil { - ml.originalMethodLogger.Log(c) +func (t eventType) MarshalJSON() ([]byte, error) { + buffer := bytes.NewBufferString(`"`) + switch t { + case eventTypeUnknown: + buffer.WriteString("EVENT_TYPE_UNKNOWN") + case eventTypeClientHeader: + buffer.WriteString("CLIENT_HEADER") + case eventTypeServerHeader: + buffer.WriteString("SERVER_HEADER") + case eventTypeClientMessage: + buffer.WriteString("CLIENT_MESSAGE") + case eventTypeServerMessage: + buffer.WriteString("SERVER_MESSAGE") + case eventTypeClientHalfClose: + buffer.WriteString("CLIENT_HALF_CLOSE") + case eventTypeServerTrailer: + buffer.WriteString("SERVER_TRAILER") + case eventTypeCancel: + buffer.WriteString("CANCEL") } + buffer.WriteString(`"`) + return buffer.Bytes(), nil +} - // Fetch the compiled binary logging log entry - if ml.childMethodLogger == nil { - logger.Info("No wrapped method logger found") - return +type loggerType int + +const ( + loggerUnknown loggerType = iota + loggerClient + loggerServer +) + +func (t loggerType) MarshalJSON() ([]byte, error) { + buffer := bytes.NewBufferString(`"`) + switch t { + case loggerUnknown: + buffer.WriteString("LOGGER_UNKNOWN") + case loggerClient: + buffer.WriteString("CLIENT") + case loggerServer: + buffer.WriteString("SERVER") } - var binlogEntry *binlogpb.GrpcLogEntry - o, ok := ml.childMethodLogger.(interface { - Build(iblog.LogEntryConfig) *binlogpb.GrpcLogEntry - }) - if !ok { - logger.Error("Failed to locate the Build method in wrapped method logger") - return + buffer.WriteString(`"`) + return buffer.Bytes(), nil +} + +type payload struct { + Metadata map[string]string `json:"metadata,omitempty"` + // Timeout is the RPC timeout value. + Timeout time.Duration `json:"timeout,omitempty"` + // StatusCode is the gRPC status code. + StatusCode uint32 `json:"statusCode,omitempty"` + // StatusMessage is the gRPC status message. + StatusMessage string `json:"statusMessage,omitempty"` + // StatusDetails is the value of the grpc-status-details-bin metadata key, + // if any. This is always an encoded google.rpc.Status message. + StatusDetails []byte `json:"statusDetails,omitempty"` + // MessageLength is the length of the message. + MessageLength uint32 `json:"messageLength,omitempty"` + // Message is the message of this entry. This is populated in the case of a + // message event. + Message []byte `json:"message,omitempty"` +} + +type addrType int + +const ( + typeUnknown addrType = iota // `json:"TYPE_UNKNOWN"` + typeIPv4 // `json:"TYPE_IPV4"` + typeIPv6 // `json:"TYPE_IPV6"` + typeUnix // `json:"TYPE_UNIX"` +) + +func (at addrType) MarshalJSON() ([]byte, error) { + buffer := bytes.NewBufferString(`"`) + switch at { + case typeUnknown: + buffer.WriteString("TYPE_UNKNOWN") + case typeIPv4: + buffer.WriteString("TYPE_IPV4") + case typeIPv6: + buffer.WriteString("TYPE_IPV6") + case typeUnix: + buffer.WriteString("TYPE_UNIX") } - binlogEntry = o.Build(c) - - // Translate to GrpcLogRecord - grpcLogRecord := &grpclogrecordpb.GrpcLogRecord{ - Timestamp: binlogEntry.GetTimestamp(), - RpcId: ml.rpcID, - SequenceId: binlogEntry.GetSequenceIdWithinCall(), - EventLogger: loggerTypeToEventLogger[binlogEntry.Logger], - // Making DEBUG the default LogLevel - LogLevel: grpclogrecordpb.GrpcLogRecord_LOG_LEVEL_DEBUG, + buffer.WriteString(`"`) + return buffer.Bytes(), nil +} + +type address struct { + // Type is the address type of the address of the peer of the RPC. + Type addrType `json:"type,omitempty"` + // Address is the address of the peer of the RPC. + Address string `json:"address,omitempty"` + // IPPort is the ip and port in string form. It is used only for addrType + // typeIPv4 and typeIPv6. + IPPort uint32 `json:"ipPort,omitempty"` +} + +type grpcLogEntry struct { + // CallID is a uuid which uniquely identifies a call. Each call may have + // several log entries. They will all have the same CallID. Nothing is + // guaranteed about their value other than they are unique across different + // RPCs in the same gRPC process. + CallID string `json:"callId,omitempty"` + // SequenceID is the entry sequence ID for this call. The first message has + // a value of 1, to disambiguate from an unset value. The purpose of this + // field is to detect missing entries in environments where durability or + // ordering is not guaranteed. + SequenceID uint64 `json:"sequenceId,omitempty"` + // Type is the type of binary logging event being logged. + Type eventType `json:"type,omitempty"` + // Logger is the entity that generates the log entry. + Logger loggerType `json:"logger,omitempty"` + // Payload is the payload of this log entry. + Payload payload `json:"payload,omitempty"` + // PayloadTruncated is whether the message or metadata field is either + // truncated or emitted due to options specified in the configuration. + PayloadTruncated bool `json:"payloadTruncated,omitempty"` + // Peer is information about the Peer of the RPC. + Peer address `json:"peer,omitempty"` + // A single process may be used to run multiple virtual servers with + // different identities. + // Authority is the name of such a server identify. It is typically a + // portion of the URI in the form of or :. + Authority string `json:"authority,omitempty"` + // ServiceName is the name of the service. + ServiceName string `json:"serviceName,omitempty"` + // MethodName is the name of the RPC method. + MethodName string `json:"methodName,omitempty"` +} + +type methodLoggerBuilder interface { + Build(iblog.LogEntryConfig) *binlogpb.GrpcLogEntry +} + +type binaryMethodLogger struct { + callID, serviceName, methodName, authority string + + mlb methodLoggerBuilder + exporter loggingExporter +} + +func (bml *binaryMethodLogger) Log(c iblog.LogEntryConfig) { + binLogEntry := bml.mlb.Build(c) + + grpcLogEntry := &grpcLogEntry{ + CallID: bml.callID, + SequenceID: binLogEntry.GetSequenceIdWithinCall(), + Logger: loggerTypeToEventLogger[binLogEntry.Logger], } - switch binlogEntry.GetType() { + switch binLogEntry.GetType() { case binlogpb.GrpcLogEntry_EVENT_TYPE_UNKNOWN: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_UNKNOWN + grpcLogEntry.Type = eventTypeUnknown case binlogpb.GrpcLogEntry_EVENT_TYPE_CLIENT_HEADER: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_REQUEST_HEADER - if binlogEntry.GetClientHeader() != nil { - methodName := binlogEntry.GetClientHeader().MethodName + grpcLogEntry.Type = eventTypeClientHeader + if binLogEntry.GetClientHeader() != nil { + methodName := binLogEntry.GetClientHeader().MethodName // Example method name: /grpc.testing.TestService/UnaryCall if strings.Contains(methodName, "/") { tokens := strings.Split(methodName, "/") if len(tokens) == 3 { - // Record service name and method name for all events - ml.serviceName = tokens[1] - ml.methodName = tokens[2] + // Record service name and method name for all events. + bml.serviceName = tokens[1] + bml.methodName = tokens[2] } else { logger.Infof("Malformed method name: %v", methodName) } } - grpcLogRecord.Timeout = binlogEntry.GetClientHeader().Timeout - grpcLogRecord.Authority = binlogEntry.GetClientHeader().Authority - grpcLogRecord.Metadata = translateMetadata(binlogEntry.GetClientHeader().Metadata) + bml.authority = binLogEntry.GetClientHeader().GetAuthority() + grpcLogEntry.Payload.Timeout = binLogEntry.GetClientHeader().GetTimeout().AsDuration() + grpcLogEntry.Payload.Metadata = translateMetadata(binLogEntry.GetClientHeader().GetMetadata()) } - grpcLogRecord.PayloadTruncated = binlogEntry.GetPayloadTruncated() - setPeerIfPresent(binlogEntry, grpcLogRecord) + grpcLogEntry.PayloadTruncated = binLogEntry.GetPayloadTruncated() + setPeerIfPresent(binLogEntry, grpcLogEntry) case binlogpb.GrpcLogEntry_EVENT_TYPE_SERVER_HEADER: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_RESPONSE_HEADER - grpcLogRecord.Metadata = translateMetadata(binlogEntry.GetServerHeader().Metadata) - grpcLogRecord.PayloadTruncated = binlogEntry.GetPayloadTruncated() - setPeerIfPresent(binlogEntry, grpcLogRecord) + grpcLogEntry.Type = eventTypeServerHeader + if binLogEntry.GetServerHeader() != nil { + grpcLogEntry.Payload.Metadata = translateMetadata(binLogEntry.GetServerHeader().GetMetadata()) + } + grpcLogEntry.PayloadTruncated = binLogEntry.GetPayloadTruncated() + setPeerIfPresent(binLogEntry, grpcLogEntry) case binlogpb.GrpcLogEntry_EVENT_TYPE_CLIENT_MESSAGE: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_REQUEST_MESSAGE - grpcLogRecord.Message = binlogEntry.GetMessage().GetData() - grpcLogRecord.PayloadSize = binlogEntry.GetMessage().GetLength() - grpcLogRecord.PayloadTruncated = binlogEntry.GetPayloadTruncated() + grpcLogEntry.Type = eventTypeClientMessage + grpcLogEntry.Payload.Message = binLogEntry.GetMessage().GetData() + grpcLogEntry.Payload.MessageLength = binLogEntry.GetMessage().GetLength() + grpcLogEntry.PayloadTruncated = binLogEntry.GetPayloadTruncated() case binlogpb.GrpcLogEntry_EVENT_TYPE_SERVER_MESSAGE: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_RESPONSE_MESSAGE - grpcLogRecord.Message = binlogEntry.GetMessage().GetData() - grpcLogRecord.PayloadSize = binlogEntry.GetMessage().GetLength() - grpcLogRecord.PayloadTruncated = binlogEntry.GetPayloadTruncated() + grpcLogEntry.Type = eventTypeServerMessage + grpcLogEntry.Payload.Message = binLogEntry.GetMessage().GetData() + grpcLogEntry.Payload.MessageLength = binLogEntry.GetMessage().GetLength() + grpcLogEntry.PayloadTruncated = binLogEntry.GetPayloadTruncated() case binlogpb.GrpcLogEntry_EVENT_TYPE_CLIENT_HALF_CLOSE: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_HALF_CLOSE + grpcLogEntry.Type = eventTypeClientHalfClose case binlogpb.GrpcLogEntry_EVENT_TYPE_SERVER_TRAILER: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_TRAILER - grpcLogRecord.Metadata = translateMetadata(binlogEntry.GetTrailer().Metadata) - grpcLogRecord.StatusCode = binlogEntry.GetTrailer().GetStatusCode() - grpcLogRecord.StatusMessage = binlogEntry.GetTrailer().GetStatusMessage() - grpcLogRecord.StatusDetails = binlogEntry.GetTrailer().GetStatusDetails() - grpcLogRecord.PayloadTruncated = binlogEntry.GetPayloadTruncated() - setPeerIfPresent(binlogEntry, grpcLogRecord) + grpcLogEntry.Type = eventTypeServerTrailer + grpcLogEntry.Payload.Metadata = translateMetadata(binLogEntry.GetTrailer().Metadata) + grpcLogEntry.Payload.StatusCode = binLogEntry.GetTrailer().GetStatusCode() + grpcLogEntry.Payload.StatusMessage = binLogEntry.GetTrailer().GetStatusMessage() + grpcLogEntry.Payload.StatusDetails = binLogEntry.GetTrailer().GetStatusDetails() + grpcLogEntry.PayloadTruncated = binLogEntry.GetPayloadTruncated() + setPeerIfPresent(binLogEntry, grpcLogEntry) case binlogpb.GrpcLogEntry_EVENT_TYPE_CANCEL: - grpcLogRecord.EventType = grpclogrecordpb.GrpcLogRecord_GRPC_CALL_CANCEL + grpcLogEntry.Type = eventTypeCancel default: - logger.Infof("Unknown event type: %v", binlogEntry.Type) + logger.Infof("Unknown event type: %v", binLogEntry.Type) return } - grpcLogRecord.ServiceName = ml.serviceName - grpcLogRecord.MethodName = ml.methodName - ml.exporter.EmitGrpcLogRecord(grpcLogRecord) -} + grpcLogEntry.ServiceName = bml.serviceName + grpcLogEntry.MethodName = bml.methodName + grpcLogEntry.Authority = bml.authority -type binaryLogger struct { - // originalLogger is needed to ensure binary logging users won't be impacted - // by this plugin. Users are allowed to subscribe to a completely different - // set of methods. - originalLogger iblog.Logger - // exporter is a loggingExporter and the handle for uploading collected data - // to backends. - exporter unsafe.Pointer // loggingExporter - // logger is a iblog.Logger wrapped for reusing the pattern matching logic - // and the method logger creating logic. - logger unsafe.Pointer // iblog.Logger -} - -func (l *binaryLogger) loadExporter() loggingExporter { - ptrPtr := atomic.LoadPointer(&l.exporter) - if ptrPtr == nil { - return nil + gcploggingEntry := gcplogging.Entry{ + Timestamp: binLogEntry.GetTimestamp().AsTime(), + Severity: 100, + Payload: grpcLogEntry, } - exporterPtr := (*loggingExporter)(ptrPtr) - return *exporterPtr -} -func (l *binaryLogger) loadLogger() iblog.Logger { - ptrPtr := atomic.LoadPointer(&l.logger) - if ptrPtr == nil { - return nil - } - loggerPtr := (*iblog.Logger)(ptrPtr) - return *loggerPtr + bml.exporter.EmitGcpLoggingEntry(gcploggingEntry) } -func (l *binaryLogger) GetMethodLogger(methodName string) iblog.MethodLogger { - var ol iblog.MethodLogger +type eventConfig struct { + ServiceMethod map[string]bool + Services map[string]bool + MatchAll bool - if l.originalLogger != nil { - ol = l.originalLogger.GetMethodLogger(methodName) - } - - // Prevent logging from logging, traces, and metrics API calls. - if strings.HasPrefix(methodName, "/google.logging.v2.LoggingServiceV2/") || strings.HasPrefix(methodName, "/google.monitoring.v3.MetricService/") || - strings.HasPrefix(methodName, "/google.devtools.cloudtrace.v2.TraceService/") { - return ol - } - - // If no exporter is specified, there is no point creating a method - // logger. We don't have any chance to inject exporter after its - // creation. - exporter := l.loadExporter() - if exporter == nil { - return ol - } + // If true, won't log anything. + Exclude bool + HeaderBytes uint64 + MessageBytes uint64 +} - // If no logger is specified, e.g., during init period, do nothing. - binLogger := l.loadLogger() - if binLogger == nil { - return ol - } +type binaryLogger struct { + EventConfigs []eventConfig + exporter loggingExporter +} - // If this method is not picked by LoggerConfig, do nothing. - ml := binLogger.GetMethodLogger(methodName) - if ml == nil { - return ol +func (bl *binaryLogger) GetMethodLogger(methodName string) iblog.MethodLogger { + s, _, err := grpcutil.ParseMethod(methodName) + if err != nil { + logger.Infof("binarylogging: failed to parse %q: %v", methodName, err) + return nil } + for _, eventConfig := range bl.EventConfigs { + if eventConfig.MatchAll || eventConfig.ServiceMethod[methodName] || eventConfig.Services[s] { + if eventConfig.Exclude { + return nil + } - return &binaryMethodLogger{ - originalMethodLogger: ol, - childMethodLogger: ml, - rpcID: uuid.NewString(), - exporter: exporter, + return &binaryMethodLogger{ + exporter: bl.exporter, + mlb: iblog.NewTruncatingMethodLogger(eventConfig.HeaderBytes, eventConfig.MessageBytes), + callID: uuid.NewString(), + } + } } + return nil } -func (l *binaryLogger) Close() { - if l == nil { +func registerClientRPCEvents(clientRPCEvents []clientRPCEvents, exporter loggingExporter) { + if len(clientRPCEvents) == 0 { return } - ePtr := atomic.LoadPointer(&l.exporter) - if ePtr != nil { - exporter := (*loggingExporter)(ePtr) - if err := (*exporter).Close(); err != nil { - logger.Infof("Failed to close logging exporter: %v", err) + var eventConfigs []eventConfig + for _, clientRPCEvent := range clientRPCEvents { + eventConfig := eventConfig{ + Exclude: clientRPCEvent.Exclude, + HeaderBytes: uint64(clientRPCEvent.MaxMetadataBytes), + MessageBytes: uint64(clientRPCEvent.MaxMessageBytes), } + for _, method := range clientRPCEvent.Methods { + eventConfig.ServiceMethod = make(map[string]bool) + eventConfig.Services = make(map[string]bool) + if method == "*" { + eventConfig.MatchAll = true + continue + } + s, m, err := grpcutil.ParseMethod(method) + if err != nil { + continue + } + if m == "*" { + eventConfig.Services[s] = true + continue + } + eventConfig.ServiceMethod[method] = true + } + eventConfigs = append(eventConfigs, eventConfig) } -} - -func validateExistingMethodLoggerConfig(existing *iblog.MethodLoggerConfig, filter logFilter) bool { - // In future, we could add more validations. Currently, we only check if the - // new filter configs are different than the existing one, if so, we log a - // warning. - if existing != nil && (existing.Header != uint64(filter.HeaderBytes) || existing.Message != uint64(filter.MessageBytes)) { - logger.Warningf("Ignored log_filter config: %+v", filter) + clientSideLogger := &binaryLogger{ + EventConfigs: eventConfigs, + exporter: exporter, } - return existing == nil + internal.AddGlobalDialOptions.(func(opt ...grpc.DialOption))(internal.WithBinaryLogger.(func(bl binarylog.Logger) grpc.DialOption)(clientSideLogger)) } -func createBinaryLoggerConfig(filters []logFilter) iblog.LoggerConfig { - config := iblog.LoggerConfig{ - Services: make(map[string]*iblog.MethodLoggerConfig), - Methods: make(map[string]*iblog.MethodLoggerConfig), +func registerServerRPCEvents(serverRPCEvents []serverRPCEvents, exporter loggingExporter) { + if len(serverRPCEvents) == 0 { + return } - // Try matching the filters one by one, pick the first match. The - // correctness of the log filter pattern is ensured by config.go. - for _, filter := range filters { - if filter.Pattern == "*" { - // Match a "*" - if !validateExistingMethodLoggerConfig(config.All, filter) { + var eventConfigs []eventConfig + for _, serverRPCEvent := range serverRPCEvents { + eventConfig := eventConfig{ + Exclude: serverRPCEvent.Exclude, + HeaderBytes: uint64(serverRPCEvent.MaxMetadataBytes), + MessageBytes: uint64(serverRPCEvent.MaxMessageBytes), + } + for _, method := range serverRPCEvent.Methods { + eventConfig.ServiceMethod = make(map[string]bool) + eventConfig.Services = make(map[string]bool) + if method == "*" { + eventConfig.MatchAll = true continue } - config.All = &iblog.MethodLoggerConfig{Header: uint64(filter.HeaderBytes), Message: uint64(filter.MessageBytes)} - continue - } - tokens := strings.SplitN(filter.Pattern, "/", 2) - filterService := tokens[0] - filterMethod := tokens[1] - if filterMethod == "*" { - // Handle "p.s/*" case - if !validateExistingMethodLoggerConfig(config.Services[filterService], filter) { + s, m, err := grpcutil.ParseMethod(method) + if err != nil { // Shouldn't happen, already validated at this point. continue } - config.Services[filterService] = &iblog.MethodLoggerConfig{Header: uint64(filter.HeaderBytes), Message: uint64(filter.MessageBytes)} - continue - } - // Exact match like "p.s/m" - if !validateExistingMethodLoggerConfig(config.Methods[filter.Pattern], filter) { - continue - } - config.Methods[filter.Pattern] = &iblog.MethodLoggerConfig{Header: uint64(filter.HeaderBytes), Message: uint64(filter.MessageBytes)} - } - return config -} - -// start is the core logic for setting up the custom binary logging logger, and -// it's also useful for testing. -func (l *binaryLogger) start(config *config, exporter loggingExporter) error { - filters := config.LogFilters - if len(filters) == 0 || exporter == nil { - // Doing nothing is allowed - if exporter != nil { - // The exporter is owned by binaryLogger, so we should close it if - // we are not planning to use it. - exporter.Close() + if m == "*" { + eventConfig.Services[s] = true + continue + } + eventConfig.ServiceMethod[method] = true } - logger.Info("Skipping gRPC Observability logger: no config") - return nil + eventConfigs = append(eventConfigs, eventConfig) } - - binLogger := iblog.NewLoggerFromConfig(createBinaryLoggerConfig(filters)) - if binLogger != nil { - atomic.StorePointer(&l.logger, unsafe.Pointer(&binLogger)) + serverSideLogger := &binaryLogger{ + EventConfigs: eventConfigs, + exporter: exporter, } - atomic.StorePointer(&l.exporter, unsafe.Pointer(&exporter)) - logger.Info("Start gRPC Observability logger") - return nil + internal.AddGlobalServerOptions.(func(opt ...grpc.ServerOption))(internal.BinaryLogger.(func(bl binarylog.Logger) grpc.ServerOption)(serverSideLogger)) } -func (l *binaryLogger) Start(ctx context.Context, config *config) error { - if config == nil || !config.EnableCloudLogging { +func startLogging(ctx context.Context, config *config) error { + if config == nil || config.CloudLogging == nil { return nil } - if config.DestinationProjectID == "" { - return fmt.Errorf("failed to enable CloudLogging: empty destination_project_id") - } - exporter, err := newCloudLoggingExporter(ctx, config) + var err error + lExporter, err = newLoggingExporter(ctx, config) if err != nil { return fmt.Errorf("unable to create CloudLogging exporter: %v", err) } - l.start(config, exporter) + + cl := config.CloudLogging + registerClientRPCEvents(cl.ClientRPCEvents, lExporter) + registerServerRPCEvents(cl.ServerRPCEvents, lExporter) return nil } -func newBinaryLogger(iblogger iblog.Logger) *binaryLogger { - return &binaryLogger{ - originalLogger: iblogger, +func stopLogging() { + internal.ClearGlobalDialOptions() + internal.ClearGlobalServerOptions() + if lExporter != nil { + // This Close() call handles the flushing of the logging buffer. + lExporter.Close() } } - -var defaultLogger *binaryLogger - -func prepareLogging() { - defaultLogger = newBinaryLogger(iblog.GetLogger()) - iblog.SetLogger(defaultLogger) -} diff --git a/gcp/observability/logging_test.go b/gcp/observability/logging_test.go new file mode 100644 index 000000000000..d91af4afc67f --- /dev/null +++ b/gcp/observability/logging_test.go @@ -0,0 +1,1098 @@ +/* + * + * Copyright 2022 gRPC 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 observability + +import ( + "context" + "encoding/base64" + "encoding/json" + "fmt" + "io" + "sync" + "testing" + + gcplogging "cloud.google.com/go/logging" + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" + binlogpb "google.golang.org/grpc/binarylog/grpc_binarylog_v1" + "google.golang.org/grpc/internal/envconfig" + "google.golang.org/grpc/internal/stubserver" + "google.golang.org/grpc/metadata" + "google.golang.org/grpc/test/grpc_testing" +) + +func cmpLoggingEntryList(got []*grpcLogEntry, want []*grpcLogEntry) error { + if diff := cmp.Diff(got, want, + // For nondeterministic metadata iteration. + cmp.Comparer(func(a map[string]string, b map[string]string) bool { + if len(a) > len(b) { + a, b = b, a + } + for k, v := range a { + if b[k] != v { + return false + } + } + return true + }), + cmpopts.IgnoreFields(grpcLogEntry{}, "CallID", "Peer"), + cmpopts.IgnoreFields(address{}, "IPPort", "Type"), + cmpopts.IgnoreFields(payload{}, "Timeout")); diff != "" { + return fmt.Errorf("got unexpected grpcLogEntry list, diff (-got, +want): %v", diff) + } + return nil +} + +type fakeLoggingExporter struct { + t *testing.T + + mu sync.Mutex + entries []*grpcLogEntry +} + +func (fle *fakeLoggingExporter) EmitGcpLoggingEntry(entry gcplogging.Entry) { + fle.mu.Lock() + defer fle.mu.Unlock() + if entry.Severity != 100 { + fle.t.Errorf("entry.Severity is not 100, this should be hardcoded") + } + grpcLogEntry, ok := entry.Payload.(*grpcLogEntry) + if !ok { + fle.t.Errorf("payload passed in isn't grpcLogEntry") + } + fle.entries = append(fle.entries, grpcLogEntry) +} + +func (fle *fakeLoggingExporter) Close() error { + return nil +} + +// setupObservabilitySystemWithConfig sets up the observability system with the +// specified config, and returns a function which cleans up the observability +// system. +func setupObservabilitySystemWithConfig(cfg *config) (func(), error) { + validConfigJSON, err := json.Marshal(cfg) + if err != nil { + return nil, fmt.Errorf("failed to convert config to JSON: %v", err) + } + oldObservabilityConfig := envconfig.ObservabilityConfig + envconfig.ObservabilityConfig = string(validConfigJSON) + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + err = Start(ctx) + if err != nil { + return nil, fmt.Errorf("error in Start: %v", err) + } + return func() { + End() + envconfig.ObservabilityConfig = oldObservabilityConfig + }, nil +} + +// TestClientRPCEventsLogAll tests the observability system configured with a +// client RPC event that logs every call. It performs a Unary and Bidirectional +// Streaming RPC, and expects certain grpcLogEntries to make it's way to the +// exporter. +func (s) TestClientRPCEventsLogAll(t *testing.T) { + fle := &fakeLoggingExporter{ + t: t, + } + defer func(ne func(ctx context.Context, config *config) (loggingExporter, error)) { + newLoggingExporter = ne + }(newLoggingExporter) + + newLoggingExporter = func(ctx context.Context, config *config) (loggingExporter, error) { + return fle, nil + } + + clientRPCEventLogAllConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + cleanup, err := setupObservabilitySystemWithConfig(clientRPCEventLogAllConfig) + if err != nil { + t.Fatalf("error setting up observability: %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error { + if _, err := stream.Recv(); err != nil { + return err + } + if err := stream.Send(&grpc_testing.StreamingOutputCallResponse{}); err != nil { + return err + } + if _, err := stream.Recv(); err != io.EOF { + return err + } + return nil + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + grpcLogEntriesWant := []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 2, + Authority: ss.Address, + Payload: payload{ + Message: []uint8{}, + }, + }, + { + Type: eventTypeServerHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 4, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 5, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + + fle.entries = nil + fle.mu.Unlock() + + // Make a streaming RPC. This should cause Log calls on the MethodLogger. + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } + if err := stream.Send(&grpc_testing.StreamingOutputCallRequest{}); err != nil { + t.Fatalf("stream.Send() failed: %v", err) + } + if _, err := stream.Recv(); err != nil { + t.Fatalf("stream.Recv() failed: %v", err) + } + if err := stream.CloseSend(); err != nil { + t.Fatalf("stream.CloseSend()() failed: %v", err) + } + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } + grpcLogEntriesWant = []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 2, + Authority: ss.Address, + Payload: payload{ + Message: []uint8{}, + }, + }, + { + Type: eventTypeServerHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 4, + Authority: ss.Address, + }, + { + Type: eventTypeClientHalfClose, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 5, + Authority: ss.Address, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 6, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + fle.mu.Unlock() +} + +func (s) TestServerRPCEventsLogAll(t *testing.T) { + fle := &fakeLoggingExporter{ + t: t, + } + defer func(ne func(ctx context.Context, config *config) (loggingExporter, error)) { + newLoggingExporter = ne + }(newLoggingExporter) + + newLoggingExporter = func(ctx context.Context, config *config) (loggingExporter, error) { + return fle, nil + } + + serverRPCEventLogAllConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ServerRPCEvents: []serverRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + cleanup, err := setupObservabilitySystemWithConfig(serverRPCEventLogAllConfig) + if err != nil { + t.Fatalf("error setting up observability %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error { + if _, err := stream.Recv(); err != nil { + return err + } + if err := stream.Send(&grpc_testing.StreamingOutputCallResponse{}); err != nil { + return err + } + if _, err := stream.Recv(); err != io.EOF { + return err + } + return nil + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + grpcLogEntriesWant := []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientMessage, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 2, + Authority: ss.Address, + }, + { + Type: eventTypeServerHeader, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 4, + Payload: payload{ + Message: []uint8{}, + }, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 5, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + fle.entries = nil + fle.mu.Unlock() + + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } + if err := stream.Send(&grpc_testing.StreamingOutputCallRequest{}); err != nil { + t.Fatalf("stream.Send() failed: %v", err) + } + if _, err := stream.Recv(); err != nil { + t.Fatalf("stream.Recv() failed: %v", err) + } + if err := stream.CloseSend(); err != nil { + t.Fatalf("stream.CloseSend()() failed: %v", err) + } + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } + + grpcLogEntriesWant = []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientMessage, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 2, + Authority: ss.Address, + }, + { + Type: eventTypeServerHeader, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 4, + Authority: ss.Address, + Payload: payload{ + Message: []uint8{}, + }, + }, + { + Type: eventTypeClientHalfClose, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 5, + Authority: ss.Address, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerServer, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 6, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + fle.mu.Unlock() +} + +// TestBothClientAndServerRPCEvents tests the scenario where you have both +// Client and Server RPC Events configured to log. Both sides should log and +// share the exporter, so the exporter should receive the collective amount of +// calls for both a client stream (corresponding to a Client RPC Event) and a +// server stream (corresponding ot a Server RPC Event). The specificity of the +// entries are tested in previous tests. +func (s) TestBothClientAndServerRPCEvents(t *testing.T) { + fle := &fakeLoggingExporter{ + t: t, + } + defer func(ne func(ctx context.Context, config *config) (loggingExporter, error)) { + newLoggingExporter = ne + }(newLoggingExporter) + + newLoggingExporter = func(ctx context.Context, config *config) (loggingExporter, error) { + return fle, nil + } + + serverRPCEventLogAllConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + ServerRPCEvents: []serverRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + + cleanup, err := setupObservabilitySystemWithConfig(serverRPCEventLogAllConfig) + if err != nil { + t.Fatalf("error setting up observability %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error { + _, err := stream.Recv() + if err != io.EOF { + return err + } + return nil + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + // Make a Unary RPC. Both client side and server side streams should log + // entries, which share the same exporter. The exporter should thus receive + // entries from both the client and server streams (the specificity of + // entries is checked in previous tests). + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + fle.mu.Lock() + if len(fle.entries) != 10 { + fle.mu.Unlock() + t.Fatalf("Unexpected length of entries %v, want 10 (collective of client and server)", len(fle.entries)) + } + fle.mu.Unlock() + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } + + stream.CloseSend() + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } + fle.mu.Lock() + if len(fle.entries) != 17 { + fle.mu.Unlock() + t.Fatalf("Unexpected length of entries %v, want 17 (collective of client and server)", len(fle.entries)) + } + fle.mu.Unlock() +} + +// TestClientRPCEventsLogAll tests the observability system configured with a +// client RPC event that logs every call and that truncates headers and +// messages. It performs a Unary RPC, and expects events with truncated payloads +// and payloadTruncated set to true, signifying the system properly truncated +// headers and messages logged. +func (s) TestClientRPCEventsTruncateHeaderAndMetadata(t *testing.T) { + fle := &fakeLoggingExporter{ + t: t, + } + defer func(ne func(ctx context.Context, config *config) (loggingExporter, error)) { + newLoggingExporter = ne + }(newLoggingExporter) + + newLoggingExporter = func(ctx context.Context, config *config) (loggingExporter, error) { + return fle, nil + } + + clientRPCEventLogAllConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 10, + MaxMessageBytes: 2, + }, + }, + }, + } + cleanup, err := setupObservabilitySystemWithConfig(clientRPCEventLogAllConfig) + if err != nil { + t.Fatalf("error setting up observability: %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + + md := metadata.MD{ + "key1": []string{"value1"}, + "key2": []string{"value2"}, + } + ctx = metadata.NewOutgoingContext(ctx, md) + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{Payload: &grpc_testing.Payload{Body: []byte("00000")}}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + grpcLogEntriesWant := []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{ + "key1": "value1", + "key2": "value2", + }, + }, + PayloadTruncated: true, + }, + { + Type: eventTypeClientMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 2, + Authority: ss.Address, + Payload: payload{ + MessageLength: 9, + Message: []uint8{ + 0x1a, + 0x07, + }, + }, + PayloadTruncated: true, + }, + { + Type: eventTypeServerHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 4, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 5, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + // Only one metadata entry should have been present in logging due to + // truncation. + if mdLen := len(fle.entries[0].Payload.Metadata); mdLen != 1 { + t.Fatalf("Metadata should have only 1 entry due to truncation, got %v", mdLen) + } + fle.mu.Unlock() +} + +// TestPrecedenceOrderingInConfiguration tests the scenario where the logging +// part of observability is configured with three client RPC events, the first +// two on specific methods in the service, the last one for any method within +// the service. This test sends three RPC's, one corresponding to each log +// entry. The logging logic dictated by that specific event should be what is +// used for emission. The second event will specify to exclude logging on RPC's, +// which should generate no log entries if an RPC gets to and matches that +// event. +func (s) TestPrecedenceOrderingInConfiguration(t *testing.T) { + fle := &fakeLoggingExporter{ + t: t, + } + + defer func(ne func(ctx context.Context, config *config) (loggingExporter, error)) { + newLoggingExporter = ne + }(newLoggingExporter) + + newLoggingExporter = func(ctx context.Context, config *config) (loggingExporter, error) { + return fle, nil + } + + threeEventsConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"/grpc.testing.TestService/UnaryCall"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + { + Methods: []string{"/grpc.testing.TestService/EmptyCall"}, + Exclude: true, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + { + Methods: []string{"/grpc.testing.TestService/*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + + cleanup, err := setupObservabilitySystemWithConfig(threeEventsConfig) + if err != nil { + t.Fatalf("error setting up observability %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + EmptyCallF: func(ctx context.Context, in *grpc_testing.Empty) (*grpc_testing.Empty, error) { + return &grpc_testing.Empty{}, nil + }, + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error { + _, err := stream.Recv() + if err != io.EOF { + return err + } + return nil + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + // A Unary RPC should match with first event and logs should correspond + // accordingly. The first event it matches to should be used for the + // configuration, even though it could potentially match to events in the + // future. + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + grpcLogEntriesWant := []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 2, + Authority: ss.Address, + Payload: payload{ + Message: []uint8{}, + }, + }, + { + Type: eventTypeServerHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerMessage, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + Authority: ss.Address, + SequenceID: 4, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "UnaryCall", + SequenceID: 5, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + fle.entries = nil + fle.mu.Unlock() + + // A unary empty RPC should match with the second event, which has the exclude + // flag set. Thus, a unary empty RPC should cause no downstream logs. + if _, err := ss.Client.EmptyCall(ctx, &grpc_testing.Empty{}); err != nil { + t.Fatalf("Unexpected error from EmptyCall: %v", err) + } + // The exporter should have received no new log entries due to this call. + fle.mu.Lock() + if len(fle.entries) != 0 { + fle.mu.Unlock() + t.Fatalf("Unexpected length of entries %v, want 0", len(fle.entries)) + } + fle.mu.Unlock() + + // A third RPC, a full duplex call, which doesn't match with first two and + // matches to last one, due to being a wildcard for every method in the + // service, should log accordingly to the last event's logic. + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } + + stream.CloseSend() + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } + + grpcLogEntriesWant = []*grpcLogEntry{ + { + Type: eventTypeClientHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 1, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeClientHalfClose, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 2, + Authority: ss.Address, + }, + { + Type: eventTypeServerHeader, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + SequenceID: 3, + Authority: ss.Address, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + { + Type: eventTypeServerTrailer, + Logger: loggerClient, + ServiceName: "grpc.testing.TestService", + MethodName: "FullDuplexCall", + Authority: ss.Address, + SequenceID: 4, + Payload: payload{ + Metadata: map[string]string{}, + }, + }, + } + fle.mu.Lock() + if err := cmpLoggingEntryList(fle.entries, grpcLogEntriesWant); err != nil { + fle.mu.Unlock() + t.Fatalf("error in logging entry list comparison %v", err) + } + fle.mu.Unlock() +} + +func (s) TestTranslateMetadata(t *testing.T) { + concatBinLogValue := base64.StdEncoding.EncodeToString([]byte("value1")) + "," + base64.StdEncoding.EncodeToString([]byte("value2")) + tests := []struct { + name string + binLogMD *binlogpb.Metadata + wantMD map[string]string + }{ + { + name: "two-entries-different-key", + binLogMD: &binlogpb.Metadata{ + Entry: []*binlogpb.MetadataEntry{ + { + Key: "header1", + Value: []byte("value1"), + }, + { + Key: "header2", + Value: []byte("value2"), + }, + }, + }, + wantMD: map[string]string{ + "header1": "value1", + "header2": "value2", + }, + }, + { + name: "two-entries-same-key", + binLogMD: &binlogpb.Metadata{ + Entry: []*binlogpb.MetadataEntry{ + { + Key: "header1", + Value: []byte("value1"), + }, + { + Key: "header1", + Value: []byte("value2"), + }, + }, + }, + wantMD: map[string]string{ + "header1": "value1,value2", + }, + }, + { + name: "two-entries-same-key-bin-header", + binLogMD: &binlogpb.Metadata{ + Entry: []*binlogpb.MetadataEntry{ + { + Key: "header1-bin", + Value: []byte("value1"), + }, + { + Key: "header1-bin", + Value: []byte("value2"), + }, + }, + }, + wantMD: map[string]string{ + "header1-bin": concatBinLogValue, + }, + }, + { + name: "four-entries-two-keys", + binLogMD: &binlogpb.Metadata{ + Entry: []*binlogpb.MetadataEntry{ + { + Key: "header1", + Value: []byte("value1"), + }, + { + Key: "header1", + Value: []byte("value2"), + }, + { + Key: "header1-bin", + Value: []byte("value1"), + }, + { + Key: "header1-bin", + Value: []byte("value2"), + }, + }, + }, + wantMD: map[string]string{ + "header1": "value1,value2", + "header1-bin": concatBinLogValue, + }, + }, + } + + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + if gotMD := translateMetadata(test.binLogMD); !cmp.Equal(gotMD, test.wantMD) { + t.Fatalf("translateMetadata(%v) = %v, want %v", test.binLogMD, gotMD, test.wantMD) + } + }) + } +} + +func (s) TestMarshalJSON(t *testing.T) { + logEntry := &grpcLogEntry{ + CallID: "300-300-300", + SequenceID: 3, + Type: eventTypeUnknown, + Logger: loggerClient, + Payload: payload{ + Metadata: map[string]string{"header1": "value1"}, + Timeout: 20, + StatusCode: 3, + StatusMessage: "ok", + StatusDetails: []byte("ok"), + MessageLength: 3, + Message: []byte("wow"), + }, + Peer: address{ + Type: typeIPv4, + Address: "localhost", + IPPort: 16000, + }, + PayloadTruncated: false, + Authority: "server", + ServiceName: "grpc-testing", + MethodName: "UnaryRPC", + } + if _, err := json.Marshal(logEntry); err != nil { + t.Fatalf("json.Marshal(%v) failed with error: %v", logEntry, err) + } +} diff --git a/gcp/observability/observability.go b/gcp/observability/observability.go index 3855bc7ebaf0..1010f72f743c 100644 --- a/gcp/observability/observability.go +++ b/gcp/observability/observability.go @@ -34,10 +34,6 @@ import ( var logger = grpclog.Component("observability") -func init() { - prepareLogging() -} - // Start is the opt-in API for gRPC Observability plugin. This function should // be invoked in the main function, and before creating any gRPC clients or // servers, otherwise, they might not be instrumented. At high-level, this @@ -55,7 +51,7 @@ func Start(ctx context.Context) error { return err } if config == nil { - return fmt.Errorf("no ObservabilityConfig found, it can be set via env %s", envObservabilityConfig) + return fmt.Errorf("no ObservabilityConfig found") } // Set the project ID if it isn't configured manually. @@ -69,7 +65,7 @@ func Start(ctx context.Context) error { } // Logging is controlled by the config at methods level. - return defaultLogger.Start(ctx, config) + return startLogging(ctx, config) } // End is the clean-up API for gRPC Observability plugin. It is expected to be @@ -79,6 +75,6 @@ func Start(ctx context.Context) error { // // Note: this method should only be invoked once. func End() { - defaultLogger.Close() + stopLogging() stopOpenCensus() } diff --git a/gcp/observability/observability_test.go b/gcp/observability/observability_test.go index e9238f898abd..1ea0424b7f5e 100644 --- a/gcp/observability/observability_test.go +++ b/gcp/observability/observability_test.go @@ -19,12 +19,11 @@ package observability import ( - "bytes" "context" "encoding/json" "fmt" + "io" "io/ioutil" - "net" "os" "sync" "testing" @@ -32,18 +31,12 @@ import ( "go.opencensus.io/stats/view" "go.opencensus.io/trace" - "google.golang.org/grpc" - "google.golang.org/grpc/credentials/insecure" - grpclogrecordpb "google.golang.org/grpc/gcp/observability/internal/logging" - iblog "google.golang.org/grpc/internal/binarylog" + "google.golang.org/grpc/internal/envconfig" "google.golang.org/grpc/internal/grpctest" "google.golang.org/grpc/internal/leakcheck" - testgrpc "google.golang.org/grpc/interop/grpc_testing" - testpb "google.golang.org/grpc/interop/grpc_testing" + "google.golang.org/grpc/internal/stubserver" "google.golang.org/grpc/metadata" - "google.golang.org/grpc/status" - "google.golang.org/protobuf/encoding/protojson" - "google.golang.org/protobuf/proto" + "google.golang.org/grpc/test/grpc_testing" ) type s struct { @@ -75,275 +68,6 @@ var ( defaultRequestCount = 24 ) -type testServer struct { - testgrpc.UnimplementedTestServiceServer -} - -func (s *testServer) UnaryCall(ctx context.Context, in *testpb.SimpleRequest) (*testpb.SimpleResponse, error) { - if err := grpc.SendHeader(ctx, testHeaderMetadata); err != nil { - return nil, status.Errorf(status.Code(err), "grpc.SendHeader(_, %v) = %v, want ", testHeaderMetadata, err) - } - if err := grpc.SetTrailer(ctx, testTrailerMetadata); err != nil { - return nil, status.Errorf(status.Code(err), "grpc.SetTrailer(_, %v) = %v, want ", testTrailerMetadata, err) - } - - if bytes.Equal(in.Payload.Body, testErrorPayload) { - return nil, fmt.Errorf(testErrorMessage) - } - - return &testpb.SimpleResponse{Payload: in.Payload}, nil -} - -type fakeLoggingExporter struct { - t *testing.T - clientEvents []*grpclogrecordpb.GrpcLogRecord - serverEvents []*grpclogrecordpb.GrpcLogRecord - isClosed bool - mu sync.Mutex -} - -func (fle *fakeLoggingExporter) EmitGrpcLogRecord(l *grpclogrecordpb.GrpcLogRecord) { - fle.mu.Lock() - defer fle.mu.Unlock() - switch l.EventLogger { - case grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT: - fle.clientEvents = append(fle.clientEvents, l) - case grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER: - fle.serverEvents = append(fle.serverEvents, l) - default: - fle.t.Fatalf("unexpected event logger: %v", l.EventLogger) - } - eventJSON, _ := protojson.Marshal(l) - fle.t.Logf("fakeLoggingExporter Emit: %s", eventJSON) -} - -func (fle *fakeLoggingExporter) Close() error { - fle.isClosed = true - return nil -} - -// test is an end-to-end test. It should be created with the newTest -// func, modified as needed, and then started with its startServer method. -// It should be cleaned up with the tearDown method. -type test struct { - t *testing.T - fle *fakeLoggingExporter - - testServer testgrpc.TestServiceServer // nil means none - // srv and srvAddr are set once startServer is called. - srv *grpc.Server - srvAddr string - - cc *grpc.ClientConn // nil until requested via clientConn -} - -func (te *test) tearDown() { - if te.cc != nil { - te.cc.Close() - te.cc = nil - } - te.srv.Stop() - End() - - if te.fle != nil && !te.fle.isClosed { - te.t.Fatalf("fakeLoggingExporter not closed!") - } -} - -// newTest returns a new test using the provided testing.T and -// environment. It is returned with default values. Tests should -// modify it before calling its startServer and clientConn methods. -func newTest(t *testing.T) *test { - return &test{ - t: t, - } -} - -// startServer starts a gRPC server listening. Callers should defer a -// call to te.tearDown to clean up. -func (te *test) startServer(ts testgrpc.TestServiceServer) { - te.testServer = ts - lis, err := net.Listen("tcp", "localhost:0") - if err != nil { - te.t.Fatalf("Failed to listen: %v", err) - } - var opts []grpc.ServerOption - s := grpc.NewServer(opts...) - te.srv = s - if te.testServer != nil { - testgrpc.RegisterTestServiceServer(s, te.testServer) - } - - go s.Serve(lis) - te.srvAddr = lis.Addr().String() -} - -func (te *test) clientConn() *grpc.ClientConn { - if te.cc != nil { - return te.cc - } - opts := []grpc.DialOption{ - grpc.WithTransportCredentials(insecure.NewCredentials()), - grpc.WithBlock(), - grpc.WithUserAgent("test/0.0.1"), - } - var err error - te.cc, err = grpc.Dial(te.srvAddr, opts...) - if err != nil { - te.t.Fatalf("Dial(%q) = %v", te.srvAddr, err) - } - return te.cc -} - -func (te *test) enablePluginWithConfig(config *config) { - // Injects the fake exporter for testing purposes - te.fle = &fakeLoggingExporter{t: te.t} - defaultLogger = newBinaryLogger(nil) - iblog.SetLogger(defaultLogger) - if err := defaultLogger.start(config, te.fle); err != nil { - te.t.Fatalf("Failed to start plugin: %v", err) - } -} - -func (te *test) enablePluginWithCaptureAll() { - te.enablePluginWithConfig(&config{ - EnableCloudLogging: true, - DestinationProjectID: "fake", - LogFilters: []logFilter{ - { - Pattern: "*", - HeaderBytes: infinitySizeBytes, - MessageBytes: infinitySizeBytes, - }, - }, - }) -} - -func (te *test) enableOpenCensus() { - defaultMetricsReportingInterval = time.Millisecond * 100 - config := &config{ - EnableCloudLogging: true, - EnableCloudTrace: true, - EnableCloudMonitoring: true, - GlobalTraceSamplingRate: 1.0, - } - startOpenCensus(config) -} - -func checkEventCommon(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord) { - if seen.RpcId == "" { - t.Fatalf("expect non-empty RpcId") - } - if seen.SequenceId == 0 { - t.Fatalf("expect non-zero SequenceId") - } -} - -func checkEventRequestHeader(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord, want *grpclogrecordpb.GrpcLogRecord) { - checkEventCommon(t, seen) - if seen.EventType != grpclogrecordpb.GrpcLogRecord_GRPC_CALL_REQUEST_HEADER { - t.Fatalf("got %v, want GrpcLogRecord_GRPC_CALL_REQUEST_HEADER", seen.EventType.String()) - } - if seen.EventLogger != want.EventLogger { - t.Fatalf("l.EventLogger = %v, want %v", seen.EventLogger, want.EventLogger) - } - if want.Authority != "" && seen.Authority != want.Authority { - t.Fatalf("l.Authority = %v, want %v", seen.Authority, want.Authority) - } - if want.ServiceName != "" && seen.ServiceName != want.ServiceName { - t.Fatalf("l.ServiceName = %v, want %v", seen.ServiceName, want.ServiceName) - } - if want.MethodName != "" && seen.MethodName != want.MethodName { - t.Fatalf("l.MethodName = %v, want %v", seen.MethodName, want.MethodName) - } - if len(seen.Metadata.Entry) != 1 { - t.Fatalf("unexpected header size: %v != 1", len(seen.Metadata.Entry)) - } - if seen.Metadata.Entry[0].Key != "header" { - t.Fatalf("unexpected header: %v", seen.Metadata.Entry[0].Key) - } - if !bytes.Equal(seen.Metadata.Entry[0].Value, []byte(testHeaderMetadata["header"][0])) { - t.Fatalf("unexpected header value: %v", seen.Metadata.Entry[0].Value) - } -} - -func checkEventResponseHeader(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord, want *grpclogrecordpb.GrpcLogRecord) { - checkEventCommon(t, seen) - if seen.EventType != grpclogrecordpb.GrpcLogRecord_GRPC_CALL_RESPONSE_HEADER { - t.Fatalf("got %v, want GrpcLogRecord_GRPC_CALL_RESPONSE_HEADER", seen.EventType.String()) - } - if seen.EventLogger != want.EventLogger { - t.Fatalf("l.EventLogger = %v, want %v", seen.EventLogger, want.EventLogger) - } - if len(seen.Metadata.Entry) != 1 { - t.Fatalf("unexpected header size: %v != 1", len(seen.Metadata.Entry)) - } - if seen.Metadata.Entry[0].Key != "header" { - t.Fatalf("unexpected header: %v", seen.Metadata.Entry[0].Key) - } - if !bytes.Equal(seen.Metadata.Entry[0].Value, []byte(testHeaderMetadata["header"][0])) { - t.Fatalf("unexpected header value: %v", seen.Metadata.Entry[0].Value) - } -} - -func checkEventRequestMessage(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord, want *grpclogrecordpb.GrpcLogRecord, payload []byte) { - checkEventCommon(t, seen) - if seen.EventType != grpclogrecordpb.GrpcLogRecord_GRPC_CALL_REQUEST_MESSAGE { - t.Fatalf("got %v, want GrpcLogRecord_GRPC_CALL_REQUEST_MESSAGE", seen.EventType.String()) - } - if seen.EventLogger != want.EventLogger { - t.Fatalf("l.EventLogger = %v, want %v", seen.EventLogger, want.EventLogger) - } - msg := &testpb.SimpleRequest{Payload: &testpb.Payload{Body: payload}} - msgBytes, _ := proto.Marshal(msg) - if !bytes.Equal(seen.Message, msgBytes) { - t.Fatalf("unexpected payload: %v != %v", seen.Message, payload) - } -} - -func checkEventResponseMessage(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord, want *grpclogrecordpb.GrpcLogRecord, payload []byte) { - checkEventCommon(t, seen) - if seen.EventType != grpclogrecordpb.GrpcLogRecord_GRPC_CALL_RESPONSE_MESSAGE { - t.Fatalf("got %v, want GrpcLogRecord_GRPC_CALL_RESPONSE_MESSAGE", seen.EventType.String()) - } - if seen.EventLogger != want.EventLogger { - t.Fatalf("l.EventLogger = %v, want %v", seen.EventLogger, want.EventLogger) - } - msg := &testpb.SimpleResponse{Payload: &testpb.Payload{Body: payload}} - msgBytes, _ := proto.Marshal(msg) - if !bytes.Equal(seen.Message, msgBytes) { - t.Fatalf("unexpected payload: %v != %v", seen.Message, payload) - } -} - -func checkEventTrailer(t *testing.T, seen *grpclogrecordpb.GrpcLogRecord, want *grpclogrecordpb.GrpcLogRecord) { - checkEventCommon(t, seen) - if seen.EventType != grpclogrecordpb.GrpcLogRecord_GRPC_CALL_TRAILER { - t.Fatalf("got %v, want GrpcLogRecord_GRPC_CALL_TRAILER", seen.EventType.String()) - } - if seen.EventLogger != want.EventLogger { - t.Fatalf("l.EventLogger = %v, want %v", seen.EventLogger, want.EventLogger) - } - if seen.StatusCode != want.StatusCode { - t.Fatalf("l.StatusCode = %v, want %v", seen.StatusCode, want.StatusCode) - } - if seen.StatusMessage != want.StatusMessage { - t.Fatalf("l.StatusMessage = %v, want %v", seen.StatusMessage, want.StatusMessage) - } - if !bytes.Equal(seen.StatusDetails, want.StatusDetails) { - t.Fatalf("l.StatusDetails = %v, want %v", seen.StatusDetails, want.StatusDetails) - } - if len(seen.Metadata.Entry) != 1 { - t.Fatalf("unexpected trailer size: %v != 1", len(seen.Metadata.Entry)) - } - if seen.Metadata.Entry[0].Key != "trailer" { - t.Fatalf("unexpected trailer: %v", seen.Metadata.Entry[0].Key) - } - if !bytes.Equal(seen.Metadata.Entry[0].Value, []byte(testTrailerMetadata["trailer"][0])) { - t.Fatalf("unexpected trailer value: %v", seen.Metadata.Entry[0].Value) - } -} - const ( TypeOpenCensusViewDistribution string = "distribution" TypeOpenCensusViewCount = "count" @@ -392,296 +116,67 @@ func (fe *fakeOpenCensusExporter) Close() error { return nil } -func (s) TestLoggingForOkCall(t *testing.T) { - te := newTest(t) - defer te.tearDown() - te.enablePluginWithCaptureAll() - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) - - var ( - resp *testpb.SimpleResponse - req *testpb.SimpleRequest - err error - ) - req = &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testOkPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() - resp, err = tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err != nil { - t.Fatalf("unary call failed: %v", err) - } - t.Logf("unary call passed: %v", resp) - - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() - // Check size of events - if len(te.fle.clientEvents) != 5 { - t.Fatalf("expects 5 client events, got %d", len(te.fle.clientEvents)) - } - if len(te.fle.serverEvents) != 5 { - t.Fatalf("expects 5 server events, got %d", len(te.fle.serverEvents)) - } - // Client events - checkEventRequestHeader(te.t, te.fle.clientEvents[0], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - Authority: te.srvAddr, - ServiceName: "grpc.testing.TestService", - MethodName: "UnaryCall", - }) - checkEventRequestMessage(te.t, te.fle.clientEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }, testOkPayload) - checkEventResponseHeader(te.t, te.fle.clientEvents[2], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }) - checkEventResponseMessage(te.t, te.fle.clientEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }, testOkPayload) - checkEventTrailer(te.t, te.fle.clientEvents[4], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - StatusCode: 0, - }) - // Server events - checkEventRequestHeader(te.t, te.fle.serverEvents[0], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }) - checkEventRequestMessage(te.t, te.fle.serverEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }, testOkPayload) - checkEventResponseHeader(te.t, te.fle.serverEvents[2], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }) - checkEventResponseMessage(te.t, te.fle.serverEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }, testOkPayload) - checkEventTrailer(te.t, te.fle.serverEvents[4], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - StatusCode: 0, - }) -} - -func (s) TestLoggingForErrorCall(t *testing.T) { - te := newTest(t) - defer te.tearDown() - te.enablePluginWithCaptureAll() - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) - - req := &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testErrorPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() - _, err := tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err == nil { - t.Fatalf("unary call expected to fail, but passed") - } - - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() - // Check size of events - if len(te.fle.clientEvents) != 4 { - t.Fatalf("expects 4 client events, got %d", len(te.fle.clientEvents)) - } - if len(te.fle.serverEvents) != 4 { - t.Fatalf("expects 4 server events, got %d", len(te.fle.serverEvents)) - } - // Client events - checkEventRequestHeader(te.t, te.fle.clientEvents[0], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - Authority: te.srvAddr, - ServiceName: "grpc.testing.TestService", - MethodName: "UnaryCall", - }) - checkEventRequestMessage(te.t, te.fle.clientEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }, testErrorPayload) - checkEventResponseHeader(te.t, te.fle.clientEvents[2], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }) - checkEventTrailer(te.t, te.fle.clientEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - StatusCode: 2, - StatusMessage: testErrorMessage, - }) - // Server events - checkEventRequestHeader(te.t, te.fle.serverEvents[0], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }) - checkEventRequestMessage(te.t, te.fle.serverEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }, testErrorPayload) - checkEventResponseHeader(te.t, te.fle.serverEvents[2], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }) - checkEventTrailer(te.t, te.fle.serverEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - StatusCode: 2, - StatusMessage: testErrorMessage, - }) -} - -func (s) TestEmptyConfig(t *testing.T) { - te := newTest(t) - defer te.tearDown() - te.enablePluginWithConfig(&config{}) - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) - - req := &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testOkPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() - resp, err := tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err != nil { - t.Fatalf("unary call failed: %v", err) - } - t.Logf("unary call passed: %v", resp) - - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() - // Check size of events - if len(te.fle.clientEvents) != 0 { - t.Fatalf("expects 0 client events, got %d", len(te.fle.clientEvents)) - } - if len(te.fle.serverEvents) != 0 { - t.Fatalf("expects 0 server events, got %d", len(te.fle.serverEvents)) - } -} - -func (s) TestOverrideConfig(t *testing.T) { - te := newTest(t) - defer te.tearDown() - // Setting 3 filters, expected to use the third filter, because it's the - // most specific one. The third filter allows message payload logging, and - // others disabling the message payload logging. We should observe this - // behavior latter. - te.enablePluginWithConfig(&config{ - EnableCloudLogging: true, - DestinationProjectID: "fake", - LogFilters: []logFilter{ - { - Pattern: "wont/match", - MessageBytes: 0, - }, - { - Pattern: "*", - MessageBytes: 0, - }, - { - Pattern: "grpc.testing.TestService/*", - MessageBytes: 4096, - }, - }, - }) - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) - - var ( - resp *testpb.SimpleResponse - req *testpb.SimpleRequest - err error - ) - req = &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testOkPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() - resp, err = tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err != nil { - t.Fatalf("unary call failed: %v", err) - } - t.Logf("unary call passed: %v", resp) - - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() - // Check size of events - if len(te.fle.clientEvents) != 5 { - t.Fatalf("expects 5 client events, got %d", len(te.fle.clientEvents)) - } - if len(te.fle.serverEvents) != 5 { - t.Fatalf("expects 5 server events, got %d", len(te.fle.serverEvents)) - } - // Check Client message payloads - checkEventRequestMessage(te.t, te.fle.clientEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }, testOkPayload) - checkEventResponseMessage(te.t, te.fle.clientEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_CLIENT, - }, testOkPayload) - // Check Server message payloads - checkEventRequestMessage(te.t, te.fle.serverEvents[1], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }, testOkPayload) - checkEventResponseMessage(te.t, te.fle.serverEvents[3], &grpclogrecordpb.GrpcLogRecord{ - EventLogger: grpclogrecordpb.GrpcLogRecord_LOGGER_SERVER, - }, testOkPayload) -} - -func (s) TestNoMatch(t *testing.T) { - te := newTest(t) - defer te.tearDown() - // Setting 3 filters, expected to use the second filter. The second filter - // allows message payload logging, and others disabling the message payload - // logging. We should observe this behavior latter. - te.enablePluginWithConfig(&config{ - EnableCloudLogging: true, - DestinationProjectID: "fake", - LogFilters: []logFilter{ - { - Pattern: "wont/match", - MessageBytes: 0, +func (s) TestRefuseStartWithInvalidPatterns(t *testing.T) { + invalidConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{":-)"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, }, }, - }) - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) - - var ( - resp *testpb.SimpleResponse - req *testpb.SimpleRequest - err error - ) - req = &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testOkPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() - resp, err = tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err != nil { - t.Fatalf("unary call failed: %v", err) } - t.Logf("unary call passed: %v", resp) - - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() - // Check size of events - if len(te.fle.clientEvents) != 0 { - t.Fatalf("expects 0 client events, got %d", len(te.fle.clientEvents)) + invalidConfigJSON, err := json.Marshal(invalidConfig) + if err != nil { + t.Fatalf("failed to convert config to JSON: %v", err) } - if len(te.fle.serverEvents) != 0 { - t.Fatalf("expects 0 server events, got %d", len(te.fle.serverEvents)) + oldObservabilityConfig := envconfig.ObservabilityConfig + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfig = string(invalidConfigJSON) + envconfig.ObservabilityConfigFile = "" + defer func() { + envconfig.ObservabilityConfig = oldObservabilityConfig + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile + }() + // If there is at least one invalid pattern, which should not be silently tolerated. + if err := Start(context.Background()); err == nil { + t.Fatalf("Invalid patterns not triggering error") } } -func (s) TestRefuseStartWithInvalidPatterns(t *testing.T) { - config := &config{ - EnableCloudLogging: true, - DestinationProjectID: "fake", - LogFilters: []logFilter{ - { - Pattern: ":-)", - }, - { - Pattern: "*", +// TestRefuseStartWithExcludeAndWildCardAll tests the sceanrio where an +// observability configuration is provided with client RPC event specifying to +// exclude, and which matches on the '*' wildcard (any). This should cause an +// error when trying to start the observability system. +func (s) TestRefuseStartWithExcludeAndWildCardAll(t *testing.T) { + invalidConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"*"}, + Exclude: true, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, }, }, } - configJSON, err := json.Marshal(config) + invalidConfigJSON, err := json.Marshal(invalidConfig) if err != nil { t.Fatalf("failed to convert config to JSON: %v", err) } - os.Setenv(envObservabilityConfigJSON, "") - os.Setenv(envObservabilityConfig, string(configJSON)) + oldObservabilityConfig := envconfig.ObservabilityConfig + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfig = string(invalidConfigJSON) + envconfig.ObservabilityConfigFile = "" + defer func() { + envconfig.ObservabilityConfig = oldObservabilityConfig + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile + }() // If there is at least one invalid pattern, which should not be silently tolerated. if err := Start(context.Background()); err == nil { t.Fatalf("Invalid patterns not triggering error") @@ -701,10 +196,11 @@ func createTmpConfigInFileSystem(rawJSON string) (func(), error) { if err != nil { return nil, fmt.Errorf("cannot write marshalled JSON: %v", err) } - os.Setenv(envObservabilityConfigJSON, configJSONFile.Name()) + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfigFile = configJSONFile.Name() return func() { configJSONFile.Close() - os.Setenv(envObservabilityConfigJSON, "") + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile }, nil } @@ -713,8 +209,7 @@ func createTmpConfigInFileSystem(rawJSON string) (func(), error) { // file path pointing to a JSON encoded config. func (s) TestJSONEnvVarSet(t *testing.T) { configJSON := `{ - "destination_project_id": "fake", - "log_filters":[{"pattern":"*","header_bytes":1073741824,"message_bytes":1073741824}] + "project_id": "fake" }` cleanup, err := createTmpConfigInFileSystem(configJSON) defer cleanup() @@ -736,24 +231,37 @@ func (s) TestJSONEnvVarSet(t *testing.T) { // configuration being invalid, even if the direct configuration environment // variable is set and valid. func (s) TestBothConfigEnvVarsSet(t *testing.T) { - configJSON := `{ - "destination_project_id":"fake", - "log_filters":[{"pattern":":-)"}, {"pattern_string":"*"}] - }` - cleanup, err := createTmpConfigInFileSystem(configJSON) + invalidConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{":-)"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + invalidConfigJSON, err := json.Marshal(invalidConfig) + if err != nil { + t.Fatalf("failed to convert config to JSON: %v", err) + } + cleanup, err := createTmpConfigInFileSystem(string(invalidConfigJSON)) defer cleanup() if err != nil { t.Fatalf("failed to create config in file system: %v", err) } // This configuration should be ignored, as precedence 2. validConfig := &config{ - EnableCloudLogging: true, - DestinationProjectID: "fake", - LogFilters: []logFilter{ - { - Pattern: "*", - HeaderBytes: infinitySizeBytes, - MessageBytes: infinitySizeBytes, + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{"*"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, }, }, } @@ -761,7 +269,11 @@ func (s) TestBothConfigEnvVarsSet(t *testing.T) { if err != nil { t.Fatalf("failed to convert config to JSON: %v", err) } - os.Setenv(envObservabilityConfig, string(validConfigJSON)) + oldObservabilityConfig := envconfig.ObservabilityConfig + envconfig.ObservabilityConfig = string(validConfigJSON) + defer func() { + envconfig.ObservabilityConfig = oldObservabilityConfig + }() if err := Start(context.Background()); err == nil { t.Fatalf("Invalid patterns not triggering error") } @@ -772,16 +284,25 @@ func (s) TestBothConfigEnvVarsSet(t *testing.T) { // location in the file system for configuration, and this location doesn't have // a file (or valid configuration). func (s) TestErrInFileSystemEnvVar(t *testing.T) { - os.Setenv(envObservabilityConfigJSON, "/this-file/does-not-exist") - defer os.Setenv(envObservabilityConfigJSON, "") + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfigFile = "/this-file/does-not-exist" + defer func() { + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile + }() if err := Start(context.Background()); err == nil { t.Fatalf("Invalid file system path not triggering error") } } func (s) TestNoEnvSet(t *testing.T) { - os.Setenv(envObservabilityConfigJSON, "") - os.Setenv(envObservabilityConfig, "") + oldObservabilityConfig := envconfig.ObservabilityConfig + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfig = "" + envconfig.ObservabilityConfigFile = "" + defer func() { + envconfig.ObservabilityConfig = oldObservabilityConfig + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile + }() // If there is no observability config set at all, the Start should return an error. if err := Start(context.Background()); err == nil { t.Fatalf("Invalid patterns not triggering error") @@ -789,9 +310,8 @@ func (s) TestNoEnvSet(t *testing.T) { } func (s) TestOpenCensusIntegration(t *testing.T) { - te := newTest(t) - defer te.tearDown() - fe := &fakeOpenCensusExporter{SeenViews: make(map[string]string), t: te.t} + defaultMetricsReportingInterval = time.Millisecond * 100 + fe := &fakeOpenCensusExporter{SeenViews: make(map[string]string), t: t} defer func(ne func(config *config) (tracingMetricsExporter, error)) { newExporter = ne @@ -801,28 +321,58 @@ func (s) TestOpenCensusIntegration(t *testing.T) { return fe, nil } - te.enableOpenCensus() - te.startServer(&testServer{}) - tc := testgrpc.NewTestServiceClient(te.clientConn()) + openCensusOnConfig := &config{ + ProjectID: "fake", + CloudMonitoring: &cloudMonitoring{}, + CloudTrace: &cloudTrace{ + SamplingRate: 1.0, + }, + } + cleanup, err := setupObservabilitySystemWithConfig(openCensusOnConfig) + if err != nil { + t.Fatalf("error setting up observability %v", err) + } + defer cleanup() + + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *grpc_testing.SimpleRequest) (*grpc_testing.SimpleResponse, error) { + return &grpc_testing.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error { + for { + _, err := stream.Recv() + if err == io.EOF { + return nil + } + } + }, + } + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() for i := 0; i < defaultRequestCount; i++ { - req := &testpb.SimpleRequest{Payload: &testpb.Payload{Body: testOkPayload}} - tCtx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) defer cancel() - _, err := tc.UnaryCall(metadata.NewOutgoingContext(tCtx, testHeaderMetadata), req) - if err != nil { - t.Fatalf("unary call failed: %v", err) + if _, err := ss.Client.UnaryCall(ctx, &grpc_testing.SimpleRequest{Payload: &grpc_testing.Payload{Body: testOkPayload}}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) } } t.Logf("unary call passed count=%v", defaultRequestCount) + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } - // Wait for the gRPC transport to gracefully close to ensure no lost event. - te.cc.Close() - te.srv.GracefulStop() + stream.CloseSend() + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } var errs []error - ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) - defer cancel() for ctx.Err() == nil { errs = nil fe.mu.RLock() @@ -855,7 +405,7 @@ func (s) TestCustomTagsTracingMetrics(t *testing.T) { }(newExporter) fe := &fakeOpenCensusExporter{SeenViews: make(map[string]string), t: t} newExporter = func(config *config) (tracingMetricsExporter, error) { - ct := config.CustomTags + ct := config.Labels if len(ct) < 1 { t.Fatalf("less than 2 custom tags sent in") } @@ -871,12 +421,12 @@ func (s) TestCustomTagsTracingMetrics(t *testing.T) { // This configuration present in file system and it's defined custom tags should make it // to the created exporter. configJSON := `{ - "destination_project_id": "fake", - "enable_cloud_trace": true, - "enable_cloud_monitoring": true, - "global_trace_sampling_rate": 1.0, - "custom_tags":{"customtag1":"wow","customtag2":"nice"} + "project_id": "fake", + "cloud_trace": {}, + "cloud_monitoring": {"sampling_rate": 1.0}, + "labels":{"customtag1":"wow","customtag2":"nice"} }` + cleanup, err := createTmpConfigInFileSystem(configJSON) defer cleanup() @@ -888,3 +438,37 @@ func (s) TestCustomTagsTracingMetrics(t *testing.T) { t.Fatalf("Start() failed with err: %v", err) } } + +// TestStartErrorsThenEnd tests that an End call after Start errors works +// without problems, as this is a possible codepath in the public observability +// API. +func (s) TestStartErrorsThenEnd(t *testing.T) { + invalidConfig := &config{ + ProjectID: "fake", + CloudLogging: &cloudLogging{ + ClientRPCEvents: []clientRPCEvents{ + { + Methods: []string{":-)"}, + MaxMetadataBytes: 30, + MaxMessageBytes: 30, + }, + }, + }, + } + invalidConfigJSON, err := json.Marshal(invalidConfig) + if err != nil { + t.Fatalf("failed to convert config to JSON: %v", err) + } + oldObservabilityConfig := envconfig.ObservabilityConfig + oldObservabilityConfigFile := envconfig.ObservabilityConfigFile + envconfig.ObservabilityConfig = string(invalidConfigJSON) + envconfig.ObservabilityConfigFile = "" + defer func() { + envconfig.ObservabilityConfig = oldObservabilityConfig + envconfig.ObservabilityConfigFile = oldObservabilityConfigFile + }() + if err := Start(context.Background()); err == nil { + t.Fatalf("Invalid patterns not triggering error") + } + End() +} diff --git a/gcp/observability/opencensus.go b/gcp/observability/opencensus.go index ccaa6a98a42c..08b853d2adc9 100644 --- a/gcp/observability/opencensus.go +++ b/gcp/observability/opencensus.go @@ -37,17 +37,17 @@ var ( defaultMetricsReportingInterval = time.Second * 30 ) -func tagsToMonitoringLabels(tags map[string]string) *stackdriver.Labels { - labels := &stackdriver.Labels{} - for k, v := range tags { - labels.Set(k, v, "") +func labelsToMonitoringLabels(labels map[string]string) *stackdriver.Labels { + sdLabels := &stackdriver.Labels{} + for k, v := range labels { + sdLabels.Set(k, v, "") } - return labels + return sdLabels } -func tagsToTraceAttributes(tags map[string]string) map[string]interface{} { - ta := make(map[string]interface{}, len(tags)) - for k, v := range tags { +func labelsToTraceAttributes(labels map[string]string) map[string]interface{} { + ta := make(map[string]interface{}, len(labels)) + for k, v := range labels { ta[k] = v } return ta @@ -62,7 +62,6 @@ type tracingMetricsExporter interface { var exporter tracingMetricsExporter -// global to stub out in tests var newExporter = newStackdriverExporter func newStackdriverExporter(config *config) (tracingMetricsExporter, error) { @@ -71,10 +70,10 @@ func newStackdriverExporter(config *config) (tracingMetricsExporter, error) { logger.Infof("Detected MonitoredResource:: %+v", mr) var err error exporter, err := stackdriver.NewExporter(stackdriver.Options{ - ProjectID: config.DestinationProjectID, + ProjectID: config.ProjectID, MonitoredResource: mr, - DefaultMonitoringLabels: tagsToMonitoringLabels(config.CustomTags), - DefaultTraceAttributes: tagsToTraceAttributes(config.CustomTags), + DefaultMonitoringLabels: labelsToMonitoringLabels(config.Labels), + DefaultTraceAttributes: labelsToTraceAttributes(config.Labels), }) if err != nil { return nil, fmt.Errorf("failed to create Stackdriver exporter: %v", err) @@ -87,7 +86,7 @@ func newStackdriverExporter(config *config) (tracingMetricsExporter, error) { func startOpenCensus(config *config) error { // If both tracing and metrics are disabled, there's no point inject default // StatsHandler. - if config == nil || (!config.EnableCloudTrace && !config.EnableCloudMonitoring) { + if config == nil || (config.CloudTrace == nil && config.CloudMonitoring == nil) { return nil } @@ -98,17 +97,17 @@ func startOpenCensus(config *config) error { } var so trace.StartOptions - if config.EnableCloudTrace { - so.Sampler = trace.ProbabilitySampler(config.GlobalTraceSamplingRate) + if config.CloudTrace != nil { + so.Sampler = trace.ProbabilitySampler(config.CloudTrace.SamplingRate) trace.RegisterExporter(exporter.(trace.Exporter)) - logger.Infof("Start collecting and exporting trace spans with global_trace_sampling_rate=%.2f", config.GlobalTraceSamplingRate) + logger.Infof("Start collecting and exporting trace spans with global_trace_sampling_rate=%.2f", config.CloudTrace.SamplingRate) } - if config.EnableCloudMonitoring { - if err := view.Register(ocgrpc.DefaultClientViews...); err != nil { + if config.CloudMonitoring != nil { + if err := view.Register(ocgrpc.ClientCompletedRPCsView); err != nil { return fmt.Errorf("failed to register default client views: %v", err) } - if err := view.Register(ocgrpc.DefaultServerViews...); err != nil { + if err := view.Register(ocgrpc.ServerCompletedRPCsView); err != nil { return fmt.Errorf("failed to register default server views: %v", err) } view.SetReportingPeriod(defaultMetricsReportingInterval) @@ -117,8 +116,8 @@ func startOpenCensus(config *config) error { } // Only register default StatsHandlers if other things are setup correctly. - internal.AddExtraServerOptions.(func(opt ...grpc.ServerOption))(grpc.StatsHandler(&ocgrpc.ServerHandler{StartOptions: so})) - internal.AddExtraDialOptions.(func(opt ...grpc.DialOption))(grpc.WithStatsHandler(&ocgrpc.ClientHandler{StartOptions: so})) + internal.AddGlobalServerOptions.(func(opt ...grpc.ServerOption))(grpc.StatsHandler(&ocgrpc.ServerHandler{StartOptions: so})) + internal.AddGlobalDialOptions.(func(opt ...grpc.DialOption))(grpc.WithStatsHandler(&ocgrpc.ClientHandler{StartOptions: so})) logger.Infof("Enabled OpenCensus StatsHandlers for clients and servers") return nil @@ -128,9 +127,8 @@ func startOpenCensus(config *config) error { // packages if exporter was created. func stopOpenCensus() { if exporter != nil { - internal.ClearExtraDialOptions() - internal.ClearExtraServerOptions() - + internal.ClearGlobalDialOptions() + internal.ClearGlobalServerOptions() // Call these unconditionally, doesn't matter if not registered, will be // a noop if not registered. trace.UnregisterExporter(exporter) diff --git a/internal/binarylog/binarylog.go b/internal/binarylog/binarylog.go index e3dfe204f9ae..809d73ccafb0 100644 --- a/internal/binarylog/binarylog.go +++ b/internal/binarylog/binarylog.go @@ -37,7 +37,7 @@ type Logger interface { // binLogger is the global binary logger for the binary. One of this should be // built at init time from the configuration (environment variable or flags). // -// It is used to get a methodLogger for each individual method. +// It is used to get a MethodLogger for each individual method. var binLogger Logger var grpclogLogger = grpclog.Component("binarylog") @@ -56,11 +56,11 @@ func GetLogger() Logger { return binLogger } -// GetMethodLogger returns the methodLogger for the given methodName. +// GetMethodLogger returns the MethodLogger for the given methodName. // // methodName should be in the format of "/service/method". // -// Each methodLogger returned by this method is a new instance. This is to +// Each MethodLogger returned by this method is a new instance. This is to // generate sequence id within the call. func GetMethodLogger(methodName string) MethodLogger { if binLogger == nil { @@ -117,7 +117,7 @@ func (l *logger) setDefaultMethodLogger(ml *MethodLoggerConfig) error { // Set method logger for "service/*". // -// New methodLogger with same service overrides the old one. +// New MethodLogger with same service overrides the old one. func (l *logger) setServiceMethodLogger(service string, ml *MethodLoggerConfig) error { if _, ok := l.config.Services[service]; ok { return fmt.Errorf("conflicting service rules for service %v found", service) @@ -131,7 +131,7 @@ func (l *logger) setServiceMethodLogger(service string, ml *MethodLoggerConfig) // Set method logger for "service/method". // -// New methodLogger with same method overrides the old one. +// New MethodLogger with same method overrides the old one. func (l *logger) setMethodMethodLogger(method string, ml *MethodLoggerConfig) error { if _, ok := l.config.Blacklist[method]; ok { return fmt.Errorf("conflicting blacklist rules for method %v found", method) @@ -161,11 +161,11 @@ func (l *logger) setBlacklist(method string) error { return nil } -// getMethodLogger returns the methodLogger for the given methodName. +// getMethodLogger returns the MethodLogger for the given methodName. // // methodName should be in the format of "/service/method". // -// Each methodLogger returned by this method is a new instance. This is to +// Each MethodLogger returned by this method is a new instance. This is to // generate sequence id within the call. func (l *logger) GetMethodLogger(methodName string) MethodLogger { s, m, err := grpcutil.ParseMethod(methodName) @@ -174,16 +174,16 @@ func (l *logger) GetMethodLogger(methodName string) MethodLogger { return nil } if ml, ok := l.config.Methods[s+"/"+m]; ok { - return newMethodLogger(ml.Header, ml.Message) + return NewTruncatingMethodLogger(ml.Header, ml.Message) } if _, ok := l.config.Blacklist[s+"/"+m]; ok { return nil } if ml, ok := l.config.Services[s]; ok { - return newMethodLogger(ml.Header, ml.Message) + return NewTruncatingMethodLogger(ml.Header, ml.Message) } if l.config.All == nil { return nil } - return newMethodLogger(l.config.All.Header, l.config.All.Message) + return NewTruncatingMethodLogger(l.config.All.Header, l.config.All.Message) } diff --git a/internal/binarylog/binarylog_test.go b/internal/binarylog/binarylog_test.go index 617aeb2e83fb..05138f8f309f 100644 --- a/internal/binarylog/binarylog_test.go +++ b/internal/binarylog/binarylog_test.go @@ -93,7 +93,7 @@ func (s) TestGetMethodLogger(t *testing.T) { t.Errorf("in: %q, failed to create logger from config string", tc.in) continue } - ml := l.GetMethodLogger(tc.method).(*methodLogger) + ml := l.GetMethodLogger(tc.method).(*TruncatingMethodLogger) if ml == nil { t.Errorf("in: %q, method logger is nil, want non-nil", tc.in) continue diff --git a/internal/binarylog/env_config.go b/internal/binarylog/env_config.go index ab589a76bf96..c5579e65065f 100644 --- a/internal/binarylog/env_config.go +++ b/internal/binarylog/env_config.go @@ -57,7 +57,7 @@ func NewLoggerFromConfigString(s string) Logger { return l } -// fillMethodLoggerWithConfigString parses config, creates methodLogger and adds +// fillMethodLoggerWithConfigString parses config, creates TruncatingMethodLogger and adds // it to the right map in the logger. func (l *logger) fillMethodLoggerWithConfigString(config string) error { // "" is invalid. diff --git a/internal/binarylog/method_logger.go b/internal/binarylog/method_logger.go index 24df0a1a0c4e..179f4a26d135 100644 --- a/internal/binarylog/method_logger.go +++ b/internal/binarylog/method_logger.go @@ -52,7 +52,9 @@ type MethodLogger interface { Log(LogEntryConfig) } -type methodLogger struct { +// TruncatingMethodLogger is a method logger that truncates headers and messages +// based on configured fields. +type TruncatingMethodLogger struct { headerMaxLen, messageMaxLen uint64 callID uint64 @@ -61,8 +63,9 @@ type methodLogger struct { sink Sink // TODO(blog): make this plugable. } -func newMethodLogger(h, m uint64) *methodLogger { - return &methodLogger{ +// NewTruncatingMethodLogger returns a new truncating method logger. +func NewTruncatingMethodLogger(h, m uint64) *TruncatingMethodLogger { + return &TruncatingMethodLogger{ headerMaxLen: h, messageMaxLen: m, @@ -75,8 +78,8 @@ func newMethodLogger(h, m uint64) *methodLogger { // Build is an internal only method for building the proto message out of the // input event. It's made public to enable other library to reuse as much logic -// in methodLogger as possible. -func (ml *methodLogger) Build(c LogEntryConfig) *pb.GrpcLogEntry { +// in TruncatingMethodLogger as possible. +func (ml *TruncatingMethodLogger) Build(c LogEntryConfig) *pb.GrpcLogEntry { m := c.toProto() timestamp, _ := ptypes.TimestampProto(time.Now()) m.Timestamp = timestamp @@ -95,11 +98,11 @@ func (ml *methodLogger) Build(c LogEntryConfig) *pb.GrpcLogEntry { } // Log creates a proto binary log entry, and logs it to the sink. -func (ml *methodLogger) Log(c LogEntryConfig) { +func (ml *TruncatingMethodLogger) Log(c LogEntryConfig) { ml.sink.Write(ml.Build(c)) } -func (ml *methodLogger) truncateMetadata(mdPb *pb.Metadata) (truncated bool) { +func (ml *TruncatingMethodLogger) truncateMetadata(mdPb *pb.Metadata) (truncated bool) { if ml.headerMaxLen == maxUInt { return false } @@ -129,7 +132,7 @@ func (ml *methodLogger) truncateMetadata(mdPb *pb.Metadata) (truncated bool) { return truncated } -func (ml *methodLogger) truncateMessage(msgPb *pb.Message) (truncated bool) { +func (ml *TruncatingMethodLogger) truncateMessage(msgPb *pb.Message) (truncated bool) { if ml.messageMaxLen == maxUInt { return false } diff --git a/internal/binarylog/method_logger_test.go b/internal/binarylog/method_logger_test.go index 31cc076343ff..ff87b6a2ec4e 100644 --- a/internal/binarylog/method_logger_test.go +++ b/internal/binarylog/method_logger_test.go @@ -34,7 +34,7 @@ import ( func (s) TestLog(t *testing.T) { idGen.reset() - ml := newMethodLogger(10, 10) + ml := NewTruncatingMethodLogger(10, 10) // Set sink to testing buffer. buf := bytes.NewBuffer(nil) ml.sink = newWriterSink(buf) @@ -350,11 +350,11 @@ func (s) TestLog(t *testing.T) { func (s) TestTruncateMetadataNotTruncated(t *testing.T) { testCases := []struct { - ml *methodLogger + ml *TruncatingMethodLogger mpPb *pb.Metadata }{ { - ml: newMethodLogger(maxUInt, maxUInt), + ml: NewTruncatingMethodLogger(maxUInt, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -362,7 +362,7 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { }, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -370,7 +370,7 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { }, }, { - ml: newMethodLogger(1, maxUInt), + ml: NewTruncatingMethodLogger(1, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: nil}, @@ -378,7 +378,7 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { }, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1, 1}}, @@ -386,7 +386,7 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { }, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -397,7 +397,7 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { // "grpc-trace-bin" is kept in log but not counted towards the size // limit. { - ml: newMethodLogger(1, maxUInt), + ml: NewTruncatingMethodLogger(1, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -417,13 +417,13 @@ func (s) TestTruncateMetadataNotTruncated(t *testing.T) { func (s) TestTruncateMetadataTruncated(t *testing.T) { testCases := []struct { - ml *methodLogger + ml *TruncatingMethodLogger mpPb *pb.Metadata entryLen int }{ { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1, 1, 1}}, @@ -432,7 +432,7 @@ func (s) TestTruncateMetadataTruncated(t *testing.T) { entryLen: 0, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -443,7 +443,7 @@ func (s) TestTruncateMetadataTruncated(t *testing.T) { entryLen: 2, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1, 1}}, @@ -453,7 +453,7 @@ func (s) TestTruncateMetadataTruncated(t *testing.T) { entryLen: 1, }, { - ml: newMethodLogger(2, maxUInt), + ml: NewTruncatingMethodLogger(2, maxUInt), mpPb: &pb.Metadata{ Entry: []*pb.MetadataEntry{ {Key: "", Value: []byte{1}}, @@ -478,23 +478,23 @@ func (s) TestTruncateMetadataTruncated(t *testing.T) { func (s) TestTruncateMessageNotTruncated(t *testing.T) { testCases := []struct { - ml *methodLogger + ml *TruncatingMethodLogger msgPb *pb.Message }{ { - ml: newMethodLogger(maxUInt, maxUInt), + ml: NewTruncatingMethodLogger(maxUInt, maxUInt), msgPb: &pb.Message{ Data: []byte{1}, }, }, { - ml: newMethodLogger(maxUInt, 3), + ml: NewTruncatingMethodLogger(maxUInt, 3), msgPb: &pb.Message{ Data: []byte{1, 1}, }, }, { - ml: newMethodLogger(maxUInt, 2), + ml: NewTruncatingMethodLogger(maxUInt, 2), msgPb: &pb.Message{ Data: []byte{1, 1}, }, @@ -511,13 +511,13 @@ func (s) TestTruncateMessageNotTruncated(t *testing.T) { func (s) TestTruncateMessageTruncated(t *testing.T) { testCases := []struct { - ml *methodLogger + ml *TruncatingMethodLogger msgPb *pb.Message oldLength uint32 }{ { - ml: newMethodLogger(maxUInt, 2), + ml: NewTruncatingMethodLogger(maxUInt, 2), msgPb: &pb.Message{ Length: 3, Data: []byte{1, 1, 1}, diff --git a/internal/envconfig/observability.go b/internal/envconfig/observability.go new file mode 100644 index 000000000000..821dd0a7c198 --- /dev/null +++ b/internal/envconfig/observability.go @@ -0,0 +1,36 @@ +/* + * + * Copyright 2022 gRPC 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 envconfig + +import "os" + +const ( + envObservabilityConfig = "GRPC_GCP_OBSERVABILITY_CONFIG" + envObservabilityConfigFile = "GRPC_GCP_OBSERVABILITY_CONFIG_FILE" +) + +var ( + // ObservabilityConfig is the json configuration for the gcp/observability + // package specified directly in the envObservabilityConfig env var. + ObservabilityConfig = os.Getenv(envObservabilityConfig) + // ObservabilityConfigFile is the json configuration for the + // gcp/observability specified in a file with the location specified in + // envObservabilityConfigFile env var. + ObservabilityConfigFile = os.Getenv(envObservabilityConfigFile) +) diff --git a/internal/internal.go b/internal/internal.go index 87cacb5b808c..fd0ee3dcaf1e 100644 --- a/internal/internal.go +++ b/internal/internal.go @@ -63,24 +63,31 @@ var ( // xDS-enabled server invokes this method on a grpc.Server when a particular // listener moves to "not-serving" mode. DrainServerTransports interface{} // func(*grpc.Server, string) - // AddExtraServerOptions adds an array of ServerOption that will be + // AddGlobalServerOptions adds an array of ServerOption that will be // effective globally for newly created servers. The priority will be: 1. // user-provided; 2. this method; 3. default values. - AddExtraServerOptions interface{} // func(opt ...ServerOption) - // ClearExtraServerOptions clears the array of extra ServerOption. This + AddGlobalServerOptions interface{} // func(opt ...ServerOption) + // ClearGlobalServerOptions clears the array of extra ServerOption. This // method is useful in testing and benchmarking. - ClearExtraServerOptions func() - // AddExtraDialOptions adds an array of DialOption that will be effective + ClearGlobalServerOptions func() + // AddGlobalDialOptions adds an array of DialOption that will be effective // globally for newly created client channels. The priority will be: 1. // user-provided; 2. this method; 3. default values. - AddExtraDialOptions interface{} // func(opt ...DialOption) - // ClearExtraDialOptions clears the array of extra DialOption. This + AddGlobalDialOptions interface{} // func(opt ...DialOption) + // ClearGlobalDialOptions clears the array of extra DialOption. This // method is useful in testing and benchmarking. - ClearExtraDialOptions func() + ClearGlobalDialOptions func() // JoinServerOptions combines the server options passed as arguments into a // single server option. JoinServerOptions interface{} // func(...grpc.ServerOption) grpc.ServerOption + // WithBinaryLogger returns a DialOption that specifies the binary logger + // for a ClientConn. + WithBinaryLogger interface{} // func(binarylog.Logger) grpc.DialOption + // BinaryLogger returns a ServerOption that can set the binary logger for a + // server. + BinaryLogger interface{} // func(binarylog.Logger) grpc.ServerOption + // NewXDSResolverWithConfigForTesting creates a new xds resolver builder using // the provided xds bootstrap config instead of the global configuration from // the supported environment variables. The resolver.Builder is meant to be diff --git a/server.go b/server.go index 6ef3df67d9e5..f4dde72b41f8 100644 --- a/server.go +++ b/server.go @@ -73,12 +73,13 @@ func init() { internal.DrainServerTransports = func(srv *Server, addr string) { srv.drainServerTransports(addr) } - internal.AddExtraServerOptions = func(opt ...ServerOption) { - extraServerOptions = opt + internal.AddGlobalServerOptions = func(opt ...ServerOption) { + extraServerOptions = append(extraServerOptions, opt...) } - internal.ClearExtraServerOptions = func() { + internal.ClearGlobalServerOptions = func() { extraServerOptions = nil } + internal.BinaryLogger = binaryLogger internal.JoinServerOptions = newJoinServerOption } @@ -156,6 +157,7 @@ type serverOptions struct { streamInt StreamServerInterceptor chainUnaryInts []UnaryServerInterceptor chainStreamInts []StreamServerInterceptor + binaryLogger binarylog.Logger inTapHandle tap.ServerInHandle statsHandlers []stats.Handler maxConcurrentStreams uint32 @@ -469,6 +471,14 @@ func StatsHandler(h stats.Handler) ServerOption { }) } +// binaryLogger returns a ServerOption that can set the binary logger for the +// server. +func binaryLogger(bl binarylog.Logger) ServerOption { + return newFuncServerOption(func(o *serverOptions) { + o.binaryLogger = bl + }) +} + // UnknownServiceHandler returns a ServerOption that allows for adding a custom // unknown service handler. The provided method is a bidi-streaming RPC service // handler that will be invoked instead of returning the "unimplemented" gRPC @@ -1216,9 +1226,16 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. } }() } - - binlog := binarylog.GetMethodLogger(stream.Method()) - if binlog != nil { + var binlogs []binarylog.MethodLogger + if ml := binarylog.GetMethodLogger(stream.Method()); ml != nil { + binlogs = append(binlogs, ml) + } + if s.opts.binaryLogger != nil { + if ml := s.opts.binaryLogger.GetMethodLogger(stream.Method()); ml != nil { + binlogs = append(binlogs, ml) + } + } + if len(binlogs) != 0 { ctx := stream.Context() md, _ := metadata.FromIncomingContext(ctx) logEntry := &binarylog.ClientHeader{ @@ -1238,7 +1255,9 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. if peer, ok := peer.FromContext(ctx); ok { logEntry.PeerAddr = peer.Addr } - binlog.Log(logEntry) + for _, binlog := range binlogs { + binlog.Log(logEntry) + } } // comp and cp are used for compression. decomp and dc are used for @@ -1278,7 +1297,7 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. } var payInfo *payloadInfo - if len(shs) != 0 || binlog != nil { + if len(shs) != 0 || len(binlogs) != 0 { payInfo = &payloadInfo{} } d, err := recvAndDecompress(&parser{r: stream}, stream, dc, s.opts.maxReceiveMessageSize, payInfo, decomp) @@ -1304,10 +1323,13 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. Length: len(d), }) } - if binlog != nil { - binlog.Log(&binarylog.ClientMessage{ + if len(binlogs) != 0 { + cm := &binarylog.ClientMessage{ Message: d, - }) + } + for _, binlog := range binlogs { + binlog.Log(cm) + } } if trInfo != nil { trInfo.tr.LazyLog(&payload{sent: false, msg: v}, true) @@ -1331,18 +1353,24 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. if e := t.WriteStatus(stream, appStatus); e != nil { channelz.Warningf(logger, s.channelzID, "grpc: Server.processUnaryRPC failed to write status: %v", e) } - if binlog != nil { + if len(binlogs) != 0 { if h, _ := stream.Header(); h.Len() > 0 { // Only log serverHeader if there was header. Otherwise it can // be trailer only. - binlog.Log(&binarylog.ServerHeader{ + sh := &binarylog.ServerHeader{ Header: h, - }) + } + for _, binlog := range binlogs { + binlog.Log(sh) + } } - binlog.Log(&binarylog.ServerTrailer{ + st := &binarylog.ServerTrailer{ Trailer: stream.Trailer(), Err: appErr, - }) + } + for _, binlog := range binlogs { + binlog.Log(st) + } } return appErr } @@ -1368,26 +1396,34 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. panic(fmt.Sprintf("grpc: Unexpected error (%T) from sendResponse: %v", st, st)) } } - if binlog != nil { + if len(binlogs) != 0 { h, _ := stream.Header() - binlog.Log(&binarylog.ServerHeader{ + sh := &binarylog.ServerHeader{ Header: h, - }) - binlog.Log(&binarylog.ServerTrailer{ + } + st := &binarylog.ServerTrailer{ Trailer: stream.Trailer(), Err: appErr, - }) + } + for _, binlog := range binlogs { + binlog.Log(sh) + binlog.Log(st) + } } return err } - if binlog != nil { + if len(binlogs) != 0 { h, _ := stream.Header() - binlog.Log(&binarylog.ServerHeader{ + sh := &binarylog.ServerHeader{ Header: h, - }) - binlog.Log(&binarylog.ServerMessage{ + } + sm := &binarylog.ServerMessage{ Message: reply, - }) + } + for _, binlog := range binlogs { + binlog.Log(sh) + binlog.Log(sm) + } } if channelz.IsOn() { t.IncrMsgSent() @@ -1399,11 +1435,14 @@ func (s *Server) processUnaryRPC(t transport.ServerTransport, stream *transport. // Should the logging be in WriteStatus? Should we ignore the WriteStatus // error or allow the stats handler to see it? err = t.WriteStatus(stream, statusOK) - if binlog != nil { - binlog.Log(&binarylog.ServerTrailer{ + if len(binlogs) != 0 { + st := &binarylog.ServerTrailer{ Trailer: stream.Trailer(), Err: appErr, - }) + } + for _, binlog := range binlogs { + binlog.Log(st) + } } return err } @@ -1516,8 +1555,15 @@ func (s *Server) processStreamingRPC(t transport.ServerTransport, stream *transp }() } - ss.binlog = binarylog.GetMethodLogger(stream.Method()) - if ss.binlog != nil { + if ml := binarylog.GetMethodLogger(stream.Method()); ml != nil { + ss.binlogs = append(ss.binlogs, ml) + } + if s.opts.binaryLogger != nil { + if ml := s.opts.binaryLogger.GetMethodLogger(stream.Method()); ml != nil { + ss.binlogs = append(ss.binlogs, ml) + } + } + if len(ss.binlogs) != 0 { md, _ := metadata.FromIncomingContext(ctx) logEntry := &binarylog.ClientHeader{ Header: md, @@ -1536,7 +1582,9 @@ func (s *Server) processStreamingRPC(t transport.ServerTransport, stream *transp if peer, ok := peer.FromContext(ss.Context()); ok { logEntry.PeerAddr = peer.Addr } - ss.binlog.Log(logEntry) + for _, binlog := range ss.binlogs { + binlog.Log(logEntry) + } } // If dc is set and matches the stream's compression, use it. Otherwise, try @@ -1602,11 +1650,14 @@ func (s *Server) processStreamingRPC(t transport.ServerTransport, stream *transp ss.mu.Unlock() } t.WriteStatus(ss.s, appStatus) - if ss.binlog != nil { - ss.binlog.Log(&binarylog.ServerTrailer{ + if len(ss.binlogs) != 0 { + st := &binarylog.ServerTrailer{ Trailer: ss.s.Trailer(), Err: appErr, - }) + } + for _, binlog := range ss.binlogs { + binlog.Log(st) + } } // TODO: Should we log an error from WriteStatus here and below? return appErr @@ -1617,11 +1668,14 @@ func (s *Server) processStreamingRPC(t transport.ServerTransport, stream *transp ss.mu.Unlock() } err = t.WriteStatus(ss.s, statusOK) - if ss.binlog != nil { - ss.binlog.Log(&binarylog.ServerTrailer{ + if len(ss.binlogs) != 0 { + st := &binarylog.ServerTrailer{ Trailer: ss.s.Trailer(), Err: appErr, - }) + } + for _, binlog := range ss.binlogs { + binlog.Log(st) + } } return err } diff --git a/stream.go b/stream.go index 446a91e323ee..0c16cfb2ea80 100644 --- a/stream.go +++ b/stream.go @@ -301,7 +301,14 @@ func newClientStreamWithParams(ctx context.Context, desc *StreamDesc, cc *Client if !cc.dopts.disableRetry { cs.retryThrottler = cc.retryThrottler.Load().(*retryThrottler) } - cs.binlog = binarylog.GetMethodLogger(method) + if ml := binarylog.GetMethodLogger(method); ml != nil { + cs.binlogs = append(cs.binlogs, ml) + } + if cc.dopts.binaryLogger != nil { + if ml := cc.dopts.binaryLogger.GetMethodLogger(method); ml != nil { + cs.binlogs = append(cs.binlogs, ml) + } + } // Pick the transport to use and create a new stream on the transport. // Assign cs.attempt upon success. @@ -322,7 +329,7 @@ func newClientStreamWithParams(ctx context.Context, desc *StreamDesc, cc *Client return nil, err } - if cs.binlog != nil { + if len(cs.binlogs) != 0 { md, _ := metadata.FromOutgoingContext(ctx) logEntry := &binarylog.ClientHeader{ OnClientSide: true, @@ -336,7 +343,9 @@ func newClientStreamWithParams(ctx context.Context, desc *StreamDesc, cc *Client logEntry.Timeout = 0 } } - cs.binlog.Log(logEntry) + for _, binlog := range cs.binlogs { + binlog.Log(logEntry) + } } if desc != unaryStreamDesc { @@ -480,7 +489,7 @@ type clientStream struct { retryThrottler *retryThrottler // The throttler active when the RPC began. - binlog binarylog.MethodLogger // Binary logger, can be nil. + binlogs []binarylog.MethodLogger // serverHeaderBinlogged is a boolean for whether server header has been // logged. Server header will be logged when the first time one of those // happens: stream.Header(), stream.Recv(). @@ -744,7 +753,7 @@ func (cs *clientStream) Header() (metadata.MD, error) { cs.finish(err) return nil, err } - if cs.binlog != nil && !cs.serverHeaderBinlogged { + if len(cs.binlogs) != 0 && !cs.serverHeaderBinlogged { // Only log if binary log is on and header has not been logged. logEntry := &binarylog.ServerHeader{ OnClientSide: true, @@ -754,8 +763,10 @@ func (cs *clientStream) Header() (metadata.MD, error) { if peer, ok := peer.FromContext(cs.Context()); ok { logEntry.PeerAddr = peer.Addr } - cs.binlog.Log(logEntry) cs.serverHeaderBinlogged = true + for _, binlog := range cs.binlogs { + binlog.Log(logEntry) + } } return m, nil } @@ -829,38 +840,44 @@ func (cs *clientStream) SendMsg(m interface{}) (err error) { return a.sendMsg(m, hdr, payload, data) } err = cs.withRetry(op, func() { cs.bufferForRetryLocked(len(hdr)+len(payload), op) }) - if cs.binlog != nil && err == nil { - cs.binlog.Log(&binarylog.ClientMessage{ + if len(cs.binlogs) != 0 && err == nil { + cm := &binarylog.ClientMessage{ OnClientSide: true, Message: data, - }) + } + for _, binlog := range cs.binlogs { + binlog.Log(cm) + } } return err } func (cs *clientStream) RecvMsg(m interface{}) error { - if cs.binlog != nil && !cs.serverHeaderBinlogged { + if len(cs.binlogs) != 0 && !cs.serverHeaderBinlogged { // Call Header() to binary log header if it's not already logged. cs.Header() } var recvInfo *payloadInfo - if cs.binlog != nil { + if len(cs.binlogs) != 0 { recvInfo = &payloadInfo{} } err := cs.withRetry(func(a *csAttempt) error { return a.recvMsg(m, recvInfo) }, cs.commitAttemptLocked) - if cs.binlog != nil && err == nil { - cs.binlog.Log(&binarylog.ServerMessage{ + if len(cs.binlogs) != 0 && err == nil { + sm := &binarylog.ServerMessage{ OnClientSide: true, Message: recvInfo.uncompressedBytes, - }) + } + for _, binlog := range cs.binlogs { + binlog.Log(sm) + } } if err != nil || !cs.desc.ServerStreams { // err != nil or non-server-streaming indicates end of stream. cs.finish(err) - if cs.binlog != nil { + if len(cs.binlogs) != 0 { // finish will not log Trailer. Log Trailer here. logEntry := &binarylog.ServerTrailer{ OnClientSide: true, @@ -873,7 +890,9 @@ func (cs *clientStream) RecvMsg(m interface{}) error { if peer, ok := peer.FromContext(cs.Context()); ok { logEntry.PeerAddr = peer.Addr } - cs.binlog.Log(logEntry) + for _, binlog := range cs.binlogs { + binlog.Log(logEntry) + } } } return err @@ -894,10 +913,13 @@ func (cs *clientStream) CloseSend() error { return nil } cs.withRetry(op, func() { cs.bufferForRetryLocked(0, op) }) - if cs.binlog != nil { - cs.binlog.Log(&binarylog.ClientHalfClose{ + if len(cs.binlogs) != 0 { + chc := &binarylog.ClientHalfClose{ OnClientSide: true, - }) + } + for _, binlog := range cs.binlogs { + binlog.Log(chc) + } } // We never returned an error here for reasons. return nil @@ -930,10 +952,13 @@ func (cs *clientStream) finish(err error) { // // Only one of cancel or trailer needs to be logged. In the cases where // users don't call RecvMsg, users must have already canceled the RPC. - if cs.binlog != nil && status.Code(err) == codes.Canceled { - cs.binlog.Log(&binarylog.Cancel{ + if len(cs.binlogs) != 0 && status.Code(err) == codes.Canceled { + c := &binarylog.Cancel{ OnClientSide: true, - }) + } + for _, binlog := range cs.binlogs { + binlog.Log(c) + } } if err == nil { cs.retryThrottler.successfulRPC() @@ -1005,6 +1030,7 @@ func (a *csAttempt) recvMsg(m interface{}, payInfo *payloadInfo) (err error) { } return io.EOF // indicates successful end of stream. } + return toRPCErr(err) } if a.trInfo != nil { @@ -1453,7 +1479,7 @@ type serverStream struct { statsHandler []stats.Handler - binlog binarylog.MethodLogger + binlogs []binarylog.MethodLogger // serverHeaderBinlogged indicates whether server header has been logged. It // will happen when one of the following two happens: stream.SendHeader(), // stream.Send(). @@ -1487,12 +1513,15 @@ func (ss *serverStream) SendHeader(md metadata.MD) error { } err = ss.t.WriteHeader(ss.s, md) - if ss.binlog != nil && !ss.serverHeaderBinlogged { + if len(ss.binlogs) != 0 && !ss.serverHeaderBinlogged { h, _ := ss.s.Header() - ss.binlog.Log(&binarylog.ServerHeader{ + sh := &binarylog.ServerHeader{ Header: h, - }) + } ss.serverHeaderBinlogged = true + for _, binlog := range ss.binlogs { + binlog.Log(sh) + } } return err } @@ -1549,17 +1578,23 @@ func (ss *serverStream) SendMsg(m interface{}) (err error) { if err := ss.t.Write(ss.s, hdr, payload, &transport.Options{Last: false}); err != nil { return toRPCErr(err) } - if ss.binlog != nil { + if len(ss.binlogs) != 0 { if !ss.serverHeaderBinlogged { h, _ := ss.s.Header() - ss.binlog.Log(&binarylog.ServerHeader{ + sh := &binarylog.ServerHeader{ Header: h, - }) + } ss.serverHeaderBinlogged = true + for _, binlog := range ss.binlogs { + binlog.Log(sh) + } } - ss.binlog.Log(&binarylog.ServerMessage{ + sm := &binarylog.ServerMessage{ Message: data, - }) + } + for _, binlog := range ss.binlogs { + binlog.Log(sm) + } } if len(ss.statsHandler) != 0 { for _, sh := range ss.statsHandler { @@ -1598,13 +1633,16 @@ func (ss *serverStream) RecvMsg(m interface{}) (err error) { } }() var payInfo *payloadInfo - if len(ss.statsHandler) != 0 || ss.binlog != nil { + if len(ss.statsHandler) != 0 || len(ss.binlogs) != 0 { payInfo = &payloadInfo{} } if err := recv(ss.p, ss.codec, ss.s, ss.dc, m, ss.maxReceiveMessageSize, payInfo, ss.decomp); err != nil { if err == io.EOF { - if ss.binlog != nil { - ss.binlog.Log(&binarylog.ClientHalfClose{}) + if len(ss.binlogs) != 0 { + chc := &binarylog.ClientHalfClose{} + for _, binlog := range ss.binlogs { + binlog.Log(chc) + } } return err } @@ -1625,10 +1663,13 @@ func (ss *serverStream) RecvMsg(m interface{}) (err error) { }) } } - if ss.binlog != nil { - ss.binlog.Log(&binarylog.ClientMessage{ + if len(ss.binlogs) != 0 { + cm := &binarylog.ClientMessage{ Message: payInfo.uncompressedBytes, - }) + } + for _, binlog := range ss.binlogs { + binlog.Log(cm) + } } return nil } diff --git a/test/end2end_test.go b/test/end2end_test.go index 725bcdb641eb..ecf5b5e303ed 100644 --- a/test/end2end_test.go +++ b/test/end2end_test.go @@ -57,6 +57,7 @@ import ( healthgrpc "google.golang.org/grpc/health/grpc_health_v1" healthpb "google.golang.org/grpc/health/grpc_health_v1" "google.golang.org/grpc/internal" + "google.golang.org/grpc/internal/binarylog" "google.golang.org/grpc/internal/channelz" "google.golang.org/grpc/internal/grpcsync" "google.golang.org/grpc/internal/grpctest" @@ -8184,3 +8185,93 @@ func (s) TestGoAwayStreamIDSmallerThanCreatedStreams(t *testing.T) { ct.writeGoAway(1, http2.ErrCodeNo, []byte{}) goAwayWritten.Fire() } + +type mockBinaryLogger struct { + mml *mockMethodLogger +} + +func newMockBinaryLogger() *mockBinaryLogger { + return &mockBinaryLogger{ + mml: &mockMethodLogger{}, + } +} + +func (mbl *mockBinaryLogger) GetMethodLogger(string) binarylog.MethodLogger { + return mbl.mml +} + +type mockMethodLogger struct { + events uint64 +} + +func (mml *mockMethodLogger) Log(binarylog.LogEntryConfig) { + atomic.AddUint64(&mml.events, 1) +} + +// TestGlobalBinaryLoggingOptions tests the binary logging options for client +// and server side. The test configures a binary logger to be plumbed into every +// created ClientConn and server. It then makes a unary RPC call, and a +// streaming RPC call. A certain amount of logging calls should happen as a +// result of the stream operations on each of these calls. +func (s) TestGlobalBinaryLoggingOptions(t *testing.T) { + csbl := newMockBinaryLogger() + ssbl := newMockBinaryLogger() + + internal.AddGlobalDialOptions.(func(opt ...grpc.DialOption))(internal.WithBinaryLogger.(func(bl binarylog.Logger) grpc.DialOption)(csbl)) + internal.AddGlobalServerOptions.(func(opt ...grpc.ServerOption))(internal.BinaryLogger.(func(bl binarylog.Logger) grpc.ServerOption)(ssbl)) + defer func() { + internal.ClearGlobalDialOptions() + internal.ClearGlobalServerOptions() + }() + ss := &stubserver.StubServer{ + UnaryCallF: func(ctx context.Context, in *testpb.SimpleRequest) (*testpb.SimpleResponse, error) { + return &testpb.SimpleResponse{}, nil + }, + FullDuplexCallF: func(stream testpb.TestService_FullDuplexCallServer) error { + for { + _, err := stream.Recv() + if err == io.EOF { + return nil + } + } + }, + } + + // No client or server options specified, because should pick up configured + // global options. + if err := ss.Start(nil); err != nil { + t.Fatalf("Error starting endpoint server: %v", err) + } + defer ss.Stop() + + ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout) + defer cancel() + // Make a Unary RPC. This should cause Log calls on the MethodLogger. + if _, err := ss.Client.UnaryCall(ctx, &testpb.SimpleRequest{}); err != nil { + t.Fatalf("Unexpected error from UnaryCall: %v", err) + } + if csbl.mml.events != 5 { + t.Fatalf("want 5 client side binary logging events, got %v", csbl.mml.events) + } + if ssbl.mml.events != 5 { + t.Fatalf("want 5 server side binary logging events, got %v", ssbl.mml.events) + } + + // Make a streaming RPC. This should cause Log calls on the MethodLogger. + stream, err := ss.Client.FullDuplexCall(ctx) + if err != nil { + t.Fatalf("ss.Client.FullDuplexCall failed: %f", err) + } + + stream.CloseSend() + if _, err = stream.Recv(); err != io.EOF { + t.Fatalf("unexpected error: %v, expected an EOF error", err) + } + + if csbl.mml.events != 9 { + t.Fatalf("want 9 client side binary logging events, got %v", csbl.mml.events) + } + if ssbl.mml.events != 8 { + t.Fatalf("want 8 server side binary logging events, got %v", ssbl.mml.events) + } +} diff --git a/version.go b/version.go index c575c3b7b08e..d472ca64307b 100644 --- a/version.go +++ b/version.go @@ -19,4 +19,4 @@ package grpc // Version is the current grpc version. -const Version = "1.50.1-dev" +const Version = "1.50.1"