From 8c5c97d3a2fe709256c6d76bb5c35e372ade9997 Mon Sep 17 00:00:00 2001 From: Tanvi Jagtap <139093547+tanvi-jagtap@users.noreply.github.com> Date: Wed, 7 Aug 2024 23:05:31 -0700 Subject: [PATCH] [Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG_ENABLED (#37388) [Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG_ENABLED Closes #37388 COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/37388 from tanvi-jagtap:GRPC_TRACE_FLAG_ENABLED_05 079535c5e185e41e70564df247c5625ea84ff43d PiperOrigin-RevId: 660693555 --- src/core/lib/channel/promise_based_filter.cc | 89 ++++++-------- src/core/lib/gprpp/work_serializer.cc | 36 +++--- src/core/lib/iomgr/ev_apple.cc | 9 -- src/core/lib/iomgr/ev_epoll1_linux.cc | 110 ++++++------------ src/core/lib/iomgr/ev_poll_posix.cc | 8 +- src/core/lib/iomgr/tcp_posix.cc | 49 +++----- src/core/lib/iomgr/tcp_server_posix.cc | 5 +- src/core/lib/iomgr/tcp_windows.cc | 16 +-- src/core/lib/iomgr/timer_manager.cc | 9 +- src/core/lib/promise/for_each.h | 23 ++-- src/core/lib/promise/inter_activity_latch.h | 20 ++-- src/core/lib/promise/latch.h | 40 +++---- src/core/lib/resource_quota/memory_quota.cc | 23 ++-- .../grpc_authorization_policy_provider.cc | 9 +- .../credentials/oauth2/oauth2_credentials.cc | 9 +- src/core/lib/transport/bdp_estimator.cc | 14 +-- src/core/lib/transport/call_filters.cc | 8 +- 17 files changed, 170 insertions(+), 307 deletions(-) diff --git a/src/core/lib/channel/promise_based_filter.cc b/src/core/lib/channel/promise_based_filter.cc index 06d34649aa4..6af8436b187 100644 --- a/src/core/lib/channel/promise_based_filter.cc +++ b/src/core/lib/channel/promise_based_filter.cc @@ -398,11 +398,9 @@ bool BaseCallData::SendMessage::IsIdle() const { void BaseCallData::SendMessage::OnComplete(absl::Status status) { Flusher flusher(base_); - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << base_->LogTag() - << " SendMessage.OnComplete st=" << StateString(state_) - << " status=" << status; - } + GRPC_TRACE_LOG(channel, INFO) + << base_->LogTag() << " SendMessage.OnComplete st=" << StateString(state_) + << " status=" << status; switch (state_) { case State::kInitial: case State::kIdle: @@ -429,11 +427,9 @@ void BaseCallData::SendMessage::OnComplete(absl::Status status) { void BaseCallData::SendMessage::Done(const ServerMetadata& metadata, Flusher* flusher) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << base_->LogTag() - << " SendMessage.Done st=" << StateString(state_) - << " md=" << metadata.DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) + << base_->LogTag() << " SendMessage.Done st=" << StateString(state_) + << " md=" << metadata.DebugString(); switch (state_) { case State::kCancelled: case State::kCancelledButNotYetPolled: @@ -681,11 +677,10 @@ void BaseCallData::ReceiveMessage::GotPipe(T* pipe_end) { } void BaseCallData::ReceiveMessage::OnComplete(absl::Status status) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << base_->LogTag() - << " ReceiveMessage.OnComplete st=" << StateString(state_) - << " status=" << status; - } + GRPC_TRACE_LOG(channel, INFO) + << base_->LogTag() + << " ReceiveMessage.OnComplete st=" << StateString(state_) + << " status=" << status; switch (state_) { case State::kInitial: case State::kIdle: @@ -722,11 +717,9 @@ void BaseCallData::ReceiveMessage::OnComplete(absl::Status status) { void BaseCallData::ReceiveMessage::Done(const ServerMetadata& metadata, Flusher* flusher) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << base_->LogTag() - << " ReceiveMessage.Done st=" << StateString(state_) - << " md=" << metadata.DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) + << base_->LogTag() << " ReceiveMessage.Done st=" << StateString(state_) + << " md=" << metadata.DebugString(); switch (state_) { case State::kInitial: state_ = State::kCancelled; @@ -842,11 +835,10 @@ void BaseCallData::ReceiveMessage::WakeInsideCombiner(Flusher* flusher, CHECK(push_.has_value()); auto r_push = (*push_)(); if (auto* p = r_push.value_if_ready()) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << base_->LogTag() - << " ReceiveMessage.WakeInsideCombiner push complete: " - << (*p ? "true" : "false"); - } + GRPC_TRACE_LOG(channel, INFO) + << base_->LogTag() + << " ReceiveMessage.WakeInsideCombiner push complete: " + << (*p ? "true" : "false"); // We haven't pulled through yet, so this certainly shouldn't succeed. CHECK(!*p); state_ = State::kCancelled; @@ -1366,9 +1358,7 @@ void ClientCallData::StartBatch(grpc_transport_stream_op_batch* b) { CapturedBatch batch(b); Flusher flusher(this); - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << " StartBatch " << DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) << LogTag() << " StartBatch " << DebugString(); // If this is a cancel stream, cancel anything we have pending and propagate // the cancellation. @@ -1489,9 +1479,8 @@ void ClientCallData::StartBatch(grpc_transport_stream_op_batch* b) { // Handle cancellation. void ClientCallData::Cancel(grpc_error_handle error, Flusher* flusher) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << " Cancel error=" << error.ToString(); - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << " Cancel error=" << error.ToString(); // Track the latest reason for cancellation. cancelled_error_ = error; // Stop running the promise. @@ -1568,11 +1557,10 @@ void ClientCallData::StartPromise(Flusher* flusher) { } void ClientCallData::RecvInitialMetadataReady(grpc_error_handle error) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << " ClientCallData.RecvInitialMetadataReady " - << DebugString() << " error:" << error.ToString() - << " md:" << recv_initial_metadata_->metadata->DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << " ClientCallData.RecvInitialMetadataReady " + << DebugString() << " error:" << error.ToString() + << " md:" << recv_initial_metadata_->metadata->DebugString(); ScopedContext context(this); Flusher flusher(this); if (!error.ok()) { @@ -1974,9 +1962,8 @@ ServerCallData::ServerCallData(grpc_call_element* elem, } ServerCallData::~ServerCallData() { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << " ~ServerCallData " << DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << " ~ServerCallData " << DebugString(); if (send_initial_metadata_ != nullptr) { send_initial_metadata_->~SendInitialMetadata(); } @@ -2001,9 +1988,7 @@ void ServerCallData::StartBatch(grpc_transport_stream_op_batch* b) { Flusher flusher(this); bool wake = false; - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << " StartBatch: " << DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) << LogTag() << " StartBatch: " << DebugString(); // If this is a cancel stream, cancel anything we have pending and // propagate the cancellation. @@ -2306,9 +2291,8 @@ void ServerCallData::RecvInitialMetadataReadyCallback(void* arg, void ServerCallData::RecvInitialMetadataReady(grpc_error_handle error) { Flusher flusher(this); - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << ": RecvInitialMetadataReady " << error; - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << ": RecvInitialMetadataReady " << error; CHECK(recv_initial_state_ == RecvInitialState::kForwarded); // If there was an error we just propagate that through if (!error.ok()) { @@ -2370,9 +2354,8 @@ std::string ServerCallData::DebugString() const { // Wakeup and poll the promise if appropriate. void ServerCallData::WakeInsideCombiner(Flusher* flusher) { PollContext poll_ctx(this, flusher); - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << ": WakeInsideCombiner " << DebugString(); - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << ": WakeInsideCombiner " << DebugString(); poll_ctx.ClearRepoll(); if (send_initial_metadata_ != nullptr) { if (send_initial_metadata_->state == @@ -2392,12 +2375,12 @@ void ServerCallData::WakeInsideCombiner(Flusher* flusher) { } if (send_initial_metadata_->metadata_push_.has_value()) { if ((*send_initial_metadata_->metadata_push_)().ready()) { - if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << ": WakeInsideCombiner: metadata_push done"; - } + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << ": WakeInsideCombiner: metadata_push done"; send_initial_metadata_->metadata_push_.reset(); - } else if (GRPC_TRACE_FLAG_ENABLED(channel)) { - LOG(INFO) << LogTag() << ": WakeInsideCombiner: metadata_push pending"; + } else { + GRPC_TRACE_LOG(channel, INFO) + << LogTag() << ": WakeInsideCombiner: metadata_push pending"; } } } diff --git a/src/core/lib/gprpp/work_serializer.cc b/src/core/lib/gprpp/work_serializer.cc index badfce84a1f..16ed3fd6e68 100644 --- a/src/core/lib/gprpp/work_serializer.cc +++ b/src/core/lib/gprpp/work_serializer.cc @@ -161,9 +161,8 @@ void WorkSerializer::LegacyWorkSerializer::Run(std::function callback, refs_.fetch_sub(MakeRefPair(1, 0), std::memory_order_acq_rel); CallbackWrapper* cb_wrapper = new CallbackWrapper(std::move(callback), location); - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << " Scheduling on queue : item " << cb_wrapper; - } + GRPC_TRACE_LOG(work_serializer, INFO) + << " Scheduling on queue : item " << cb_wrapper; queue_.Push(&cb_wrapper->mpscq_node); } } @@ -172,19 +171,15 @@ void WorkSerializer::LegacyWorkSerializer::Schedule( std::function callback, const DebugLocation& location) { CallbackWrapper* cb_wrapper = new CallbackWrapper(std::move(callback), location); - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << "WorkSerializer::Schedule() " << this - << " Scheduling callback " << cb_wrapper << " [" - << location.file() << ":" << location.line() << "]"; - } + GRPC_TRACE_LOG(work_serializer, INFO) + << "WorkSerializer::Schedule() " << this << " Scheduling callback " + << cb_wrapper << " [" << location.file() << ":" << location.line() << "]"; refs_.fetch_add(MakeRefPair(0, 1), std::memory_order_acq_rel); queue_.Push(&cb_wrapper->mpscq_node); } void WorkSerializer::LegacyWorkSerializer::Orphan() { - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << "WorkSerializer::Orphan() " << this; - } + GRPC_TRACE_LOG(work_serializer, INFO) << "WorkSerializer::Orphan() " << this; const uint64_t prev_ref_pair = refs_.fetch_sub(MakeRefPair(0, 1), std::memory_order_acq_rel); if (GetOwners(prev_ref_pair) == 0 && GetSize(prev_ref_pair) == 1) { @@ -196,9 +191,8 @@ void WorkSerializer::LegacyWorkSerializer::Orphan() { // The thread that calls this loans itself to the work serializer so as to // execute all the scheduled callbacks. void WorkSerializer::LegacyWorkSerializer::DrainQueue() { - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << "WorkSerializer::DrainQueue() " << this; - } + GRPC_TRACE_LOG(work_serializer, INFO) + << "WorkSerializer::DrainQueue() " << this; // Attempt to take ownership of the WorkSerializer. Also increment the queue // size as required by `DrainQueueOwned()`. const uint64_t prev_ref_pair = @@ -217,9 +211,8 @@ void WorkSerializer::LegacyWorkSerializer::DrainQueue() { } void WorkSerializer::LegacyWorkSerializer::DrainQueueOwned() { - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << "WorkSerializer::DrainQueueOwned() " << this; - } + GRPC_TRACE_LOG(work_serializer, INFO) + << "WorkSerializer::DrainQueueOwned() " << this; while (true) { auto prev_ref_pair = refs_.fetch_sub(MakeRefPair(0, 1)); // It is possible that while draining the queue, the last callback ended @@ -264,11 +257,10 @@ void WorkSerializer::LegacyWorkSerializer::DrainQueueOwned() { GRPC_TRACE_LOG(work_serializer, INFO) << " Queue returned nullptr, trying again"; } - if (GRPC_TRACE_FLAG_ENABLED(work_serializer)) { - LOG(INFO) << " Running item " << cb_wrapper - << " : callback scheduled at [" << cb_wrapper->location.file() - << ":" << cb_wrapper->location.line() << "]"; - } + GRPC_TRACE_LOG(work_serializer, INFO) + << " Running item " << cb_wrapper << " : callback scheduled at [" + << cb_wrapper->location.file() << ":" << cb_wrapper->location.line() + << "]"; cb_wrapper->callback(); delete cb_wrapper; } diff --git a/src/core/lib/iomgr/ev_apple.cc b/src/core/lib/iomgr/ev_apple.cc index 98607ea6441..88f07921f3a 100644 --- a/src/core/lib/iomgr/ev_apple.cc +++ b/src/core/lib/iomgr/ev_apple.cc @@ -39,15 +39,6 @@ #include "src/core/lib/gprpp/time_util.h" #include "src/core/lib/iomgr/ev_apple.h" -#ifndef NDEBUG -#define GRPC_POLLING_TRACE(format, ...) \ - if (GRPC_TRACE_FLAG_ENABLED(apple_polling)) { \ - VLOG(2) << "(polling) " << absl::StrFormat(format, __VA_ARGS__); \ - } -#else -#define GRPC_POLLING_TRACE(...) -#endif // NDEBUG - #define GRPC_POLLSET_KICK_BROADCAST ((grpc_pollset_worker*)1) struct GlobalRunLoopContext { diff --git a/src/core/lib/iomgr/ev_epoll1_linux.cc b/src/core/lib/iomgr/ev_epoll1_linux.cc index 964d2627f70..278e544bb79 100644 --- a/src/core/lib/iomgr/ev_epoll1_linux.cc +++ b/src/core/lib/iomgr/ev_epoll1_linux.cc @@ -727,9 +727,8 @@ static grpc_error_handle do_epoll_wait(grpc_pollset* ps, if (r < 0) return GRPC_OS_ERROR(errno, "epoll_wait"); - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << "ps: " << ps << " poll got " << r << " events"; - } + GRPC_TRACE_LOG(polling, INFO) + << "ps: " << ps << " poll got " << r << " events"; gpr_atm_rel_store(&g_epoll_set.num_events, r); gpr_atm_rel_store(&g_epoll_set.cursor, 0); @@ -746,9 +745,8 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, worker->schedule_on_end_work = (grpc_closure_list)GRPC_CLOSURE_LIST_INIT; pollset->begin_refs++; - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << "PS:" << pollset << " BEGIN_STARTS:" << worker; - } + GRPC_TRACE_LOG(polling, INFO) + << "PS:" << pollset << " BEGIN_STARTS:" << worker; if (pollset->seen_inactive) { // pollset has been observed to be inactive, we need to move back to the @@ -765,11 +763,10 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, retry_lock_neighborhood: gpr_mu_lock(&neighborhood->mu); gpr_mu_lock(&pollset->mu); - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << "PS:" << pollset << " BEGIN_REORG:" << worker - << " kick_state=" << kick_state_string(worker->state) - << " is_reassigning=" << is_reassigning; - } + GRPC_TRACE_LOG(polling, INFO) + << "PS:" << pollset << " BEGIN_REORG:" << worker + << " kick_state=" << kick_state_string(worker->state) + << " is_reassigning=" << is_reassigning; if (pollset->seen_inactive) { if (neighborhood != pollset->neighborhood) { gpr_mu_unlock(&neighborhood->mu); @@ -818,11 +815,10 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, worker->initialized_cv = true; gpr_cv_init(&worker->cv); while (worker->state == UNKICKED && !pollset->shutting_down) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << "PS:" << pollset << " BEGIN_WAIT:" << worker - << " kick_state=" << kick_state_string(worker->state) - << " shutdown=" << pollset->shutting_down; - } + GRPC_TRACE_LOG(polling, INFO) + << "PS:" << pollset << " BEGIN_WAIT:" << worker + << " kick_state=" << kick_state_string(worker->state) + << " shutdown=" << pollset->shutting_down; if (gpr_cv_wait(&worker->cv, &pollset->mu, deadline.as_timespec(GPR_CLOCK_MONOTONIC)) && @@ -877,17 +873,15 @@ static bool check_neighborhood_for_available_poller( if (gpr_atm_no_barrier_cas( &g_active_poller, 0, reinterpret_cast(inspect_worker))) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. choose next poller to be " << inspect_worker; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. choose next poller to be " << inspect_worker; SET_KICK_STATE(inspect_worker, DESIGNATED_POLLER); if (inspect_worker->initialized_cv) { gpr_cv_signal(&inspect_worker->cv); } } else { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. beaten to choose next poller"; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. beaten to choose next poller"; } // even if we didn't win the cas, there's a worker, we can stop found_worker = true; @@ -903,9 +897,8 @@ static bool check_neighborhood_for_available_poller( } while (!found_worker && inspect_worker != inspect->root_worker); } if (!found_worker) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. mark pollset " << inspect << " inactive"; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. mark pollset " << inspect << " inactive"; inspect->seen_inactive = true; if (inspect == neighborhood->active_root) { neighborhood->active_root = @@ -922,9 +915,7 @@ static bool check_neighborhood_for_available_poller( static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, grpc_pollset_worker** worker_hdl) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << "PS:" << pollset << " END_WORKER:" << worker; - } + GRPC_TRACE_LOG(polling, INFO) << "PS:" << pollset << " END_WORKER:" << worker; if (worker_hdl != nullptr) *worker_hdl = nullptr; // Make sure we appear kicked SET_KICK_STATE(worker, KICKED); @@ -933,9 +924,8 @@ static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, if (gpr_atm_no_barrier_load(&g_active_poller) == reinterpret_cast(worker)) { if (worker->next != worker && worker->next->state == UNKICKED) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. choose next poller to be peer " << worker; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. choose next poller to be peer " << worker; CHECK(worker->next->initialized_cv); gpr_atm_no_barrier_store(&g_active_poller, (gpr_atm)worker->next); SET_KICK_STATE(worker->next, DESIGNATED_POLLER); @@ -984,9 +974,7 @@ static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker, if (worker->initialized_cv) { gpr_cv_destroy(&worker->cv); } - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. remove worker"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. remove worker"; if (EMPTIED == worker_remove(pollset, worker)) { pollset_maybe_finish_shutdown(pollset); } @@ -1075,22 +1063,16 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset, grpc_pollset_worker* root_worker = pollset->root_worker; if (root_worker == nullptr) { pollset->kicked_without_poller = true; - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kicked_without_poller"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kicked_without_poller"; goto done; } grpc_pollset_worker* next_worker = root_worker->next; if (root_worker->state == KICKED) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. already kicked " << root_worker; - } + GRPC_TRACE_LOG(polling, INFO) << " .. already kicked " << root_worker; SET_KICK_STATE(root_worker, KICKED); goto done; } else if (next_worker->state == KICKED) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. already kicked " << next_worker; - } + GRPC_TRACE_LOG(polling, INFO) << " .. already kicked " << next_worker; SET_KICK_STATE(next_worker, KICKED); goto done; } else if (root_worker == next_worker && // only try and wake up a poller @@ -1098,27 +1080,22 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset, root_worker == reinterpret_cast( gpr_atm_no_barrier_load(&g_active_poller))) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kicked " << root_worker; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kicked " << root_worker; SET_KICK_STATE(root_worker, KICKED); ret_err = grpc_wakeup_fd_wakeup(&global_wakeup_fd); goto done; } else if (next_worker->state == UNKICKED) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kicked " << next_worker; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kicked " << next_worker; CHECK(next_worker->initialized_cv); SET_KICK_STATE(next_worker, KICKED); gpr_cv_signal(&next_worker->cv); goto done; } else if (next_worker->state == DESIGNATED_POLLER) { if (root_worker->state != DESIGNATED_POLLER) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kicked root non-poller " << root_worker - << " (initialized_cv=" << root_worker->initialized_cv - << ") (poller=" << next_worker << ")"; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. kicked root non-poller " << root_worker + << " (initialized_cv=" << root_worker->initialized_cv + << ") (poller=" << next_worker << ")"; SET_KICK_STATE(root_worker, KICKED); if (root_worker->initialized_cv) { gpr_cv_signal(&root_worker->cv); @@ -1137,9 +1114,7 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset, goto done; } } else { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kicked while waking up"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kicked while waking up"; goto done; } @@ -1147,36 +1122,27 @@ static grpc_error_handle pollset_kick(grpc_pollset* pollset, } if (specific_worker->state == KICKED) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. specific worker already kicked"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. specific worker already kicked"; goto done; } else if (g_current_thread_worker == specific_worker) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. mark " << specific_worker << " kicked"; - } + GRPC_TRACE_LOG(polling, INFO) + << " .. mark " << specific_worker << " kicked"; SET_KICK_STATE(specific_worker, KICKED); goto done; } else if (specific_worker == reinterpret_cast( gpr_atm_no_barrier_load(&g_active_poller))) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kick active poller"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kick active poller"; SET_KICK_STATE(specific_worker, KICKED); ret_err = grpc_wakeup_fd_wakeup(&global_wakeup_fd); goto done; } else if (specific_worker->initialized_cv) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kick waiting worker"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kick waiting worker"; SET_KICK_STATE(specific_worker, KICKED); gpr_cv_signal(&specific_worker->cv); goto done; } else { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << " .. kick non-waiting worker"; - } + GRPC_TRACE_LOG(polling, INFO) << " .. kick non-waiting worker"; SET_KICK_STATE(specific_worker, KICKED); goto done; } diff --git a/src/core/lib/iomgr/ev_poll_posix.cc b/src/core/lib/iomgr/ev_poll_posix.cc index b2a30686331..9d0728a97d0 100644 --- a/src/core/lib/iomgr/ev_poll_posix.cc +++ b/src/core/lib/iomgr/ev_poll_posix.cc @@ -1028,9 +1028,7 @@ static grpc_error_handle pollset_work(grpc_pollset* pollset, r = grpc_poll_function(pfds, pfd_count, timeout); GRPC_SCHEDULING_END_BLOCKING_REGION; - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << pollset << " poll=" << r; - } + GRPC_TRACE_LOG(polling, INFO) << pollset << " poll=" << r; if (r < 0) { if (errno != EINTR) { @@ -1052,9 +1050,7 @@ static grpc_error_handle pollset_work(grpc_pollset* pollset, } } else { if (pfds[0].revents & POLLIN_CHECK) { - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - LOG(INFO) << pollset << ": got_wakeup"; - } + GRPC_TRACE_LOG(polling, INFO) << pollset << ": got_wakeup"; work_combine_error( &error, grpc_wakeup_fd_consume_wakeup(&worker.wakeup_fd->fd)); } diff --git a/src/core/lib/iomgr/tcp_posix.cc b/src/core/lib/iomgr/tcp_posix.cc index 78af9addd99..d0c68d40c7f 100644 --- a/src/core/lib/iomgr/tcp_posix.cc +++ b/src/core/lib/iomgr/tcp_posix.cc @@ -618,18 +618,14 @@ static void tcp_drop_uncovered_then_handle_write(void* arg /* grpc_tcp */, static void done_poller(void* bp, grpc_error_handle /*error_ignored*/) { backup_poller* p = static_cast(bp); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "BACKUP_POLLER:" << p << " destroy"; - } + GRPC_TRACE_LOG(tcp, INFO) << "BACKUP_POLLER:" << p << " destroy"; grpc_pollset_destroy(BACKUP_POLLER_POLLSET(p)); gpr_free(p); } static void run_poller(void* bp, grpc_error_handle /*error_ignored*/) { backup_poller* p = static_cast(bp); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "BACKUP_POLLER:" << p << " run"; - } + GRPC_TRACE_LOG(tcp, INFO) << "BACKUP_POLLER:" << p << " run"; gpr_mu_lock(p->pollset_mu); grpc_core::Timestamp deadline = grpc_core::Timestamp::Now() + grpc_core::Duration::Seconds(10); @@ -644,17 +640,13 @@ static void run_poller(void* bp, grpc_error_handle /*error_ignored*/) { g_backup_poller = nullptr; g_uncovered_notifications_pending = 0; g_backup_poller_mu->Unlock(); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "BACKUP_POLLER:" << p << " shutdown"; - } + GRPC_TRACE_LOG(tcp, INFO) << "BACKUP_POLLER:" << p << " shutdown"; grpc_pollset_shutdown(BACKUP_POLLER_POLLSET(p), GRPC_CLOSURE_INIT(&p->run_poller, done_poller, p, grpc_schedule_on_exec_ctx)); } else { g_backup_poller_mu->Unlock(); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "BACKUP_POLLER:" << p << " reschedule"; - } + GRPC_TRACE_LOG(tcp, INFO) << "BACKUP_POLLER:" << p << " reschedule"; grpc_core::Executor::Run(&p->run_poller, absl::OkStatus(), grpc_core::ExecutorType::DEFAULT, grpc_core::ExecutorJobType::LONG); @@ -691,9 +683,7 @@ static void cover_self(grpc_tcp* tcp) { g_backup_poller = p; grpc_pollset_init(BACKUP_POLLER_POLLSET(p), &p->pollset_mu); g_backup_poller_mu->Unlock(); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "BACKUP_POLLER:" << p << " create"; - } + GRPC_TRACE_LOG(tcp, INFO) << "BACKUP_POLLER:" << p << " create"; grpc_core::Executor::Run( GRPC_CLOSURE_INIT(&p->run_poller, run_poller, p, nullptr), absl::OkStatus(), grpc_core::ExecutorType::DEFAULT, @@ -709,16 +699,12 @@ static void cover_self(grpc_tcp* tcp) { } static void notify_on_read(grpc_tcp* tcp) { - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " notify_on_read"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " notify_on_read"; grpc_fd_notify_on_read(tcp->em_fd, &tcp->read_done_closure); } static void notify_on_write(grpc_tcp* tcp) { - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " notify_on_write"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " notify_on_write"; if (!grpc_event_engine_run_in_background()) { cover_self(tcp); } @@ -815,9 +801,8 @@ static void tcp_destroy(grpc_endpoint* ep) { static void perform_reclamation(grpc_tcp* tcp) ABSL_LOCKS_EXCLUDED(tcp->read_mu) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "TCP: benign reclamation to free memory"; - } + GRPC_TRACE_LOG(resource_quota, INFO) + << "TCP: benign reclamation to free memory"; tcp->read_mu.Lock(); if (tcp->incoming_buffer != nullptr) { grpc_slice_buffer_reset_and_unref(tcp->incoming_buffer); @@ -910,9 +895,7 @@ static void update_rcvlowat(grpc_tcp* tcp) static bool tcp_do_read(grpc_tcp* tcp, grpc_error_handle* error) ABSL_EXCLUSIVE_LOCKS_REQUIRED(tcp->read_mu) { GRPC_LATENT_SEE_INNER_SCOPE("tcp_do_read"); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " do_read"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " do_read"; struct msghdr msg; struct iovec iov[MAX_READ_IOVEC]; ssize_t read_bytes; @@ -1479,9 +1462,7 @@ static bool process_errors(grpc_tcp* tcp) { static void tcp_handle_error(void* arg /* grpc_tcp */, grpc_error_handle error) { grpc_tcp* tcp = static_cast(arg); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " got_error: " << error; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " got_error: " << error; if (!error.ok() || static_cast(gpr_atm_acq_load(&tcp->stop_error_notification))) { @@ -1809,9 +1790,7 @@ static void tcp_handle_write(void* arg /* grpc_tcp */, ? tcp_flush_zerocopy(tcp, tcp->current_zerocopy_send, &error) : tcp_flush(tcp, &error); if (!flush_result) { - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "write: delayed"; - } + GRPC_TRACE_LOG(tcp, INFO) << "write: delayed"; notify_on_write(tcp); // tcp_flush does not populate error if it has returned false. DCHECK(error.ok()); @@ -1880,9 +1859,7 @@ static void tcp_write(grpc_endpoint* ep, grpc_slice_buffer* buf, TCP_REF(tcp, "write"); tcp->write_cb = cb; tcp->current_zerocopy_send = zerocopy_send_record; - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "write: delayed"; - } + GRPC_TRACE_LOG(tcp, INFO) << "write: delayed"; notify_on_write(tcp); } else { GRPC_TRACE_LOG(tcp, INFO) << "write: " << grpc_core::StatusToString(error); diff --git a/src/core/lib/iomgr/tcp_server_posix.cc b/src/core/lib/iomgr/tcp_server_posix.cc index 877f6a21d08..a45a0c8e32f 100644 --- a/src/core/lib/iomgr/tcp_server_posix.cc +++ b/src/core/lib/iomgr/tcp_server_posix.cc @@ -459,9 +459,8 @@ static void on_read(void* arg, grpc_error_handle err) { LOG(ERROR) << "Invalid address: " << addr_uri.status(); goto error; } - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "SERVER_CONNECT: incoming connection: " << *addr_uri; - } + GRPC_TRACE_LOG(tcp, INFO) + << "SERVER_CONNECT: incoming connection: " << *addr_uri; std::string name = absl::StrCat("tcp-server-connection:", addr_uri.value()); grpc_fd* fdobj = grpc_fd_create(fd, name.c_str(), true); diff --git a/src/core/lib/iomgr/tcp_windows.cc b/src/core/lib/iomgr/tcp_windows.cc index 0888f92ff19..b94ffcfe912 100644 --- a/src/core/lib/iomgr/tcp_windows.cc +++ b/src/core/lib/iomgr/tcp_windows.cc @@ -176,9 +176,7 @@ static void on_read(void* tcpp, grpc_error_handle error) { grpc_winsocket* socket = tcp->socket; grpc_winsocket_callback_info* info = &socket->read_info; - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " on_read"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " on_read"; if (error.ok()) { if (info->wsa_error != 0 && !tcp->shutting_down) { @@ -208,9 +206,7 @@ static void on_read(void* tcpp, grpc_error_handle error) { } } } else { - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " unref read_slice"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " unref read_slice"; grpc_slice_buffer_reset_and_unref(tcp->read_slices); error = grpc_error_set_int( tcp->shutting_down ? GRPC_ERROR_CREATE("TCP stream shutting down") @@ -239,9 +235,7 @@ static void win_read(grpc_endpoint* ep, grpc_slice_buffer* read_slices, WSABUF buffers[MAX_WSABUF_COUNT]; size_t i; - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " win_read"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " win_read"; if (tcp->shutting_down) { grpc_core::ExecCtx::Run( @@ -310,9 +304,7 @@ static void on_write(void* tcpp, grpc_error_handle error) { grpc_winsocket_callback_info* info = &handle->write_info; grpc_closure* cb; - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - LOG(INFO) << "TCP:" << tcp << " on_write"; - } + GRPC_TRACE_LOG(tcp, INFO) << "TCP:" << tcp << " on_write"; gpr_mu_lock(&tcp->mu); cb = tcp->write_cb; diff --git a/src/core/lib/iomgr/timer_manager.cc b/src/core/lib/iomgr/timer_manager.cc index 5136ad35d1a..312ed68a025 100644 --- a/src/core/lib/iomgr/timer_manager.cc +++ b/src/core/lib/iomgr/timer_manager.cc @@ -195,11 +195,10 @@ static bool wait_until(grpc_core::Timestamp next) { gpr_cv_wait(&g_cv_wait, &g_mu, next.as_timespec(GPR_CLOCK_MONOTONIC)); - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - LOG(INFO) << "wait ended: was_timed:" - << (my_timed_waiter_generation == g_timed_waiter_generation) - << " kicked:" << g_kicked; - } + GRPC_TRACE_LOG(timer_check, INFO) + << "wait ended: was_timed:" + << (my_timed_waiter_generation == g_timed_waiter_generation) + << " kicked:" << g_kicked; // if this was the timed waiter, then we need to check timers, and flag // that there's now no timed waiter... we'll look for a replacement if // there's work to do after checking timers (code above) diff --git a/src/core/lib/promise/for_each.h b/src/core/lib/promise/for_each.h index 62a4c8de561..60eb19b713a 100644 --- a/src/core/lib/promise/for_each.h +++ b/src/core/lib/promise/for_each.h @@ -172,16 +172,13 @@ class ForEach { } GPR_ATTRIBUTE_ALWAYS_INLINE_FUNCTION Poll PollReaderNext() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << " PollReaderNext"; - } + GRPC_TRACE_LOG(promise_primitives, INFO) << DebugTag() << " PollReaderNext"; auto r = reader_next_(); if (auto* p = r.value_if_ready()) { switch (NextValueTraits::Type(*p)) { case NextValueType::kValue: { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << " PollReaderNext: got value"; - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << " PollReaderNext: got value"; Destruct(&reader_next_); auto action = action_factory_.Make( std::move(NextValueTraits::MutableValue(*p))); @@ -190,15 +187,13 @@ class ForEach { return PollAction(); } case NextValueType::kEndOfStream: { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << " PollReaderNext: got end of stream"; - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << " PollReaderNext: got end of stream"; return Done::Make(false); } case NextValueType::kError: { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << " PollReaderNext: got error"; - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << " PollReaderNext: got error"; return Done::Make(true); } } @@ -207,9 +202,7 @@ class ForEach { } Poll PollAction() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << " PollAction"; - } + GRPC_TRACE_LOG(promise_primitives, INFO) << DebugTag() << " PollAction"; auto r = in_action_.promise(); if (auto* p = r.value_if_ready()) { if (IsStatusOk(*p)) { diff --git a/src/core/lib/promise/inter_activity_latch.h b/src/core/lib/promise/inter_activity_latch.h index 79f68316b71..38ef2a0aa4e 100644 --- a/src/core/lib/promise/inter_activity_latch.h +++ b/src/core/lib/promise/inter_activity_latch.h @@ -45,9 +45,8 @@ class InterActivityLatch { auto Wait() { return [this]() -> Poll { MutexLock lock(&mu_); - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "PollWait " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "PollWait " << StateString(); if (is_set_) { return std::move(value_); } else { @@ -60,9 +59,8 @@ class InterActivityLatch { // Set the latch. void Set(T value) { MutexLock lock(&mu_); - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Set " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Set " << StateString(); is_set_ = true; value_ = std::move(value); waiters_.WakeupAsync(); @@ -102,9 +100,8 @@ class InterActivityLatch { auto Wait() { return [this]() -> Poll { MutexLock lock(&mu_); - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "PollWait " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "PollWait " << StateString(); if (is_set_) { return Empty{}; } else { @@ -117,9 +114,8 @@ class InterActivityLatch { // Set the latch. void Set() { MutexLock lock(&mu_); - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Set " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Set " << StateString(); is_set_ = true; waiters_.WakeupAsync(); } diff --git a/src/core/lib/promise/latch.h b/src/core/lib/promise/latch.h index e946cd739d5..10f4776117f 100644 --- a/src/core/lib/promise/latch.h +++ b/src/core/lib/promise/latch.h @@ -67,9 +67,8 @@ class Latch { has_had_waiters_ = true; #endif return [this]() -> Poll { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Wait " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Wait " << StateString(); if (has_value_) { return std::move(value_); } else { @@ -85,9 +84,8 @@ class Latch { has_had_waiters_ = true; #endif return [this]() -> Poll { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "WaitAndCopy " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "WaitAndCopy " << StateString(); if (has_value_) { return value_; } else { @@ -98,9 +96,8 @@ class Latch { // Set the value of the latch. Can only be called once. void Set(T value) { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Set " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Set " << StateString(); DCHECK(!has_value_); value_ = std::move(value); has_value_ = true; @@ -161,9 +158,8 @@ class Latch { has_had_waiters_ = true; #endif return [this]() -> Poll { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "PollWait " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "PollWait " << StateString(); if (is_set_) { return Empty{}; } else { @@ -174,9 +170,8 @@ class Latch { // Set the latch. Can only be called once. void Set() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Set " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Set " << StateString(); DCHECK(!is_set_); is_set_ = true; waiter_.Wake(); @@ -223,9 +218,8 @@ class ExternallyObservableLatch { // Produce a promise to wait for this latch. auto Wait() { return [this]() -> Poll { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "PollWait " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "PollWait " << StateString(); if (IsSet()) { return Empty{}; } else { @@ -236,9 +230,8 @@ class ExternallyObservableLatch { // Set the latch. void Set() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Set " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Set " << StateString(); is_set_.store(true, std::memory_order_relaxed); waiter_.Wake(); } @@ -246,9 +239,8 @@ class ExternallyObservableLatch { bool IsSet() const { return is_set_.load(std::memory_order_relaxed); } void Reset() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - LOG(INFO) << DebugTag() << "Reset " << StateString(); - } + GRPC_TRACE_LOG(promise_primitives, INFO) + << DebugTag() << "Reset " << StateString(); is_set_.store(false, std::memory_order_relaxed); } diff --git a/src/core/lib/resource_quota/memory_quota.cc b/src/core/lib/resource_quota/memory_quota.cc index 9ec3cf0b00d..29b3a581a92 100644 --- a/src/core/lib/resource_quota/memory_quota.cc +++ b/src/core/lib/resource_quota/memory_quota.cc @@ -355,9 +355,8 @@ void GrpcMemoryAllocatorImpl::MaybeDonateBack() { if (free_bytes_.compare_exchange_weak(free, new_free, std::memory_order_acq_rel, std::memory_order_acquire)) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "[" << this << "] Early return " << ret << " bytes"; - } + GRPC_TRACE_LOG(resource_quota, INFO) + << "[" << this << "] Early return " << ret << " bytes"; CHECK(taken_bytes_.fetch_sub(ret, std::memory_order_relaxed) >= ret); memory_quota_->Return(ret); return; @@ -548,9 +547,7 @@ void BasicMemoryQuota::Return(size_t amount) { } void BasicMemoryQuota::AddNewAllocator(GrpcMemoryAllocatorImpl* allocator) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "Adding allocator " << allocator; - } + GRPC_TRACE_LOG(resource_quota, INFO) << "Adding allocator " << allocator; AllocatorBucket::Shard& shard = small_allocators_.SelectShard(allocator); @@ -561,9 +558,7 @@ void BasicMemoryQuota::AddNewAllocator(GrpcMemoryAllocatorImpl* allocator) { } void BasicMemoryQuota::RemoveAllocator(GrpcMemoryAllocatorImpl* allocator) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "Removing allocator " << allocator; - } + GRPC_TRACE_LOG(resource_quota, INFO) << "Removing allocator " << allocator; AllocatorBucket::Shard& small_shard = small_allocators_.SelectShard(allocator); @@ -608,9 +603,8 @@ void BasicMemoryQuota::MaybeMoveAllocator(GrpcMemoryAllocatorImpl* allocator, void BasicMemoryQuota::MaybeMoveAllocatorBigToSmall( GrpcMemoryAllocatorImpl* allocator) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "Moving allocator " << allocator << " to small"; - } + GRPC_TRACE_LOG(resource_quota, INFO) + << "Moving allocator " << allocator << " to small"; AllocatorBucket::Shard& old_shard = big_allocators_.SelectShard(allocator); @@ -629,9 +623,8 @@ void BasicMemoryQuota::MaybeMoveAllocatorBigToSmall( void BasicMemoryQuota::MaybeMoveAllocatorSmallToBig( GrpcMemoryAllocatorImpl* allocator) { - if (GRPC_TRACE_FLAG_ENABLED(resource_quota)) { - LOG(INFO) << "Moving allocator " << allocator << " to big"; - } + GRPC_TRACE_LOG(resource_quota, INFO) + << "Moving allocator " << allocator << " to big"; AllocatorBucket::Shard& old_shard = small_allocators_.SelectShard(allocator); diff --git a/src/core/lib/security/authorization/grpc_authorization_policy_provider.cc b/src/core/lib/security/authorization/grpc_authorization_policy_provider.cc index cefe2d6db37..4380e09086a 100644 --- a/src/core/lib/security/authorization/grpc_authorization_policy_provider.cc +++ b/src/core/lib/security/authorization/grpc_authorization_policy_provider.cc @@ -167,11 +167,10 @@ absl::Status FileWatcherAuthorizationPolicyProvider::ForceUpdate() { if (cb_ != nullptr) { cb_(contents_changed, absl::OkStatus()); } - if (GRPC_TRACE_FLAG_ENABLED(grpc_authz_api)) { - LOG(INFO) << "authorization policy reload status: successfully loaded new " - "policy\n" - << file_contents_; - } + GRPC_TRACE_LOG(grpc_authz_api, INFO) + << "authorization policy reload status: successfully loaded new " + "policy\n" + << file_contents_; return absl::OkStatus(); } diff --git a/src/core/lib/security/credentials/oauth2/oauth2_credentials.cc b/src/core/lib/security/credentials/oauth2/oauth2_credentials.cc index 014e53ee3cb..a0738bce008 100644 --- a/src/core/lib/security/credentials/oauth2/oauth2_credentials.cc +++ b/src/core/lib/security/credentials/oauth2/oauth2_credentials.cc @@ -511,11 +511,10 @@ grpc_call_credentials* grpc_google_refresh_token_credentials_create( const char* json_refresh_token, void* reserved) { grpc_auth_refresh_token token = grpc_auth_refresh_token_create_from_string(json_refresh_token); - if (GRPC_TRACE_FLAG_ENABLED(api)) { - LOG(INFO) << "grpc_refresh_token_credentials_create(json_refresh_token=" - << create_loggable_refresh_token(&token) - << ", reserved=" << reserved << ")"; - } + GRPC_TRACE_LOG(api, INFO) + << "grpc_refresh_token_credentials_create(json_refresh_token=" + << create_loggable_refresh_token(&token) << ", reserved=" << reserved + << ")"; CHECK_EQ(reserved, nullptr); return grpc_refresh_token_credentials_create_from_auth_refresh_token(token) .release(); diff --git a/src/core/lib/transport/bdp_estimator.cc b/src/core/lib/transport/bdp_estimator.cc index 6a49137f7e3..ed2176bea61 100644 --- a/src/core/lib/transport/bdp_estimator.cc +++ b/src/core/lib/transport/bdp_estimator.cc @@ -47,18 +47,16 @@ Timestamp BdpEstimator::CompletePing() { 1e-9 * static_cast(dt_ts.tv_nsec); double bw = dt > 0 ? (static_cast(accumulator_) / dt) : 0; Duration start_inter_ping_delay = inter_ping_delay_; - if (GRPC_TRACE_FLAG_ENABLED(bdp_estimator)) { - LOG(INFO) << "bdp[" << name_ << "]:complete acc=" << accumulator_ - << " est=" << estimate_ << " dt=" << dt << " bw=" << bw / 125000.0 - << "Mbs bw_est=" << bw_est_ / 125000.0 << "Mbs"; - } + GRPC_TRACE_LOG(bdp_estimator, INFO) + << "bdp[" << name_ << "]:complete acc=" << accumulator_ + << " est=" << estimate_ << " dt=" << dt << " bw=" << bw / 125000.0 + << "Mbs bw_est=" << bw_est_ / 125000.0 << "Mbs"; CHECK(ping_state_ == PingState::STARTED); if (accumulator_ > 2 * estimate_ / 3 && bw > bw_est_) { estimate_ = std::max(accumulator_, estimate_ * 2); bw_est_ = bw; - if (GRPC_TRACE_FLAG_ENABLED(bdp_estimator)) { - LOG(INFO) << "bdp[" << name_ << "]: estimate increased to " << estimate_; - } + GRPC_TRACE_LOG(bdp_estimator, INFO) + << "bdp[" << name_ << "]: estimate increased to " << estimate_; inter_ping_delay_ /= 2; // if the ping estimate changes, // exponentially get faster at probing } else if (inter_ping_delay_ < Duration::Seconds(10)) { diff --git a/src/core/lib/transport/call_filters.cc b/src/core/lib/transport/call_filters.cc index 7d0cadf0bc1..28619c214a7 100644 --- a/src/core/lib/transport/call_filters.cc +++ b/src/core/lib/transport/call_filters.cc @@ -200,11 +200,9 @@ void CallFilters::CancelDueToFailedPipeOperation(SourceLocation but_where) { void CallFilters::PushServerTrailingMetadata(ServerMetadataHandle md) { CHECK(md != nullptr); - if (GRPC_TRACE_FLAG_ENABLED(call)) { - LOG(INFO) << GetContext()->DebugTag() - << " PushServerTrailingMetadata[" << this - << "]: " << md->DebugString() << " into " << DebugString(); - } + GRPC_TRACE_LOG(call, INFO) + << GetContext()->DebugTag() << " PushServerTrailingMetadata[" + << this << "]: " << md->DebugString() << " into " << DebugString(); CHECK(md != nullptr); if (call_state_.PushServerTrailingMetadata( md->get(GrpcCallWasCancelled()).value_or(false))) {