Chiebot-Mirror
/
grpc
mirror of https://github.com/grpc/grpc.git
8
0
Fork 0
Code Issues Projects Releases Wiki Activity

[Gpr_To_Absl_Logging] Replace GRPC_ARES_RESOLVER_TRACE_LOG with GRPC_TRACE_LOG (#37462)

Browse Source 
[Gpr_To_Absl_Logging] Replace GRPC_ARES_RESOLVER_TRACE_LOG with GRPC_TRACE_LOG

Closes #37462

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/37462 from tanvi-jagtap:remove_GRPC_POLLING_API_TRACE bf93c6327c
PiperOrigin-RevId: 663811107
pull/37519/head
Tanvi Jagtap 3 months ago committed by Copybara-Service
parent 42bd720fee
commit 7c673870c7
1 changed files with 120 additions and 100 deletions
Whitespace
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Split View
Diff Options
Show Stats Download Patch File Download Diff File
  1. 220
      src/core/lib/event_engine/windows/grpc_polled_fd_windows.cc

220
src/core/lib/event_engine/windows/grpc_polled_fd_windows.cc
Unescape View File

@ -53,14 +53,6 @@ namespace grpc_event_engine {
namespace experimental {
namespace {
#define GRPC_ARES_RESOLVER_TRACE_LOG(format, ...) \
do { \
if (GRPC_TRACE_FLAG_ENABLED(cares_resolver)) { \
LOG(INFO) << "(EventEngine c-ares resolver) " \
<< absl::StrFormat(format, __VA_ARGS__); \
} \
} while (0)
constexpr int kRecvFromSourceAddrSize = 200;
constexpr int kReadBufferSize = 4192;
@ -136,9 +128,9 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
event_engine_(event_engine) {}
~GrpcPolledFdWindows() override {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| ~GrpcPolledFdWindows shutdown_called_: %d ", GetName(),
shutdown_called_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| ~GrpcPolledFdWindows shutdown_called_: " << shutdown_called_;
grpc_core::CSliceUnref(read_buf_);
grpc_core::CSliceUnref(write_buf_);
CHECK(read_closure_ == nullptr);
@ -166,14 +158,16 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
void RegisterForOnWriteableLocked(
absl::AnyInvocable<void(absl::Status)> write_closure) override {
if (socket_type_ == SOCK_DGRAM) {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| RegisterForOnWriteableLocked called", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| RegisterForOnWriteableLocked called";
} else {
CHECK(socket_type_ == SOCK_STREAM);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| RegisterForOnWriteableLocked called tcp_write_state_: %d "
"connect_done_: %d",
GetName(), tcp_write_state_, connect_done_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| RegisterForOnWriteableLocked called tcp_write_state_: "
<< static_cast<int>(tcp_write_state_)
<< " connect_done_: " << connect_done_;
}
CHECK(write_closure_ == nullptr);
write_closure_ = std::move(write_closure);
@ -192,7 +186,8 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
if (!absl::IsCancelled(error)) {
return false;
}
GRPC_ARES_RESOLVER_TRACE_LOG("fd:|%s| ShutdownLocked", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO) << "(EventEngine c-ares resolver) fd:|"
<< GetName() << "| ShutdownLocked";
shutdown_called_ = true;
// The socket is disconnected and closed here since this is an external
// cancel request, e.g. a timeout. c-ares shouldn't do anything on the
@ -211,10 +206,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
ares_ssize_t RecvFrom(WSAErrorContext* wsa_error_ctx, void* data,
ares_socket_t data_len, int /* flags */,
struct sockaddr* from, ares_socklen_t* from_len) {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| RecvFrom called read_buf_has_data:%d Current read buf "
"length:|%d|",
GetName(), read_buf_has_data_, GRPC_SLICE_LENGTH(read_buf_));
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " RecvFrom called read_buf_has_data:" << read_buf_has_data_
<< " Current read buf length:" << GRPC_SLICE_LENGTH(read_buf_);
if (!read_buf_has_data_) {
wsa_error_ctx->SetWSAError(WSAEWOULDBLOCK);
return -1;
@ -241,9 +236,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
ares_ssize_t SendV(WSAErrorContext* wsa_error_ctx, const struct iovec* iov,
int iov_count) {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| SendV called connect_done_:%d wsa_connect_error_:%d",
GetName(), connect_done_, wsa_connect_error_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| SendV called connect_done_:" << connect_done_
<< " wsa_connect_error_:" << wsa_connect_error_;
if (!connect_done_) {
wsa_error_ctx->SetWSAError(WSAEWOULDBLOCK);
return -1;
@ -296,10 +292,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
}
void ContinueRegisterForOnReadableLocked() {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| ContinueRegisterForOnReadableLocked "
"wsa_connect_error_:%d",
GetName(), wsa_connect_error_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| ContinueRegisterForOnReadableLocked wsa_connect_error_:"
<< wsa_connect_error_;
CHECK(connect_done_);
if (wsa_connect_error_ != 0) {
ScheduleAndNullReadClosure(GRPC_WSA_ERROR(wsa_connect_error_, "connect"));
@ -317,11 +313,11 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
winsocket_->read_info()->overlapped(), nullptr) != 0) {
int wsa_last_error = WSAGetLastError();
char* msg = gpr_format_message(wsa_last_error);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| ContinueRegisterForOnReadableLocked WSARecvFrom error "
"code:|%d| "
"msg:|%s|",
GetName(), wsa_last_error, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " ContinueRegisterForOnReadableLocked WSARecvFrom error "
"code:"
<< wsa_last_error << " msg:" << msg;
gpr_free(msg);
if (wsa_last_error != WSA_IO_PENDING) {
winsocket_->UnregisterReadCallback();
@ -333,10 +329,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
}
void ContinueRegisterForOnWriteableLocked() {
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| ContinueRegisterForOnWriteableLocked "
"wsa_connect_error_:%d",
GetName(), wsa_connect_error_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| ContinueRegisterForOnWriteableLocked wsa_connect_error_:"
<< wsa_connect_error_;
CHECK(connect_done_);
if (wsa_connect_error_ != 0) {
ScheduleAndNullWriteClosure(
@ -380,12 +376,12 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int out = WSASend(winsocket_->raw_socket(), &buf, 1, bytes_sent_ptr, flags,
overlapped, nullptr);
*wsa_error_code = WSAGetLastError();
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| SendWriteBuf WSASend buf.len:%d *bytes_sent_ptr:%d "
"overlapped:%p "
"return:%d *wsa_error_code:%d",
GetName(), buf.len, bytes_sent_ptr != nullptr ? *bytes_sent_ptr : 0,
overlapped, out, *wsa_error_code);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " SendWriteBuf WSASend buf.len:" << buf.len << " *bytes_sent_ptr:"
<< (bytes_sent_ptr != nullptr ? *bytes_sent_ptr : 0)
<< " overlapped:" << overlapped << " return:" << out
<< " *wsa_error_code:" << *wsa_error_code;
return out;
}
@ -394,7 +390,8 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
// c-ares doesn't handle retryable errors on writes of UDP sockets.
// Therefore, the sendv handler for UDP sockets must only attempt
// to write everything inline.
GRPC_ARES_RESOLVER_TRACE_LOG("fd:|%s| SendVUDP called", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO) << "(EventEngine c-ares resolver) fd:|"
<< GetName() << "| SendVUDP called";
CHECK_EQ(GRPC_SLICE_LENGTH(write_buf_), 0);
grpc_core::CSliceUnref(write_buf_);
write_buf_ = FlattenIovec(iov, iov_count);
@ -405,9 +402,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
write_buf_ = grpc_empty_slice();
wsa_error_ctx->SetWSAError(wsa_error_code);
char* msg = gpr_format_message(wsa_error_code);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| SendVUDP SendWriteBuf error code:%d msg:|%s|", GetName(),
wsa_error_code, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| SendVUDP SendWriteBuf error code:" << wsa_error_code << " msg:|"
<< msg << "|";
gpr_free(msg);
return -1;
}
@ -423,8 +421,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
// out in the background, and making further send progress in general, will
// happen as long as c-ares continues to show interest in writeability on
// this fd.
GRPC_ARES_RESOLVER_TRACE_LOG("fd:|%s| SendVTCP called tcp_write_state_:%d",
GetName(), tcp_write_state_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| SendVTCP called tcp_write_state_:"
<< static_cast<int>(tcp_write_state_);
switch (tcp_write_state_) {
case WRITE_IDLE:
tcp_write_state_ = WRITE_REQUESTED;
@ -461,12 +461,12 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
void OnTcpConnect() {
grpc_core::MutexLock lock(mu_);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:%s InnerOnTcpConnectLocked "
"pending_register_for_readable:%d"
" pending_register_for_writeable:%d",
GetName(), pending_continue_register_for_on_readable_locked_,
pending_continue_register_for_on_writeable_locked_);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " InnerOnTcpConnectLocked pending_register_for_readable:"
<< pending_continue_register_for_on_readable_locked_
<< " pending_register_for_writeable:"
<< pending_continue_register_for_on_writeable_locked_;
CHECK(!connect_done_);
connect_done_ = true;
CHECK_EQ(wsa_connect_error_, 0);
@ -482,10 +482,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
if (!wsa_success) {
wsa_connect_error_ = WSAGetLastError();
char* msg = gpr_format_message(wsa_connect_error_);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:%s InnerOnTcpConnectLocked WSA overlapped result code:%d "
"msg:|%s|",
GetName(), wsa_connect_error_, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " InnerOnTcpConnectLocked WSA overlapped result code:"
<< wsa_connect_error_ << " msg:|" << msg << "|";
gpr_free(msg);
}
}
@ -499,7 +499,8 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int ConnectUDP(WSAErrorContext* wsa_error_ctx, const struct sockaddr* target,
ares_socklen_t target_len) {
GRPC_ARES_RESOLVER_TRACE_LOG("fd:%s ConnectUDP", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName() << " ConnectUDP";
CHECK(!connect_done_);
CHECK_EQ(wsa_connect_error_, 0);
SOCKET s = winsocket_->raw_socket();
@ -509,8 +510,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
wsa_error_ctx->SetWSAError(wsa_connect_error_);
connect_done_ = true;
char* msg = gpr_format_message(wsa_connect_error_);
GRPC_ARES_RESOLVER_TRACE_LOG("fd:%s WSAConnect error code:|%d| msg:|%s|",
GetName(), wsa_connect_error_, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " WSAConnect error code:|" << wsa_connect_error_ << "| msg:|" << msg
<< "|";
gpr_free(msg);
// c-ares expects a posix-style connect API
return out == 0 ? 0 : -1;
@ -518,7 +521,8 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int ConnectTCP(WSAErrorContext* wsa_error_ctx, const struct sockaddr* target,
ares_socklen_t target_len) {
GRPC_ARES_RESOLVER_TRACE_LOG("fd:%s ConnectTCP", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName() << " ConnectTCP";
LPFN_CONNECTEX ConnectEx;
GUID guid = WSAID_CONNECTEX;
DWORD ioctl_num_bytes;
@ -529,10 +533,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int wsa_last_error = WSAGetLastError();
wsa_error_ctx->SetWSAError(wsa_last_error);
char* msg = gpr_format_message(wsa_last_error);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:%s WSAIoctl(SIO_GET_EXTENSION_FUNCTION_POINTER) error code:%d "
"msg:|%s|",
GetName(), wsa_last_error, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " WSAIoctl(SIO_GET_EXTENSION_FUNCTION_POINTER) error code:"
<< wsa_last_error << " msg:|" << msg << "|";
gpr_free(msg);
connect_done_ = true;
wsa_connect_error_ = wsa_last_error;
@ -552,8 +556,9 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int wsa_last_error = WSAGetLastError();
wsa_error_ctx->SetWSAError(wsa_last_error);
char* msg = gpr_format_message(wsa_last_error);
GRPC_ARES_RESOLVER_TRACE_LOG("fd:%s bind error code:%d msg:|%s|",
GetName(), wsa_last_error, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " bind error code:" << wsa_last_error << " msg:|" << msg << "|";
gpr_free(msg);
connect_done_ = true;
wsa_connect_error_ = wsa_last_error;
@ -569,8 +574,10 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
int wsa_last_error = WSAGetLastError();
wsa_error_ctx->SetWSAError(wsa_last_error);
char* msg = gpr_format_message(wsa_last_error);
GRPC_ARES_RESOLVER_TRACE_LOG("fd:%s ConnectEx error code:%d msg:|%s|",
GetName(), wsa_last_error, msg);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << GetName()
<< " ConnectEx error code:" << wsa_last_error << " msg:|" << msg
<< "|";
gpr_free(msg);
if (wsa_last_error == WSA_IO_PENDING) {
// c-ares only understands WSAEINPROGRESS and EWOULDBLOCK error codes on
@ -605,11 +612,12 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
if (winsocket_->read_info()->result().wsa_error != WSAEMSGSIZE) {
error = GRPC_WSA_ERROR(winsocket_->read_info()->result().wsa_error,
"OnIocpReadableInner");
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| OnIocpReadableInner winsocket_->read_info.wsa_error "
"code:|%d| msg:|%s|",
GetName(), winsocket_->read_info()->result().wsa_error,
grpc_core::StatusToString(error).c_str());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| OnIocpReadableInner winsocket_->read_info.wsa_error "
"code:|"
<< winsocket_->read_info()->result().wsa_error << "| msg:|"
<< grpc_core::StatusToString(error) << "|";
}
}
if (error.ok()) {
@ -620,34 +628,40 @@ class GrpcPolledFdWindows : public GrpcPolledFd {
grpc_core::CSliceUnref(read_buf_);
read_buf_ = grpc_empty_slice();
}
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| OnIocpReadable finishing. read buf length now:|%d|", GetName(),
GRPC_SLICE_LENGTH(read_buf_));
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| OnIocpReadable finishing. read buf length now:|"
<< GRPC_SLICE_LENGTH(read_buf_) << "|";
ScheduleAndNullReadClosure(error);
}
void OnIocpWriteable() {
grpc_core::MutexLock lock(mu_);
GRPC_ARES_RESOLVER_TRACE_LOG("OnIocpWriteableInner. fd:|%s|", GetName());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) OnIocpWriteableInner. fd:|"
<< GetName() << "|";
CHECK(socket_type_ == SOCK_STREAM);
absl::Status error;
if (winsocket_->write_info()->result().wsa_error != 0) {
error = GRPC_WSA_ERROR(winsocket_->write_info()->result().wsa_error,
"OnIocpWriteableInner");
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| OnIocpWriteableInner. winsocket_->write_info.wsa_error "
"code:|%d| msg:|%s|",
GetName(), winsocket_->write_info()->result().wsa_error,
grpc_core::StatusToString(error).c_str());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| OnIocpWriteableInner. winsocket_->write_info.wsa_error "
"code:|"
<< winsocket_->write_info()->result().wsa_error << "| msg:|"
<< grpc_core::StatusToString(error) << "|";
}
CHECK(tcp_write_state_ == WRITE_PENDING);
if (error.ok()) {
tcp_write_state_ = WRITE_WAITING_FOR_VERIFICATION_UPON_RETRY;
write_buf_ = grpc_slice_sub_no_ref(
write_buf_, 0, winsocket_->write_info()->result().bytes_transferred);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| OnIocpWriteableInner. bytes transferred:%d", GetName(),
winsocket_->write_info()->result().bytes_transferred);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:|" << GetName()
<< "| OnIocpWriteableInner. bytes transferred:"
<< winsocket_->write_info()->result().bytes_transferred;
} else {
grpc_core::CSliceUnref(write_buf_);
write_buf_ = grpc_empty_slice();
@ -694,8 +708,10 @@ class CustomSockFuncs {
public:
static ares_socket_t Socket(int af, int type, int protocol, void* user_data) {
if (type != SOCK_DGRAM && type != SOCK_STREAM) {
GRPC_ARES_RESOLVER_TRACE_LOG("Socket called with invalid socket type:%d",
type);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) Socket called with invalid socket "
"type:"
<< type;
return INVALID_SOCKET;
}
GrpcPolledFdFactoryWindows* self =
@ -703,24 +719,26 @@ class CustomSockFuncs {
SOCKET s = WSASocket(af, type, protocol, nullptr, 0,
IOCP::GetDefaultSocketFlags());
if (s == INVALID_SOCKET) {
GRPC_ARES_RESOLVER_TRACE_LOG(
"WSASocket failed with params af:%d type:%d protocol:%d", af, type,
protocol);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) WSASocket failed with params af:"
<< af << " type:" << type << " protocol:" << protocol;
return INVALID_SOCKET;
}
if (type == SOCK_STREAM) {
absl::Status error = PrepareSocket(s);
if (!error.ok()) {
GRPC_ARES_RESOLVER_TRACE_LOG("WSAIoctl failed with error: %s",
grpc_core::StatusToString(error).c_str());
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) WSAIoctl failed with error: "
<< grpc_core::StatusToString(error);
return INVALID_SOCKET;
}
}
auto polled_fd = std::make_unique<GrpcPolledFdWindows>(
self->iocp_->Watch(s), self->mu_, af, type, self->event_engine_);
GRPC_ARES_RESOLVER_TRACE_LOG(
"fd:|%s| created with params af:%d type:%d protocol:%d",
polled_fd->GetName(), af, type, protocol);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) fd:" << polled_fd->GetName()
<< " created with params af:" << af << " type:" << type
<< " protocol:" << protocol;
CHECK(self->sockets_.insert({s, std::move(polled_fd)}).second);
return s;
}
@ -758,7 +776,9 @@ class CustomSockFuncs {
}
static int CloseSocket(SOCKET s, void*) {
GRPC_ARES_RESOLVER_TRACE_LOG("c-ares socket: %d CloseSocket", s);
GRPC_TRACE_LOG(cares_resolver, INFO)
<< "(EventEngine c-ares resolver) c-ares socket: " << s
<< " CloseSocket";
return 0;
}
};

Write Preview
Loading…
Cancel
Save