- log-servfail: yes prints log lines that say why queries are

returning SERVFAIL to clients.


git-svn-id: file:///svn/unbound/trunk@4863 be551aaa-1e26-0410-a405-d3ace91eadb9

doc/Changelog

@@ -8,6 +8,8 @@
 	  that use it, to recompile against the new header definition.
 	- print servfail info to log as error.
 	- added more servfail printout statements, to the iterator.
+	- log-servfail: yes prints log lines that say why queries are
+	  returning SERVFAIL to clients.
 
 16 August 2018: Wouter
 	- Fix warning on compile without threads.

doc/example.conf.in

@@ -318,6 +318,9 @@ server:
 	# timetoresolve, fromcache and responsesize.
 	# log-replies: no
 
+	# print log lines that say why queries return SERVFAIL to clients.
+	# log-servfail: no
+
 	# the pid file. Can be an absolute path outside of chroot/work dir.
 	# pidfile: "@UNBOUND_PIDFILE@"
 

doc/unbound.conf.5.in

@@ -655,6 +655,11 @@ Default is no.  Note that it takes time to print these
 lines which makes the server (significantly) slower.  Odd (nonprintable)
 characters in names are printed as '?'.
 .TP
+.B log\-servfail: \fI<yes or no>
+Print log lines that say why queries return SERVFAIL to clients.
+This is separate from the verbosity debug logs, much smaller, and printed
+at the error level, not the info level of debug info from verbosity.
+.TP
 .B pidfile: \fI<filename>
 The process id is written to the file. Default is "@UNBOUND_PIDFILE@".
 So,

services/mesh.c

@@ -1155,8 +1155,10 @@ void mesh_query_done(struct mesh_state* mstate)
 	struct mesh_cb* c;
 	struct reply_info* rep = (mstate->s.return_msg?
 		mstate->s.return_msg->rep:NULL);
-	if(mstate->s.return_rcode == LDNS_RCODE_SERVFAIL ||
-		(rep && FLAGS_GET_RCODE(rep->flags) == LDNS_RCODE_SERVFAIL)) {
+	if((mstate->s.return_rcode == LDNS_RCODE_SERVFAIL ||
+		(rep && FLAGS_GET_RCODE(rep->flags) == LDNS_RCODE_SERVFAIL))
+		&& mstate->s.env->cfg->log_servfail
+		&& !mstate->s.env->cfg->val_log_squelch) {
 		char* err = errinf_to_str_servfail(&mstate->s);
 		if(err)
 			log_err("%s", err);

util/config_file.c

@@ -118,6 +118,7 @@ config_create(void)
 	cfg->log_time_ascii = 0;
 	cfg->log_queries = 0;
 	cfg->log_replies = 0;
+	cfg->log_servfail = 0;
 #ifndef USE_WINSOCK
 #  ifdef USE_MINI_EVENT
 	/* select max 1024 sockets */
@@ -547,6 +548,7 @@ int config_set_option(struct config_file* cfg, const char* opt,
 	else S_YNO("val-log-squelch:", val_log_squelch)
 	else S_YNO("log-queries:", log_queries)
 	else S_YNO("log-replies:", log_replies)
+	else S_YNO("log-servfail:", log_servfail)
 	else S_YNO("val-permissive-mode:", val_permissive_mode)
 	else S_YNO("aggressive-nsec:", aggressive_nsec)
 	else S_YNO("ignore-cd-flag:", ignore_cd)
@@ -903,6 +905,7 @@ config_get_option(struct config_file* cfg, const char* opt,
 	else O_STR(opt, "logfile", logfile)
 	else O_YNO(opt, "log-queries", log_queries)
 	else O_YNO(opt, "log-replies", log_replies)
+	else O_YNO(opt, "log-servfail", log_servfail)
 	else O_STR(opt, "pidfile", pidfile)
 	else O_YNO(opt, "hide-identity", hide_identity)
 	else O_YNO(opt, "hide-version", hide_version)

util/config_file.h

@@ -277,6 +277,8 @@ struct config_file {
 	int log_queries;
 	/** log replies with one line per reply */
 	int log_replies;
+	/** log servfails with a reason */
+	int log_servfail;
 	/** log identity to report */
 	char* log_identity;
 

util/configlexer.lex

@@ -371,6 +371,7 @@ log-identity{COLON}		{ YDVAR(1, VAR_LOG_IDENTITY) }
 log-time-ascii{COLON}		{ YDVAR(1, VAR_LOG_TIME_ASCII) }
 log-queries{COLON}		{ YDVAR(1, VAR_LOG_QUERIES) }
 log-replies{COLON}		{ YDVAR(1, VAR_LOG_REPLIES) }
+log-servfail{COLON}		{ YDVAR(1, VAR_LOG_SERVFAIL) }
 local-zone{COLON}		{ YDVAR(2, VAR_LOCAL_ZONE) }
 local-data{COLON}		{ YDVAR(1, VAR_LOCAL_DATA) }
 local-data-ptr{COLON}		{ YDVAR(1, VAR_LOCAL_DATA_PTR) }

util/configparser.h

@@ -291,7 +291,8 @@ extern int yydebug;
     VAR_TLS_WIN_CERT = 501,
     VAR_TCP_CONNECTION_LIMIT = 502,
     VAR_FORWARD_NO_CACHE = 503,
-    VAR_STUB_NO_CACHE = 504
+    VAR_STUB_NO_CACHE = 504,
+    VAR_LOG_SERVFAIL = 505
   };
 #endif
 /* Tokens.  */
@@ -542,6 +543,7 @@ extern int yydebug;
 #define VAR_TCP_CONNECTION_LIMIT 502
 #define VAR_FORWARD_NO_CACHE 503
 #define VAR_STUB_NO_CACHE 504
+#define VAR_LOG_SERVFAIL 505
 
 /* Value type.  */
 #if ! defined YYSTYPE && ! defined YYSTYPE_IS_DECLARED
@@ -552,7 +554,7 @@ union YYSTYPE
 
 	char*	str;
 
-#line 556 "util/configparser.h" /* yacc.c:1909  */
+#line 558 "util/configparser.h" /* yacc.c:1909  */
 };
 
 typedef union YYSTYPE YYSTYPE;

util/configparser.y

@@ -159,7 +159,7 @@ extern struct config_parser_state* cfg_parser;
 %token VAR_AUTH_ZONE VAR_ZONEFILE VAR_MASTER VAR_URL VAR_FOR_DOWNSTREAM
 %token VAR_FALLBACK_ENABLED VAR_TLS_ADDITIONAL_PORT VAR_LOW_RTT VAR_LOW_RTT_PERMIL
 %token VAR_ALLOW_NOTIFY VAR_TLS_WIN_CERT VAR_TCP_CONNECTION_LIMIT
-%token VAR_FORWARD_NO_CACHE VAR_STUB_NO_CACHE
+%token VAR_FORWARD_NO_CACHE VAR_STUB_NO_CACHE VAR_LOG_SERVFAIL
 
 %%
 toplevelvars: /* empty */ | toplevelvars toplevelvar ;
@@ -253,7 +253,7 @@ content_server: server_num_threads | server_verbosity | server_port |
 	server_udp_upstream_without_downstream | server_aggressive_nsec |
 	server_tls_cert_bundle | server_tls_additional_port | server_low_rtt |
 	server_low_rtt_permil | server_tls_win_cert |
-	server_tcp_connection_limit
+	server_tcp_connection_limit | server_log_servfail
 	;
 stubstart: VAR_STUB_ZONE
 	{
@@ -803,6 +803,15 @@ server_log_replies: VAR_LOG_REPLIES STRING_ARG
   	free($2);
   }
   ;
+server_log_servfail: VAR_LOG_SERVFAIL STRING_ARG
+	{
+		OUTYY(("P(server_log_servfail:%s)\n", $2));
+		if(strcmp($2, "yes") != 0 && strcmp($2, "no") != 0)
+			yyerror("expected yes or no.");
+		else cfg_parser->cfg->log_servfail = (strcmp($2, "yes")==0);
+		free($2);
+	}
+	;
 server_chroot: VAR_CHROOT STRING_ARG
 	{
 		OUTYY(("P(server_chroot:%s)\n", $2));

validator/validator.c

@@ -2235,9 +2235,11 @@ processFinished(struct module_qstate* qstate, struct val_qstate* vq,
 		vq->orig_msg->rep->ttl = ve->bogus_ttl;
 		vq->orig_msg->rep->prefetch_ttl = 
 			PREFETCH_TTL_CALC(vq->orig_msg->rep->ttl);
-		if(qstate->env->cfg->val_log_level >= 1 &&
+		if((qstate->env->cfg->val_log_level >= 1 ||
+			qstate->env->cfg->log_servfail) &&
 			!qstate->env->cfg->val_log_squelch) {
-			if(qstate->env->cfg->val_log_level < 2)
+			if(qstate->env->cfg->val_log_level < 2 &&
+				!qstate->env->cfg->log_servfail)
 				log_query_info(0, "validation failure",
 					&qstate->qinfo);
 			else {