bind 9 logging best practices

© Men & Mice http://menandmice.com

WebinarBIND 9 logging best practices

1

2.2.2017


Agenda - BIND 9 logging

BIND 9 logging configuration

The BIND 9 logging categories

Query- and Debug-Logging

A BIND 9 logging configuration template

Using the logeater tools

Filtering Logs with artificial ignorance

2


BIND 9 logging configuration

3


BIND 9 logging

Compared with other Unix-Daemons, BIND 9 has a sophisticated log infrastructure built in.

It contains:

•several destinations for log information (channel)

•logging to syslog, stdout, files

•several categories

•syslog severities

•date/timestamp

•automatic size-based log-file rotation

4


BIND Logging

Channel (where to log)

syslog

file /var/named/query.log

file /var/named/transfer.log

null

stdout

Category (what to log)

security

xfer-in / xfer-out

queries

dnssec

default

5


The Default Category

The default category defines the logging for categories where no specific configuration has been defined

The queries category is an exception, and not logged through default.

6

Category (what to log)

default


Example Logging Configuration

logging { channel syslog { syslog daemon; severity info; }; channel stdout { stderr; severity info; }; channel transfer_log { file "/var/named/transfer.log" versions 10 size 10M; severity info; print-time yes; print-severity yes; print-category yes; }; channel query_log { file "/var/named/query.log" versions 10 size 50M; severity debug; print-time yes; }; category security { syslog; }; category queries { query_log; }; category xfer-in { transfer_log; }; category xfer-out { transfer_log; }; category dnssec { syslog; }; category default { syslog; stdout; };};

7

Channel names have no special meaning (this includes

syslog and stdout in the example).

By default, file size is not limited, and file rotation (versions) are not made.

The default severity is info.

By default, the time, severity and category are not logged.


Predefined Channels

logging { channel syslog { syslog daemon; severity info; }; channel stdout { stderr; severity info; }; channel transfer_log { file "/var/named/transfer.log" versions 10 size 10M; severity info; print-time yes; print-severity yes; print-category yes; }; channel query_log { file "/var/named/query.log" versions 10 size 50M; severity debug; print-time yes; }; category security { default_syslog; }; category queries { query_log; }; category xfer-in { transfer_log; }; category xfer-out { transfer_log; }; category dnssec { default_syslog; }; category default { default_syslog; default_stderr; };};

8

There are four predefined channels:

default_syslog, default_stderr,default_debug,

null.

default_syslog and default_stderr are identical to the channels in the example, making those unnecessary.

default_debug writes to the file named.run in BIND's working

directory.


Logging Defaults

If named.conf has no logging statement, BIND essentially defaults to use syslog.

The default configuration is:logging { category default { default_syslog; default_debug; }; category unmatched { null; };};

The BIND 9 process can be started with a default log-file. The default category will then be logged into this file instead to syslog:

# named -L /var/log/bind9.log

9


BIND 9 logging categories

10


logging categories (1)

Below is a list of available logging categories in BIND 9

11

https://ftp.isc.org/isc/bind9/cur/9.11/doc/arm/Bv9ARM.pdf

Category Description

default The default category defines the logging options for those categories where no specific configuration has been defined.

client Processing of client requests.

cname Logs nameservers that are skipped due to them being a CNAME rather than A / AAAA records.

config Configuration file parsing and processing.



12



database Messages relating to the databases used internally by the name server to store zone and cache data.

delegation-only Logs queries that have been forced to NXDOMAIN as the result of a delegation-only zone or statement. declaration

dispatch Dispatching of incoming packets to the server modules where they are to be processed.

dnssec DNSSEC and TSIG protocol processing.

dnstap The "dnstap" DNS traffic capture system.

edns-disabled Log queries that have been forced to use plain DNS due to timeouts. See BIND 9 ARM for additional information.

general The catch-all. Many things still aren’t classified into categories, and they all end up here

lame-servers Lame servers. These are misconfigurations in remote servers.



13



network Network operations.

notify The NOTIFY protocol. Used to inform servers of slave-copies of a zone about changes.

queries Query-Logging. See below.

query-errors Information about queries that resulted in some failure.

rate-limit DNS response rate limiting. Logs start- and end-times of limiting.

resolver DNS resolution, such as the recursive lookups performed on behalf of clients by a caching name server.

rpz Information about errors in response policy zone files, rewritten responses.

security Approval and denial of requests. ACL violations.



14



spill Logs queries that have been terminated, either by dropping or responding with SERVFAIL, or as a result of a fetchlimit quota.

unmatched Messages that named was unable to determine the class of or for which there was no matching view.

update Dynamic updates.

update-security Approval and denial of update requests.

xfer-in Zone transfers the server is receiving.

xfer-out Zone transfers the server is sending.


Query Logging

•Query logging generates one line for each query received, and can be toggled on/off with: rndc querylog

•Logging queries slows BIND down significantly.

•Use it for troubleshooting.

•A server receiving 100 qps (queries/sec) handles logging.

•Tests show a server with 400 kqps drops to 50% performance with query logging enabled.

15


Query Logging

31-Jan-2016 21:39:27.784 client ::1#42482 (alpha.zone02.dnslab.org):query: alpha.zone02.dnslab.org IN A +ET (::1)31-Jan-2016 21:48:30.172 client 192.168.53.251#7691 (zone02.dnslab.org): query: zone02.dnslab.org IN NS -EDC (192.168.53.102)

client's IP address and port

domain name queried

record type queried

Flags: (+) = recursive query (RD flag) (-) = iterative query (no RD flag) (E) = EDNS used in query (T) = query over TCP(D) = DO (DNSSEC Ok) (C)= Checking Disabled (S) = Signed Query

Server's address query arrived on

16


Debug-Logging

•trace <level>: Change BIND's debugging level to the file "named.run" (Reading output requires some knowledge of BIND internals.) rndc trace 10rndc tracerndc notracerndc trace 0

•The debugging level is part of BIND's status. rndc status | grep debugdebug level: 0

17

Set debug level to ten.

Increase the debugging level by one (now 11).

Either command will disable debugging.


rndc trace

> rndc trace 15> dig +noall slaveme.dnslab.org soa> cat named.run25-Nov-2015 09:56:11.012 debug level is now 1525-Nov-2015 09:56:34.167 client 192.168.53.251#49360: UDP request25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: using view '_default'25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: request is not signed25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: recursion not available25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: query25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): ns_client_attach: ref = 125-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): query 'slaveme.dnslab.org/SOA/IN' approved25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): send25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): sendto25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): senddone25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): next25-Nov-2015 09:56:34.168 client 192.168.53.251#49360 (slaveme.dnslab.org): ns_client_detach: ref = 025-Nov-2015 09:56:34.168 client 192.168.53.251#49360 (slaveme.dnslab.org): endrequest25-Nov-2015 09:56:34.168 client @0xb7430868: udprecv[...]

18

The commands were run on the authoritative server for the

queried zone.


rndc trace

> rndc trace 15> dig +noall slaveme.dnslab.org soa> cat named.run25-Nov-2015 09:56:11.012 debug level is now 1525-Nov-2015 09:56:34.167 client 192.168.53.251#49360: UDP request25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: using view '_default'25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: request is not signed25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: recursion not available25-Nov-2015 09:56:34.167 client 192.168.53.251#49360: query25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): ns_client_attach: ref = 125-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): query 'slaveme.dnslab.org/SOA/IN' approved25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): send25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): sendto25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): senddone25-Nov-2015 09:56:34.167 client 192.168.53.251#49360 (slaveme.dnslab.org): next25-Nov-2015 09:56:34.168 client 192.168.53.251#49360 (slaveme.dnslab.org): ns_client_detach: ref = 025-Nov-2015 09:56:34.168 client 192.168.53.251#49360 (slaveme.dnslab.org): endrequest25-Nov-2015 09:56:34.168 client @0xb7430868: udprecv[...]

19

original query name. use to group all messages for one

query, on a busy server


BIND 9 log configuration templates

20


Resolver Logging Template

Below is a template for the BIND 9 logging configuration for a DNS resolver:

logging { channel named { file "named.log" versions 10 size 20M; print-time yes; print-category yes; }; channel security { file "security.log" versions 10 size 20M; print-time yes; }; channel dnssec { file "dnssec.log" versions 10 size 20M; print-time yes; }; channel resolver { file "resolver.log" versions 10 size 20M; print-time yes; }; channel query_log { file "query.log" versions 10 size 20M; severity debug; print-time yes; }; channel query-error { file "query-errors.log" versions 10 size 20M; severity info; print-time yes; }; category default { default_syslog; named; }; category general { default_syslog; named; }; category security { security; }; category queries { query_log; }; category dnssec { dnssec; }; category edns-disabled { default_syslog; }; category config { default_syslog; named; }; category resolver { resolver; }; category spill { default_syslog; named; }; category client { default_syslog; named; }; category network { default_syslog; named; }; category lame-servers { null; }; };

21


Authoritative-Server Logging Template

Below is a template for the BIND 9 logging configuration for an authoritative DNS-Server: logging { channel named { file "named.log" versions 10 size 20M; print-time yes; print-category yes; }; channel security { file "security.log" versions 10 size 20M; print-time yes; }; channel ratelimit { file "ratelimit.log" versions 10 size 20M; print-time yes; }; channel query_log { file "query.log" versions 10 size 20M; severity debug; print-time yes; }; channel query-error { file "query-errors.log" versions 10 size 20M; severity info; print-time yes; }; channel xfer { file "transfer.log" versions 10 size 10M; print-time yes; }; channel update { file "update.log" versions 10 size 10M; print-time yes; }; category default { default_syslog; named; }; category general { default_syslog; named; }; category security { security; }; category queries { query_log; }; category config { default_syslog; named; }; category resolver { resolver; }; category network { default_syslog; named; }; category rate-limit { ratelimit; }; category xfer-in { default_syslog; xfer; }; category xfer-out { default_syslog; xfer; }; category notify { default_syslog; xfer; }; category update { default_syslog; update; }; category update-security { default_syslog; update; }; };

22


Men & Mice logeater tools

23


Men & Mice "logeater" tools

the logeater tools are a collection of tools around BIND 9 log files

The source code (golang) can be found at https://github.com/menandmice-services/logeater

Binary executable for Linux (x86_64/i386), MacOS X (x86_64) and Windows can be found on the Men & Mice Packages download serverhttp://packages.menandmice.com/logeater/

24



logeater-queries will read a BIND 9 (9.10+) style query log file and will output statistics and aggregated information from the file:$ ./logeater-queries -h

Usage of ./logeater-queries: -c list query network classes -d list domain names -i list query IP addresses -n no reverse IP lookup -s list statistics -t list query type

25



logeater-queries Example - printing overall statistics:$ cat query.log | ./logeater-queries -s | column -t -s ":"

Query-Statistics21385 total queries ( 100 % )20471 iterative queries ( 95 % )914 recursive queries ( 4 % )863 queries over TCP ( 4 % )16987 queries with EDNS support ( 79 % )15197 queries indicate DNSSEC support ( 71 % )8804 queries with DNSSEC validation disabled (CD-flag) ( 41 % )1571 queries TSIG signed ( 7 % )

26



logeater-queries Example - printing network classes and query types of queries:$ cat query.log | ./logeater-queries -c -t | column -tQuery-Network-Classes21379 : IN6 : CHQuery-Network-Types8514 : A4060 : AAAA3079 : SOA2372 : DNSKEY927 : PTR658 : MX543 : NS312 : DS286 : TXT186 : NSEC129 : ANY115 : CNAME[…]

27



logeater-queries Example - printing the top ten query IP addresses with reverse name resolution (can be slow): $ cat query.log | ./logeater-queries -i | head | column -t

Query-IP-Addresses1571 : 212.114.206.217 [muc.example.de.]821 : 2620:74:13:4400::41 [dnsviz-db.verisignlabs.com.]794 : 72.13.58.112 [dnsviz-db.verisignlabs.com.]704 : 54.234.42.241 [241.compute-1.amazonaws.com.]682 : 2001:19f0:5001:df:76d7:5703:ba0a:e220 []565 : 185.92.221.212 [185.92.221.212.vultr.com.]467 : 185.22.143.29 [b9168f1d.cgn.dg-w.de.]314 : 91.51.184.46 [3b82e.dip0.t-ipconnect.de.]

28



logeater-dnssec analyses the a log file with messages from the "DNSSEC" category and groups the error messages : $ cat dnssec.log | ./logeater-dnssec | head

8727 : 0C9F6LGOE6NADAS8KG1CLIK9UO9G7EIG.ad/NSEC3: no valid signature found 6953 : ad/SOA: no valid signature found 3976 : sat-tv.com/A: got insecure response; parent indicates it should be secure 1730 : mozilla.com/SOA: no valid signature found 1586 : stream.bestvideostreaming.is/A: no valid signature found 1577 : 8FC1DQ3C2Q3ERFD4UO40ENDBTSFME5JO5.ad/NSEC3: no valid signature found 1576 : sat-tv.com/SOA: got insecure response; parent indicates it should be secure 1576 : cdws.eu-west-1.amazonaws.com.Cisco/AAAA: bad cache hit (amazonaws.com.Cisco/DS) 1483 : 0c9f6lgoe6n13ad9iu1clik9uo9g7eig.ad/NSEC3: no valid signature found 968 : cbr.de/NSEC: no valid signature found

29



logeater-resolver analyses the a log file with messages from the "resolver" category and groups the error messages : $ cat resolvers.log | ./logeater-resolvers | head

42908 : s-cnc1.qq.com/AAAA: Name qq.com (SOA) not subdomain of zone ns-cnc1.qq.com -- invalid response42713 : s-tel1.qq.com/AAAA: Name qq.com (SOA) not subdomain of zone ns-tel1.qq.com -- invalid response42484 : s-os1.qq.com/AAAA: Name qq.com (SOA) not subdomain of zone ns-os1.qq.com -- invalid response42297 : s-cmn1.qq.com/AAAA: Name qq.com (SOA) not subdomain of zone ns-cmn1.qq.com -- invalid response20346 : mails.sonymusicfans.com/DS: invalid response10920 : tp1.glb.nist.gov/DS: invalid response9693 : media.netd.com.tr/AAAA for client 192.0.2.165#3347: Name netd.com.tr (SOA) not subdomain of zone media.netd.com.tr -- invalid response7932 : service.superc.net/AAAA for client 192.0.2.11#3073: Name superc.net (SOA) not subdomain of zone service.superc.net — invalid response4597 : brickleonavon.com/NS for client 192.0.2.46#3073: Name . (SOA) not subdomain of zone brickleonavon.com -- invalid response4474 : promo.mobile.de/AAAA for client 2001:db8:1800:88:78f9:ba4:45fe:d438#48296: Name mobile.de (SOA) not subdomain of zone promo.mobile.de -- invalid response

30


Filtering logs with artificial ignorance

31


Artificial Ignorance

Artificial ignorance is a concept coined by Marcus Ranum. It is used to filter the noise away from any log-file. To apply "ai"

1.Inspect a log message. Decide if the log message is a serious issue.

A.If yes, fix the issue.

B.If no, enter the message into a filter expression that hides the message in the future.

2.Repeat 1. until all messages are gone.

3.Inspect the filtered log every day (for example, have the log output send my mail to your inbox). Apply steps 1a or 1b for every new message.

32

http://www.ranum.com/security/computer_security/papers/ai/


logtemplater

logtemplater is an open source tool that implements artificial ignorance:

• http://www.uberadmin.com/Projects/logtemplater/

• https://github.com/rondilley/tmpltr

Installation

git clone https://github.com/rondilley/tmpltr.git cd tmpltr./bootstrapautoreconf -i./configuremakemake install

33


logtemplater

logtemplater example: $ cat named.log | tmpltr - | sort -n | sed -e 's/%s.*||//' | tail

Opening [-] for read

121 27-Jan-2017 00:51:38.574 client @0x7a0d47b0 2001:19f0::76d7:5703:ba0a:e220#49188 (menandmice.training): transfer of 'menandmice.training/IN': IXFR ended 121 27-Jan-2017 00:51:38.415 zone menandmice.training/IN: sending notifies (serial 315) 170 26-Jan-2017 23:00:37.060 client @0x7bf057b0 192.0.2.197#33796 (1.1.1.1.in-addr.arpa): query failed (REFUSED) for 1.1.1.1.in-addr.arpa/IN/PTR at query.c:6899 216 26-Jan-2017 22:57:22.482 zone _openpgpkey.example.de/IN: next key event: 26-Jan-2017 23:57:22.480 216 26-Jan-2017 22:57:22.480 zone _openpgpkey.example.de/IN: reconfiguring zone keys 5184 26-Jan-2017 22:57:21.702 zone 6.b.2.0.8.9.1.0.1.0.a.2.ip6.arpa/IN: next key event: 26-Jan-2017 23:57:21.675 5184 26-Jan-2017 22:57:21.675 zone 6.b.2.0.8.9.1.0.1.0.a.2.ip6.arpa/IN: reconfiguring zone keys 6495 26-Jan-2017 22:11:20.136 client @0x7bf057b0 192.0.2.217#47130/key dyn.example.de: signer "dyn.example.de" approved 6495 26-Jan-2017 22:11:20.137 client @0x7bf057b0 192.0.2.217#47130/key dyn.example.de: updating […] 6496 26-Jan-2017 22:10:20.765 client @0x7bf057b0 192.0.2.217#42821/key dyn.example.de: updating […]

34

Date and time of 1st occurrence of this type of

message

Number of messages of this type

inside the file

Content of 1st occurrence of this type of message


logtemplater

to filter out well-known but not important log messages, save the template into an "ignore" file and edit the file $ cat named.log | tmpltr w named.log.ignore — $ $EDITOR named.log.ignore

next time, the template will be called with the "ignore" file: $ cat named.log | tmpltr -t named.log.ignore — | sort -n | sed -e 's/%s.*||//'

from a crontab file or cron.daily script:$ cat named.log | tmpltr - | sort -n | sed -e 's/%s.*||//' | \ mailx -s 'BIND 9 Log-Message filtered' [email protected]

35


Men & Mice DNS Training

•Introduction to DNS & BIND Hands-On Class

•March 6 – 8, 2017, Amsterdam NL

•April 3 – 5, 2017, Redwood City (CA), USA

•May 1 – 3, 2017, Boston (MA), USA

•June 5 – 7, 2017, Zürich, Switzerland

36

https://www.menandmice.com/support-training/training/



•Introduction & Advanced DNS and BIND Topics Hands-On Class

•March 6 – 10, 2017, Amsterdam NL

•April 3 – 7, 2017, Redwood City (CA), USA

•May 1 – 5, 2017, Boston (MA), USA

•June 5 – 9, 2017, Zürich, Switzerland

37

https://www.menandmice.com/support-training/training/



•DNS & BIND (German Language)

•February 6 – 8, 2017, Essen, DE

•DNS Sicherheit (German Language)

•February 9-10, 2017, Essen, DE

38

http://linuxhotel.de/


our next webinar DNSSEC Zone Signing Tutorial

Love it or hate it, DNSSEC can make a vital difference to protecting your DNS. Yet starting with DNSSEC can be intimidating.

This webinar is designed as an easy-to-follow tutorial on DNSSEC signing a zone for DNS admins. Our focus will be on DNSSEC zone signing automation with the Knot DNS Server and BIND 9.

Join us for a 45-minute webinar with a Q&A session at the end, on Thursday, March 23, 2017 at 4:00 PM CET/ 3:00 PM GMT/ 11:00 AM EDT / 8:00 AM PDT.

39

https://www.menandmice.com/resources/educational-resources/webinars/dnssec-zone-signing-tutorial/

bind 9 logging best practices

Technology