"recursion available: denied" message even for non-recursive queries?

[gschmid at notes.cc.sunysb.edu]

> gschmid at notes.cc.sunysb.edu wrote:
>
> > I'm running 9.2.0 on a Tru64/DEC UNIX box.
> >
> > In my named.conf file I have an
> >       allow-recursion { acl_list; };
> > statement.
> >
> > Everything seems to be working as expected.
> > Hosts on the acl list get answers to all queries.
> > Hosts not on the acl list do not get answers to
> > recursive queries.
> >
> > The question that I have is with the logging of the
> > security category messages when my name server
> > is queried from hosts not on the acl list.
> >
> > I get the following log message:
> >
> > recursion available: denied
> >
> > when hosts who are not on the acl list make
> > recursive *and* non-recursive queries.  I would
> > have expected that message only when hosts
> > not on the acl list make recursive queries.
> > Why do I also get the message when hosts not
> > on the acl list make non-recursive queries
> > (and get answers to those non-rec. queries)?
>
> I'd consider it a logging bug. Even if the message is intended to be
> purely informational, it shouldn't use the term "denied" in this
situation, nor should it log to the "security" category.
>
>
> - Kevin

             Well if you turn on debugging you get lots of additional
             things logged.

             Mark

OK, I've restarted named with a "-d 9" and made two queries, one recursive
and one non-recursive.

The security log file shows:

Apr 04 10:04:06.825 security: client 192.168.99.28#10203: recursion
available: denied
Apr 04 10:04:25.864 security: client 192.168.99.28#10195: recursion
available: denied

and the named.run file shows:

Apr 04 10:04:06.824 client 192.168.99.28#10203: UDP request
Apr 04 10:04:06.825 client 192.168.99.28#10203: using view '_default'
Apr 04 10:04:06.825 client 192.168.99.28#10203: query
Apr 04 10:04:06.827 client 192.168.99.28#10203: send
Apr 04 10:04:06.827 client 192.168.99.28#10203: sendto
Apr 04 10:04:06.828 client 192.168.99.28#10203: senddone
Apr 04 10:04:06.828 client 192.168.99.28#10203: next
Apr 04 10:04:06.828 client 192.168.99.28#10203: endrequest
Apr 04 10:04:06.828 client @14010aa00: udprecv
Apr 04 10:04:25.862 client 192.168.99.28#10195: UDP request
Apr 04 10:04:25.864 client 192.168.99.28#10195: using view '_default'
Apr 04 10:04:25.864 client 192.168.99.28#10195: query
Apr 04 10:04:25.867 client 192.168.99.28#10195: send
Apr 04 10:04:25.868 client 192.168.99.28#10195: sendto
Apr 04 10:04:25.868 client 192.168.99.28#10195: senddone
Apr 04 10:04:25.868 client 192.168.99.28#10195: next
Apr 04 10:04:25.868 client 192.168.99.28#10195: endrequest
Apr 04 10:04:25.869 client @140106700: udprecv

The debugging info looks the same for both queries.
Was "-d 9" not the correct debug switch & level?
When you said "if you turn on debugging you get lots of additional
things logged", is this what was expected?
I'm not too familiar with running in debug mode,
pls lemme know if there's anything else I can check.

Thanks.