@ -124,7 +124,8 @@ bool IsIpv6LoopbackAvailable() {
absl : : Status SetRequestDNSServer ( absl : : string_view dns_server ,
ares_channel * channel ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " Using DNS server %s " , dns_server . data ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) Using DNS server " < < dns_server ;
grpc_resolved_address addr ;
struct ares_addr_port_node dns_server_addr = { } ;
if ( grpc_parse_ipv4_hostport ( dns_server , & addr , /*log_errors=*/ false ) ) {
@ -251,8 +252,9 @@ void AresResolver::Orphan() {
}
for ( const auto & fd_node : fd_node_list_ ) {
if ( ! fd_node - > already_shutdown ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver: %p shutdown fd: %s " , this ,
fd_node - > polled_fd - > GetName ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " shutdown fd: " < < fd_node - > polled_fd - > GetName ( ) ;
CHECK ( fd_node - > polled_fd - > ShutdownLocked (
absl : : CancelledError ( " AresResolver::Orphan " ) ) ) ;
fd_node - > already_shutdown = true ;
@ -423,8 +425,9 @@ void AresResolver::CheckSocketsLocked() {
fd_node_list_ . begin ( ) , fd_node_list_ . end ( ) ,
[ sock = socks [ i ] ] ( const auto & node ) { return node - > as = = sock ; } ) ;
if ( iter = = fd_node_list_ . end ( ) ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p new fd: %d " , this ,
socks [ i ] ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " new fd: " < < socks [ i ] ;
new_list . push_back ( std : : make_unique < FdNode > (
socks [ i ] , polled_fd_factory_ - > NewGrpcPolledFdLocked ( socks [ i ] ) ) ) ;
} else {
@ -440,8 +443,9 @@ void AresResolver::CheckSocketsLocked() {
// to cope with the edge-triggered poller not getting an event if no
// new data arrives and c-ares hasn't read all the data in the
// previous ares_process_fd.
GRPC_ARES_RESOLVER_TRACE_LOG (
" resolver:%p schedule read directly on: %d " , this , fd_node - > as ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " schedule read directly on: " < < fd_node - > as ;
event_engine_ - > Run (
[ self = Ref ( DEBUG_LOCATION , " CheckSocketsLocked " ) ,
fd_node ] ( ) mutable {
@ -450,8 +454,9 @@ void AresResolver::CheckSocketsLocked() {
} ) ;
} else {
// Otherwise register with the poller for readable event.
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p notify read on: %d " , this ,
fd_node - > as ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " notify read on: " < < fd_node - > as ;
fd_node - > polled_fd - > RegisterForOnReadableLocked (
[ self = Ref ( DEBUG_LOCATION , " CheckSocketsLocked " ) ,
fd_node ] ( absl : : Status status ) mutable {
@ -464,8 +469,9 @@ void AresResolver::CheckSocketsLocked() {
// has not been registered with this socket.
if ( ARES_GETSOCK_WRITABLE ( socks_bitmask , i ) & &
! fd_node - > writable_registered ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p notify write on: %d " , this ,
fd_node - > as ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " notify write on: " < < fd_node - > as ;
fd_node - > writable_registered = true ;
fd_node - > polled_fd - > RegisterForOnWriteableLocked (
[ self = Ref ( DEBUG_LOCATION , " CheckSocketsLocked " ) ,
@ -487,14 +493,16 @@ void AresResolver::CheckSocketsLocked() {
while ( ! fd_node_list_ . empty ( ) ) {
FdNode * fd_node = fd_node_list_ . front ( ) . get ( ) ;
if ( ! fd_node - > already_shutdown ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver: %p shutdown fd: %s " , this ,
fd_node - > polled_fd - > GetName ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " shutdown fd: " < < fd_node - > polled_fd - > GetName ( ) ;
fd_node - > already_shutdown =
fd_node - > polled_fd - > ShutdownLocked ( absl : : OkStatus ( ) ) ;
}
if ( ! fd_node - > readable_registered & & ! fd_node - > writable_registered ) {
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver: %p delete fd: %s " , this ,
fd_node - > polled_fd - > GetName ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < this
< < " delete fd: " < < fd_node - > polled_fd - > GetName ( ) ;
fd_node_list_ . pop_front ( ) ;
} else {
new_list . splice ( new_list . end ( ) , fd_node_list_ , fd_node_list_ . begin ( ) ) ;
@ -508,9 +516,10 @@ void AresResolver::MaybeStartTimerLocked() {
return ;
}
// Initialize the backup poll alarm
GRPC_ARES_RESOLVER_TRACE_LOG (
" request:%p MaybeStartTimerLocked next ares process poll time in %zu ms " ,
this , Milliseconds ( kAresBackupPollAlarmDuration ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) request: " < < this
< < " MaybeStartTimerLocked next ares process poll time in "
< < Milliseconds ( kAresBackupPollAlarmDuration ) < < " ms " ;
ares_backup_poll_alarm_handle_ = event_engine_ - > RunAfter (
kAresBackupPollAlarmDuration ,
[ self = Ref ( DEBUG_LOCATION , " MaybeStartTimerLocked " ) ] ( ) {
@ -522,8 +531,9 @@ void AresResolver::OnReadable(FdNode* fd_node, absl::Status status) {
grpc_core : : MutexLock lock ( & mutex_ ) ;
CHECK ( fd_node - > readable_registered ) ;
fd_node - > readable_registered = false ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " OnReadable: fd: %d; request: %p; status: %s " ,
fd_node - > as , this , status . ToString ( ) . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) OnReadable: fd: " < < fd_node - > as
< < " ; request: " < < this < < " ; status: " < < status ;
if ( status . ok ( ) & & ! shutting_down_ ) {
ares_process_fd ( channel_ , fd_node - > as , ARES_SOCKET_BAD ) ;
} else {
@ -541,8 +551,9 @@ void AresResolver::OnWritable(FdNode* fd_node, absl::Status status) {
grpc_core : : MutexLock lock ( & mutex_ ) ;
CHECK ( fd_node - > writable_registered ) ;
fd_node - > writable_registered = false ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " OnWritable: fd: %d; request:%p; status: %s " ,
fd_node - > as , this , status . ToString ( ) . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) OnWritable: fd: " < < fd_node - > as
< < " ; request: " < < this < < " ; status: " < < status ;
if ( status . ok ( ) & & ! shutting_down_ ) {
ares_process_fd ( channel_ , ARES_SOCKET_BAD , fd_node - > as ) ;
} else {
@ -567,15 +578,16 @@ void AresResolver::OnWritable(FdNode* fd_node, absl::Status status) {
void AresResolver : : OnAresBackupPollAlarm ( ) {
grpc_core : : MutexLock lock ( & mutex_ ) ;
ares_backup_poll_alarm_handle_ . reset ( ) ;
GRPC_ARES_RESOLVER_ TRACE_LOG (
" request:%p OnAresBackupPollAlarm shutting_down=%d. " , this ,
shutting_down_ ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) request: " < < this
< < " OnAresBackupPollAlarm shutting_down= " < < shutting_down_ ;
if ( ! shutting_down_ ) {
for ( const auto & fd_node : fd_node_list_ ) {
if ( ! fd_node - > already_shutdown ) {
GRPC_ARES_RESOLVER_TRACE_LOG (
" request:%p OnAresBackupPollAlarm; ares_process_fd. fd=%s " , this ,
fd_node - > polled_fd - > GetName ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) request: " < < this
< < " OnAresBackupPollAlarm; ares_process_fd. fd= "
< < fd_node - > polled_fd - > GetName ( ) ;
ares_socket_t as = fd_node - > polled_fd - > GetWrappedAresSocketLocked ( ) ;
ares_process_fd ( channel_ , as , as ) ;
}
@ -595,13 +607,15 @@ void AresResolver::OnHostbynameDoneLocked(void* arg, int status,
std : : string error_msg =
absl : : StrFormat ( " address lookup failed for %s: %s " ,
hostname_qa - > query_name , ares_strerror ( status ) ) ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p OnHostbynameDoneLocked: %s " ,
ares_resolver , error_msg . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " OnHostbynameDoneLocked: " < < error_msg ;
hostname_qa - > error_status = AresStatusToAbslStatus ( status , error_msg ) ;
} else {
GRPC_ARES_RESOLVER_TRACE_LOG (
" resolver:%p OnHostbynameDoneLocked name=%s ARES_SUCCESS " ,
ares_resolver , hostname_qa - > query_name . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " OnHostbynameDoneLocked name= " < < hostname_qa - > query_name
< < " ARES_SUCCESS " ;
for ( size_t i = 0 ; hostent - > h_addr_list [ i ] ! = nullptr ; i + + ) {
if ( hostname_qa - > result . size ( ) = = kMaxRecordSize ) {
LOG ( ERROR ) < < " A/AAAA response exceeds maximum record size of 65536 " ;
@ -620,10 +634,11 @@ void AresResolver::OnHostbynameDoneLocked(void* arg, int status,
reinterpret_cast < const sockaddr * > ( & addr ) , addr_len ) ;
char output [ INET6_ADDRSTRLEN ] ;
ares_inet_ntop ( AF_INET6 , & addr . sin6_addr , output , INET6_ADDRSTRLEN ) ;
GRPC_ARES_RESOLVER_TRACE_LOG (
" resolver:%p c-ares resolver gets a AF_INET6 result: \n "
" addr: %s \n port: %d \n sin6_scope_id: %d \n " ,
ares_resolver , output , hostname_qa - > port , addr . sin6_scope_id ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " c-ares resolver gets a AF_INET6 result: \n addr: " < < output
< < " \n port: " < < hostname_qa - > port
< < " \n sin6_scope_id: " < < addr . sin6_scope_id ;
break ;
}
case AF_INET : {
@ -638,10 +653,10 @@ void AresResolver::OnHostbynameDoneLocked(void* arg, int status,
reinterpret_cast < const sockaddr * > ( & addr ) , addr_len ) ;
char output [ INET_ADDRSTRLEN ] ;
ares_inet_ntop ( AF_INET , & addr . sin_addr , output , INET_ADDRSTRLEN ) ;
GRPC_ARES_RESOLVER_ TRACE_LOG (
" resolver:%p c-ares resolver gets a AF_INET result: \n "
" addr: %s \n port: %d \n " ,
ares_resolver , output , hostname_qa - > port ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " c-ares resolver gets a AF_INET result: \n addr: " < < output
< < " \n port: " < < hostname_qa - > port ;
break ;
}
default :
@ -689,8 +704,9 @@ void AresResolver::OnSRVQueryDoneLocked(void* arg, int status, int /*timeouts*/,
auto fail = [ & ] ( absl : : string_view prefix ) {
std : : string error_message = absl : : StrFormat (
" %s for %s: %s " , prefix , qa - > query_name , ares_strerror ( status ) ) ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " OnSRVQueryDoneLocked: %s " ,
error_message . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) OnSRVQueryDoneLocked: "
< < error_message ;
ares_resolver - > event_engine_ - > Run (
[ callback = std : : move ( callback ) ,
status = AresStatusToAbslStatus ( status , error_message ) ] ( ) mutable {
@ -701,13 +717,14 @@ void AresResolver::OnSRVQueryDoneLocked(void* arg, int status, int /*timeouts*/,
fail ( " SRV lookup failed " ) ;
return ;
}
GRPC_ARES_RESOLVER_ TRACE_LOG (
" resolver:%p OnSRVQueryDoneLocked name=%s ARES_SUCCESS " , ares_resolver ,
qa - > query_name . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " OnSRVQueryDoneLocked name= " < < qa - > query_name < < " ARES_SUCCESS " ;
struct ares_srv_reply * reply = nullptr ;
status = ares_parse_srv_reply ( abuf , alen , & reply ) ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p ares_parse_srv_reply: %d " ,
ares_resolver , status ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " ares_parse_srv_reply: " < < status ;
if ( status ! = ARES_SUCCESS ) {
fail ( " Failed to parse SRV reply " ) ;
return ;
@ -748,8 +765,9 @@ void AresResolver::OnTXTDoneLocked(void* arg, int status, int /*timeouts*/,
auto fail = [ & ] ( absl : : string_view prefix ) {
std : : string error_message = absl : : StrFormat (
" %s for %s: %s " , prefix , qa - > query_name , ares_strerror ( status ) ) ;
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p OnTXTDoneLocked: %s " ,
ares_resolver , error_message . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " OnTXTDoneLocked: " < < error_message ;
ares_resolver - > event_engine_ - > Run (
[ callback = std : : move ( callback ) ,
status = AresStatusToAbslStatus ( status , error_message ) ] ( ) mutable {
@ -760,9 +778,9 @@ void AresResolver::OnTXTDoneLocked(void* arg, int status, int /*timeouts*/,
fail ( " TXT lookup failed " ) ;
return ;
}
GRPC_ARES_RESOLVER_ TRACE_LOG (
" resolver:%p OnTXTDoneLocked name=%s ARES_SUCCESS " , ares_resolver ,
qa - > query_name . c_str ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver
< < " OnTXTDoneLocked name= " < < qa - > query_name < < " ARES_SUCCESS " ;
struct ares_txt_ext * reply = nullptr ;
status = ares_parse_txt_reply_ext ( buf , len , & reply ) ;
if ( status ! = ARES_SUCCESS ) {
@ -779,8 +797,9 @@ void AresResolver::OnTXTDoneLocked(void* arg, int status, int /*timeouts*/,
std : : string ( reinterpret_cast < char * > ( part - > txt ) , part - > length ) ) ;
}
}
GRPC_ARES_RESOLVER_TRACE_LOG ( " resolver:%p Got %zu TXT records " , ares_resolver ,
result . size ( ) ) ;
GRPC_TRACE_LOG ( cares_resolver , INFO )
< < " (EventEngine c-ares resolver) resolver: " < < ares_resolver < < " Got "
< < result . size ( ) < < " TXT records " ;
if ( GRPC_TRACE_FLAG_ENABLED ( cares_resolver ) ) {
for ( const auto & record : result ) {
LOG ( INFO ) < < record ;