Browse Source

[1383] Log more detailed information on response received by NSAS

Not strictly part of the ticket, but added because the first tests I
did with the existing code returned NSAS_INVALID_RESPONSE messages. This
was a common error to three conditions: the change separates these
out and logs a different message for each one.  It also changes the
severity of two of those conditions (which are caused by the contents
of the returned packet) from ERROR to DEBUG.

(Of course, once the change was made, the original problem could not
be reproduced...
 Please enter the commit message for your changes. Lines starting
Stephen Morris 13 years ago
parent
commit
d6d90c1976
2 changed files with 36 additions and 17 deletions
  1. 18 6
      src/lib/nsas/nameserver_entry.cc
  2. 18 11
      src/lib/nsas/nsas_messages.mes

+ 18 - 6
src/lib/nsas/nameserver_entry.cc

@@ -1,4 +1,4 @@
-// Copyright (C) 2010  Internet Systems Consortium, Inc. ("ISC")
+// Copyright (C) 2010-2011  Internet Systems Consortium, Inc. ("ISC")
 //
 //
 // Permission to use, copy, modify, and/or distribute this software for any
 // Permission to use, copy, modify, and/or distribute this software for any
 // purpose with or without fee is hereby granted, provided that the above
 // purpose with or without fee is hereby granted, provided that the above
@@ -223,7 +223,8 @@ class NameserverEntry::ResolverCallback :
          * \short We received the address successfully.
          * \short We received the address successfully.
          *
          *
          * This extracts the addresses out from the response and puts them
          * This extracts the addresses out from the response and puts them
-         * inside the entry. It tries to reuse the address entries from before (if there were any), to keep their RTTs.
+         * inside the entry. It tries to reuse the address entries from before
+         * (if there were any), to keep their RTTs.
          */
          */
         virtual void success(MessagePtr response_message) {
         virtual void success(MessagePtr response_message) {
             time_t now = time(NULL);
             time_t now = time(NULL);
@@ -231,10 +232,21 @@ class NameserverEntry::ResolverCallback :
             Lock lock(entry_->mutex_);
             Lock lock(entry_->mutex_);
 
 
             // TODO: find the correct RRset, not simply the first
             // TODO: find the correct RRset, not simply the first
-            if (!response_message ||
-                response_message->getRcode() != isc::dns::Rcode::NOERROR() ||
+            if (!response_message) {
+                LOG_ERROR(nsas_logger, NSAS_NULL_RESPONSE).arg(entry_->getName());
+                failureInternal(lock);
+                return;
+
+            } else if (response_message->getRcode() != isc::dns::Rcode::NOERROR()) {
+                LOG_DEBUG(nsas_logger, NSAS_DBG_RESULTS, NSAS_ERROR_RESPONSE).
+                          arg(response_message->getRcode()).arg(entry_->getName());
+                failureInternal(lock);
+                return;
+
+            } else if (
                 response_message->getRRCount(isc::dns::Message::SECTION_ANSWER) == 0) {
                 response_message->getRRCount(isc::dns::Message::SECTION_ANSWER) == 0) {
-                LOG_ERROR(nsas_logger, NSAS_INVALID_RESPONSE).arg(entry_->getName());
+                LOG_DEBUG(nsas_logger, NSAS_DBG_RESULTS, NSAS_EMPTY_RESPONSE).
+                          arg(entry_->getName());
                 failureInternal(lock);
                 failureInternal(lock);
                 return;
                 return;
             }
             }
@@ -371,7 +383,7 @@ class NameserverEntry::ResolverCallback :
             }
             }
         }
         }
 
 
-        // Handle a failure to optain data. Dispatches callbacks and leaves
+        // Handle a failure to obtain data. Dispatches callbacks and leaves
         // lock unlocked
         // lock unlocked
         void failureInternal(Lock &lock) {
         void failureInternal(Lock &lock) {
             // Set state of the addresses
             // Set state of the addresses

+ 18 - 11
src/lib/nsas/nsas_messages.mes

@@ -14,6 +14,16 @@
 
 
 $NAMESPACE isc::nsas
 $NAMESPACE isc::nsas
 
 
+% NSAS_EMPTY_RESPONSE response to query for %2 returned an empty answer section
+The NSAS (nameserver address store - part of the resolver) made a query
+for information it needed.  The query completed successfully but the
+answer section in the response was empty.
+
+% NSAS_ERROR_RESPONSE error response of %1 returned in query for %2
+The NSAS (nameserver address store - part of the resolver) made a query
+for information it needed.  The query successfully completed but RCODE
+in the response was something other than NOERROR.
+
 % NSAS_FIND_NS_ADDRESS asking resolver to obtain A and AAAA records for %1
 % NSAS_FIND_NS_ADDRESS asking resolver to obtain A and AAAA records for %1
 A debug message issued when the NSAS (nameserver address store - part
 A debug message issued when the NSAS (nameserver address store - part
 of the resolver) is making a callback into the resolver to retrieve the
 of the resolver) is making a callback into the resolver to retrieve the
@@ -24,17 +34,6 @@ A debug message issued when the NSAS (nameserver address store - part
 of the resolver) has retrieved the given address for the specified
 of the resolver) has retrieved the given address for the specified
 nameserver through an external query.
 nameserver through an external query.
 
 
-% NSAS_INVALID_RESPONSE queried for %1 but got invalid response
-The NSAS (nameserver address store - part of the resolver) made a query
-for a RR for the specified nameserver but received an invalid response.
-Either the success function was called without a DNS message or the
-message was invalid on some way. (In the latter case, the error should
-have been picked up elsewhere in the processing logic, hence the raising
-of the error here.)
-
-This message indicates an internal error in the NSAS.  Please raise a
-bug report.
-
 % NSAS_LOOKUP_CANCEL lookup for zone %1 has been canceled
 % NSAS_LOOKUP_CANCEL lookup for zone %1 has been canceled
 A debug message issued when an NSAS (nameserver address store - part of
 A debug message issued when an NSAS (nameserver address store - part of
 the resolver) lookup for a zone has been canceled.
 the resolver) lookup for a zone has been canceled.
@@ -46,6 +45,14 @@ for the specified nameserver.  This is not necessarily a problem - the
 nameserver may be unreachable, in which case the NSAS will try other
 nameserver may be unreachable, in which case the NSAS will try other
 nameservers in the zone.
 nameservers in the zone.
 
 
+% NSAS_NULL_RESPONSE got null message in success callback for query for %1
+The NSAS (nameserver address store - part of the resolver) made a query
+for information it needed.  The query completed completed successfully,
+but the message passed to the callback was null.
+
+This message indicates an internal error in the NSAS.  Please raise a
+bug report.
+
 % NSAS_SEARCH_ZONE_NS searching NSAS for nameservers for zone %1
 % NSAS_SEARCH_ZONE_NS searching NSAS for nameservers for zone %1
 A debug message output when a call is made to the NSAS (nameserver 
 A debug message output when a call is made to the NSAS (nameserver 
 address store - part of the resolver) to obtain the nameservers for 
 address store - part of the resolver) to obtain the nameservers for