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

[Mark_Andrews at isc.org]

> 
> 
> 
> 
> 
> > 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.
> 
> 
	You had already turned on debugging.  The message in question only
	gets logged when debugging is enabled.

        if (client->view->resolver != NULL &&
            client->view->recursion == ISC_TRUE &&
            /* XXX this will log too much too early */
            ns_client_checkacl(client, "recursion available:",
                               client->view->recursionacl,
                               ISC_TRUE, ISC_LOG_DEBUG(1)) == ISC_R_SUCCESS)

	Mark
--
Mark Andrews, Internet Software Consortium
1 Seymour St., Dundas Valley, NSW 2117, Australia
PHONE: +61 2 9871 4742                 INTERNET: Mark.Andrews at isc.org