Merge branch 'master' into events-replan

Conflicts:
	src/knot/zone/events.c

NEWS

@@ -4,6 +4,13 @@ Knot DNS NEWS
 -----------------------
 Features:
 	* edns-client-subnet support in kdig
+	* Optional asynchronous startup (config "asynchronous-start")
+Improvements:
+	* Preempt task queue for faster reload
+	* Lazy zone file write after zone transfer (governed by "zonefile-sync")
+Bugfixes:
+	* Close zone transfer after SERVFAIL response
+	* Incremental to full zone transfer fallback, wrong log message
 
 1.5.0-rc1 - Jun 3, 2014
 -----------------------

configure.ac

 #                                               -*- Autoconf -*-
 
 AC_PREREQ([2.60])
-AC_INIT([knot], [1.5.0-rc1], [knot-dns@labs.nic.cz])
+AC_INIT([knot], [1.5.0-rc2], [knot-dns@labs.nic.cz])
 AM_INIT_AUTOMAKE([gnits subdir-objects dist-xz -Wall -Werror])
 AM_SILENT_RULES([yes])
 AC_CONFIG_SRCDIR([src/knot/main.c])

doc/configuration.rst

@@ -23,7 +23,7 @@ which can be used as a base for your Knot DNS setup::
     }
 
     log {
-      syslog { any notice, warning, error; }
+      syslog { any info; }
     }
 
     zones {
@@ -40,10 +40,10 @@ Now let's go step by step through this minimal configuration file:
   on port 53 and second IPv6 called ``second_int`` also listening on
   port 53, which is the default port for the DNS. See :ref:`interfaces`.
 * The ``log`` statement defines the log facilities for Knot DNS.
-  In this example we told Knot DNS to send its log messages with the severities
-  ``debug``, ``warning`` and ``notice`` into the syslog.
-  If you omit this sections, all severities will printed to
-  either ``stdout`` or ``stderr``, and the severities
+  In this example we told Knot DNS to send its log messages with the severity
+  ``info`` or more serious to the syslog.
+  If you omit this sections, all severities will be printed
+  either to ``stdout`` or ``stderr``, and the severities
   from the ``warning`` and more serious to syslog. You can find all
   possible combinations in the :ref:`log`.
 * The ``zones`` statement is probably the most important one,

doc/reference.rst

@@ -1063,10 +1063,10 @@ an error:
 
     log {
       [ log_name {
-        [ category severity [, severity ... ]; ]
+        [ category severity; ]
       } ]
       [ log_file filename {
-        [ category severity [, severity ... ]; ]
+        [ category severity; ]
       } ]
     }
 
@@ -1104,7 +1104,6 @@ Knot DNS allows user to choose from these logging categories:
 
 * ``server`` - Messages related to general operation of the server.
 * ``zone`` - Messages related to zones, zone parsing and loading.
-* ``answering`` - Messages regarding query processing and response creation.
 * ``any`` - All categories.
 
 .. _severity:
@@ -1119,11 +1118,10 @@ Knot DNS has the following logging severities:
 * ``notice`` - Server notices and hints.
 * ``warning`` - Warnings that might require user action.
 * ``error`` - Recoverable error.  Action should be taken.
-* ``all`` - All severities.
+* ``critical`` - Non-recoverable error resulting in server shutdown.
 
-More severities may be listed for each category, but all severities
-have to be listed explicitly, i.e.  using ``warning`` severity does
-not mean that ``error`` severity messages will be logged as well.
+Each severity level includes all more serious levels, i.e. ``warning`` severity
+also includes ``error`` and ``critical`` severities.
 
 .. _log_file:
 

samples/knot.full.conf

@@ -399,28 +399,21 @@ zones {
 #
 # Log messages are characterized by severity and category.
 # Supported severities:
-#   debug     - Debug messages. Must be turned on at compile time.
-#   info      - Informational messages.
-#   notice    - Notices and hints.
-#   warning   - Warnings. An action from the operator may be required.
-#   error     - Recoverable error. Some action should be taken.
+#   debug     - Debug messages and below. Must be turned on at compile time.
+#   info      - Informational messages and below.
+#   notice    - Notices and hints and below.
+#   warning   - Warnings and below. An action from the operator may be required.
+#   error     - Recoverable error and below. Some action should be taken.
 #   critical  - Non-recoverable errors resulting in server shutdown.
 #               (Not supported yet.)
-#   all       - All severities.
 #
 # Categories designate the source of the log message and roughly correspond
 #   to server modules
 # Supported categories:
 #   server    - Messages related to general operation of the server.
 #   zone      - Messages related to zones, zone parsing and loading.
-#   answering - Messages regarding query processing and response creation.
 #   any       - All categories
 #
-# More severities (separated by commas) may be listed for each category.
-# All applicable severities must be listed.
-#   (I.e. specifying 'error' severity does mean: 'log error messages',
-#    and NOT 'log all messages of severity error and above'.)
-#
 # Default settings (in case there are no entries in 'log' section or the section
 # is missing at all):
 #
@@ -428,34 +421,32 @@ zones {
 # syslog { any error; }
 log {
 
-  # Log entry
-  #
   # Format 1:
   # <log> {
-  #   <category1> <severity1> [, <severity2> ...];
-  #   <category2> <severity1> [, <severity2> ...];
+  #   <category1> <severity1>;
+  #   <category2> <severity2>;
   #   ...
   # }
-  syslog {     # <log> is a symbolic name of a log device (see above)
-    # log errors of any category
-    any error;    # for <category> and <severity> see above
-    # log also warnings and notices from category 'zone'
-    zone warning, notice;
-    # log info from server
+
+  syslog {
+    # Log any error or critical to syslog
+    any error;
+    # Log all (excluding debug) from server to syslog
     server info;
   }
 
-  # Log fatal, warnings and errors to stderr
+  # Log any warning, error or critical to stderr
   stderr {
-    any error, warning;
+    any warning;
   }
 
   # Format 2:
-  # file <path> {
-  #   <category1> <severity1> [, <severity2> ...];
-  #   <category2> <severity1> [, <severity2> ...];
+  # file <path> { # <path> is absolute or relative path to log file
+  #   <category1> <severity1>;
+  #   <category2> <severity2>;
   # }
-  file "/tmp/knot-sample/knotd.debug" {  # <path> is absolute or relative path to log file
+
+  file "/tmp/knot-sample/knotd.debug" {
     server debug;
   }
 }

samples/knot.sample.conf.in

@@ -79,16 +79,12 @@ zones {
 
 log {
   syslog {
-    # log errors of any category
-    any error;    # for <category> and <severity> see above
-    # log also warnings and notices from category 'zone'
-    zone warning, notice;
-    # log info from server
-    server info;
+    # Log info and more serious events to syslog
+    any info;
   }
 
-  # Log fatal, warnings and errors to stderr
+  # Log warnings, errors and criticals to stderr
   stderr {
-    any error, warning;
+    any warning;
   }
 }

src/common/debug.h

@@ -208,8 +208,8 @@
 
 /* Brief messages. */
 #ifdef DEBUG_ENABLE_BRIEF
-#define dbg_response(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_response_hex(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_response(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_response_hex(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_response_exec(cmds) do { cmds } while (0)
 #else
 #define dbg_response(msg...)
@@ -219,8 +219,8 @@
 
 /* Verbose messages. */
 #ifdef DEBUG_ENABLE_VERBOSE
-#define dbg_response_verb(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_response_hex_verb(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_response_verb(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_response_hex_verb(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_response_exec_verb(cmds) do { cmds } while (0)
 #else
 #define dbg_response_verb(msg...)
@@ -230,8 +230,8 @@
 
 /* Detail messages. */
 #ifdef DEBUG_ENABLE_DETAILS
-#define dbg_response_detail(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_response_hex_detail(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_response_detail(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_response_hex_detail(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_response_exec_detail(cmds) do { cmds } while (0)
 #else
 #define dbg_response_detail(msg...)
@@ -258,8 +258,8 @@
 
 /* Brief messages. */
 #ifdef DEBUG_ENABLE_BRIEF
-#define dbg_packet(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_packet_hex(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_packet(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_packet_hex(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_packet_exec(cmds) do { cmds } while (0)
 #else
 #define dbg_packet(msg...)
@@ -269,8 +269,8 @@
 
 /* Verbose messages. */
 #ifdef DEBUG_ENABLE_VERBOSE
-#define dbg_packet_verb(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_packet_hex_verb(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_packet_verb(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_packet_hex_verb(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_packet_exec_verb(cmds) do { cmds } while (0)
 #else
 #define dbg_packet_verb(msg...)
@@ -280,8 +280,8 @@
 
 /* Detail messages. */
 #ifdef DEBUG_ENABLE_DETAILS
-#define dbg_packet_detail(msg...) log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-#define dbg_packet_hex_detail(data, len)  hex_log(LOG_ANSWER, (data), (len))
+#define dbg_packet_detail(msg...) log_msg(LOG_SERVER, LOG_DEBUG, msg)
+#define dbg_packet_hex_detail(data, len)  hex_log(LOG_SERVER, (data), (len))
 #define dbg_packet_exec_detail(cmds) do { cmds } while (0)
 #else
 #define dbg_packet_detail(msg...)

src/common/log.h

@@ -54,8 +54,7 @@ typedef enum {
 /*! \brief Log sources (max. LOG_SRC_BITS bits). */
 typedef enum {
 	LOG_SERVER = 0, /*!< Server module. */
-	LOG_ANSWER = 1, /*!< Query answering module. */
-	LOG_ZONE   = 2, /*!< Zone manipulation module. */
+	LOG_ZONE   = 1, /*!< Zone manipulation module. */
 	LOG_ANY    = 7  /*!< Any module. */
 } logsrc_t;
 
@@ -154,13 +153,6 @@ void hex_log(int source, const char *data, int length);
 #define log_server_info(msg...)      log_msg(LOG_SERVER, LOG_INFO, msg)
 #define log_server_debug(msg...)     log_msg(LOG_SERVER, LOG_DEBUG, msg)
 
-#define log_answer_fatal(msg...)     log_msg(LOG_ANSWER, LOG_CRIT, msg)
-#define log_answer_error(msg...)     log_msg(LOG_ANSWER, LOG_ERR, msg)
-#define log_answer_warning(msg...)   log_msg(LOG_ANSWER, LOG_WARNING, msg)
-#define log_answer_notice(msg...)    log_msg(LOG_ANSWER, LOG_NOTICE, msg)
-#define log_answer_info(msg...)      log_msg(LOG_ANSWER, LOG_INFO, msg)
-#define log_answer_debug(msg...)     log_msg(LOG_ANSWER, LOG_DEBUG, msg)
-
 #define log_zone_fatal(msg...)       log_msg(LOG_ZONE, LOG_CRIT, msg)
 #define log_zone_error(msg...)       log_msg(LOG_ZONE, LOG_ERR, msg)
 #define log_zone_warning(msg...)     log_msg(LOG_ZONE, LOG_WARNING, msg)

src/knot/conf/cf-lex.l

@@ -149,18 +149,30 @@ log             { lval.t = yytext; return LOG; }
 
 any { lval.t = yytext; lval.i = LOG_ANY; return LOG_SRC; }
 server { lval.t = yytext; lval.i = LOG_SERVER; return LOG_SRC; }
-answering { lval.t = yytext; lval.i = LOG_ANSWER; return LOG_SRC; }
+answering {
+	lval.t = yytext;
+	lval.i = LOG_SERVER;
+	fprintf(stderr, "Warning: log category 'answering' is no longer "
+	                "supported. Using 'server' instead.\n");
+	return LOG_SRC;
+}
 zone { lval.t = yytext; lval.i = LOG_ZONE; return LOG_SRC; }
 stdout { lval.t = yytext; lval.i = LOGT_STDOUT; return LOG_DEST; }
 stderr { lval.t = yytext; lval.i = LOGT_STDERR; return LOG_DEST; }
 syslog { lval.t = yytext; lval.i = LOGT_SYSLOG; return LOG_DEST; }
-all { lval.t = yytext; lval.i = LOG_UPTO(LOG_DEBUG); return LOG_LEVEL; }
-debug { lval.t = yytext; lval.i = LOG_MASK(LOG_DEBUG); return LOG_LEVEL; }
-info { lval.t = yytext; lval.i = LOG_MASK(LOG_INFO); return LOG_LEVEL; }
-notice { lval.t = yytext; lval.i = LOG_MASK(LOG_NOTICE); return LOG_LEVEL; }
-warning { lval.t = yytext; lval.i = LOG_MASK(LOG_WARNING); return LOG_LEVEL; }
-error { lval.t = yytext; lval.i = LOG_MASK(LOG_ERR); return LOG_LEVEL; }
-critical { lval.t = yytext; lval.i = LOG_MASK(LOG_CRIT); return LOG_LEVEL; }
+debug { lval.t = yytext; lval.i = LOG_UPTO(LOG_DEBUG); return LOG_LEVEL; }
+info { lval.t = yytext; lval.i = LOG_UPTO(LOG_INFO); return LOG_LEVEL; }
+notice { lval.t = yytext; lval.i = LOG_UPTO(LOG_NOTICE); return LOG_LEVEL; }
+warning { lval.t = yytext; lval.i = LOG_UPTO(LOG_WARNING); return LOG_LEVEL; }
+error { lval.t = yytext; lval.i = LOG_UPTO(LOG_ERR); return LOG_LEVEL; }
+critical { lval.t = yytext; lval.i = LOG_UPTO(LOG_CRIT); return LOG_LEVEL; }
+all {
+	lval.t = yytext;
+	lval.i = LOG_UPTO(LOG_DEBUG);
+	fprintf(stderr, "Warning: log severity 'all'' is deprecated. "
+	                "Use 'debug' or 'info' instead.\n");
+	return LOG_LEVEL;
+}
 
 increment|unixtime {
   lval.t = yytext;

src/knot/conf/cf-parse.y

@@ -981,7 +981,10 @@ log_prios_start: {
 
 log_prios:
    log_prios_start
- | log_prios LOG_LEVEL ',' { this_logmap->prios |= $2.i; }
+ | log_prios LOG_LEVEL ',' { this_logmap->prios |= $2.i;
+	fprintf(stderr, "Warning: more log severities per statement is deprecated. "
+	                "Using the least serious one.\n");
+ }
  | log_prios LOG_LEVEL ';' { this_logmap->prios |= $2.i; }
  ;
 

src/knot/ctl/remote.c

@@ -648,7 +648,7 @@ static int zones_verify_tsig_query(const knot_pkt_t *query,
 	assert(tsig_rcode != NULL);
 
 	if (query->tsig_rr == NULL) {
-		log_answer_info("TSIG key required, but not in query - REFUSED.\n");
+		log_server_info("TSIG key required, but not in query - REFUSED.\n");
 		*rcode = KNOT_RCODE_REFUSED;
 		return KNOT_TSIG_EBADKEY;
 	}
@@ -658,7 +658,7 @@ static int zones_verify_tsig_query(const knot_pkt_t *query,
 	 */
 	knot_tsig_algorithm_t alg = tsig_rdata_alg(query->tsig_rr);
 	if (knot_tsig_digest_length(alg) == 0) {
-		log_answer_info("Unsupported digest algorithm "
+		log_server_info("Unsupported digest algorithm "
 		                "requested, treating as bad key\n");
 		/*! \todo [TSIG] It is unclear from RFC if I
 		 *               should treat is as a bad key
@@ -702,7 +702,7 @@ static int zones_verify_tsig_query(const knot_pkt_t *query,
 
 	if (mac_len > digest_max_size) {
 		*rcode = KNOT_RCODE_FORMERR;
-		log_answer_info("MAC length %zu exceeds digest "
+		log_server_info("MAC length %zu exceeds digest "
 		                "maximum size %zu\n", mac_len, digest_max_size);
 		return KNOT_EMALF;
 	} else {

src/knot/knot.h

@@ -36,7 +36,7 @@
 
 #define DEFAULT_THR_COUNT 2  /*!< \brief Default thread count. */
 #define TCP_BACKLOG_SIZE 10  /*!< \brief TCP listen backlog size. */
-#define RECVMMSG_BATCHLEN 64 /*!< \brief Define for recvmmsg() batch size. */
+#define RECVMMSG_BATCHLEN 10 /*!< \brief Define for recvmmsg() batch size. */
 
 /* Workarounds for clock_gettime() not available on some platforms. */
 #ifdef HAVE_CLOCK_GETTIME

src/knot/server/server.c

@@ -122,6 +122,9 @@ static int server_init_iface(iface_t *new_if, conf_iface_t *cfg_if)
 		return sock;
 	}
 
+	/* Set UDP as non-blocking. */
+	fcntl(sock, F_SETFL, O_NONBLOCK);
+
 	new_if->fd[IO_UDP] = sock;
 
 	/* Create bound TCP socket. */

src/knot/server/udp-handler.c

@@ -489,10 +489,8 @@ int udp_master(dthread_t *thread)
 {
 	unsigned cpu = dt_online_cpus();
 	if (cpu > 1) {
-		unsigned cpu_mask[2];
-		cpu_mask[0] = dt_get_id(thread) % cpu;
-		cpu_mask[1] = (cpu_mask[0] + 2) % cpu;
-		dt_setaffinity(thread, cpu_mask, 2);
+		unsigned cpu_mask = (dt_get_id(thread) % cpu);
+		dt_setaffinity(thread, &cpu_mask, 1);
 	}
 
 	/* Drop all capabilities on all workers. */
@@ -559,7 +557,7 @@ int udp_master(dthread_t *thread)
 		/* Bound sockets will be usually closely coupled. */
 		for (unsigned fd = minfd; fd <= maxfd; ++fd) {
 			if (FD_ISSET(fd, &rfds)) {
-				while ((rcvd = _udp_recv(fd, rq)) > 0) {
+				if ((rcvd = _udp_recv(fd, rq)) > 0) {
 					_udp_handle(&udp, rq);
 					/* Flush allocated memory. */
 					mp_flush(udp.query_ctx.mm.ctx);

src/knot/zone/events.c

@@ -274,7 +274,7 @@ static int event_reload(zone_t *zone)
 		zone_contents_deep_free(&old);
 	}
 
-	/* Schedule notify, expire and refresh after load. */
+	/* Schedule notify and refresh after load. */
 	if (zone_master(zone)) {
 		zone_events_schedule(zone, ZONE_EVENT_REFRESH, ZONE_EVENT_NOW);
 		const knot_rdataset_t *soa = node_rdataset(contents->apex, KNOT_RRTYPE_SOA);

src/knot/zone/zone.c

@@ -270,6 +270,9 @@ int zone_flush_journal(zone_t *zone)
 	zone->zonefile_serial = serial_to;
 	journal_mark_synced(zone->conf->ixfr_db);
 
+	/* Trim extra heap. */
+	mem_trim();
+
 	return ret;
 }
 

tests-extra/tests/events/soa/data/example.zone

+$ORIGIN example.
+$TTL 3600
+
+@	SOA	dns1 hostmaster 1 1 1 3 600
+	NS	dns1
+
+dns1	A	192.0.2.1

tests-extra/tests/events/soa/data/example.zone.1

+$ORIGIN example.
+$TTL 3600
+
+@	SOA	dns1 hostmaster 2 10 1 3 600
+	NS	dns1
+
+dns1	A	192.0.2.1

tests-extra/tests/events/soa/test.py

+#!/usr/bin/env python3
+
+'''Test to end all tests'''
+
+from dnstest.utils import *
+from dnstest.test import Test
+
+EXPIRE_SLEEP = 5
+
+def test_refresh(slave):
+    resp = slave.dig("example.", "SOA")
+    resp.check(rcode="NOERROR")
+    t.sleep(EXPIRE_SLEEP)
+    resp = slave.dig("example.", "SOA")
+    resp.check(rcode="NOERROR")
+    
+def test_expire(slave):
+    resp = slave.dig("example.", "SOA")
+    resp.check(rcode="NOERROR")
+    t.sleep(EXPIRE_SLEEP)
+    resp = slave.dig("example.", "SOA")
+    resp.check(rcode="SERVFAIL")
+
+t = Test()
+
+master = t.server("bind")
+slave = t.server("knot")
+slave.max_conn_idle = "1s"
+
+# this zone has refresh = 1s, retry = 1s and expire = 1s + 2s for connection timeouts
+zone = t.zone("example.", storage=".")
+
+t.link(zone, master, slave)
+
+t.start()
+
+slave.zone_wait(zone)
+#test that zone does not expire when master is alive
+test_refresh(slave)
+master.stop()
+#test that zone does expire when master is down
+test_expire(slave)
+
+#update master zone file with 10s refresh in SOA
+master.update_zonefile(zone, version=1)
+master.start()
+
+slave.zone_wait(zone) #this has to work - retry is 1s
+slave.flush()
+
+#zone should expire, because refresh < expire
+test_expire(slave)
+
+#switch server roles, slave becomes master - there should be no expire
+master.stop()
+slave.zones = {}
+master.zones = {}
+t.link(zone, slave)
+t.generate_conf()
+slave.reload()
+
+slave.zone_wait(zone)
+t.sleep(EXPIRE_SLEEP)
+slave.zone_wait(zone)
+
+#switch again - zone should expire now
+slave.zones = {}
+t.link(zone, master, slave)
+t.generate_conf()
+slave.reload()
+
+test_expire(slave)
+
+t.stop()
+

tests-extra/tools/dnstest/server.py

@@ -139,6 +139,7 @@ class Server(object):
 
         self.ratelimit = None
         self.disable_any = None
+        self.max_conn_idle = None
 
         self.ip = None
         self.addr = None
@@ -199,7 +200,7 @@ class Server(object):
         '''Set the server as a slave for the zone'''
 
         if zone.name in self.zones:
-            raise Exception("Can't set zone='%s' as a slave" % name)
+            raise Exception("Can't set zone='%s' as a slave" % zone.name)
 
         slave_file = zone.clone(self.dir + "/slave", exists=False)
         z = Zone(slave_file, ddns, ixfr)
@@ -815,6 +816,8 @@ class Knot(Server):
         self._on_str_hex(s, "nsid", self.nsid)
         self._on_str_hex(s, "rate-limit", self.ratelimit)
         s.item_str("rundir", self.dir)
+        if (self.max_conn_idle):
+            s.item("max-conn-idle", self.max_conn_idle)
         s.end()
 
         s.begin("control")