Merge pull request grpc#18384 from apolcyn/log_more_query_status

Trace log the status of every c-ares lookup; cleanup error handling
dgl · Mar 15, 2019 · ee72c63 · ee72c63
2 parents 00bc804 + c02034e
commit ee72c63
Showing 1 changed file with 20 additions and 27 deletions.
diff --git a/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc b/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc
@@ -67,9 +67,7 @@ struct grpc_ares_request {
   /** number of ongoing queries */
   size_t pending_queries;
 
-  /** is there at least one successful query, set in on_done_cb */
-  bool success;
-  /** the errors explaining the request failure, set in on_done_cb */
+  /** the errors explaining query failures, appended to in query callbacks */
   grpc_error* error;
 };
 
@@ -145,6 +143,10 @@ void grpc_ares_complete_request_locked(grpc_ares_request* r) {
   ServerAddressList* addresses = r->addresses_out->get();
   if (addresses != nullptr) {
     grpc_cares_wrapper_address_sorting_sort(addresses);
+    GRPC_ERROR_UNREF(r->error);
+    r->error = GRPC_ERROR_NONE;
+    // TODO(apolcyn): allow c-ares to return a service config
+    // with no addresses along side it
   }
   GRPC_CLOSURE_SCHED(r->on_done, r->error);
 }
@@ -175,9 +177,9 @@ static void on_hostbyname_done_locked(void* arg, int status, int timeouts,
       static_cast<grpc_ares_hostbyname_request*>(arg);
   grpc_ares_request* r = hr->parent_request;
   if (status == ARES_SUCCESS) {
-    GRPC_ERROR_UNREF(r->error);
-    r->error = GRPC_ERROR_NONE;
-    r->success = true;
+    GRPC_CARES_TRACE_LOG(
+        "request:%p on_hostbyname_done_locked host=%s ARES_SUCCESS", r,
+        hr->host);
     if (*r->addresses_out == nullptr) {
       *r->addresses_out = grpc_core::MakeUnique<ServerAddressList>();
     }
@@ -229,27 +231,24 @@ static void on_hostbyname_done_locked(void* arg, int status, int timeouts,
         }
       }
     }
-  } else if (!r->success) {
+  } else {
     char* error_msg;
     gpr_asprintf(&error_msg, "C-ares status is not ARES_SUCCESS: %s",
                  ares_strerror(status));
+    GRPC_CARES_TRACE_LOG("request:%p on_hostbyname_done_locked host=%s %s", r,
+                         hr->host, error_msg);
     grpc_error* error = GRPC_ERROR_CREATE_FROM_COPIED_STRING(error_msg);
     gpr_free(error_msg);
-    if (r->error == GRPC_ERROR_NONE) {
-      r->error = error;
-    } else {
-      r->error = grpc_error_add_child(error, r->error);
-    }
+    r->error = grpc_error_add_child(error, r->error);
   }
   destroy_hostbyname_request_locked(hr);
 }
 
 static void on_srv_query_done_locked(void* arg, int status, int timeouts,
                                      unsigned char* abuf, int alen) {
   grpc_ares_request* r = static_cast<grpc_ares_request*>(arg);
-  GRPC_CARES_TRACE_LOG("request:%p on_query_srv_done_locked", r);
   if (status == ARES_SUCCESS) {
-    GRPC_CARES_TRACE_LOG("request:%p on_query_srv_done_locked ARES_SUCCESS", r);
+    GRPC_CARES_TRACE_LOG("request:%p on_srv_query_done_locked ARES_SUCCESS", r);
     struct ares_srv_reply* reply;
     const int parse_status = ares_parse_srv_reply(abuf, alen, &reply);
     if (parse_status == ARES_SUCCESS) {
@@ -273,17 +272,15 @@ static void on_srv_query_done_locked(void* arg, int status, int timeouts,
     if (reply != nullptr) {
       ares_free_data(reply);
     }
-  } else if (!r->success) {
+  } else {
     char* error_msg;
     gpr_asprintf(&error_msg, "C-ares status is not ARES_SUCCESS: %s",
                  ares_strerror(status));
+    GRPC_CARES_TRACE_LOG("request:%p on_srv_query_done_locked %s", r,
+                         error_msg);
     grpc_error* error = GRPC_ERROR_CREATE_FROM_COPIED_STRING(error_msg);
     gpr_free(error_msg);
-    if (r->error == GRPC_ERROR_NONE) {
-      r->error = error;
-    } else {
-      r->error = grpc_error_add_child(error, r->error);
-    }
+    r->error = grpc_error_add_child(error, r->error);
   }
   grpc_ares_request_unref_locked(r);
 }
@@ -294,12 +291,12 @@ static void on_txt_done_locked(void* arg, int status, int timeouts,
                                unsigned char* buf, int len) {
   char* error_msg;
   grpc_ares_request* r = static_cast<grpc_ares_request*>(arg);
-  GRPC_CARES_TRACE_LOG("request:%p on_txt_done_locked", r);
   const size_t prefix_len = sizeof(g_service_config_attribute_prefix) - 1;
   struct ares_txt_ext* result = nullptr;
   struct ares_txt_ext* reply = nullptr;
   grpc_error* error = GRPC_ERROR_NONE;
   if (status != ARES_SUCCESS) goto fail;
+  GRPC_CARES_TRACE_LOG("request:%p on_txt_done_locked ARES_SUCCESS", r);
   status = ares_parse_txt_reply_ext(buf, len, &reply);
   if (status != ARES_SUCCESS) goto fail;
   // Find service config in TXT record.
@@ -337,12 +334,9 @@ static void on_txt_done_locked(void* arg, int status, int timeouts,
   gpr_asprintf(&error_msg, "C-ares TXT lookup status is not ARES_SUCCESS: %s",
                ares_strerror(status));
   error = GRPC_ERROR_CREATE_FROM_COPIED_STRING(error_msg);
+  GRPC_CARES_TRACE_LOG("request:%p on_txt_done_locked %s", r, error_msg);
   gpr_free(error_msg);
-  if (r->error == GRPC_ERROR_NONE) {
-    r->error = error;
-  } else {
-    r->error = grpc_error_add_child(error, r->error);
-  }
+  r->error = grpc_error_add_child(error, r->error);
 done:
   grpc_ares_request_unref_locked(r);
 }
@@ -534,7 +528,6 @@ static grpc_ares_request* grpc_dns_lookup_ares_locked_impl(
   r->on_done = on_done;
   r->addresses_out = addrs;
   r->service_config_json_out = service_config_json;
-  r->success = false;
   r->error = GRPC_ERROR_NONE;
   r->pending_queries = 0;
   GRPC_CARES_TRACE_LOG(