Consider removing Channelz log during Init

[banks]

What version of gRPC are you using?

8997b5f

(master as off a few days ago but problem still in master and most recent tag)

What version of Go are you using (go version)?

go version go1.11 darwin/amd64

What operating system (Linux, Windows, …) and version?

macOS 10.13.6

What did you do?

Import grpc in order to serve a gRPC service:

import "google.golang.org/grpc"

I created an implementation of grpclog.LoggerV2 that forward logs to the existing logger we have and tested it.

What did you expect to see?

A working server with controlled logging.

What did you see instead?

Some tests that verify command output in error cases now fail because:

INFO: 2018/09/27 12:17:39 Channelz: socket options are not supported on non-linux os and appengine.

Is printed to stderr by

grpc-go/internal/channelz/types_nonlinux.go

Line 26 in 804c2a9

grpclog.Infof("Channelz: socket options are not supported on non-linux os and appengine.")

during init.

It might be possible to control this logging if I imported grpclog so I can call grpclog.SetLoggerV2 before the actual grpc root import but this is not really practical in my large application just to work around this issue since the logger is setup as part of a subcommand of a CLI and the core code is already included at this point.

It seems unfriendly for a widely used library to unconditionally write to STDIO at all from an init function.

Would you consider removing this warning or at least deferring it until later at runtime where it can be controlled and directed to the appropriate location?

[banks]

There is a good chance this issue is bogus. Since writing it up I've observed some behaviour I can't really explain.

First I noticed that I never saw the same Warning on stderr when running the same command that is run in a test in my terminal. After much debugging, i finally restarted VSCode which was the tool running go test when it failed and now I can't reproduce at all with or without a call to SetLoggerV2. That's somewhat good but I can't explain how this file is no longer being imported by the build when I've not changed anything in the code, imports or build environment.

It seems like internal/channelz is imported directly from server.go in the main package so it seems hard to understand why this init function doesn't always run...

grpc-go/server.go

Line 46 in a338994

"google.golang.org/grpc/internal/channelz"

or how it could be non-deterministic whether that is printed given that init functions all run in a fixed order in a single thread before real execution begins.

🤔

[banks]

Ah... mystery solved.

I opened that VSCode from command line a few days ago, at the time I had GRPC_GO_LOG_SEVERITY_LEVEL=INFO in the terminal that opened it's ENV, clearly it inherited that.

So I can reproduce this if I run tests with that in ENV. That's not ideal but workable at least.

I still think there is a good argument for removing any logging from init functions - I've seen a few other places do that in platform-specific code in this lib. Logging only if those features are actually used seems like better behaviour in general.

But I can see it's not a big issue for most people who tend not to hard-code GRPC_GO_LOG_SEVERITY_LEVEL into their environments.