Optimize absl::StrFormat calls showing up on profiles (#32647)

- construct string for tracing in chttp2_transport only if tracing is
enabled
- use equivalent absl::StrCat/StrAppend instead of
absl::StrFormat/StrJoin for formatting showing up on cpu profiles
pull/32666/head
scwhittle 2 years ago committed by GitHub
parent 0c1797cd9f
commit 525e736977
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 39
      src/core/ext/transport/chttp2/transport/chttp2_transport.cc
  2. 90
      src/core/lib/transport/transport_op_string.cc

@ -205,20 +205,14 @@ static void keepalive_watchdog_fired_locked(
static void maybe_reset_keepalive_ping_timer_locked(grpc_chttp2_transport* t);
namespace {
void MaybeRecordTransportAnnotation(grpc_chttp2_stream* s,
absl::string_view annotation) {
GPR_ASSERT(s->context);
if (!grpc_core::IsTraceRecordCallopsEnabled()) {
return;
grpc_core::CallTracerInterface* CallTracerIfEnabled(grpc_chttp2_stream* s) {
if (s->context == nullptr || !grpc_core::IsTraceRecordCallopsEnabled()) {
return nullptr;
}
auto* call_tracer = static_cast<grpc_core::CallTracerInterface*>(
return static_cast<grpc_core::CallTracerInterface*>(
static_cast<grpc_call_context_element*>(
s->context)[GRPC_CONTEXT_CALL_TRACER_ANNOTATION_INTERFACE]
.value);
if (!call_tracer) {
return;
}
call_tracer->RecordAnnotation(annotation);
}
} // namespace
@ -369,8 +363,8 @@ static void read_channel_args(grpc_chttp2_transport* t,
grpc_core::MakeRefCounted<grpc_core::channelz::SocketNode>(
std::string(grpc_endpoint_get_local_address(t->ep)),
std::string(t->peer_string.as_string_view()),
absl::StrFormat("%s %s", get_vtable()->name,
t->peer_string.as_string_view()),
absl::StrCat(get_vtable()->name, " ",
t->peer_string.as_string_view()),
channel_args
.GetObjectRef<grpc_core::channelz::SocketNode::Security>());
}
@ -1231,10 +1225,11 @@ void grpc_chttp2_complete_closure_step(grpc_chttp2_transport* t,
write_state_name(t->write_state));
}
if (s->context != nullptr) {
MaybeRecordTransportAnnotation(
s, absl::StrFormat("on_complete: s=%p %p desc=%s err=%s", s, closure,
desc, grpc_core::StatusToString(error).c_str()));
auto* tracer = CallTracerIfEnabled(s);
if (tracer != nullptr) {
tracer->RecordAnnotation(
absl::StrFormat("on_complete: s=%p %p desc=%s err=%s", s, closure, desc,
grpc_core::StatusToString(error).c_str()));
}
if (!error.ok()) {
@ -1309,12 +1304,12 @@ static void perform_stream_op_locked(void* stream_op,
}
}
if (s->context != nullptr) {
MaybeRecordTransportAnnotation(
s, absl::StrFormat(
"perform_stream_op_locked[s=%p; op=%p]: %s; on_complete = %p", s,
op, grpc_transport_stream_op_batch_string(op, true).c_str(),
op->on_complete));
auto* tracer = CallTracerIfEnabled(s);
if (tracer != nullptr) {
tracer->RecordAnnotation(absl::StrFormat(
"perform_stream_op_locked[s=%p; op=%p]: %s; on_complete = %p", s, op,
grpc_transport_stream_op_batch_string(op, true).c_str(),
op->on_complete));
}
grpc_closure* on_complete = op->on_complete;

@ -18,15 +18,12 @@
#include <grpc/support/port_platform.h>
#include <algorithm>
#include <initializer_list>
#include <memory>
#include <string>
#include <vector>
#include "absl/strings/str_cat.h"
#include "absl/strings/str_format.h"
#include "absl/strings/str_join.h"
#include <grpc/support/log.h>
@ -45,111 +42,112 @@
std::string grpc_transport_stream_op_batch_string(
grpc_transport_stream_op_batch* op, bool truncate) {
std::vector<std::string> out;
std::string out;
if (op->send_initial_metadata) {
out.push_back(" SEND_INITIAL_METADATA{");
absl::StrAppend(&out, " SEND_INITIAL_METADATA{");
if (truncate) {
out.push_back(absl::StrFormat(
"Length=%zu", op->payload->send_initial_metadata
.send_initial_metadata->TransportSize()));
absl::StrAppend(&out, "Length=",
op->payload->send_initial_metadata.send_initial_metadata
->TransportSize());
} else {
out.push_back(op->payload->send_initial_metadata.send_initial_metadata
->DebugString());
absl::StrAppend(&out, op->payload->send_initial_metadata
.send_initial_metadata->DebugString());
}
out.push_back("}");
absl::StrAppend(&out, "}");
}
if (op->send_message) {
if (op->payload->send_message.send_message != nullptr) {
out.push_back(absl::StrFormat(
" SEND_MESSAGE:flags=0x%08x:len=%d", op->payload->send_message.flags,
op->payload->send_message.send_message->Length()));
absl::StrAppendFormat(&out, " SEND_MESSAGE:flags=0x%08x:len=%d",
op->payload->send_message.flags,
op->payload->send_message.send_message->Length());
} else {
// This can happen when we check a batch after the transport has
// processed and cleared the send_message op.
out.push_back(" SEND_MESSAGE(flag and length unknown, already orphaned)");
absl::StrAppend(
&out, " SEND_MESSAGE(flag and length unknown, already orphaned)");
}
}
if (op->send_trailing_metadata) {
out.push_back(" SEND_TRAILING_METADATA{");
absl::StrAppend(&out, " SEND_TRAILING_METADATA{");
if (truncate) {
out.push_back(absl::StrFormat(
"Length=%zu", op->payload->send_trailing_metadata
.send_trailing_metadata->TransportSize()));
absl::StrAppend(&out, "Length=",
op->payload->send_trailing_metadata
.send_trailing_metadata->TransportSize());
} else {
out.push_back(op->payload->send_trailing_metadata.send_trailing_metadata
->DebugString());
absl::StrAppend(&out, op->payload->send_trailing_metadata
.send_trailing_metadata->DebugString());
}
out.push_back("}");
absl::StrAppend(&out, "}");
}
if (op->recv_initial_metadata) {
out.push_back(" RECV_INITIAL_METADATA");
absl::StrAppend(&out, " RECV_INITIAL_METADATA");
}
if (op->recv_message) {
out.push_back(" RECV_MESSAGE");
absl::StrAppend(&out, " RECV_MESSAGE");
}
if (op->recv_trailing_metadata) {
out.push_back(" RECV_TRAILING_METADATA");
absl::StrAppend(&out, " RECV_TRAILING_METADATA");
}
if (op->cancel_stream) {
out.push_back(absl::StrCat(
" CANCEL:",
grpc_core::StatusToString(op->payload->cancel_stream.cancel_error)));
absl::StrAppend(
&out, " CANCEL:",
grpc_core::StatusToString(op->payload->cancel_stream.cancel_error));
}
return absl::StrJoin(out, "");
return out;
}
std::string grpc_transport_op_string(grpc_transport_op* op) {
std::vector<std::string> out;
std::string out;
if (op->start_connectivity_watch != nullptr) {
out.push_back(absl::StrFormat(
" START_CONNECTIVITY_WATCH:watcher=%p:from=%s",
absl::StrAppendFormat(
&out, " START_CONNECTIVITY_WATCH:watcher=%p:from=%s",
op->start_connectivity_watch.get(),
grpc_core::ConnectivityStateName(op->start_connectivity_watch_state)));
grpc_core::ConnectivityStateName(op->start_connectivity_watch_state));
}
if (op->stop_connectivity_watch != nullptr) {
out.push_back(absl::StrFormat(" STOP_CONNECTIVITY_WATCH:watcher=%p",
op->stop_connectivity_watch));
absl::StrAppendFormat(&out, " STOP_CONNECTIVITY_WATCH:watcher=%p",
op->stop_connectivity_watch);
}
if (!op->disconnect_with_error.ok()) {
out.push_back(absl::StrCat(
" DISCONNECT:", grpc_core::StatusToString(op->disconnect_with_error)));
absl::StrAppend(&out, " DISCONNECT:",
grpc_core::StatusToString(op->disconnect_with_error));
}
if (!op->goaway_error.ok()) {
out.push_back(absl::StrCat(" SEND_GOAWAY:",
grpc_core::StatusToString(op->goaway_error)));
absl::StrAppend(
&out, " SEND_GOAWAY:", grpc_core::StatusToString(op->goaway_error));
}
if (op->set_accept_stream) {
out.push_back(absl::StrFormat(" SET_ACCEPT_STREAM:%p(%p,...)",
op->set_accept_stream_fn,
op->set_accept_stream_user_data));
absl::StrAppendFormat(&out, " SET_ACCEPT_STREAM:%p(%p,...)",
op->set_accept_stream_fn,
op->set_accept_stream_user_data);
}
if (op->bind_pollset != nullptr) {
out.push_back(" BIND_POLLSET");
absl::StrAppend(&out, " BIND_POLLSET");
}
if (op->bind_pollset_set != nullptr) {
out.push_back(" BIND_POLLSET_SET");
absl::StrAppend(&out, " BIND_POLLSET_SET");
}
if (op->send_ping.on_initiate != nullptr || op->send_ping.on_ack != nullptr) {
out.push_back(" SEND_PING");
absl::StrAppend(&out, " SEND_PING");
}
return absl::StrJoin(out, "");
return out;
}
void grpc_call_log_op(const char* file, int line, gpr_log_severity severity,

Loading…
Cancel
Save