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

zasweq · 2022-10-08T03:56:31Z

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

dfawley

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.

dfawley · 2022-10-10T20:07:38Z

gcp/observability/config.go

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


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

Ping on this one.

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

gcp/observability/go.mod

gcp/observability/logging.go

gcp/observability/opencensus.go

internal/binarylog/binarylog.go

internal/binarylog/method_logger.go

zasweq

Thanks for the comments boss man :D!

gcp/observability/go.mod

gcp/observability/logging.go

gcp/observability/opencensus.go

internal/binarylog/binarylog.go

gcp/observability/config.go

dfawley

Almost fully LGTM. Mostly just some small things.

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

dfawley · 2022-10-11T23:19:44Z

gcp/observability/config.go

 envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY"
 envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON"


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

Can we add these into envconfig instead?

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.

dfawley · 2022-10-11T23:23:10Z

gcp/observability/logging_test.go

+func cmpLoggingEntryList(entryList1 []*grpcLogEntry, entryList2 []*grpcLogEntry) error {
+ if diff := cmp.Diff(entryList1, entryList2,


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

dfawley · 2022-10-11T23:27:06Z

gcp/observability/logging_test.go

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


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

Added a send.

dfawley · 2022-10-11T23:27:24Z

gcp/observability/logging_test.go

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


As above; send a message?

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

Done. Added send from client in both cases.

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.

dfawley · 2022-10-11T23:29:41Z

gcp/observability/logging_test.go

+ grpcLogEntriesWant := make([]*grpcLogEntry, 5)
+ grpcLogEntriesWant[0] = &grpcLogEntry{


FWIW you can initialize these like:

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

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

zasweq

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

zasweq · 2022-10-12T00:40:26Z

gcp/observability/logging_test.go

+func cmpLoggingEntryList(entryList1 []*grpcLogEntry, entryList2 []*grpcLogEntry) error {
+ if diff := cmp.Diff(entryList1, entryList2,


zasweq · 2022-10-12T00:41:51Z

gcp/observability/config.go

 envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY"
 envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON"


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.

zasweq · 2022-10-12T02:33:19Z

gcp/observability/logging_test.go

+ grpcLogEntriesWant := make([]*grpcLogEntry, 5)
+ grpcLogEntriesWant[0] = &grpcLogEntry{


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

zasweq · 2022-10-12T02:48:10Z

gcp/observability/logging_test.go

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


Added a send.

zasweq · 2022-10-12T02:48:37Z

gcp/observability/logging_test.go

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


Done. Added send from client in both cases.

zasweq · 2022-10-12T03:10:11Z

gcp/observability/logging_test.go

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


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.

…ed metadata

dfawley · 2022-10-12T15:56:36Z

gcp/observability/config.go

- 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


Consider:

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

Done, except with GCP added.

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

dfawley · 2022-10-12T15:57:27Z

gcp/observability/config.go

@@ -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 != "" {


To avoid repeating this long exported variable you can do:

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

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.

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

dfawley · 2022-10-12T16:00:19Z

gcp/observability/logging_test.go

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


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

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

dfawley · 2022-10-12T16:02:54Z

gcp/observability/logging_test.go

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


Similar re: not using a loop here.

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

dfawley · 2022-10-12T16:10:55Z

gcp/observability/logging_test.go

@@ -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{},


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.

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.

zasweq

Thanks for the comments bossman :D!

zasweq · 2022-10-12T16:59:11Z

gcp/observability/config.go

@@ -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 != "" {


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.

zasweq · 2022-10-12T17:01:06Z

gcp/observability/config.go

@@ -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 != "" {


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

zasweq · 2022-10-12T17:09:53Z

gcp/observability/config.go

- 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


Done, except with GCP added.

zasweq · 2022-10-12T17:15:23Z

gcp/observability/logging_test.go

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


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

zasweq · 2022-10-12T17:25:16Z

gcp/observability/logging_test.go

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


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

zasweq · 2022-10-12T17:31:23Z

gcp/observability/logging_test.go

@@ -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{},


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.

zasweq · 2022-10-12T17:47:52Z

gcp/observability/config.go

- 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


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

dfawley

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

dfawley · 2022-10-12T18:34:32Z

gcp/observability/config.go

- 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.")


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

…hema, and exposed metrics (grpc#5704)

…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

zasweq added this to the 1.51 Release milestone Oct 8, 2022

zasweq added the Type: Feature New features or improvements in behavior label Oct 8, 2022

zasweq force-pushed the observability-changes branch 2 times, most recently from 2356e03 to 8882810 Compare October 8, 2022 05:35

zasweq requested a review from dfawley October 8, 2022 05:44

zasweq assigned dfawley Oct 8, 2022

Observability changes for public preview

9b7e76d

zasweq force-pushed the observability-changes branch from 8882810 to 9b7e76d Compare October 8, 2022 06:32

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

dfawley reviewed Oct 10, 2022

View reviewed changes

dfawley assigned zasweq and unassigned dfawley Oct 10, 2022

zasweq commented Oct 10, 2022

View reviewed changes

Responded to Doug's comments

6a49085

zasweq assigned dfawley and unassigned zasweq Oct 10, 2022

Responded to Doug's comments

77d6555

dfawley reviewed Oct 11, 2022

View reviewed changes

dfawley assigned zasweq and unassigned dfawley Oct 11, 2022

zasweq commented Oct 12, 2022

View reviewed changes

Responded to Doug's comments

1c60786

zasweq force-pushed the observability-changes branch from 036951c to 1c60786 Compare October 12, 2022 04:03

get rid of non determinism in expectation in logging test for truncat…

b18bf95

…ed metadata

zasweq assigned dfawley and unassigned zasweq Oct 12, 2022

dfawley reviewed Oct 12, 2022

View reviewed changes

zasweq commented Oct 12, 2022

View reviewed changes

zasweq added 2 commits October 12, 2022 13:51

Responded to Doug's comments

7e8c2f9

Offline discussion with Doug

fb87d70

dfawley approved these changes Oct 12, 2022

View reviewed changes

zasweq added 2 commits October 12, 2022 14:36

Add check from offline discussion to make check more robust

e820693

Added conditional to warning log

7479221

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

gcp/observability: implement public preview config syntax, logging sc…

3a5afbd

…hema, and exposed metrics (grpc#5704)

github-actions bot locked as resolved and limited conversation to collaborators Apr 11, 2023

		envObservabilityConfig = "GRPC_CONFIG_OBSERVABILITY"
		envObservabilityConfigJSON = "GRPC_CONFIG_OBSERVABILITY_JSON"

		func cmpLoggingEntryList(entryList1 []grpcLogEntry, entryList2 []grpcLogEntry) error {
		if diff := cmp.Diff(entryList1, entryList2,

		grpcLogEntriesWant := make([]*grpcLogEntry, 5)
		grpcLogEntriesWant[0] = &grpcLogEntry{

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

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

Conversation

zasweq commented Oct 8, 2022 • edited by dfawley Loading

dfawley left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zasweq left a comment

Choose a reason for hiding this comment

dfawley left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zasweq left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zasweq left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dfawley left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zasweq commented Oct 8, 2022 •

edited by dfawley

Loading