Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

gcp/observability: implement public preview config syntax, logging schema, and exposed metrics #5704

Merged
merged 9 commits into from
Oct 12, 2022

Conversation

zasweq
Copy link
Contributor

@zasweq zasweq commented Oct 8, 2022

This PR implements all the changes defined for public preview. The biggest change is the configuration change, which switched the logging from precedence based to iterative based and added a partition between client and server RPC events. The second one is the logging schema change defined by Eric, which I used an internal go struct to represent. The final trivial change is the change in the metrics collected/views registered to only Completed RPCs.

RELEASE NOTES:

  • gcp/observability: support new configuration defined in public preview user guide

@zasweq zasweq added this to the 1.51 Release milestone Oct 8, 2022
@zasweq zasweq added the Type: Feature New features or improvements in behavior label Oct 8, 2022
@zasweq zasweq force-pushed the observability-changes branch 2 times, most recently from 2356e03 to 8882810 Compare October 8, 2022 05:35
@zasweq zasweq requested a review from dfawley October 8, 2022 05:44
@zasweq zasweq force-pushed the observability-changes branch from 8882810 to 9b7e76d Compare October 8, 2022 06:32
@dfawley dfawley changed the title o11y: Observability changes for public preview gcp/observability: implement public preview config syntax, logging schema, and exposed metrics Oct 10, 2022
Copy link
Member

@dfawley dfawley left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Mostly nits so far, but I haven't dug into the tests.

We need to get this running in an integration type of test ASAP to make sure we figure out if it's using the proper JSON field names for the config and log entries being exported.

if method == "*" {
if exclude {
return errors.New("cannot have exclude and a '*' wildcard")
}
continue
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Was there also supposed to be an error if "*" isn't last in the list?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ping on this one.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh sorry forgot to respond to this earlier (I swear I typed something out at least - it must've gotten lost). No, there was not supposed to be an error here. Previously, yes this was speced out somewhere (was a docstring in the config type by Lidi). However, now we decided not to do any preprocessing (me and you had a discussion about this) and left it up to the user to know if he specifies a * somewhere in method[] for an event, no further event will hit, and entrusted the user with more responsibility in that regard, and trusted the user.

gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/go.mod Show resolved Hide resolved
gcp/observability/logging.go Outdated Show resolved Hide resolved
gcp/observability/opencensus.go Outdated Show resolved Hide resolved
internal/binarylog/binarylog.go Outdated Show resolved Hide resolved
internal/binarylog/method_logger.go Outdated Show resolved Hide resolved
@dfawley dfawley assigned zasweq and unassigned dfawley Oct 10, 2022
Copy link
Contributor Author

@zasweq zasweq left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the comments boss man :D!

gcp/observability/go.mod Show resolved Hide resolved
gcp/observability/logging.go Outdated Show resolved Hide resolved
gcp/observability/logging.go Outdated Show resolved Hide resolved
gcp/observability/opencensus.go Outdated Show resolved Hide resolved
internal/binarylog/binarylog.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Outdated Show resolved Hide resolved
gcp/observability/config.go Show resolved Hide resolved
@zasweq zasweq assigned dfawley and unassigned zasweq Oct 10, 2022
Copy link
Member

@dfawley dfawley left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Almost fully LGTM. Mostly just some small things.

Please also add a test that configures payload and metadata truncation and verifies the output events.

Comment on lines 35 to 36
envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY"
envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The only env vars we have now are GRPC_OBSERVABILITY_CONFIG and GRPC_OBSERVABILITY_CONFIG_FILE.

Can we add these into envconfig instead?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Whoops, didn't realize there was a change in the env var names. Thanks for finding this. Sorry, looking at internal/envconfig, it doesn't seem like the correct place for these. One of the files is for grpc settings, one of the files is for xDS. But since you suggested it, I'll reluctantly add it there. I added a new file called observability, with a similar structure to the file xds.go in that package.

Comment on lines 39 to 40
func cmpLoggingEntryList(entryList1 []*grpcLogEntry, entryList2 []*grpcLogEntry) error {
if diff := cmp.Diff(entryList1, entryList2,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please name these got and want so it's clear how to call it when adding a new test case.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
_, err := stream.Recv()
if err == io.EOF {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Send a message here to make sure ServerMessage works for streaming RPCs?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added a send.

FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
_, err := stream.Recv()
if err == io.EOF {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As above; send a message?

Also it seems worthwhile to send a message from the client in both cases.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done. Added send from client in both cases.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, something I just realized is this takes away having to change this test in the future due to that bin logging bug of logging Server Headers on Trailers only response. Luckily we have it clearly documented in other PRs test and this PRs history.

Comment on lines 611 to 612
grpcLogEntriesWant := make([]*grpcLogEntry, 5)
grpcLogEntriesWant[0] = &grpcLogEntry{
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FWIW you can initialize these like:

grpcLogEntriesWant := []*grpcLogEntry{
	{
		Type: eventTypeClientHeader,
		Logger: ....
		...
	}, {
		Type: eventTypeClientMessage,
		...
	}
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, this way is much cleaner. Thanks. Switched.

@dfawley dfawley assigned zasweq and unassigned dfawley Oct 11, 2022
Copy link
Contributor Author

@zasweq zasweq left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the pass bossman :D! Got to all your comments and added a headers/message truncated test.

Comment on lines 39 to 40
func cmpLoggingEntryList(entryList1 []*grpcLogEntry, entryList2 []*grpcLogEntry) error {
if diff := cmp.Diff(entryList1, entryList2,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done.

Comment on lines 35 to 36
envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY"
envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON"
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Whoops, didn't realize there was a change in the env var names. Thanks for finding this. Sorry, looking at internal/envconfig, it doesn't seem like the correct place for these. One of the files is for grpc settings, one of the files is for xDS. But since you suggested it, I'll reluctantly add it there. I added a new file called observability, with a similar structure to the file xds.go in that package.

Comment on lines 611 to 612
grpcLogEntriesWant := make([]*grpcLogEntry, 5)
grpcLogEntriesWant[0] = &grpcLogEntry{
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, this way is much cleaner. Thanks. Switched.

FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
_, err := stream.Recv()
if err == io.EOF {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added a send.

FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
_, err := stream.Recv()
if err == io.EOF {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done. Added send from client in both cases.

FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
_, err := stream.Recv()
if err == io.EOF {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, something I just realized is this takes away having to change this test in the future due to that bin logging bug of logging Server Headers on Trailers only response. Luckily we have it clearly documented in other PRs test and this PRs history.

@zasweq zasweq force-pushed the observability-changes branch from 036951c to 1c60786 Compare October 12, 2022 04:03
@zasweq zasweq assigned dfawley and unassigned zasweq Oct 12, 2022
if fileSystemPath := os.Getenv(envObservabilityConfigJSON); fileSystemPath != "" {
content, err := ioutil.ReadFile(fileSystemPath) // TODO: Switch to os.ReadFile once dropped support for go 1.15
if envconfig.ObservabilityConfigFile != "" {
content, err := ioutil.ReadFile(envconfig.ObservabilityConfigFile) // TODO: Switch to os.ReadFile once dropped support for go 1.15
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Consider:

if envconfig.ObservabilityConfig != "" {
	grpclog.Warning("Ignoring GRPC_OBSERVABILITY_CONFIG and using GRPC_OBSERVABILITY_CONFIG_FILE contents.")
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done, except with GCP added.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also I'm assuming you wanted this call on the logger, not the package grpclog? Used the logger.

@@ -113,14 +112,14 @@ func unmarshalAndVerifyConfig(rawJSON json.RawMessage) (*config, error) {
}

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 envconfig.ObservabilityConfigFile != "" {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To avoid repeating this long exported variable you can do:

if f := envconfig.ObservabilityConfigFile; f != "" {
	// use f
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure thing. Switched. I was thinking of this too but didn't know if the assignment to a local var (copying to a string on the stack) was worth the code simplification it provides.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The else if below the "long exported variable" is used once so I think it's fair there.

@@ -131,8 +133,13 @@ func (s) TestClientRPCEventsLogAll(t *testing.T) {
},
FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think this actually wants to be in a loop. The client just sends once, right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, lol fair point :). Lol unnecessary while true.

@@ -306,8 +341,13 @@ func (s) TestServerRPCEventsLogAll(t *testing.T) {
},
FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Similar re: not using a loop here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Got rid of every while true loop in all my FullDuplexCallF definitions.

@@ -671,7 +671,7 @@ func (s) TestClientRPCEventsTruncateHeaderAndMetadata(t *testing.T) {
Authority: ss.Address,
SequenceID: 1,
Payload: payload{
Metadata: map[string]string{"key1": "value1"},
Metadata: map[string]string{},
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is definitely unfortunate that we don't get anything here. It would be better if we could accept either header. There should be a way to do that in the cmp package.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I looked through cmp/cmpopts, and I couldn't find an explicit option that had the behavior you desire. The solution I came up with is to ignore the metadata in the cmp.Diff, and then compare with an or explicitly afterward.

Copy link
Contributor Author

@zasweq zasweq left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the comments bossman :D!

@@ -113,14 +112,14 @@ func unmarshalAndVerifyConfig(rawJSON json.RawMessage) (*config, error) {
}

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 envconfig.ObservabilityConfigFile != "" {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure thing. Switched. I was thinking of this too but didn't know if the assignment to a local var (copying to a string on the stack) was worth the code simplification it provides.

@@ -113,14 +112,14 @@ func unmarshalAndVerifyConfig(rawJSON json.RawMessage) (*config, error) {
}

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 envconfig.ObservabilityConfigFile != "" {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The else if below the "long exported variable" is used once so I think it's fair there.

if fileSystemPath := os.Getenv(envObservabilityConfigJSON); fileSystemPath != "" {
content, err := ioutil.ReadFile(fileSystemPath) // TODO: Switch to os.ReadFile once dropped support for go 1.15
if envconfig.ObservabilityConfigFile != "" {
content, err := ioutil.ReadFile(envconfig.ObservabilityConfigFile) // TODO: Switch to os.ReadFile once dropped support for go 1.15
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done, except with GCP added.

@@ -131,8 +133,13 @@ func (s) TestClientRPCEventsLogAll(t *testing.T) {
},
FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, lol fair point :). Lol unnecessary while true.

@@ -306,8 +341,13 @@ func (s) TestServerRPCEventsLogAll(t *testing.T) {
},
FullDuplexCallF: func(stream grpc_testing.TestService_FullDuplexCallServer) error {
for {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Got rid of every while true loop in all my FullDuplexCallF definitions.

@@ -671,7 +671,7 @@ func (s) TestClientRPCEventsTruncateHeaderAndMetadata(t *testing.T) {
Authority: ss.Address,
SequenceID: 1,
Payload: payload{
Metadata: map[string]string{"key1": "value1"},
Metadata: map[string]string{},
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I looked through cmp/cmpopts, and I couldn't find an explicit option that had the behavior you desire. The solution I came up with is to ignore the metadata in the cmp.Diff, and then compare with an or explicitly afterward.

if fileSystemPath := os.Getenv(envObservabilityConfigJSON); fileSystemPath != "" {
content, err := ioutil.ReadFile(fileSystemPath) // TODO: Switch to os.ReadFile once dropped support for go 1.15
if envconfig.ObservabilityConfigFile != "" {
content, err := ioutil.ReadFile(envconfig.ObservabilityConfigFile) // TODO: Switch to os.ReadFile once dropped support for go 1.15
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also I'm assuming you wanted this call on the logger, not the package grpclog? Used the logger.

Copy link
Member

@dfawley dfawley left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please check len() of metadata in the test that is expecting truncation. And fix the other final issue. Otherwise LGTM!

if envconfig.ObservabilityConfigFile != "" {
content, err := ioutil.ReadFile(envconfig.ObservabilityConfigFile) // TODO: Switch to os.ReadFile once dropped support for go 1.15
if f := envconfig.ObservabilityConfigFile; f != "" {
logger.Warning("Ignoring GRPC_GCP_OBSERVABILITY_CONFIG and using GRPC_GCP_OBSERVABILITY_CONFIG_FILE contents.")
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can't log this warning unconditionally; only if the other var is set.

@zasweq zasweq merged commit 8b3b10b into grpc:master Oct 12, 2022
zasweq added a commit to zasweq/grpc-go that referenced this pull request Oct 14, 2022
zasweq added a commit that referenced this pull request Oct 14, 2022
…ersion to 1.50.1 (#5722)

* Add binary logger option for client and server (#5675)

* Add binary logger option for client and server

* gcp/observability: implement public preview config syntax, logging schema, and exposed metrics (#5704)

* Fix o11y typo (#5719)

* o11y: Fixed o11y bug (#5720)

* update version to 1.50.1
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Apr 11, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Type: Feature New features or improvements in behavior
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants