Skip to content

Commit

Permalink
[Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG…
Browse files Browse the repository at this point in the history 
…_ENABLED (#37516)

[Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG_ENABLED

Closes #37516

COPYBARA_INTEGRATE_REVIEW=#37516 from tanvi-jagtap:GRPC_TRACE_FLAG_ENABLED_09 c21f60f
PiperOrigin-RevId: 663811332
  • Loading branch information
@tanvi-jagtap @copybara-github
tanvi-jagtap authored and copybara-github committed Aug 16, 2024
1 parent 7c67387 commit 4d111b0
Show file tree
Hide file tree
Showing 27 changed files with 266 additions and 361 deletions.
7 changes: 3 additions & 4 deletions src/core/ext/transport/chaotic_good/server_transport.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -203,10 +203,9 @@ auto ChaoticGoodServerTransport::CallOutboundLoop(
Map(SendCallInitialMetadataAndBody(stream_id, outgoing_frames,
call_initiator),
[stream_id](absl::Status main_body_result) {
if (GRPC_TRACE_FLAG_ENABLED(chaotic_good)) {
VLOG(2) << "CHAOTIC_GOOD: CallOutboundLoop: stream_id="
<< stream_id << " main_body_result=" << main_body_result;
}
GRPC_TRACE_VLOG(chaotic_good, 2)
<< "CHAOTIC_GOOD: CallOutboundLoop: stream_id=" << stream_id
<< " main_body_result=" << main_body_result;
return Empty{};
}),
call_initiator.PullServerTrailingMetadata(),
Expand Down
63 changes: 28 additions & 35 deletions src/core/ext/transport/chttp2/transport/chttp2_transport.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1308,15 +1308,14 @@ void grpc_chttp2_complete_closure_step(grpc_chttp2_transport* t,
return;
}
closure->next_data.scratch -= CLOSURE_BARRIER_FIRST_REF_BIT;
if (GRPC_TRACE_FLAG_ENABLED(http)) {
LOG(INFO) << "complete_closure_step: t=" << t << " " << closure << " refs="
<< (closure->next_data.scratch / CLOSURE_BARRIER_FIRST_REF_BIT)
<< " flags="
<< (closure->next_data.scratch % CLOSURE_BARRIER_FIRST_REF_BIT)
<< " desc=" << desc << " err=" << grpc_core::StatusToString(error)
<< " write_state=" << write_state_name(t->write_state)
<< " whence=" << whence.file() << ":" << whence.line();
}
GRPC_TRACE_LOG(http, INFO)
<< "complete_closure_step: t=" << t << " " << closure << " refs="
<< (closure->next_data.scratch / CLOSURE_BARRIER_FIRST_REF_BIT)
<< " flags="
<< (closure->next_data.scratch % CLOSURE_BARRIER_FIRST_REF_BIT)
<< " desc=" << desc << " err=" << grpc_core::StatusToString(error)
<< " write_state=" << write_state_name(t->write_state)
<< " whence=" << whence.file() << ":" << whence.line();

if (!error.ok()) {
grpc_error_handle cl_err =
Expand Down Expand Up @@ -2085,11 +2084,10 @@ void grpc_chttp2_maybe_complete_recv_message(grpc_chttp2_transport* t,
// Lambda is immediately invoked as a big scoped section that can be
// exited out of at any point by returning.
[&]() {
if (GRPC_TRACE_FLAG_ENABLED(http)) {
VLOG(2) << "maybe_complete_recv_message " << s
<< " final_metadata_requested=" << s->final_metadata_requested
<< " seen_error=" << s->seen_error;
}
GRPC_TRACE_VLOG(http, 2)
<< "maybe_complete_recv_message " << s
<< " final_metadata_requested=" << s->final_metadata_requested
<< " seen_error=" << s->seen_error;
if (s->final_metadata_requested && s->seen_error) {
grpc_slice_buffer_reset_and_unref(&s->frame_storage);
s->recv_message->reset();
Expand All @@ -2100,11 +2098,10 @@ void grpc_chttp2_maybe_complete_recv_message(grpc_chttp2_transport* t,
int64_t min_progress_size;
auto r = grpc_deframe_unprocessed_incoming_frames(
s, &min_progress_size, &**s->recv_message, s->recv_message_flags);
if (GRPC_TRACE_FLAG_ENABLED(http)) {
VLOG(2) << "Deframe data frame: "
<< grpc_core::PollToString(
r, [](absl::Status r) { return r.ToString(); });
}
GRPC_TRACE_VLOG(http, 2)
<< "Deframe data frame: "
<< grpc_core::PollToString(
r, [](absl::Status r) { return r.ToString(); });
if (r.pending()) {
if (s->read_closed) {
grpc_slice_buffer_reset_and_unref(&s->frame_storage);
Expand Down Expand Up @@ -2155,13 +2152,12 @@ void grpc_chttp2_maybe_complete_recv_message(grpc_chttp2_transport* t,
void grpc_chttp2_maybe_complete_recv_trailing_metadata(grpc_chttp2_transport* t,
grpc_chttp2_stream* s) {
grpc_chttp2_maybe_complete_recv_message(t, s);
if (GRPC_TRACE_FLAG_ENABLED(http)) {
VLOG(2) << "maybe_complete_recv_trailing_metadata cli=" << t->is_client
<< " s=" << s << " closure=" << s->recv_trailing_metadata_finished
<< " read_closed=" << s->read_closed
<< " write_closed=" << s->write_closed << " "
<< s->frame_storage.length;
}
GRPC_TRACE_VLOG(http, 2) << "maybe_complete_recv_trailing_metadata cli="
<< t->is_client << " s=" << s
<< " closure=" << s->recv_trailing_metadata_finished
<< " read_closed=" << s->read_closed
<< " write_closed=" << s->write_closed << " "
<< s->frame_storage.length;
if (s->recv_trailing_metadata_finished != nullptr && s->read_closed &&
s->write_closed) {
if (s->seen_error || !t->is_client) {
Expand Down Expand Up @@ -2365,15 +2361,12 @@ grpc_chttp2_transport::RemovedStreamHandle grpc_chttp2_mark_stream_closed(
grpc_chttp2_transport* t, grpc_chttp2_stream* s, int close_reads,
int close_writes, grpc_error_handle error) {
grpc_chttp2_transport::RemovedStreamHandle rsh;
if (GRPC_TRACE_FLAG_ENABLED(http)) {
VLOG(2) << "MARK_STREAM_CLOSED: t=" << t << " s=" << s << "(id=" << s->id
<< ") "
<< ((close_reads && close_writes)
? "read+write"
: (close_reads ? "read"
: (close_writes ? "write" : "nothing??")))
<< " [" << grpc_core::StatusToString(error) << "]";
}
GRPC_TRACE_VLOG(http, 2)
<< "MARK_STREAM_CLOSED: t=" << t << " s=" << s << "(id=" << s->id << ") "
<< ((close_reads && close_writes)
? "read+write"
: (close_reads ? "read" : (close_writes ? "write" : "nothing??")))
<< " [" << grpc_core::StatusToString(error) << "]";
if (s->read_closed && s->write_closed) {
// already closed, but we should still fake the status if needed.
grpc_error_handle overall_error = removal_error(error, s, "Stream removed");
Expand Down
6 changes: 2 additions & 4 deletions src/core/ext/transport/chttp2/transport/parsing.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -883,10 +883,8 @@ static grpc_error_handle parse_frame_slice(grpc_chttp2_transport* t,
if (GPR_LIKELY(err.ok())) {
return err;
}
if (GRPC_TRACE_FLAG_ENABLED(http)) {
LOG(ERROR) << "INCOMING[" << t << ";" << s << "]: Parse failed with "
<< err;
}
GRPC_TRACE_LOG(http, ERROR)
<< "INCOMING[" << t << ";" << s << "]: Parse failed with " << err;
if (grpc_error_get_int(err, grpc_core::StatusIntProperty::kStreamId,
&unused)) {
grpc_chttp2_parsing_become_skip_parser(t);
Expand Down
33 changes: 15 additions & 18 deletions src/core/ext/transport/chttp2/transport/writing.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -204,24 +204,21 @@ static bool update_list(grpc_chttp2_transport* t, int64_t send_bytes,

static void report_stall(grpc_chttp2_transport* t, grpc_chttp2_stream* s,
const char* staller) {
if (GRPC_TRACE_FLAG_ENABLED(flowctl)) {
VLOG(2) << t->peer_string.as_string_view() << ":" << t << " stream "
<< s->id << " moved to stalled list by " << staller
<< ". This is FULLY expected to happen in a healthy program that "
"is not seeing flow control stalls. However, if you know that "
"there are unwanted stalls, here is some helpful data: "
"[fc:pending="
<< s->flow_controlled_buffer.length
<< ":flowed=" << s->flow_controlled_bytes_flowed
<< ":peer_initwin=" << t->settings.acked().initial_window_size()
<< ":t_win=" << t->flow_control.remote_window() << ":s_win="
<< static_cast<uint32_t>(
std::max(int64_t{0},
s->flow_control.remote_window_delta() +
static_cast<int64_t>(
t->settings.peer().initial_window_size())))
<< ":s_delta=" << s->flow_control.remote_window_delta() << "]";
}
GRPC_TRACE_VLOG(flowctl, 2)
<< t->peer_string.as_string_view() << ":" << t << " stream " << s->id
<< " moved to stalled list by " << staller
<< ". This is FULLY expected to happen in a healthy program that is not "
"seeing flow control stalls. However, if you know that there are "
"unwanted stalls, here is some helpful data: [fc:pending="
<< s->flow_controlled_buffer.length
<< ":flowed=" << s->flow_controlled_bytes_flowed
<< ":peer_initwin=" << t->settings.acked().initial_window_size()
<< ":t_win=" << t->flow_control.remote_window() << ":s_win="
<< static_cast<uint32_t>(std::max(
int64_t{0}, s->flow_control.remote_window_delta() +
static_cast<int64_t>(
t->settings.peer().initial_window_size())))
<< ":s_delta=" << s->flow_control.remote_window_delta() << "]";
}

namespace {
Expand Down
25 changes: 11 additions & 14 deletions src/core/lib/channel/promise_based_filter.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2111,15 +2111,13 @@ void ServerCallData::StartBatch(grpc_transport_stream_op_batch* b) {
// Handle cancellation.
void ServerCallData::Completed(grpc_error_handle error,
bool tarpit_cancellation, Flusher* flusher) {
if (GRPC_TRACE_FLAG_ENABLED(channel)) {
VLOG(2) << LogTag() << "ServerCallData::Completed: send_trailing_state="
<< StateString(send_trailing_state_) << " send_initial_state="
<< (send_initial_metadata_ == nullptr
? "null"
: SendInitialMetadata::StateString(
send_initial_metadata_->state))
<< " error=" << error;
}
GRPC_TRACE_VLOG(channel, 2)
<< LogTag() << "ServerCallData::Completed: send_trailing_state="
<< StateString(send_trailing_state_) << " send_initial_state="
<< (send_initial_metadata_ == nullptr
? "null"
: SendInitialMetadata::StateString(send_initial_metadata_->state))
<< " error=" << error;
// Track the latest reason for cancellation.
cancelled_error_ = error;
// Stop running the promise.
Expand Down Expand Up @@ -2388,11 +2386,10 @@ void ServerCallData::WakeInsideCombiner(Flusher* flusher) {
flusher,
send_initial_metadata_ == nullptr ||
send_initial_metadata_->state == SendInitialMetadata::kForwarded);
if (GRPC_TRACE_FLAG_ENABLED(channel)) {
VLOG(2) << LogTag() << ": After send_message WakeInsideCombiner "
<< DebugString() << " is_idle=" << send_message()->IsIdle()
<< " is_forwarded=" << send_message()->IsForwarded();
}
GRPC_TRACE_VLOG(channel, 2)
<< LogTag() << ": After send_message WakeInsideCombiner "
<< DebugString() << " is_idle=" << send_message()->IsIdle()
<< " is_forwarded=" << send_message()->IsForwarded();
if (send_trailing_state_ == SendTrailingState::kQueuedBehindSendMessage &&
(send_message()->IsIdle() ||
(send_trailing_metadata_batch_->send_message &&
Expand Down
13 changes: 4 additions & 9 deletions src/core/lib/event_engine/posix_engine/timer_manager.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -118,17 +118,13 @@ void TimerManager::Shutdown() {
{
grpc_core::MutexLock lock(&mu_);
if (shutdown_) return;
if (GRPC_TRACE_FLAG_ENABLED(timer)) {
VLOG(2) << "TimerManager::" << this << " shutting down";
}
GRPC_TRACE_VLOG(timer, 2) << "TimerManager::" << this << " shutting down";
shutdown_ = true;
// Wait on the main loop to exit.
cv_wait_.Signal();
}
main_loop_exit_signal_->WaitForNotification();
if (GRPC_TRACE_FLAG_ENABLED(timer)) {
VLOG(2) << "TimerManager::" << this << " shutdown complete";
}
GRPC_TRACE_VLOG(timer, 2) << "TimerManager::" << this << " shutdown complete";
}

TimerManager::~TimerManager() { Shutdown(); }
Expand All @@ -144,9 +140,8 @@ void TimerManager::Kick() {
void TimerManager::RestartPostFork() {
grpc_core::MutexLock lock(&mu_);
CHECK(GPR_LIKELY(shutdown_));
if (GRPC_TRACE_FLAG_ENABLED(timer)) {
VLOG(2) << "TimerManager::" << this << " restarting after shutdown";
}
GRPC_TRACE_VLOG(timer, 2)
<< "TimerManager::" << this << " restarting after shutdown";
shutdown_ = false;
main_loop_exit_signal_.emplace();
thread_pool_->Run([this]() { MainLoop(); });
Expand Down
14 changes: 6 additions & 8 deletions src/core/lib/iomgr/cfstream_handle.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -65,10 +65,9 @@ void CFStreamHandle::ReadCallback(CFReadStreamRef stream,
grpc_error_handle error;
CFErrorRef stream_error;
CFStreamHandle* handle = static_cast<CFStreamHandle*>(client_callback_info);
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream ReadCallback (" << handle << ", " << stream << ", "
<< type << ", " << client_callback_info << ")";
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream ReadCallback (" << handle << ", "
<< stream << ", " << type << ", "
<< client_callback_info << ")";
switch (type) {
case kCFStreamEventOpenCompleted:
handle->open_event_.SetReady();
Expand Down Expand Up @@ -99,10 +98,9 @@ void CFStreamHandle::WriteCallback(CFWriteStreamRef stream,
grpc_error_handle error;
CFErrorRef stream_error;
CFStreamHandle* handle = static_cast<CFStreamHandle*>(clientCallBackInfo);
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream WriteCallback (" << handle << ", " << stream << ", "
<< type << ", " << clientCallBackInfo << ")";
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream WriteCallback (" << handle << ", "
<< stream << ", " << type << ", "
<< clientCallBackInfo << ")";
switch (type) {
case kCFStreamEventOpenCompleted:
handle->open_event_.SetReady();
Expand Down
13 changes: 5 additions & 8 deletions src/core/lib/iomgr/closure.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -292,18 +292,15 @@ class Closure {
return;
}
#ifndef NDEBUG
if (GRPC_TRACE_FLAG_ENABLED(closure)) {
VLOG(2) << "running closure " << closure << ": created ["
<< closure->file_created << ":" << closure->line_created
<< "]: run [" << location.file() << ":" << location.line() << "]";
}
GRPC_TRACE_VLOG(closure, 2)
<< "running closure " << closure << ": created ["
<< closure->file_created << ":" << closure->line_created << "]: run ["
<< location.file() << ":" << location.line() << "]";
CHECK_NE(closure->cb, nullptr);
#endif
closure->cb(closure->cb_arg, error);
#ifndef NDEBUG
if (GRPC_TRACE_FLAG_ENABLED(closure)) {
VLOG(2) << "closure " << closure << " finished";
}
GRPC_TRACE_VLOG(closure, 2) << "closure " << closure << " finished";
#endif
}
};
Expand Down
14 changes: 6 additions & 8 deletions src/core/lib/iomgr/combiner.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -71,14 +71,12 @@ static void start_destroy(grpc_core::Combiner* lock) {
}

#ifndef NDEBUG
#define GRPC_COMBINER_DEBUG_SPAM(op, delta) \
if (GRPC_TRACE_FLAG_ENABLED(combiner)) { \
VLOG(2).AtLocation(file, line) \
<< "C:" << lock << " " << (op) << " " \
<< gpr_atm_no_barrier_load(&lock->refs.count) << " --> " \
<< gpr_atm_no_barrier_load(&lock->refs.count) + (delta) << " " \
<< reason; \
}
#define GRPC_COMBINER_DEBUG_SPAM(op, delta) \
GRPC_TRACE_VLOG(combiner, 2).AtLocation(file, line) \
<< "C:" << lock << " " << (op) << " " \
<< gpr_atm_no_barrier_load(&lock->refs.count) << " --> " \
<< gpr_atm_no_barrier_load(&lock->refs.count) + (delta) << " " \
<< reason;
#else
#define GRPC_COMBINER_DEBUG_SPAM(op, delta)
#endif
Expand Down
31 changes: 13 additions & 18 deletions src/core/lib/iomgr/endpoint_cfstream.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -129,11 +129,10 @@ static void CallReadCb(CFStreamEndpoint* ep, grpc_error_handle error) {
}

static void CallWriteCb(CFStreamEndpoint* ep, grpc_error_handle error) {
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream endpoint:" << ep << " call_write_cb " << ep->write_cb
<< " " << ep->write_cb->cb << ":" << ep->write_cb->cb_arg;
VLOG(2) << "write: error=" << grpc_core::StatusToString(error);
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream endpoint:" << ep << " call_write_cb "
<< ep->write_cb << " " << ep->write_cb->cb << ":"
<< ep->write_cb->cb_arg << "write: error="
<< grpc_core::StatusToString(error);
grpc_closure* cb = ep->write_cb;
ep->write_cb = nullptr;
ep->write_slices = nullptr;
Expand Down Expand Up @@ -233,10 +232,9 @@ static void CFStreamRead(grpc_endpoint* ep, grpc_slice_buffer* slices,
grpc_closure* cb, bool /*urgent*/,
int /*min_progress_size*/) {
CFStreamEndpoint* ep_impl = reinterpret_cast<CFStreamEndpoint*>(ep);
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream endpoint:" << ep_impl << " read (" << slices << ", "
<< cb << ") length:" << slices->length;
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream endpoint:" << ep_impl << " read ("
<< slices << ", " << cb
<< ") length:" << slices->length;
CHECK_EQ(ep_impl->read_cb, nullptr);
ep_impl->read_cb = cb;
ep_impl->read_slices = slices;
Expand All @@ -251,10 +249,9 @@ static void CFStreamWrite(grpc_endpoint* ep, grpc_slice_buffer* slices,
grpc_closure* cb, void* /*arg*/,
int /*max_frame_size*/) {
CFStreamEndpoint* ep_impl = reinterpret_cast<CFStreamEndpoint*>(ep);
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream endpoint:" << ep_impl << " write (" << slices << ", "
<< cb << ") length:" << slices->length;
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream endpoint:" << ep_impl << " write ("
<< slices << ", " << cb
<< ") length:" << slices->length;
CHECK_EQ(ep_impl->write_cb, nullptr);
ep_impl->write_cb = cb;
ep_impl->write_slices = slices;
Expand Down Expand Up @@ -308,11 +305,9 @@ grpc_endpoint* grpc_cfstream_endpoint_create(CFReadStreamRef read_stream,
const char* peer_string,
CFStreamHandle* stream_sync) {
CFStreamEndpoint* ep_impl = new CFStreamEndpoint;
if (GRPC_TRACE_FLAG_ENABLED(tcp)) {
VLOG(2) << "CFStream endpoint:" << ep_impl
<< " create readStream:" << read_stream
<< " writeStream: " << write_stream;
}
GRPC_TRACE_VLOG(tcp, 2) << "CFStream endpoint:" << ep_impl
<< " create readStream:" << read_stream
<< " writeStream: " << write_stream;
ep_impl->base.vtable = &vtable;
gpr_ref_init(&ep_impl->refcount, 1);
ep_impl->read_stream = read_stream;
Expand Down
5 changes: 2 additions & 3 deletions src/core/lib/iomgr/ev_epoll1_linux.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -360,9 +360,8 @@ static grpc_fd* fd_create(int fd, const char* name, bool track_err) {
grpc_iomgr_register_object(&new_fd->iomgr_object, fd_name.c_str());
fork_fd_list_add_grpc_fd(new_fd);
#ifndef NDEBUG
if (GRPC_TRACE_FLAG_ENABLED(fd_refcount)) {
VLOG(2) << "FD " << fd << " " << new_fd << " create " << fd_name;
}
GRPC_TRACE_VLOG(fd_refcount, 2)
<< "FD " << fd << " " << new_fd << " create " << fd_name;
#endif

struct epoll_event ev;
Expand Down
Loading

0 comments on commit 4d111b0

Please sign in to comment.