OpenCensus: Fix round_trip time (#32694)

Fix the end timestamp of `grpc.io/client/roundtrip_latency` to when we
receive the trailers from the previous end timestamp of when we clean-up
the call attempt.

The reason to do this is to make sure that `grpc.io/client/api_latency`
(the end-to-end latency for the call) is always greater than
`grpc.io/client/roundtrip_latency` and fix the bug found by
@stanley-cheung

--

<br class="Apple-interchange-newline">

<!--

If you know who should review your pull request, please assign it to
that
person, otherwise the pull request would get assigned randomly.

If your pull request is for a specific language, please add the
appropriate
lang label.

-->
pull/32706/head
Yash Tibrewal 2 years ago committed by GitHub
parent 3fe678e306
commit 62f3c448fe
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 32
      src/cpp/ext/filters/census/client_filter.cc

@ -209,27 +209,35 @@ void OpenCensusCallTracer::OpenCensusCallAttemptTracer::
absl::Status status, grpc_metadata_batch* recv_trailing_metadata,
const grpc_transport_stream_stats* transport_stream_stats) {
status_code_ = status.code();
if (recv_trailing_metadata == nullptr || transport_stream_stats == nullptr) {
return;
}
if (OpenCensusStatsEnabled()) {
uint64_t elapsed_time = 0;
FilterTrailingMetadata(recv_trailing_metadata, &elapsed_time);
if (recv_trailing_metadata != nullptr) {
FilterTrailingMetadata(recv_trailing_metadata, &elapsed_time);
}
std::vector<std::pair<opencensus::tags::TagKey, std::string>> tags =
context_.tags().tags();
tags.emplace_back(ClientMethodTagKey(), std::string(parent_->method_));
tags.emplace_back(ClientStatusTagKey(),
absl::StatusCodeToString(status_code_));
::opencensus::stats::Record(
// TODO(yashykt): Recording zeros here when transport_stream_stats is
// nullptr is unfortunate and should be fixed.
{{RpcClientSentBytesPerRpc(),
static_cast<double>(transport_stream_stats->outgoing.data_bytes)},
static_cast<double>(transport_stream_stats != nullptr
? transport_stream_stats->outgoing.data_bytes
: 0)},
{RpcClientReceivedBytesPerRpc(),
static_cast<double>(transport_stream_stats->incoming.data_bytes)},
static_cast<double>(transport_stream_stats != nullptr
? transport_stream_stats->incoming.data_bytes
: 0)},
{RpcClientServerLatency(),
ToDoubleMilliseconds(absl::Nanoseconds(elapsed_time))}},
ToDoubleMilliseconds(absl::Nanoseconds(elapsed_time))},
{RpcClientRoundtripLatency(),
absl::ToDoubleMilliseconds(absl::Now() - start_time_)}},
tags);
if (grpc_core::IsTransportSuppliesClientLatencyEnabled()) {
if (gpr_time_cmp(transport_stream_stats->latency,
if (transport_stream_stats != nullptr &&
gpr_time_cmp(transport_stream_stats->latency,
gpr_inf_future(GPR_TIMESPAN)) != 0) {
double latency_ms = absl::ToDoubleMilliseconds(absl::Microseconds(
gpr_timespec_to_micros(transport_stream_stats->latency)));
@ -241,21 +249,17 @@ void OpenCensusCallTracer::OpenCensusCallAttemptTracer::
}
void OpenCensusCallTracer::OpenCensusCallAttemptTracer::RecordCancel(
absl::Status /*cancel_error*/) {
status_code_ = absl::StatusCode::kCancelled;
}
absl::Status /*cancel_error*/) {}
void OpenCensusCallTracer::OpenCensusCallAttemptTracer::RecordEnd(
const gpr_timespec& /*latency*/) {
if (OpenCensusStatsEnabled()) {
double latency_ms = absl::ToDoubleMilliseconds(absl::Now() - start_time_);
std::vector<std::pair<opencensus::tags::TagKey, std::string>> tags =
context_.tags().tags();
tags.emplace_back(ClientMethodTagKey(), std::string(parent_->method_));
tags.emplace_back(ClientStatusTagKey(), StatusCodeToString(status_code_));
::opencensus::stats::Record(
{{RpcClientRoundtripLatency(), latency_ms},
{RpcClientSentMessagesPerRpc(), sent_message_count_},
{{RpcClientSentMessagesPerRpc(), sent_message_count_},
{RpcClientReceivedMessagesPerRpc(), recv_message_count_}},
tags);
grpc_core::MutexLock lock(&parent_->mu_);

Loading…
Cancel
Save