From 14083ed106bec798a639dc0b50f9e097c0b10ecb Mon Sep 17 00:00:00 2001 From: Marc Gravell Date: Thu, 23 Feb 2023 02:00:39 +0000 Subject: [PATCH] Core; fix avoidable work (allocs+CPU) when logs enabled but trace level means work will not be used (#31098) core; ref #30979 1. avoid calling `grpc_dump_slice` if the log level is too low (and the result will be ignored) 2. use `GRPC_TRACE_FLAG_ENABLED(x)` over `x.enabled()` in the touched code --------- Co-authored-by: Yash Tibrewal --- .../client_channel/lb_policy/grpclb/grpclb.cc | 16 +++++++++------- src/core/lib/iomgr/endpoint_cfstream.cc | 6 ++++-- src/core/lib/iomgr/tcp_windows.cc | 6 ++++-- .../lib/security/transport/secure_endpoint.cc | 6 ++++-- 4 files changed, 21 insertions(+), 13 deletions(-) diff --git a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc index 9209ccdbcbe..a187edda077 100644 --- a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc +++ b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.cc @@ -1162,13 +1162,15 @@ void GrpcLb::BalancerCallState::OnBalancerMessageReceivedLocked() { upb::Arena arena; if (!GrpcLbResponseParse(response_slice, arena.ptr(), &response) || (response.type == response.INITIAL && seen_initial_response_)) { - char* response_slice_str = - grpc_dump_slice(response_slice, GPR_DUMP_ASCII | GPR_DUMP_HEX); - gpr_log(GPR_ERROR, - "[grpclb %p] lb_calld=%p: Invalid LB response received: '%s'. " - "Ignoring.", - grpclb_policy(), this, response_slice_str); - gpr_free(response_slice_str); + if (gpr_should_log(GPR_LOG_SEVERITY_ERROR)) { + char* response_slice_str = + grpc_dump_slice(response_slice, GPR_DUMP_ASCII | GPR_DUMP_HEX); + gpr_log(GPR_ERROR, + "[grpclb %p] lb_calld=%p: Invalid LB response received: '%s'. " + "Ignoring.", + grpclb_policy(), this, response_slice_str); + gpr_free(response_slice_str); + } } else { switch (response.type) { case response.INITIAL: { diff --git a/src/core/lib/iomgr/endpoint_cfstream.cc b/src/core/lib/iomgr/endpoint_cfstream.cc index 3cb8c9e9863..edfea7c802f 100644 --- a/src/core/lib/iomgr/endpoint_cfstream.cc +++ b/src/core/lib/iomgr/endpoint_cfstream.cc @@ -113,7 +113,8 @@ static grpc_error_handle CFStreamAnnotateError(grpc_error_handle src_error, } static void CallReadCb(CFStreamEndpoint* ep, grpc_error_handle error) { - if (grpc_tcp_trace.enabled()) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace) && + gpr_should_log(GPR_LOG_SEVERITY_DEBUG)) { gpr_log(GPR_DEBUG, "CFStream endpoint:%p call_read_cb %p %p:%p", ep, ep->read_cb, ep->read_cb->cb, ep->read_cb->cb_arg); size_t i; @@ -225,7 +226,8 @@ static void WriteAction(void* arg, grpc_error_handle error) { EP_UNREF(ep, "write"); } - if (grpc_tcp_trace.enabled()) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace) && + gpr_should_log(GPR_LOG_SEVERITY_DEBUG)) { grpc_slice trace_slice = grpc_slice_sub(slice, 0, write_size); char* dump = grpc_dump_slice(trace_slice, GPR_DUMP_HEX | GPR_DUMP_ASCII); gpr_log(GPR_DEBUG, "WRITE %p (peer=%s): %s", ep, ep->peer_string.c_str(), diff --git a/src/core/lib/iomgr/tcp_windows.cc b/src/core/lib/iomgr/tcp_windows.cc index 42bfa039ef8..41aa1f4a387 100644 --- a/src/core/lib/iomgr/tcp_windows.cc +++ b/src/core/lib/iomgr/tcp_windows.cc @@ -203,7 +203,8 @@ static void on_read(void* tcpp, grpc_error_handle error) { } GPR_ASSERT((size_t)info->bytes_transferred == tcp->read_slices->length); - if (grpc_tcp_trace.enabled()) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace) && + gpr_should_log(GPR_LOG_SEVERITY_INFO)) { size_t i; for (i = 0; i < tcp->read_slices->count; i++) { char* dump = grpc_dump_slice(tcp->read_slices->slices[i], @@ -353,7 +354,8 @@ static void win_write(grpc_endpoint* ep, grpc_slice_buffer* slices, WSABUF* buffers = local_buffers; size_t len, async_buffers_offset = 0; - if (grpc_tcp_trace.enabled()) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_tcp_trace) && + gpr_should_log(GPR_LOG_SEVERITY_INFO)) { size_t i; for (i = 0; i < slices->count; i++) { char* data = diff --git a/src/core/lib/security/transport/secure_endpoint.cc b/src/core/lib/security/transport/secure_endpoint.cc index 3e64aacb7f3..3155b29df4b 100644 --- a/src/core/lib/security/transport/secure_endpoint.cc +++ b/src/core/lib/security/transport/secure_endpoint.cc @@ -236,7 +236,8 @@ static void flush_read_staging_buffer(secure_endpoint* ep, uint8_t** cur, } static void call_read_cb(secure_endpoint* ep, grpc_error_handle error) { - if (GRPC_TRACE_FLAG_ENABLED(grpc_trace_secure_endpoint)) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_trace_secure_endpoint) && + gpr_should_log(GPR_LOG_SEVERITY_INFO)) { size_t i; for (i = 0; i < ep->read_buffer->count; i++) { char* data = grpc_dump_slice(ep->read_buffer->slices[i], @@ -394,7 +395,8 @@ static void endpoint_write(grpc_endpoint* secure_ep, grpc_slice_buffer* slices, grpc_slice_buffer_reset_and_unref(&ep->output_buffer); - if (GRPC_TRACE_FLAG_ENABLED(grpc_trace_secure_endpoint)) { + if (GRPC_TRACE_FLAG_ENABLED(grpc_trace_secure_endpoint) && + gpr_should_log(GPR_LOG_SEVERITY_INFO)) { for (i = 0; i < slices->count; i++) { char* data = grpc_dump_slice(slices->slices[i], GPR_DUMP_HEX | GPR_DUMP_ASCII);