How to debug grpc call?

Question

I'm trying to figure out why my grpc call isn't working, but I can't figure out how to turn on debugging, so I can see the data that's being sent and received over the grpc connection.

How do you turn on debugging for grpc calls?

Answer 1

You can set the GRPC_TRACE environment variable to all to have grpc dump a whole bunch of data about what the connection is doing:

export GRPC_TRACE=all

edit from comment: apparently you also need to set:

export GRPC_VERBOSITY=DEBUG

Answer 2

In Golang, you need to set the GODEBUG environment variable to see HTTP2 traces, i.e. headers set by gRPC:

GODEBUG=http2debug=1   # enable verbose HTTP/2 debug logs
GODEBUG=http2debug=2   # ... even more verbose, with frame dumps

The output will then be sent to stdout. here's an example:

{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: wrote SETTINGS len=0","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: wrote WINDOW_UPDATE len=4 (conn) incr=983025","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: read SETTINGS len=18, settings: ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: read WINDOW_UPDATE len=4 (conn) incr=983041","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: wrote SETTINGS flags=ACK len=0","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: read SETTINGS flags=ACK len=0","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: Framer 0xc42009c0e0: read HEADERS flags=END_HEADERS|PRIORITY stream=3 len=249","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \":authority\" = \"\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \":path\" = \"/internal.push.v1.UnifiedDevicePush/SendMessage\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \":method\" = \"POST\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \":scheme\" = \"http\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \"content-type\" = \"application/grpc\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \"te\" = \"trailers\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \"user-agent\" = \"grpc-java-netty/1.0.3\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \"root-common.xirequestid-bin\" = \"ChIJzE6lBfCTCsYRoIIJujc92JY=\"","time":"2017-06-11T08:52:20Z"}
{"level":"info","msg":"2017/06/11 08:52:20 http2: decoded hpack field header field \"te\" = \"trailers\"","time":"2017-06-11T08:52:20Z"}

Answer 3

export GRPC_GO_LOG_VERBOSITY_LEVEL=99
export GRPC_GO_LOG_SEVERITY_LEVEL=info

Try this with latest grpc go version.

Answer 4

From the docs

GRPC_VERBOSITY is used to set the minimum level of log messages printed by gRPC (supported values are DEBUG, INFO, and ERROR). If this environment variable is unset, only ERROR logs will be printed.

Also, check GRPC_TRACE

There are 15+ grpc environment variables

A note for Windows users, quoting from docs:

Known limitations: GPRC_TRACE=tcp is currently not implemented for Windows (you won't see any TCP traces).

Answer 5

You can use the Mediator Tool to debug and tracing gRPC calls.

It is a GUI tool just like the charles, but if you need to resolve the protobuf message body, the gRPC server needs to support the Server Reflection.

Answer 6

There is another tool grpcdebug

grpcdebug is a command line interface focusing on simplifying the debugging process of gRPC applications. grpcdebug fetches the internal states of the gRPC library from the application via gRPC protocol and provide a human-friendly UX to browse them. Currently, it supports Channelz/Health Checking/CSDS (aka. admin services). In other words, it can fetch statistics about how many RPCs has being sent or failed on a given gRPC channel, it can inspect address resolution results, it can dump the in-effective xDS configuration that directs the routing of RPCs.

Here are some samples

• Usage 1: Raw Channelz Output

For all Channelz commands, you can add --json to get the raw Channelz output.

grpcdebug localhost:50051 channelz channels --json
grpcdebug localhost:50051 channelz servers --json

• Usage 2: List Client Channels

grpcdebug localhost:50051 channelz channels

# Channel ID   Target            State     Calls(Started/Succeeded/Failed)   Created Time
# 7            localhost:10001   READY     5136/4631/505                     8 minutes ago

• Usage 3: List Servers

grpcdebug localhost:50051 channelz servers

# Server ID   Listen Addresses   Calls(Started/Succeeded/Failed)   Last Call Started
# 1           [:::10001]         2852/2530/322                     now
# 2           [:::50051]         29/28/0                           now
# 3           [:::50052]         4/4/0                             26 seconds ago