GRPC TTFB Determination clarity

[mjones713]

When executing grpcurl command and using "-vv" command I notice this output:

Response trailers received:
(empty)
Sent 1 request and received 1 response
Timing Data: 1.336617959s
Dial: 663.003042ms
TLS Setup: 4.083µs
BlockingDial: 662.955083ms
InvokeRPC: 520.699667ms

ChatGPT mentioned the following:

InvokeRPC:

• Represents the time taken to send the request and receive the first byte of the response (TTFB).

• This is equivalent to Time to First Byte.

InvokeRPC measures the duration between when the RPC request is sent and the first meaningful data is received from the server.
This includes the server processing time and any network latency after the connection is established.

So the question we're needing clarity is; In the example above InvokeRPC: 520.699667ms. Does the 520ms represent the 1st byte received or when the full response returned?

[jhump]

@mjones713, "InvokeRPC" is the entire RPC duration. So it includes the time to both upload all of the request bytes and download all of the response bytes.

If we were to expand the timing data to be more granular, the likely best that could be done is "time to first message" (and include time to download the entire initial message). But that wouldn't really be an improvement for unary and client-stream RPCs, which only ever have one response message. And it's of questionable value for bidirectional streams (or at least unclear exactly how to measure/interpret it), since the first response message could actually arrive before any request message is sent.

Unfortunately, the grpc-go library that this tool uses does not provide visibility into "time to first byte". The tool doesn't currently install a stats.Handler to collect more fine-grained data. But even if it did, the message receipt timestamps are for when an entire message is received in its entirety; no information is provided about when the first byte/packet was received.

[mjones713]

Thanks @jhump for your detailed response.