[Gpr_To_Absl_Logging] Reduce log noise (#37218)

[Gpr_To_Absl_Logging] Reduce log noise

Closes #37218

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/37218 from tanvi-jagtap:remove_log_noise_multiple 987c2fb08b
PiperOrigin-RevId: 652466161
dependabot/pip/setuptools-70.0.0
Tanvi Jagtap 7 months ago committed by Copybara-Service
parent 55aee09b81
commit a0b78c468d
  1. 5
      src/core/ext/transport/chaotic_good/server/chaotic_good_server.cc
  2. 3
      src/core/ext/transport/inproc/inproc_transport.cc
  3. 4
      src/core/handshaker/http_connect/http_connect_handshaker.cc
  4. 60
      src/core/lib/gprpp/dual_ref_counted.h
  5. 29
      src/core/lib/iomgr/socket_utils_common_posix.cc
  6. 4
      src/core/lib/security/security_connector/tls/tls_security_connector.cc
  7. 2
      src/core/server/server.cc
  8. 14
      src/core/util/log.cc
  9. 2
      test/core/end2end/fixtures/http_proxy_fixture.cc

@ -488,7 +488,7 @@ int grpc_server_add_chaotic_good_port(grpc_server* server, const char* addr) {
grpc_event_engine::experimental::CreateResolvedAddress(resolved_addr);
std::string addr_str =
*grpc_event_engine::experimental::ResolvedAddressToString(ee_addr);
LOG(INFO) << "BIND: " << addr_str;
GRPC_TRACE_LOG(chaotic_good, INFO) << "BIND: " << addr_str;
auto bind_result = listener->Bind(ee_addr);
if (!bind_result.ok()) {
error_list.push_back(
@ -510,7 +510,8 @@ int grpc_server_add_chaotic_good_port(grpc_server* server, const char* addr) {
} else if (!error_list.empty()) {
LOG(INFO) << "Failed to bind some addresses for " << addr;
for (const auto& error : error_list) {
LOG(INFO) << " " << error.first << ": " << error.second;
GRPC_TRACE_LOG(chaotic_good, INFO)
<< "Binding Failed: " << error.first << ": " << error.second;
}
}
return port_num;

@ -77,7 +77,8 @@ class InprocServerTransport final : public ServerTransport {
void SetPollset(grpc_stream*, grpc_pollset*) override {}
void SetPollsetSet(grpc_stream*, grpc_pollset_set*) override {}
void PerformOp(grpc_transport_op* op) override {
LOG(INFO) << "inproc server op: " << grpc_transport_op_string(op);
GRPC_TRACE_LOG(inproc, INFO)
<< "inproc server op: " << grpc_transport_op_string(op);
if (op->start_connectivity_watch != nullptr) {
connected_state()->AddWatcher(op->start_connectivity_watch_state,
std::move(op->start_connectivity_watch));

@ -296,8 +296,8 @@ void HttpConnectHandshaker::DoHandshake(
// Log connection via proxy.
std::string proxy_name(grpc_endpoint_get_peer(args->endpoint.get()));
std::string server_name_string(*server_name);
LOG(INFO) << "Connecting to server " << server_name_string
<< " via HTTP proxy " << proxy_name;
VLOG(2) << "Connecting to server " << server_name_string << " via HTTP proxy "
<< proxy_name;
// Construct HTTP CONNECT request.
grpc_http_request request;
request.method = const_cast<char*>("CONNECT");

@ -93,9 +93,9 @@ class DualRefCounted : public Impl {
#ifndef NDEBUG
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " unref " << strong_refs << " -> "
<< strong_refs - 1 << ", weak_ref " << weak_refs << " -> "
<< weak_refs + 1;
VLOG(2) << trace_ << ":" << this << " unref " << strong_refs << " -> "
<< strong_refs - 1 << ", weak_ref " << weak_refs << " -> "
<< weak_refs + 1;
}
CHECK_GT(strong_refs, 0u);
#endif
@ -112,10 +112,10 @@ class DualRefCounted : public Impl {
#ifndef NDEBUG
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " unref " << strong_refs << " -> "
<< strong_refs - 1 << ", weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << ") " << reason;
VLOG(2) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " unref " << strong_refs << " -> "
<< strong_refs - 1 << ", weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << ") " << reason;
}
CHECK_GT(strong_refs, 0u);
#else
@ -137,9 +137,9 @@ class DualRefCounted : public Impl {
#ifndef NDEBUG
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " ref_if_non_zero " << strong_refs
<< " -> " << strong_refs + 1 << " (weak_refs=" << weak_refs
<< ")";
VLOG(2) << trace_ << ":" << this << " ref_if_non_zero " << strong_refs
<< " -> " << strong_refs + 1 << " (weak_refs=" << weak_refs
<< ")";
}
#endif
if (strong_refs == 0) return nullptr;
@ -156,10 +156,10 @@ class DualRefCounted : public Impl {
#ifndef NDEBUG
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " ref_if_non_zero " << strong_refs
<< " -> " << strong_refs + 1 << " (weak_refs=" << weak_refs
<< ") " << reason;
VLOG(2) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " ref_if_non_zero " << strong_refs
<< " -> " << strong_refs + 1 << " (weak_refs=" << weak_refs
<< ") " << reason;
}
#else
// Avoid unused-parameter warnings for debug-only parameters
@ -214,8 +214,8 @@ class DualRefCounted : public Impl {
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
const uint32_t strong_refs = GetStrongRefs(prev_ref_pair);
if (trace != nullptr) {
LOG(INFO) << trace << ":" << this << " weak_unref " << weak_refs << " -> "
<< weak_refs - 1 << " (refs=" << strong_refs << ")";
VLOG(2) << trace << ":" << this << " weak_unref " << weak_refs << " -> "
<< weak_refs - 1 << " (refs=" << strong_refs << ")";
}
CHECK_GT(weak_refs, 0u);
#endif
@ -236,9 +236,9 @@ class DualRefCounted : public Impl {
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
const uint32_t strong_refs = GetStrongRefs(prev_ref_pair);
if (trace != nullptr) {
LOG(INFO) << trace << ":" << this << " " << location.file() << ":"
<< location.line() << " weak_unref " << weak_refs << " -> "
<< weak_refs - 1 << " (refs=" << strong_refs << ") " << reason;
VLOG(2) << trace << ":" << this << " " << location.file() << ":"
<< location.line() << " weak_unref " << weak_refs << " -> "
<< weak_refs - 1 << " (refs=" << strong_refs << ") " << reason;
}
CHECK_GT(weak_refs, 0u);
#else
@ -301,8 +301,8 @@ class DualRefCounted : public Impl {
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
CHECK_NE(strong_refs, 0u);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " ref " << strong_refs << " -> "
<< strong_refs + 1 << "; (weak_refs=" << weak_refs << ")";
VLOG(2) << trace_ << ":" << this << " ref " << strong_refs << " -> "
<< strong_refs + 1 << "; (weak_refs=" << weak_refs << ")";
}
#else
refs_.fetch_add(MakeRefPair(1, 0), std::memory_order_relaxed);
@ -316,10 +316,10 @@ class DualRefCounted : public Impl {
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
CHECK_NE(strong_refs, 0u);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " ref " << strong_refs << " -> "
<< strong_refs + 1 << " (weak_refs=" << weak_refs << ") "
<< reason;
VLOG(2) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " ref " << strong_refs << " -> "
<< strong_refs + 1 << " (weak_refs=" << weak_refs << ") "
<< reason;
}
#else
// Use conditionally-important parameters
@ -336,8 +336,8 @@ class DualRefCounted : public Impl {
const uint32_t strong_refs = GetStrongRefs(prev_ref_pair);
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << "; (refs=" << strong_refs << ")";
VLOG(2) << trace_ << ":" << this << " weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << "; (refs=" << strong_refs << ")";
}
if (strong_refs == 0) CHECK_NE(weak_refs, 0u);
#else
@ -352,9 +352,9 @@ class DualRefCounted : public Impl {
const uint32_t strong_refs = GetStrongRefs(prev_ref_pair);
const uint32_t weak_refs = GetWeakRefs(prev_ref_pair);
if (trace_ != nullptr) {
LOG(INFO) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << " (refs=" << strong_refs << ") " << reason;
VLOG(2) << trace_ << ":" << this << " " << location.file() << ":"
<< location.line() << " weak_ref " << weak_refs << " -> "
<< weak_refs + 1 << " (refs=" << strong_refs << ") " << reason;
}
if (strong_refs == 0) CHECK_NE(weak_refs, 0u);
#else

@ -373,20 +373,21 @@ grpc_error_handle grpc_set_socket_tcp_user_timeout(
// if it is available.
if (g_socket_supports_tcp_user_timeout.load() == 0) {
if (0 != getsockopt(fd, IPPROTO_TCP, TCP_USER_TIMEOUT, &newval, &len)) {
LOG(INFO) << "TCP_USER_TIMEOUT is not available. TCP_USER_TIMEOUT "
"won't be used thereafter";
GRPC_TRACE_LOG(tcp, INFO)
<< "TCP_USER_TIMEOUT is not available. TCP_USER_TIMEOUT won't be "
"used thereafter";
g_socket_supports_tcp_user_timeout.store(-1);
} else {
LOG(INFO) << "TCP_USER_TIMEOUT is available. TCP_USER_TIMEOUT will "
"be used thereafter";
GRPC_TRACE_LOG(tcp, INFO)
<< "TCP_USER_TIMEOUT is available. TCP_USER_TIMEOUT will be used "
"thereafter";
g_socket_supports_tcp_user_timeout.store(1);
}
}
if (g_socket_supports_tcp_user_timeout.load() > 0) {
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
LOG(INFO) << "Enabling TCP_USER_TIMEOUT with a timeout of " << timeout
<< " ms";
}
GRPC_TRACE_LOG(tcp, INFO)
<< "Enabling TCP_USER_TIMEOUT with a timeout of " << timeout
<< " ms";
if (0 != setsockopt(fd, IPPROTO_TCP, TCP_USER_TIMEOUT, &timeout,
sizeof(timeout))) {
LOG(ERROR) << "setsockopt(TCP_USER_TIMEOUT) "
@ -399,9 +400,9 @@ grpc_error_handle grpc_set_socket_tcp_user_timeout(
return absl::OkStatus();
}
if (newval != timeout) {
LOG(INFO) << "Setting TCP_USER_TIMEOUT to value " << timeout
<< " ms. Actual TCP_USER_TIMEOUT value is " << newval
<< " ms";
GRPC_TRACE_LOG(tcp, INFO)
<< "Setting TCP_USER_TIMEOUT to value " << timeout
<< " ms. Actual TCP_USER_TIMEOUT value is " << newval << " ms";
return absl::OkStatus();
}
}
@ -438,7 +439,8 @@ static void probe_ipv6_once(void) {
int fd = socket(AF_INET6, SOCK_STREAM, 0);
g_ipv6_loopback_available = 0;
if (fd < 0) {
LOG(INFO) << "Disabling AF_INET6 sockets because socket() failed.";
GRPC_TRACE_LOG(tcp, INFO)
<< "Disabling AF_INET6 sockets because socket() failed.";
} else {
grpc_sockaddr_in6 addr;
memset(&addr, 0, sizeof(addr));
@ -447,7 +449,8 @@ static void probe_ipv6_once(void) {
if (bind(fd, reinterpret_cast<grpc_sockaddr*>(&addr), sizeof(addr)) == 0) {
g_ipv6_loopback_available = 1;
} else {
LOG(INFO) << "Disabling AF_INET6 sockets because ::1 is not available.";
GRPC_TRACE_LOG(tcp, INFO)
<< "Disabling AF_INET6 sockets because ::1 is not available.";
}
close(fd);
}

@ -397,8 +397,8 @@ void TlsChannelSecurityConnector::cancel_check_peer(
if (it != pending_verifier_requests_.end()) {
pending_verifier_request = it->second->request();
} else {
LOG(INFO) << "TlsChannelSecurityConnector::cancel_check_peer: no "
"corresponding pending request found";
VLOG(2) << "TlsChannelSecurityConnector::cancel_check_peer: no "
"corresponding pending request found";
}
}
if (pending_verifier_request != nullptr) {

@ -974,7 +974,7 @@ grpc_error_handle Server::SetupTransport(
}
t->StartConnectivityWatch(MakeOrphanable<TransportConnectivityWatcher>(
t->RefAsSubclass<ServerTransport>(), Ref()));
LOG(INFO) << "Adding connection";
GRPC_TRACE_LOG(server_channel, INFO) << "Adding connection";
connections_.emplace(std::move(t));
++connections_open_;
} else {

@ -115,15 +115,17 @@ void gpr_log_verbosity_init(void) {
absl::string_view verbosity = grpc_core::ConfigVars::Get().Verbosity();
DVLOG(2) << "Log verbosity: " << verbosity;
if (absl::EqualsIgnoreCase(verbosity, "INFO")) {
LOG(WARNING) << "Not suitable for production. Prefer WARNING or ERROR. "
"However if you see this message in a debug environmenmt "
"or test environmenmt it is safe to ignore this message.";
LOG_FIRST_N(WARNING, 1)
<< "Log level INFO is not suitable for production. Prefer WARNING or "
"ERROR. However if you see this message in a debug environmenmt or "
"test environmenmt it is safe to ignore this message.";
absl::SetVLogLevel("*grpc*/*", -1);
absl::SetMinLogLevel(absl::LogSeverityAtLeast::kInfo);
} else if (absl::EqualsIgnoreCase(verbosity, "DEBUG")) {
LOG(WARNING) << "Not suitable for production. Prefer WARNING or ERROR. "
"However if you see this message in a debug environmenmt "
"or test environmenmt it is safe to ignore this message.";
LOG_FIRST_N(WARNING, 1)
<< "Log level DEBUG is not suitable for production. Prefer WARNING or "
"ERROR. However if you see this message in a debug environmenmt or "
"test environmenmt it is safe to ignore this message.";
absl::SetVLogLevel("*grpc*/*", 2);
absl::SetMinLogLevel(absl::LogSeverityAtLeast::kInfo);
} else if (absl::EqualsIgnoreCase(verbosity, "ERROR")) {

@ -682,7 +682,7 @@ grpc_end2end_http_proxy* grpc_end2end_http_proxy_create(
// Construct proxy address.
const int proxy_port = grpc_pick_unused_port_or_die();
proxy->proxy_name = grpc_core::JoinHostPort("localhost", proxy_port);
LOG(INFO) << "Proxy address: " << proxy->proxy_name;
VLOG(2) << "Proxy address: " << proxy->proxy_name;
// Create TCP server.
auto channel_args = grpc_core::CoreConfiguration::Get()
.channel_args_preconditioning()

Loading…
Cancel
Save