BIND9 logging gets too verbose (too chatty) for my taste

grigory · 11-01-2015, 09:23 AM

Hello!

I've configured logging in my BIND9 server and I have 2 log files:
1) debug.log;
2) query.log.
The second one is Okay. No complaints so far. But the first one is too verbose (too chatty) for me. Like 90% of what it says there I don't even understand. You get like 100's of thousands of text lines within couple of hours only. That's crazy!
Here how it's set:

Code:

 channel debug_log {
         file "/var/log/named/debug.log";
        severity debug 3;

If I understand it right, to make it less verbose (chatty), I can try debug 2 or simply debug (which defaults to debug 1). Right?
The next level (less chatty) would be:

Code:

severity info;

Right?

bathory · 11-01-2015, 12:56 PM

Quote:

If I understand it right, to make it less verbose (chatty), I can try debug 2 or simply debug (which defaults to debug 1). Right?
The next level (less chatty) would be:

severity info;

You could use severity "warning" or "notice", that are less verbose.
Besides debug is used for debugging purposes, so it's not recommended for a production dns server

Regards

grigory · 11-01-2015, 10:51 PM

Thanks for your reply!

I don't know... After I switched to info, both logs stopped doing anything (they're both empty).

Here's my full logging section:

Quote:

logging {

channel debug_log {
file "/var/log/named/debug.log";
severity info;
print-category yes;
print-severity yes;
print-time yes;
};

channel query_log {
file "/var/log/named/query.log";
severity dynamic;
print-category yes;
print-severity yes;
print-time yes;
};

category resolver { debug_log; };
category security { debug_log; };
category queries { query_log; };

};

grigory · 11-01-2015, 11:22 PM

Sorry, had to re-start BIND. Now my second file gets the info (query.log), but debug.log is still empty.

Has switched debug.log to notice, still no difference. query.log is getting the info, but debug.log is still empty. Looks like it needs to be done differently...

bathory · 11-02-2015, 02:38 AM

Quote:

Originally Posted by grigory

Sorry, had to re-start BIND. Now my second file gets the info (query.log), but debug.log is still empty.

Has switched debug.log to notice, still no difference. query.log is getting the info, but debug.log is still empty. Looks like it needs to be done differently...

If the logfile remains blank that means that everything works as expected

If you want, you can turn severity to info (the default), so you get some logs.
Read this for more info

Regards

grigory · 11-02-2015, 04:39 AM

Thanks for your reply!
Frankly, it needs some clarification for me. Otherwise, I don't quite understand.
Are you saying that in my debug.log I won't get any info if all works right? But that's when I use info level or less. When I had severity level debug 3, I got too much info being added into the log file. Again, right now I'm talking about my 1st log file (debug.log). As per 2nd log file (query.log), it gets "populated" without any issues, no matter what.
Is it Okay to have two different levels of severity at the same time for my two log files OR I'd better stick to just one?
Does it make any difference?

bathory · 11-02-2015, 07:16 AM

Quote:

Are you saying that in my debug.log I won't get any info if all works right?

Yes. If you're using severity notice and above, you'll get no logs, unless something goes terribly wrong.

Quote:

When I had severity level debug 3, I got too much info being added into the log file. Again, right now I'm talking about my 1st log file (debug.log). As per 2nd log file (query.log), it gets "populated" without any issues, no matter what.

Debug and its various levels is used when you're having dns problems. In a normal dns operation you don't need debug.
The default severity info is good in most cases.

Quote:

Is it Okay to have two different levels of severity at the same time for my two log files OR I'd better stick to just one?
Does it make any difference?

These are 2 different logs. One regarding the dns operation and the other regarding client queries.
In a production server with a modest traffic, you don't even need to log the queries, as it makes the respective logfile getting big very fast. That's why the queries category is not enabled by default in bind logging.
So it's up to you what you want to log and how to do this.

BTW you can use rndc to change the logging setting at run-time.

grigory · 11-02-2015, 08:05 AM

Thank you!

Well, I should probably learn some more about BIND9 logging, 'cos it seems to me a little bit more complicated than it should've been.
And what about just temporarily commenting out just the debug.log section? Should I use # for that?

bathory · 11-02-2015, 08:43 AM

Quote:

Originally Posted by grigory

Thank you!

Well, I should probably learn some more about BIND9 logging, 'cos it seems to me a little bit more complicated than it should've been.
And what about just temporarily commenting out just the debug.log section? Should I use # for that?

You should also comment out:

Quote:

category resolver { debug_log; };
category security { debug_log; };

or use another logging channel.

grigory · 11-02-2015, 10:47 AM

Some update:
I have severity level "notice" for debug.log
After I turned on my PC, there's something new that was added to the file:

02-Nov-2015 19:16:01.684 security: warning: using built-in root key for view _default

And query.log works as usual. Does it mean that both files are getting the info that they should be getting under the conditions set in named.conf.local? Should I just leave it alone for now and IF there're problems with BIND, then I could escalate the severity level to debug 3 for debugging purposes?

bathory · 11-02-2015, 12:16 PM

Quote:

have severity level "notice" for debug.log
After I turned on my PC, there's something new that was added to the file:

02-Nov-2015 19:16:01.684 security: warning: using built-in root key for view _default

From the log snippet above, I see that you use severity warningand not severity notice. Not a big deal, but note that's less verbose than notice.

Quote:

And query.log works as usual. Does it mean that both files are getting the info that they should be getting under the conditions set in named.conf.local?

Yup

Quote:

Should I just leave it alone for now and IF there're problems with BIND, then I could escalate the severity level to debug 3 for debugging purposes?

As I've already told you, turn on debugging only if you have problems that are not logged with the current setting.

grigory · 11-02-2015, 07:26 PM

Thanks for your reply!

How could it be that I'm using severity level "warning", when my debug.log is set to "notice" and query.log to "dynamic"?

Can I make it this way?

Quote:

category default { debug_log; };
category queries { query_log; };

So BIND would log everything except the queries which would go to query.log?

OR... I could do this?

Quote:

logging {

#channel debug_log {
# file "/var/log/named/debug.log";
# severity debug 3;
# print-category yes;
#print-severity yes;
# print-time yes;
# };

channel query_log {
file "/var/log/named/query.log";
severity dynamic;
print-category yes;
print-severity yes;
print-time yes;
};

#category resolver { debug_log; };
#category security { debug_log; };
category queries { query_log; };

};

And then uncomment the appropriate lines if needed for debugging purposes...?

grigory · 11-02-2015, 09:04 PM

P.S. In my example above " 02-Nov-2015 19:16:01.684 security: warning: using built-in root key for view _default" I just happened to extract the line which corresponded to a LOWER LEVEL than the current that was set at a time. Bad example.

bathory · 11-03-2015, 02:19 AM

Yes you can have debug stuff commented out and uncomment it when needed
Or you can set the debug level to 0 at a first place and use

Code:

rndc trace X

to start using debug at level X

grigory · 11-03-2015, 03:58 AM

Thank you!