diff --git a/src/core/ext/transport/chaotic_good/server_transport.cc b/src/core/ext/transport/chaotic_good/server_transport.cc index 67f1eca4ee698..6ffb6b7f0670d 100644 --- a/src/core/ext/transport/chaotic_good/server_transport.cc +++ b/src/core/ext/transport/chaotic_good/server_transport.cc @@ -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(), diff --git a/src/core/ext/transport/chttp2/transport/chttp2_transport.cc b/src/core/ext/transport/chttp2/transport/chttp2_transport.cc index 94d45f56637e2..d3c5d994c1d53 100644 --- a/src/core/ext/transport/chttp2/transport/chttp2_transport.cc +++ b/src/core/ext/transport/chttp2/transport/chttp2_transport.cc @@ -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 = @@ -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(); @@ -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); @@ -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) { @@ -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"); diff --git a/src/core/ext/transport/chttp2/transport/parsing.cc b/src/core/ext/transport/chttp2/transport/parsing.cc index 919e8473c685e..d8c1680c3b21c 100644 --- a/src/core/ext/transport/chttp2/transport/parsing.cc +++ b/src/core/ext/transport/chttp2/transport/parsing.cc @@ -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); diff --git a/src/core/ext/transport/chttp2/transport/writing.cc b/src/core/ext/transport/chttp2/transport/writing.cc index 029608120cc2b..29c3b67e82a90 100644 --- a/src/core/ext/transport/chttp2/transport/writing.cc +++ b/src/core/ext/transport/chttp2/transport/writing.cc @@ -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( - std::max(int64_t{0}, - s->flow_control.remote_window_delta() + - static_cast( - 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(std::max( + int64_t{0}, s->flow_control.remote_window_delta() + + static_cast( + t->settings.peer().initial_window_size()))) + << ":s_delta=" << s->flow_control.remote_window_delta() << "]"; } namespace { diff --git a/src/core/lib/channel/promise_based_filter.cc b/src/core/lib/channel/promise_based_filter.cc index e1253c702be15..5f0879dda27cf 100644 --- a/src/core/lib/channel/promise_based_filter.cc +++ b/src/core/lib/channel/promise_based_filter.cc @@ -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. @@ -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 && diff --git a/src/core/lib/event_engine/posix_engine/timer_manager.cc b/src/core/lib/event_engine/posix_engine/timer_manager.cc index 3ab3eb75f4c9b..8a0373cf86b1a 100644 --- a/src/core/lib/event_engine/posix_engine/timer_manager.cc +++ b/src/core/lib/event_engine/posix_engine/timer_manager.cc @@ -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(); } @@ -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(); }); diff --git a/src/core/lib/iomgr/cfstream_handle.cc b/src/core/lib/iomgr/cfstream_handle.cc index de9810ad2c823..55604791a7bd0 100644 --- a/src/core/lib/iomgr/cfstream_handle.cc +++ b/src/core/lib/iomgr/cfstream_handle.cc @@ -65,10 +65,9 @@ void CFStreamHandle::ReadCallback(CFReadStreamRef stream, grpc_error_handle error; CFErrorRef stream_error; CFStreamHandle* handle = static_cast(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(); @@ -99,10 +98,9 @@ void CFStreamHandle::WriteCallback(CFWriteStreamRef stream, grpc_error_handle error; CFErrorRef stream_error; CFStreamHandle* handle = static_cast(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(); diff --git a/src/core/lib/iomgr/closure.h b/src/core/lib/iomgr/closure.h index bebdb41a0a4d8..9f8a22493d317 100644 --- a/src/core/lib/iomgr/closure.h +++ b/src/core/lib/iomgr/closure.h @@ -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 } }; diff --git a/src/core/lib/iomgr/combiner.cc b/src/core/lib/iomgr/combiner.cc index 7032c40f768b2..56db07f562758 100644 --- a/src/core/lib/iomgr/combiner.cc +++ b/src/core/lib/iomgr/combiner.cc @@ -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 diff --git a/src/core/lib/iomgr/endpoint_cfstream.cc b/src/core/lib/iomgr/endpoint_cfstream.cc index dbe123a554e4f..c542c6ae6bc0a 100644 --- a/src/core/lib/iomgr/endpoint_cfstream.cc +++ b/src/core/lib/iomgr/endpoint_cfstream.cc @@ -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; @@ -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(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; @@ -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(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; @@ -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; diff --git a/src/core/lib/iomgr/ev_epoll1_linux.cc b/src/core/lib/iomgr/ev_epoll1_linux.cc index f3c4ad1decf67..c2c60e9663a4b 100644 --- a/src/core/lib/iomgr/ev_epoll1_linux.cc +++ b/src/core/lib/iomgr/ev_epoll1_linux.cc @@ -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; diff --git a/src/core/lib/iomgr/ev_poll_posix.cc b/src/core/lib/iomgr/ev_poll_posix.cc index a2e8e7a083e53..a95adea7c856c 100644 --- a/src/core/lib/iomgr/ev_poll_posix.cc +++ b/src/core/lib/iomgr/ev_poll_posix.cc @@ -332,12 +332,11 @@ static void fork_fd_list_add_wakeup_fd(grpc_cached_wakeup_fd* fd) { #define UNREF_BY(fd, n, reason) unref_by(fd, n, reason, __FILE__, __LINE__) static void ref_by(grpc_fd* fd, int n, const char* reason, const char* file, int line) { - if (GRPC_TRACE_FLAG_ENABLED(fd_refcount)) { - VLOG(2) << "FD " << fd->fd << " " << fd << " ref " << n << " " - << gpr_atm_no_barrier_load(&fd->refst) << " -> " - << gpr_atm_no_barrier_load(&fd->refst) + n << " [" << reason << "; " - << file << ":" << line << "]"; - } + GRPC_TRACE_VLOG(fd_refcount, 2) + << "FD " << fd->fd << " " << fd << " ref " << n << " " + << gpr_atm_no_barrier_load(&fd->refst) << " -> " + << gpr_atm_no_barrier_load(&fd->refst) + n << " [" << reason << "; " + << file << ":" << line << "]"; #else #define REF_BY(fd, n, reason) \ do { \ @@ -357,12 +356,11 @@ static void ref_by(grpc_fd* fd, int n) { #ifndef NDEBUG static void unref_by(grpc_fd* fd, int n, const char* reason, const char* file, int line) { - if (GRPC_TRACE_FLAG_ENABLED(fd_refcount)) { - VLOG(2) << "FD " << fd->fd << " " << fd << " unref " << n << " " - << gpr_atm_no_barrier_load(&fd->refst) << " -> " - << gpr_atm_no_barrier_load(&fd->refst) - n << " [" << reason << "; " - << file << ":" << line << "]"; - } + GRPC_TRACE_VLOG(fd_refcount, 2) + << "FD " << fd->fd << " " << fd << " unref " << n << " " + << gpr_atm_no_barrier_load(&fd->refst) << " -> " + << gpr_atm_no_barrier_load(&fd->refst) - n << " [" << reason << "; " + << file << ":" << line << "]"; #else static void unref_by(grpc_fd* fd, int n) { #endif diff --git a/src/core/lib/iomgr/event_engine_shims/closure.cc b/src/core/lib/iomgr/event_engine_shims/closure.cc index e38b295bbaff1..8a362210b805d 100644 --- a/src/core/lib/iomgr/event_engine_shims/closure.cc +++ b/src/core/lib/iomgr/event_engine_shims/closure.cc @@ -35,18 +35,16 @@ void RunEventEngineClosure(grpc_closure* closure, grpc_error_handle error) { grpc_core::ExecCtx exec_ctx; #ifndef NDEBUG closure->scheduled = false; - if (GRPC_TRACE_FLAG_ENABLED(closure)) { - VLOG(2) << "EventEngine: running closure " << closure << ": created [" - << closure->file_created << ":" << closure->line_created - << "]: " << (closure->run ? "run" : "scheduled") << " [" - << closure->file_initiated << ":" << closure->line_initiated << "]"; - } + GRPC_TRACE_VLOG(closure, 2) + << "EventEngine: running closure " << closure << ": created [" + << closure->file_created << ":" << closure->line_created + << "]: " << (closure->run ? "run" : "scheduled") << " [" + << closure->file_initiated << ":" << closure->line_initiated << "]"; #endif closure->cb(closure->cb_arg, error); #ifndef NDEBUG - if (GRPC_TRACE_FLAG_ENABLED(closure)) { - VLOG(2) << "EventEngine: closure " << closure << " finished"; - } + GRPC_TRACE_VLOG(closure, 2) + << "EventEngine: closure " << closure << " finished"; #endif } diff --git a/src/core/lib/iomgr/exec_ctx.cc b/src/core/lib/iomgr/exec_ctx.cc index 0a3ae056eb87f..804ae6f64948d 100644 --- a/src/core/lib/iomgr/exec_ctx.cc +++ b/src/core/lib/iomgr/exec_ctx.cc @@ -32,21 +32,18 @@ static void exec_ctx_run(grpc_closure* closure) { #ifndef NDEBUG closure->scheduled = false; - if (GRPC_TRACE_FLAG_ENABLED(closure)) { - VLOG(2) << "running closure " << closure << ": created [" - << closure->file_created << ":" << closure->line_created - << "]: " << (closure->run ? "run" : "scheduled") << " [" - << closure->file_initiated << ":" << closure->line_initiated << "]"; - } + GRPC_TRACE_VLOG(closure, 2) + << "running closure " << closure << ": created [" << closure->file_created + << ":" << closure->line_created + << "]: " << (closure->run ? "run" : "scheduled") << " [" + << closure->file_initiated << ":" << closure->line_initiated << "]"; #endif grpc_error_handle error = grpc_core::internal::StatusMoveFromHeapPtr(closure->error_data.error); closure->error_data.error = 0; closure->cb(closure->cb_arg, std::move(error)); #ifndef NDEBUG - if (GRPC_TRACE_FLAG_ENABLED(closure)) { - VLOG(2) << "closure " << closure << " finished"; - } + GRPC_TRACE_VLOG(closure, 2) << "closure " << closure << " finished"; #endif } diff --git a/src/core/lib/iomgr/lockfree_event.cc b/src/core/lib/iomgr/lockfree_event.cc index ab4f563979608..51e46ab9764d2 100644 --- a/src/core/lib/iomgr/lockfree_event.cc +++ b/src/core/lib/iomgr/lockfree_event.cc @@ -95,10 +95,8 @@ void LockfreeEvent::NotifyOn(grpc_closure* closure) { // sure that the shutdown error has been initialized properly before us // referencing it. gpr_atm curr = gpr_atm_acq_load(&state_); - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - VLOG(2) << "LockfreeEvent::NotifyOn: " << this << " curr=" << curr - << " closure=" << closure; - } + GRPC_TRACE_VLOG(polling, 2) << "LockfreeEvent::NotifyOn: " << this + << " curr=" << curr << " closure=" << closure; switch (curr) { case kClosureNotReady: { // kClosureNotReady -> . @@ -163,10 +161,9 @@ bool LockfreeEvent::SetShutdown(grpc_error_handle shutdown_error) { while (true) { gpr_atm curr = gpr_atm_no_barrier_load(&state_); - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - VLOG(2) << "LockfreeEvent::SetShutdown: " << &state_ << " curr=" << curr - << " err=" << StatusToString(shutdown_error); - } + GRPC_TRACE_VLOG(polling, 2) + << "LockfreeEvent::SetShutdown: " << &state_ << " curr=" << curr + << " err=" << StatusToString(shutdown_error); switch (curr) { case kClosureReady: case kClosureNotReady: @@ -212,9 +209,8 @@ void LockfreeEvent::SetReady() { while (true) { gpr_atm curr = gpr_atm_no_barrier_load(&state_); - if (GRPC_TRACE_FLAG_ENABLED(polling)) { - VLOG(2) << "LockfreeEvent::SetReady: " << &state_ << " curr=" << curr; - } + GRPC_TRACE_VLOG(polling, 2) + << "LockfreeEvent::SetReady: " << &state_ << " curr=" << curr; switch (curr) { case kClosureReady: { diff --git a/src/core/lib/iomgr/tcp_client_cfstream.cc b/src/core/lib/iomgr/tcp_client_cfstream.cc index 06c6a6fb4863c..f3228ad20ca38 100644 --- a/src/core/lib/iomgr/tcp_client_cfstream.cc +++ b/src/core/lib/iomgr/tcp_client_cfstream.cc @@ -78,10 +78,8 @@ static void CFStreamConnectCleanup(CFStreamConnect* connect) { static void OnAlarm(void* arg, grpc_error_handle error) { CFStreamConnect* connect = static_cast(arg); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - VLOG(2) << "CLIENT_CONNECT :" << connect - << " OnAlarm, error:" << grpc_core::StatusToString(error); - } + GRPC_TRACE_VLOG(tcp, 2) << "CLIENT_CONNECT :" << connect << " OnAlarm, error:" + << grpc_core::StatusToString(error); gpr_mu_lock(&connect->mu); grpc_closure* closure = connect->closure; connect->closure = nil; @@ -99,10 +97,8 @@ static void OnAlarm(void* arg, grpc_error_handle error) { static void OnOpen(void* arg, grpc_error_handle error) { CFStreamConnect* connect = static_cast(arg); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - VLOG(2) << "CLIENT_CONNECT :" << connect - << " OnOpen, error:" << grpc_core::StatusToString(error); - } + GRPC_TRACE_VLOG(tcp, 2) << "CLIENT_CONNECT :" << connect << " OnOpen, error:" + << grpc_core::StatusToString(error); gpr_mu_lock(&connect->mu); grpc_timer_cancel(&connect->alarm); grpc_closure* closure = connect->closure; @@ -173,10 +169,9 @@ static int64_t CFStreamClientConnect( gpr_ref_init(&connect->refcount, 1); gpr_mu_init(&connect->mu); - if (GRPC_TRACE_FLAG_ENABLED(tcp)) { - VLOG(2) << "CLIENT_CONNECT: " << connect << ", " << connect->addr_name - << ": asynchronously connecting"; - } + GRPC_TRACE_VLOG(tcp, 2) << "CLIENT_CONNECT: " << connect << ", " + << connect->addr_name + << ": asynchronously connecting"; CFReadStreamRef read_stream; CFWriteStreamRef write_stream; diff --git a/src/core/lib/iomgr/timer_generic.cc b/src/core/lib/iomgr/timer_generic.cc index f931658c6700f..7b1c9d205c266 100644 --- a/src/core/lib/iomgr/timer_generic.cc +++ b/src/core/lib/iomgr/timer_generic.cc @@ -334,12 +334,11 @@ static void timer_init(grpc_timer* timer, grpc_core::Timestamp deadline, timer->hash_table_next = nullptr; #endif - if (GRPC_TRACE_FLAG_ENABLED(timer)) { - VLOG(2) << "TIMER " << timer << ": SET " - << deadline.milliseconds_after_process_epoch() << " now " - << grpc_core::Timestamp::Now().milliseconds_after_process_epoch() - << " call " << closure << "[" << closure->cb << "]"; - } + GRPC_TRACE_VLOG(timer, 2) + << "TIMER " << timer << ": SET " + << deadline.milliseconds_after_process_epoch() << " now " + << grpc_core::Timestamp::Now().milliseconds_after_process_epoch() + << " call " << closure << "[" << closure->cb << "]"; if (!g_shared_mutables.initialized) { timer->pending = false; @@ -370,12 +369,11 @@ static void timer_init(grpc_timer* timer, grpc_core::Timestamp deadline, timer->heap_index = INVALID_HEAP_INDEX; list_join(&shard->list, timer); } - if (GRPC_TRACE_FLAG_ENABLED(timer)) { - VLOG(2) << " .. add to shard " << (shard - g_shards) - << " with queue_deadline_cap=" - << shard->queue_deadline_cap.milliseconds_after_process_epoch() - << " => is_first_timer=" << (is_first_timer ? "true" : "false"); - } + GRPC_TRACE_VLOG(timer, 2) + << " .. add to shard " << (shard - g_shards) + << " with queue_deadline_cap=" + << shard->queue_deadline_cap.milliseconds_after_process_epoch() + << " => is_first_timer=" << (is_first_timer ? "true" : "false"); gpr_mu_unlock(&shard->mu); // Deadline may have decreased, we need to adjust the main queue. Note @@ -391,10 +389,9 @@ static void timer_init(grpc_timer* timer, grpc_core::Timestamp deadline, // grpc_timer_check. if (is_first_timer) { gpr_mu_lock(&g_shared_mutables.mu); - if (GRPC_TRACE_FLAG_ENABLED(timer)) { - VLOG(2) << " .. old shard min_deadline=" - << shard->min_deadline.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer, 2) + << " .. old shard min_deadline=" + << shard->min_deadline.milliseconds_after_process_epoch(); if (deadline < shard->min_deadline) { grpc_core::Timestamp old_min_deadline = g_shard_queue[0]->min_deadline; shard->min_deadline = deadline; @@ -433,10 +430,9 @@ static void timer_cancel(grpc_timer* timer) { timer_shard* shard = &g_shards[grpc_core::HashPointer(timer, g_num_shards)]; gpr_mu_lock(&shard->mu); - if (GRPC_TRACE_FLAG_ENABLED(timer)) { - VLOG(2) << "TIMER " << timer - << ": CANCEL pending=" << (timer->pending ? "true" : "false"); - } + GRPC_TRACE_VLOG(timer, 2) + << "TIMER " << timer + << ": CANCEL pending=" << (timer->pending ? "true" : "false"); if (timer->pending) { REMOVE_FROM_HASH_TABLE(timer); @@ -474,11 +470,9 @@ static bool refill_heap(timer_shard* shard, grpc_core::Timestamp now) { std::max(now, shard->queue_deadline_cap) + grpc_core::Duration::FromSecondsAsDouble(deadline_delta); - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << " .. shard[" << (shard - g_shards) - << "]->queue_deadline_cap --> " - << shard->queue_deadline_cap.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. shard[" << (shard - g_shards) << "]->queue_deadline_cap --> " + << shard->queue_deadline_cap.milliseconds_after_process_epoch(); for (timer = shard->list.next; timer != &shard->list; timer = next) { next = timer->next; auto timer_deadline = @@ -486,11 +480,9 @@ static bool refill_heap(timer_shard* shard, grpc_core::Timestamp now) { timer->deadline); if (timer_deadline < shard->queue_deadline_cap) { - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << " .. add timer with deadline " - << timer_deadline.milliseconds_after_process_epoch() - << " to heap"; - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. add timer with deadline " + << timer_deadline.milliseconds_after_process_epoch() << " to heap"; list_remove(timer); grpc_timer_heap_add(&shard->heap, timer); } @@ -504,10 +496,9 @@ static bool refill_heap(timer_shard* shard, grpc_core::Timestamp now) { static grpc_timer* pop_one(timer_shard* shard, grpc_core::Timestamp now) { grpc_timer* timer; for (;;) { - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << " .. shard[" << (shard - g_shards) << "]: heap_empty=" - << (grpc_timer_heap_is_empty(&shard->heap) ? "true" : "false"); - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. shard[" << (shard - g_shards) << "]: heap_empty=" + << (grpc_timer_heap_is_empty(&shard->heap) ? "true" : "false"); if (grpc_timer_heap_is_empty(&shard->heap)) { if (now < shard->queue_deadline_cap) return nullptr; if (!refill_heap(shard, now)) return nullptr; @@ -516,16 +507,13 @@ static grpc_timer* pop_one(timer_shard* shard, grpc_core::Timestamp now) { auto timer_deadline = grpc_core::Timestamp::FromMillisecondsAfterProcessEpoch( timer->deadline); - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << " .. check top timer deadline=" - << timer_deadline.milliseconds_after_process_epoch() - << " now=" << now.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. check top timer deadline=" + << timer_deadline.milliseconds_after_process_epoch() + << " now=" << now.milliseconds_after_process_epoch(); if (timer_deadline > now) return nullptr; - if (GRPC_TRACE_FLAG_ENABLED(timer)) { - VLOG(2) << "TIMER " << timer << ": FIRE " - << (now - timer_deadline).millis() << "ms late"; - } + GRPC_TRACE_VLOG(timer, 2) << "TIMER " << timer << ": FIRE " + << (now - timer_deadline).millis() << "ms late"; timer->pending = false; grpc_timer_heap_pop(&shard->heap); return timer; @@ -546,9 +534,8 @@ static size_t pop_timers(timer_shard* shard, grpc_core::Timestamp now, } *new_min_deadline = compute_min_deadline(shard); gpr_mu_unlock(&shard->mu); - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << " .. shard[" << (shard - g_shards) << "] popped " << n; - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. shard[" << (shard - g_shards) << "] popped " << n; return n; } @@ -584,12 +571,10 @@ static grpc_timer_check_result run_some_expired_timers( gpr_mu_lock(&g_shared_mutables.mu); result = GRPC_TIMERS_CHECKED_AND_EMPTY; - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) - << " .. shard[" << (g_shard_queue[0] - g_shards) - << "]->min_deadline = " - << g_shard_queue[0]->min_deadline.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. shard[" << (g_shard_queue[0] - g_shards) + << "]->min_deadline = " + << g_shard_queue[0]->min_deadline.milliseconds_after_process_epoch(); while (g_shard_queue[0]->min_deadline < now || (now != grpc_core::Timestamp::InfFuture() && @@ -603,14 +588,12 @@ static grpc_timer_check_result run_some_expired_timers( result = GRPC_TIMERS_FIRED; } - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) - << " .. result --> " << result << ", shard[" - << (g_shard_queue[0] - g_shards) << "]->min_deadline " - << g_shard_queue[0]->min_deadline.milliseconds_after_process_epoch() - << " --> " << new_min_deadline.milliseconds_after_process_epoch() - << ", now=" << now.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer_check, 2) + << " .. result --> " << result << ", shard[" + << (g_shard_queue[0] - g_shards) << "]->min_deadline " + << g_shard_queue[0]->min_deadline.milliseconds_after_process_epoch() + << " --> " << new_min_deadline.milliseconds_after_process_epoch() + << ", now=" << now.milliseconds_after_process_epoch(); // An grpc_timer_init() on the shard could intervene here, adding a new // timer that is earlier than new_min_deadline. However, @@ -660,11 +643,9 @@ static grpc_timer_check_result timer_check(grpc_core::Timestamp* next) { if (next != nullptr) { *next = std::min(*next, min_timer); } - if (GRPC_TRACE_FLAG_ENABLED(timer_check)) { - VLOG(2) << "TIMER CHECK SKIP: now=" - << now.milliseconds_after_process_epoch() - << " min_timer=" << min_timer.milliseconds_after_process_epoch(); - } + GRPC_TRACE_VLOG(timer_check, 2) + << "TIMER CHECK SKIP: now=" << now.milliseconds_after_process_epoch() + << " min_timer=" << min_timer.milliseconds_after_process_epoch(); return GRPC_TIMERS_CHECKED_AND_EMPTY; } diff --git a/src/core/lib/promise/interceptor_list.h b/src/core/lib/promise/interceptor_list.h index dc36c2ee289c8..a47a75bc97af3 100644 --- a/src/core/lib/promise/interceptor_list.h +++ b/src/core/lib/promise/interceptor_list.h @@ -87,10 +87,8 @@ class InterceptorList { public: RunPromise(size_t memory_required, Map** factory, absl::optional value) { if (!value.has_value() || *factory == nullptr) { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this - << "]: create immediate"; - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this << "]: create immediate"; is_immediately_resolved_ = true; Construct(&result_, std::move(value)); } else { @@ -100,17 +98,15 @@ class InterceptorList { async_resolution_.space.get()); async_resolution_.current_factory = *factory; async_resolution_.first_factory = factory; - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this - << "]: create async; mem=" << async_resolution_.space.get(); - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this + << "]: create async; mem=" << async_resolution_.space.get(); } } ~RunPromise() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this << "]: destroy"; - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this << "]: destroy"; if (is_immediately_resolved_) { Destruct(&result_); } else { @@ -127,10 +123,9 @@ class InterceptorList { RunPromise(RunPromise&& other) noexcept : is_immediately_resolved_(other.is_immediately_resolved_) { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this << "]: move from " - << &other; - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this << "]: move from " + << &other; if (is_immediately_resolved_) { Construct(&result_, std::move(other.result_)); } else { @@ -141,10 +136,8 @@ class InterceptorList { RunPromise& operator=(RunPromise&& other) noexcept = delete; Poll> operator()() { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this - << "]: " << DebugString(); - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this << "]: " << DebugString(); if (is_immediately_resolved_) return std::move(result_); while (true) { if (*async_resolution_.first_factory == nullptr) { @@ -159,10 +152,9 @@ class InterceptorList { async_resolution_.current_factory = async_resolution_.current_factory->next(); if (!p->has_value()) async_resolution_.current_factory = nullptr; - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << "InterceptorList::RunPromise[" << this - << "]: " << DebugString(); - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << "InterceptorList::RunPromise[" << this + << "]: " << DebugString(); if (async_resolution_.current_factory == nullptr) { return std::move(*p); } diff --git a/src/core/lib/promise/pipe.h b/src/core/lib/promise/pipe.h index 86f0b98d8ef73..59ec003f47de8 100644 --- a/src/core/lib/promise/pipe.h +++ b/src/core/lib/promise/pipe.h @@ -634,10 +634,9 @@ class Push { Poll operator()() { if (center_ == nullptr) { - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2) << GetContext()->DebugTag() - << " Pipe push has a null center"; - } + GRPC_TRACE_VLOG(promise_primitives, 2) + << GetContext()->DebugTag() + << " Pipe push has a null center"; return false; } if (auto* p = absl::get_if(&state_)) { diff --git a/src/core/lib/security/authorization/grpc_server_authz_filter.cc b/src/core/lib/security/authorization/grpc_server_authz_filter.cc index c83d1cc50a7fd..672b02a9d9127 100644 --- a/src/core/lib/security/authorization/grpc_server_authz_filter.cc +++ b/src/core/lib/security/authorization/grpc_server_authz_filter.cc @@ -64,13 +64,12 @@ GrpcServerAuthzFilter::Create(const ChannelArgs& args, ChannelFilter::Args) { bool GrpcServerAuthzFilter::IsAuthorized(ClientMetadata& initial_metadata) { EvaluateArgs args(&initial_metadata, &per_channel_evaluate_args_); - if (GRPC_TRACE_FLAG_ENABLED(grpc_authz_api)) { - VLOG(2) << "checking request: url_path=" << args.GetPath() - << ", transport_security_type=" << args.GetTransportSecurityType() - << ", uri_sans=[" << absl::StrJoin(args.GetUriSans(), ",") - << "], dns_sans=[" << absl::StrJoin(args.GetDnsSans(), ",") - << "], subject=" << args.GetSubject(); - } + GRPC_TRACE_VLOG(grpc_authz_api, 2) + << "checking request: url_path=" << args.GetPath() + << ", transport_security_type=" << args.GetTransportSecurityType() + << ", uri_sans=[" << absl::StrJoin(args.GetUriSans(), ",") + << "], dns_sans=[" << absl::StrJoin(args.GetDnsSans(), ",") + << "], subject=" << args.GetSubject(); grpc_authorization_policy_provider::AuthorizationEngines engines = provider_->engines(); if (engines.deny_engine != nullptr) { @@ -87,10 +86,9 @@ bool GrpcServerAuthzFilter::IsAuthorized(ClientMetadata& initial_metadata) { AuthorizationEngine::Decision decision = engines.allow_engine->Evaluate(args); if (decision.type == AuthorizationEngine::Decision::Type::kAllow) { - if (GRPC_TRACE_FLAG_ENABLED(grpc_authz_api)) { - VLOG(2) << "chand=" << this << ": request allowed by policy " - << decision.matching_policy_name; - } + GRPC_TRACE_VLOG(grpc_authz_api, 2) + << "chand=" << this << ": request allowed by policy " + << decision.matching_policy_name; return true; } } diff --git a/src/core/lib/transport/call_filters.cc b/src/core/lib/transport/call_filters.cc index 28619c214a702..0e378a86d0457 100644 --- a/src/core/lib/transport/call_filters.cc +++ b/src/core/lib/transport/call_filters.cc @@ -188,10 +188,9 @@ void CallFilters::Finalize(const grpc_call_final_info* final_info) { void CallFilters::CancelDueToFailedPipeOperation(SourceLocation but_where) { // We expect something cancelled before now if (push_server_trailing_metadata_ == nullptr) return; - if (GRPC_TRACE_FLAG_ENABLED(promise_primitives)) { - VLOG(2).AtLocation(but_where.file(), but_where.line()) - << "Cancelling due to failed pipe operation: " << DebugString(); - } + GRPC_TRACE_VLOG(promise_primitives, 2) + .AtLocation(but_where.file(), but_where.line()) + << "Cancelling due to failed pipe operation: " << DebugString(); auto status = ServerMetadataFromStatus(GRPC_STATUS_CANCELLED, "Failed pipe operation"); status->Set(GrpcCallWasCancelled(), true); diff --git a/src/core/lib/transport/transport.h b/src/core/lib/transport/transport.h index fa32ce2aed406..4c16314558cf9 100644 --- a/src/core/lib/transport/transport.h +++ b/src/core/lib/transport/transport.h @@ -190,10 +190,9 @@ void grpc_stream_ref_init(grpc_stream_refcount* refcount, int initial_refs, #ifndef NDEBUG inline void grpc_stream_ref(grpc_stream_refcount* refcount, const char* reason) { - if (GRPC_TRACE_FLAG_ENABLED(stream_refcount)) { - VLOG(2) << refcount->object_type << " " << refcount << ":" - << refcount->destroy.cb_arg << " REF " << reason; - } + GRPC_TRACE_VLOG(stream_refcount, 2) + << refcount->object_type << " " << refcount << ":" + << refcount->destroy.cb_arg << " REF " << reason; refcount->refs.RefNonZero(DEBUG_LOCATION, reason); } #else @@ -207,10 +206,9 @@ void grpc_stream_destroy(grpc_stream_refcount* refcount); #ifndef NDEBUG inline void grpc_stream_unref(grpc_stream_refcount* refcount, const char* reason) { - if (GRPC_TRACE_FLAG_ENABLED(stream_refcount)) { - VLOG(2) << refcount->object_type << " " << refcount << ":" - << refcount->destroy.cb_arg << " UNREF " << reason; - } + GRPC_TRACE_VLOG(stream_refcount, 2) + << refcount->object_type << " " << refcount << ":" + << refcount->destroy.cb_arg << " UNREF " << reason; if (GPR_UNLIKELY(refcount->refs.Unref(DEBUG_LOCATION, reason))) { grpc_stream_destroy(refcount); } diff --git a/src/core/load_balancing/grpclb/grpclb.cc b/src/core/load_balancing/grpclb/grpclb.cc index af895a97241e9..d91812d95988d 100644 --- a/src/core/load_balancing/grpclb/grpclb.cc +++ b/src/core/load_balancing/grpclb/grpclb.cc @@ -851,14 +851,12 @@ void GrpcLb::Helper::UpdateState(grpc_connectivity_state state, parent()->lb_calld_->client_stats() != nullptr) { client_stats = parent()->lb_calld_->client_stats()->Ref(); } - if (GRPC_TRACE_FLAG_ENABLED(glb)) { - GRPC_TRACE_LOG(glb, INFO) - << "[grpclb " << parent() << " helper " << this - << "] state=" << ConnectivityStateName(state) << " (" - << status.ToString() << ") wrapping child picker " << picker.get() - << " (serverlist=" << serverlist.get() - << ", client_stats=" << client_stats.get() << ")"; - } + GRPC_TRACE_LOG(glb, INFO) + << "[grpclb " << parent() << " helper " << this + << "] state=" << ConnectivityStateName(state) << " (" << status.ToString() + << ") wrapping child picker " << picker.get() + << " (serverlist=" << serverlist.get() + << ", client_stats=" << client_stats.get() << ")"; parent()->channel_control_helper()->UpdateState( state, status, MakeRefCounted(std::move(serverlist), std::move(picker), diff --git a/src/core/load_balancing/pick_first/pick_first.cc b/src/core/load_balancing/pick_first/pick_first.cc index f3280a9c9d8f9..c63424cada4bc 100644 --- a/src/core/load_balancing/pick_first/pick_first.cc +++ b/src/core/load_balancing/pick_first/pick_first.cc @@ -790,22 +790,21 @@ PickFirst::SubchannelList::SubchannelData::SubchannelData( void PickFirst::SubchannelList::SubchannelData::OnConnectivityStateChange( grpc_connectivity_state new_state, absl::Status status) { PickFirst* p = subchannel_list_->policy_.get(); - if (GRPC_TRACE_FLAG_ENABLED(pick_first)) { - LOG(INFO) << "[PF " << p << "] subchannel list " << subchannel_list_ - << " index " << index_ << " of " << subchannel_list_->size() - << " (subchannel_state " << subchannel_state_.get() - << "): connectivity changed: old_state=" - << (connectivity_state_.has_value() - ? ConnectivityStateName(*connectivity_state_) - : "N/A") - << ", new_state=" << ConnectivityStateName(new_state) - << ", status=" << status - << ", seen_transient_failure=" << seen_transient_failure_ - << ", p->selected_=" << p->selected_.get() - << ", p->subchannel_list_=" << p->subchannel_list_.get() - << ", p->subchannel_list_->shutting_down_=" - << p->subchannel_list_->shutting_down_; - } + GRPC_TRACE_LOG(pick_first, INFO) + << "[PF " << p << "] subchannel list " << subchannel_list_ << " index " + << index_ << " of " << subchannel_list_->size() << " (subchannel_state " + << subchannel_state_.get() << "): connectivity changed: old_state=" + << (connectivity_state_.has_value() + ? ConnectivityStateName(*connectivity_state_) + : "N/A") + << ", new_state=" << ConnectivityStateName(new_state) + << ", status=" << status + << ", seen_transient_failure=" << seen_transient_failure_ + << ", p->selected_=" << p->selected_.get() + << ", p->subchannel_list_=" << p->subchannel_list_.get() + << ", p->subchannel_list_->shutting_down_=" + << p->subchannel_list_->shutting_down_; + if (subchannel_list_->shutting_down_) return; // The notification must be for a subchannel in the current list. CHECK(subchannel_list_ == p->subchannel_list_.get()); @@ -1596,24 +1595,23 @@ void OldPickFirst::SubchannelList::SubchannelData::ShutdownLocked() { void OldPickFirst::SubchannelList::SubchannelData::OnConnectivityStateChange( grpc_connectivity_state new_state, absl::Status status) { OldPickFirst* p = subchannel_list_->policy_.get(); - if (GRPC_TRACE_FLAG_ENABLED(pick_first)) { - LOG(INFO) << "[PF " << p << "] subchannel list " << subchannel_list_ - << " index " << index_ << " of " << subchannel_list_->size() - << " (subchannel " << subchannel_.get() - << "): connectivity changed: old_state=" - << (connectivity_state_.has_value() - ? ConnectivityStateName(*connectivity_state_) - : "N/A") - << ", new_state=" << ConnectivityStateName(new_state) - << ", status=" << status - << ", shutting_down=" << subchannel_list_->shutting_down_ - << ", pending_watcher=" << pending_watcher_ - << ", seen_transient_failure=" << seen_transient_failure_ - << ", p->selected_=" << p->selected_ - << ", p->subchannel_list_=" << p->subchannel_list_.get() - << ", p->latest_pending_subchannel_list_=" - << p->latest_pending_subchannel_list_.get(); - } + GRPC_TRACE_LOG(pick_first, INFO) + << "[PF " << p << "] subchannel list " << subchannel_list_ << " index " + << index_ << " of " << subchannel_list_->size() << " (subchannel " + << subchannel_.get() << "): connectivity changed: old_state=" + << (connectivity_state_.has_value() + ? ConnectivityStateName(*connectivity_state_) + : "N/A") + << ", new_state=" << ConnectivityStateName(new_state) + << ", status=" << status + << ", shutting_down=" << subchannel_list_->shutting_down_ + << ", pending_watcher=" << pending_watcher_ + << ", seen_transient_failure=" << seen_transient_failure_ + << ", p->selected_=" << p->selected_ + << ", p->subchannel_list_=" << p->subchannel_list_.get() + << ", p->latest_pending_subchannel_list_=" + << p->latest_pending_subchannel_list_.get(); + if (subchannel_list_->shutting_down_ || pending_watcher_ == nullptr) return; auto& stats_plugins = subchannel_list_->policy_->channel_control_helper() ->GetStatsPluginGroup(); diff --git a/src/core/resolver/dns/native/dns_resolver.cc b/src/core/resolver/dns/native/dns_resolver.cc index 0fb59889d06d9..1a3ca55f9b054 100644 --- a/src/core/resolver/dns/native/dns_resolver.cc +++ b/src/core/resolver/dns/native/dns_resolver.cc @@ -90,15 +90,11 @@ NativeClientChannelDNSResolver::NativeClientChannelDNSResolver( .set_max_backoff(Duration::Milliseconds( GRPC_DNS_RECONNECT_MAX_BACKOFF_SECONDS * 1000)), &dns_resolver_trace) { - if (GRPC_TRACE_FLAG_ENABLED(dns_resolver)) { - VLOG(2) << "[dns_resolver=" << this << "] created"; - } + GRPC_TRACE_VLOG(dns_resolver, 2) << "[dns_resolver=" << this << "] created"; } NativeClientChannelDNSResolver::~NativeClientChannelDNSResolver() { - if (GRPC_TRACE_FLAG_ENABLED(dns_resolver)) { - VLOG(2) << "[dns_resolver=" << this << "] destroyed"; - } + GRPC_TRACE_VLOG(dns_resolver, 2) << "[dns_resolver=" << this << "] destroyed"; } OrphanablePtr NativeClientChannelDNSResolver::StartRequest() { @@ -107,19 +103,17 @@ OrphanablePtr NativeClientChannelDNSResolver::StartRequest() { absl::bind_front(&NativeClientChannelDNSResolver::OnResolved, this), name_to_resolve(), kDefaultSecurePort, kDefaultDNSRequestTimeout, interested_parties(), /*name_server=*/""); - if (GRPC_TRACE_FLAG_ENABLED(dns_resolver)) { - VLOG(2) << "[dns_resolver=" << this << "] starting request=" - << DNSResolver::HandleToString(dns_request_handle); - } + GRPC_TRACE_VLOG(dns_resolver, 2) + << "[dns_resolver=" << this << "] starting request=" + << DNSResolver::HandleToString(dns_request_handle); return MakeOrphanable(); } void NativeClientChannelDNSResolver::OnResolved( absl::StatusOr> addresses_or) { - if (GRPC_TRACE_FLAG_ENABLED(dns_resolver)) { - VLOG(2) << "[dns_resolver=" << this - << "] request complete, status=" << addresses_or.status(); - } + GRPC_TRACE_VLOG(dns_resolver, 2) + << "[dns_resolver=" << this + << "] request complete, status=" << addresses_or.status(); // Convert result from iomgr DNS API into Resolver::Result. Result result; if (addresses_or.ok()) { diff --git a/src/core/util/http_client/parser.cc b/src/core/util/http_client/parser.cc index 5e905ce3acdad..b0c7416c6c9b2 100644 --- a/src/core/util/http_client/parser.cc +++ b/src/core/util/http_client/parser.cc @@ -376,10 +376,9 @@ static grpc_error_handle addbyte(grpc_http_parser* parser, uint8_t byte, case GRPC_HTTP_HEADERS: case GRPC_HTTP_TRAILERS: if (parser->cur_line_length >= GRPC_HTTP_PARSER_MAX_HEADER_LENGTH) { - if (GRPC_TRACE_FLAG_ENABLED(http1)) { - LOG(ERROR) << "HTTP header max line length (" - << GRPC_HTTP_PARSER_MAX_HEADER_LENGTH << ") exceeded"; - } + GRPC_TRACE_LOG(http1, ERROR) + << "HTTP header max line length (" + << GRPC_HTTP_PARSER_MAX_HEADER_LENGTH << ") exceeded"; return GRPC_ERROR_CREATE("HTTP header max line length exceeded"); } parser->cur_line[parser->cur_line_length] = byte; diff --git a/src/cpp/ext/gcp/environment_autodetect.cc b/src/cpp/ext/gcp/environment_autodetect.cc index ceee1c249bd12..90e958c55b270 100644 --- a/src/cpp/ext/gcp/environment_autodetect.cc +++ b/src/cpp/ext/gcp/environment_autodetect.cc @@ -63,10 +63,9 @@ std::string GetNamespaceName() { "/var/run/secrets/kubernetes.io/serviceaccount/namespace"; auto namespace_name = grpc_core::LoadFile(filename, false); if (!namespace_name.ok()) { - if (GRPC_TRACE_FLAG_ENABLED(environment_autodetect)) { - VLOG(2) << "Reading file " << filename << " failed: " - << grpc_core::StatusToString(namespace_name.status()); - } + GRPC_TRACE_VLOG(environment_autodetect, 2) + << "Reading file " << filename + << " failed: " << grpc_core::StatusToString(namespace_name.status()); // Fallback on an environment variable return grpc_core::GetEnv("NAMESPACE_NAME").value_or(""); }