make log lines info to help out a customer (#31842)

pull/31846/head
Craig Tiller 2 years ago committed by GitHub
parent c3132358d6
commit f32701f840
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 64
      src/core/lib/channel/promise_based_filter.cc

@ -246,7 +246,7 @@ BaseCallData::Flusher::~Flusher() {
BaseCallData* call =
static_cast<BaseCallData*>(batch->handler_private.extra_arg);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "FLUSHER:forward batch via closure: %s",
gpr_log(GPR_INFO, "FLUSHER:forward batch via closure: %s",
grpc_transport_stream_op_batch_string(batch).c_str());
}
grpc_call_next_op(call->elem(), batch);
@ -255,7 +255,7 @@ BaseCallData::Flusher::~Flusher() {
for (size_t i = 1; i < release_.size(); i++) {
auto* batch = release_[i];
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "FLUSHER:queue batch to forward in closure: %s",
gpr_log(GPR_INFO, "FLUSHER:queue batch to forward in closure: %s",
grpc_transport_stream_op_batch_string(release_[i]).c_str());
}
batch->handler_private.extra_arg = call_;
@ -267,7 +267,7 @@ BaseCallData::Flusher::~Flusher() {
}
call_closures_.RunClosuresWithoutYielding(call_->call_combiner());
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "FLUSHER:forward batch: %s",
gpr_log(GPR_INFO, "FLUSHER:forward batch: %s",
grpc_transport_stream_op_batch_string(release_[0]).c_str());
}
grpc_call_next_op(call_->elem(), release_[0]);
@ -301,7 +301,7 @@ const char* BaseCallData::SendMessage::StateString(State state) {
void BaseCallData::SendMessage::StartOp(CapturedBatch batch) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s SendMessage.StartOp st=%s", base_->LogTag().c_str(),
gpr_log(GPR_INFO, "%s SendMessage.StartOp st=%s", base_->LogTag().c_str(),
StateString(state_));
}
switch (state_) {
@ -327,7 +327,7 @@ void BaseCallData::SendMessage::StartOp(CapturedBatch batch) {
void BaseCallData::SendMessage::GotPipe(PipeReceiver<MessageHandle>* receiver) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s SendMessage.GotPipe st=%s", base_->LogTag().c_str(),
gpr_log(GPR_INFO, "%s SendMessage.GotPipe st=%s", base_->LogTag().c_str(),
StateString(state_));
}
GPR_ASSERT(receiver != nullptr);
@ -372,7 +372,7 @@ bool BaseCallData::SendMessage::IsIdle() const {
void BaseCallData::SendMessage::OnComplete(absl::Status status) {
Flusher flusher(base_);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s SendMessage.OnComplete st=%s status=%s",
gpr_log(GPR_INFO, "%s SendMessage.OnComplete st=%s status=%s",
base_->LogTag().c_str(), StateString(state_),
status.ToString().c_str());
}
@ -400,7 +400,7 @@ void BaseCallData::SendMessage::OnComplete(absl::Status status) {
void BaseCallData::SendMessage::Done(const ServerMetadata& metadata) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s SendMessage.Done st=%s md=%s",
gpr_log(GPR_INFO, "%s SendMessage.Done st=%s md=%s",
base_->LogTag().c_str(), StateString(state_),
metadata.DebugString().c_str());
}
@ -428,7 +428,7 @@ void BaseCallData::SendMessage::Done(const ServerMetadata& metadata) {
void BaseCallData::SendMessage::WakeInsideCombiner(Flusher* flusher) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s SendMessage.WakeInsideCombiner st=%s%s",
gpr_log(GPR_INFO, "%s SendMessage.WakeInsideCombiner st=%s%s",
base_->LogTag().c_str(), StateString(state_),
state_ == State::kBatchCompleted
? absl::StrCat(" status=", completed_status_.ToString()).c_str()
@ -455,7 +455,7 @@ void BaseCallData::SendMessage::WakeInsideCombiner(Flusher* flusher) {
auto r_push = (*push_)();
if (auto* p = absl::get_if<bool>(&r_push)) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s SendMessage.WakeInsideCombiner push complete, result=%s",
base_->LogTag().c_str(), *p ? "true" : "false");
}
@ -469,7 +469,7 @@ void BaseCallData::SendMessage::WakeInsideCombiner(Flusher* flusher) {
auto r_next = (*next_)();
if (auto* p = absl::get_if<NextResult<MessageHandle>>(&r_next)) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s SendMessage.WakeInsideCombiner next complete, "
"result.has_value=%s",
base_->LogTag().c_str(), p->has_value() ? "true" : "false");
@ -543,7 +543,7 @@ const char* BaseCallData::ReceiveMessage::StateString(State state) {
void BaseCallData::ReceiveMessage::StartOp(CapturedBatch& batch) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ReceiveMessage.StartOp st=%s",
gpr_log(GPR_INFO, "%s ReceiveMessage.StartOp st=%s",
base_->LogTag().c_str(), StateString(state_));
}
switch (state_) {
@ -581,7 +581,7 @@ void BaseCallData::ReceiveMessage::StartOp(CapturedBatch& batch) {
void BaseCallData::ReceiveMessage::GotPipe(PipeSender<MessageHandle>* sender) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ReceiveMessage.GotPipe st=%s",
gpr_log(GPR_INFO, "%s ReceiveMessage.GotPipe st=%s",
base_->LogTag().c_str(), StateString(state_));
}
switch (state_) {
@ -615,7 +615,7 @@ void BaseCallData::ReceiveMessage::GotPipe(PipeSender<MessageHandle>* sender) {
void BaseCallData::ReceiveMessage::OnComplete(absl::Status status) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ReceiveMessage.OnComplete st=%s status=%s",
gpr_log(GPR_INFO, "%s ReceiveMessage.OnComplete st=%s status=%s",
base_->LogTag().c_str(), StateString(state_),
status.ToString().c_str());
}
@ -652,7 +652,7 @@ void BaseCallData::ReceiveMessage::OnComplete(absl::Status status) {
void BaseCallData::ReceiveMessage::Done(const ServerMetadata& metadata,
Flusher* flusher) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ReceiveMessage.Done st=%s md=%s",
gpr_log(GPR_INFO, "%s ReceiveMessage.Done st=%s md=%s",
base_->LogTag().c_str(), StateString(state_),
metadata.DebugString().c_str());
}
@ -702,7 +702,7 @@ void BaseCallData::ReceiveMessage::Done(const ServerMetadata& metadata,
void BaseCallData::ReceiveMessage::WakeInsideCombiner(Flusher* flusher) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s ReceiveMessage.WakeInsideCombiner st=%s push?=%s next?=%s",
base_->LogTag().c_str(), StateString(state_),
push_.has_value() ? "yes" : "no", next_.has_value() ? "yes" : "no");
@ -749,7 +749,7 @@ void BaseCallData::ReceiveMessage::WakeInsideCombiner(Flusher* flusher) {
auto r_push = (*push_)();
if (auto* p = absl::get_if<bool>(&r_push)) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s ReceiveMessage.WakeInsideCombiner push complete: %s",
base_->LogTag().c_str(), *p ? "true" : "false");
}
@ -762,7 +762,7 @@ void BaseCallData::ReceiveMessage::WakeInsideCombiner(Flusher* flusher) {
auto r_next = (*next_)();
if (auto* p = absl::get_if<NextResult<MessageHandle>>(&r_next)) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s ReceiveMessage.WakeInsideCombiner next complete: %s",
base_->LogTag().c_str(),
p->has_value() ? "got message" : "end of stream");
@ -793,7 +793,7 @@ void BaseCallData::ReceiveMessage::WakeInsideCombiner(Flusher* flusher) {
GPR_ASSERT(push_.has_value());
if (!absl::holds_alternative<Pending>((*push_)())) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s ReceiveMessage.WakeInsideCombiner push complete",
base_->LogTag().c_str());
}
@ -888,7 +888,7 @@ class ClientCallData::PollContext {
void Run() {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ClientCallData.PollContext.Run %s",
gpr_log(GPR_INFO, "%s ClientCallData.PollContext.Run %s",
self_->LogTag().c_str(), self_->DebugString().c_str());
}
GPR_ASSERT(have_scoped_activity_);
@ -950,7 +950,7 @@ class ClientCallData::PollContext {
// Poll the promise once since we're waiting for it.
Poll<ServerMetadataHandle> poll = self_->promise_();
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ClientCallData.PollContext.Run: poll=%s",
gpr_log(GPR_INFO, "%s ClientCallData.PollContext.Run: poll=%s",
self_->LogTag().c_str(),
PollToString(poll, [](const ServerMetadataHandle& h) {
return h->DebugString();
@ -1210,7 +1210,7 @@ void ClientCallData::StartBatch(grpc_transport_stream_op_batch* b) {
Flusher flusher(this);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s StartBatch %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s StartBatch %s", LogTag().c_str(),
DebugString().c_str());
}
@ -1335,7 +1335,7 @@ void ClientCallData::StartBatch(grpc_transport_stream_op_batch* b) {
// Handle cancellation.
void ClientCallData::Cancel(grpc_error_handle error, Flusher* flusher) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s Cancel error=%s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s Cancel error=%s", LogTag().c_str(),
error.ToString().c_str());
}
// Track the latest reason for cancellation.
@ -1408,7 +1408,7 @@ void ClientCallData::StartPromise(Flusher* flusher) {
void ClientCallData::RecvInitialMetadataReady(grpc_error_handle error) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ClientCallData.RecvInitialMetadataReady %s",
gpr_log(GPR_INFO, "%s ClientCallData.RecvInitialMetadataReady %s",
LogTag().c_str(), DebugString().c_str());
}
ScopedContext context(this);
@ -1490,7 +1490,7 @@ void ClientCallData::HookRecvTrailingMetadata(CapturedBatch batch) {
ArenaPromise<ServerMetadataHandle> ClientCallData::MakeNextPromise(
CallArgs call_args) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ClientCallData.MakeNextPromise %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s ClientCallData.MakeNextPromise %s", LogTag().c_str(),
DebugString().c_str());
}
GPR_ASSERT(poll_ctx_ != nullptr);
@ -1554,7 +1554,7 @@ ArenaPromise<ServerMetadataHandle> ClientCallData::MakeNextPromise(
// application.
Poll<ServerMetadataHandle> ClientCallData::PollTrailingMetadata() {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ClientCallData.PollTrailingMetadata %s",
gpr_log(GPR_INFO, "%s ClientCallData.PollTrailingMetadata %s",
LogTag().c_str(), DebugString().c_str());
}
GPR_ASSERT(poll_ctx_ != nullptr);
@ -1606,7 +1606,7 @@ void ClientCallData::RecvTrailingMetadataReadyCallback(
void ClientCallData::RecvTrailingMetadataReady(grpc_error_handle error) {
Flusher flusher(this);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG,
gpr_log(GPR_INFO,
"%s ClientCallData.RecvTrailingMetadataReady "
"recv_trailing_state=%s error=%s md=%s",
LogTag().c_str(), StateString(recv_trailing_state_),
@ -1800,7 +1800,7 @@ ServerCallData::ServerCallData(grpc_call_element* elem,
ServerCallData::~ServerCallData() {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s ~ServerCallData %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s ~ServerCallData %s", LogTag().c_str(),
DebugString().c_str());
}
GPR_ASSERT(poll_ctx_ == nullptr);
@ -1821,7 +1821,7 @@ void ServerCallData::StartBatch(grpc_transport_stream_op_batch* b) {
bool wake = false;
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s StartBatch: %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s StartBatch: %s", LogTag().c_str(),
DebugString().c_str());
}
@ -2062,7 +2062,7 @@ void ServerCallData::RecvTrailingMetadataReadyCallback(
void ServerCallData::RecvTrailingMetadataReady(grpc_error_handle error) {
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s: RecvTrailingMetadataReady error=%s md=%s",
gpr_log(GPR_INFO, "%s: RecvTrailingMetadataReady error=%s md=%s",
LogTag().c_str(), error.ToString().c_str(),
recv_trailing_metadata_->DebugString().c_str());
}
@ -2081,7 +2081,7 @@ void ServerCallData::RecvInitialMetadataReadyCallback(void* arg,
void ServerCallData::RecvInitialMetadataReady(grpc_error_handle error) {
Flusher flusher(this);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s: RecvInitialMetadataReady %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s: RecvInitialMetadataReady %s", LogTag().c_str(),
error.ToString().c_str());
}
GPR_ASSERT(recv_initial_state_ == RecvInitialState::kForwarded);
@ -2143,7 +2143,7 @@ std::string ServerCallData::DebugString() const {
void ServerCallData::WakeInsideCombiner(Flusher* flusher) {
PollContext poll_ctx(this, flusher);
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s: WakeInsideCombiner %s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s: WakeInsideCombiner %s", LogTag().c_str(),
DebugString().c_str());
}
if (send_initial_metadata_ != nullptr &&
@ -2169,7 +2169,7 @@ void ServerCallData::WakeInsideCombiner(Flusher* flusher) {
Poll<ServerMetadataHandle> poll;
poll = promise_();
if (grpc_trace_channel.enabled()) {
gpr_log(GPR_DEBUG, "%s: WakeInsideCombiner poll=%s", LogTag().c_str(),
gpr_log(GPR_INFO, "%s: WakeInsideCombiner poll=%s", LogTag().c_str(),
PollToString(poll, [](const ServerMetadataHandle& h) {
return h->DebugString();
}).c_str());

Loading…
Cancel
Save