From a863532c6293eceacdddfd5ce685507091cf30a0 Mon Sep 17 00:00:00 2001 From: Craig Tiller Date: Thu, 11 May 2023 23:48:21 -0700 Subject: [PATCH] better debug --- src/core/lib/transport/batch_builder.cc | 4 ++ src/core/lib/transport/batch_builder.h | 54 +++++++++++++------------ 2 files changed, 33 insertions(+), 25 deletions(-) diff --git a/src/core/lib/transport/batch_builder.cc b/src/core/lib/transport/batch_builder.cc index 06d8c0a72f9..82c3bba863e 100644 --- a/src/core/lib/transport/batch_builder.cc +++ b/src/core/lib/transport/batch_builder.cc @@ -71,6 +71,10 @@ BatchBuilder::Batch::Batch(grpc_transport_stream_op_batch_payload* payload, BatchBuilder::Batch::~Batch() { auto* arena = party->arena(); + if (grpc_call_trace.enabled()) { + gpr_log(GPR_DEBUG, "%s[connected] [batch %p] Destroy", + Activity::current()->DebugTag().c_str(), this); + } if (pending_receive_message != nullptr) { arena->DeletePooled(pending_receive_message); } diff --git a/src/core/lib/transport/batch_builder.h b/src/core/lib/transport/batch_builder.h index 6b494a00fb1..f714af6e7f8 100644 --- a/src/core/lib/transport/batch_builder.h +++ b/src/core/lib/transport/batch_builder.h @@ -282,12 +282,12 @@ class BatchBuilder { }; inline auto BatchBuilder::SendMessage(Target target, MessageHandle message) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue send message: %s", - Activity::current()->DebugTag().c_str(), + gpr_log(GPR_DEBUG, "%s[connected] [batch %p] Queue send message: %s", + Activity::current()->DebugTag().c_str(), batch, message->DebugString().c_str()); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion(&Batch::pending_sends); batch->batch.on_complete = &pc->on_done_closure; batch->batch.send_message = true; @@ -299,11 +299,13 @@ inline auto BatchBuilder::SendMessage(Target target, MessageHandle message) { inline auto BatchBuilder::SendInitialMetadata( Target target, Arena::PoolPtr md) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue send initial metadata: %s", - Activity::current()->DebugTag().c_str(), md->DebugString().c_str()); + gpr_log(GPR_DEBUG, + "%s[connected] [batch %p] Queue send initial metadata: %s", + Activity::current()->DebugTag().c_str(), batch, + md->DebugString().c_str()); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion(&Batch::pending_sends); batch->batch.on_complete = &pc->on_done_closure; batch->batch.send_initial_metadata = true; @@ -318,11 +320,11 @@ inline auto BatchBuilder::SendClientInitialMetadata( } inline auto BatchBuilder::SendClientTrailingMetadata(Target target) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue send trailing metadata", - Activity::current()->DebugTag().c_str()); + gpr_log(GPR_DEBUG, "%s[connected] [batch %p] Queue send trailing metadata", + Activity::current()->DebugTag().c_str(), batch); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion(&Batch::pending_sends); batch->batch.on_complete = &pc->on_done_closure; batch->batch.send_trailing_metadata = true; @@ -342,13 +344,6 @@ inline auto BatchBuilder::SendServerInitialMetadata( inline auto BatchBuilder::SendServerTrailingMetadata( Target target, ServerMetadataHandle metadata, bool convert_to_cancellation) { - if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] %s: %s", - Activity::current()->DebugTag().c_str(), - convert_to_cancellation ? "Send trailing metadata as cancellation" - : "Queue send trailing metadata", - metadata->DebugString().c_str()); - } Batch* batch; PendingSends* pc; if (convert_to_cancellation) { @@ -368,6 +363,13 @@ inline auto BatchBuilder::SendServerTrailingMetadata( payload_->send_trailing_metadata.send_trailing_metadata = metadata.get(); payload_->send_trailing_metadata.sent = &pc->trailing_metadata_sent; } + if (grpc_call_trace.enabled()) { + gpr_log(GPR_DEBUG, "%s[connected] [batch %p] %s: %s", + Activity::current()->DebugTag().c_str(), batch, + convert_to_cancellation ? "Send trailing metadata as cancellation" + : "Queue send trailing metadata", + metadata->DebugString().c_str()); + } batch->batch.on_complete = &pc->on_done_closure; pc->send_trailing_metadata = std::move(metadata); auto promise = batch->RefUntil( @@ -383,11 +385,11 @@ inline auto BatchBuilder::SendServerTrailingMetadata( } inline auto BatchBuilder::ReceiveMessage(Target target) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue receive message", - Activity::current()->DebugTag().c_str()); + gpr_log(GPR_DEBUG, "%s[connected] [batch %p] Queue receive message", + Activity::current()->DebugTag().c_str(), batch); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion(&Batch::pending_receive_message); batch->batch.recv_message = true; payload_->recv_message.recv_message_ready = &pc->on_done_closure; @@ -411,11 +413,12 @@ inline auto BatchBuilder::ReceiveMessage(Target target) { } inline auto BatchBuilder::ReceiveInitialMetadata(Target target) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue receive initial metadata", - Activity::current()->DebugTag().c_str()); + gpr_log(GPR_DEBUG, + "%s[connected] [batch %p] Queue receive initial metadata", + Activity::current()->DebugTag().c_str(), batch); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion(&Batch::pending_receive_initial_metadata); batch->batch.recv_initial_metadata = true; @@ -439,11 +442,12 @@ inline auto BatchBuilder::ReceiveServerInitialMetadata(Target target) { } inline auto BatchBuilder::ReceiveTrailingMetadata(Target target) { + auto* batch = GetBatch(target); if (grpc_call_trace.enabled()) { - gpr_log(GPR_DEBUG, "%s[connected] Queue receive trailing metadata", - Activity::current()->DebugTag().c_str()); + gpr_log(GPR_DEBUG, + "%s[connected] [batch %p] Queue receive trailing metadata", + Activity::current()->DebugTag().c_str(), batch); } - auto* batch = GetBatch(target); auto* pc = batch->GetInitializedCompletion( &Batch::pending_receive_trailing_metadata); batch->batch.recv_trailing_metadata = true;