[bind10-dev] b10-resolver.reslib logging comments

[JINMEI Tatuya / 神明達哉]

At Mon, 22 Aug 2011 10:45:59 -0500 (CDT),
"Jeremy C. Reed" <jreed at isc.org> wrote:
> 
> 2011-08-20 02:41:20.231 DEBUG [b10-resolver.reslib] RESLIB_RUNQ_SUCCESS 
> success callback - sending query to 204.238.107.85
> 
> http://bind10.isc.org/docs/bind10-messages.html#RESLIB_RUNQ_SUCCESS
> 
> Not enough info here .... why would it send a query?  Maybe we just need 
> to improve the longer description? (Any suggestions?)

Not reading the code, but from this description:

  A debug message indicating that a RunningQuery's success callback
  has been called because a nameserver has been found, and that a
  query is being sent to the specified nameserver.

my guess is that the resolver tried to send a query to a nameserver
but didn't know the address of it at that time (either because it's
"out-of-bailiwick" or the address information has expired in the
NSAS), and first tried to resolve the address.  And now the resolver
knows the address, it's resuming the pending query.

If my guess is correct, the original description does not seem to be
so bad to me, but that may because I'm too familiar with how a
resolver implementation generally works internally.

I see a different problem in the description though: what's
"RunningQuery"?  It seems to indicate an implementation specific
notion, but unless you're familiar with code details it's not helpful.
Considering this is a debug message it may be okay, but we may want to
consider a way to be more helpful about such implementation-specific
technical terms in log messages.  It would be great, for example, if
the http version of the description has a hyper link to a separate
document that describes the component.

> 2011-08-20 02:41:20.253 DEBUG [b10-resolver.reslib] RESLIB_RTT 
> round-trip time of last query calculated as 21 ms
> 
> Messages like this can be unuseful --- how to know what is "last query"? 
> By sorting busy log and searching it?  Instead of "last query" it could 
> tell us the query details.

Especially because this is a debug message (which would normally be
suppressed), I think it should also include the name/class/type tuple
in the log message.

---
JINMEI, Tatuya