- log-tag-queryreply: yes in unbound.conf tags the log-queries and

log-replies in the log file for easier log filter maintenance.


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

daemon/worker.c

@@ -1208,7 +1208,7 @@ worker_handle_request(struct comm_point* c, void* arg, int error,
 	if(worker->env.cfg->log_queries) {
 		char ip[128];
 		addr_to_str(&repinfo->addr, repinfo->addrlen, ip, sizeof(ip));
-		log_nametypeclass(0, ip, qinfo.qname, qinfo.qtype, qinfo.qclass);
+		log_query_in(ip, qinfo.qname, qinfo.qtype, qinfo.qclass);
 	}
 	if(qinfo.qtype == LDNS_RR_TYPE_AXFR || 
 		qinfo.qtype == LDNS_RR_TYPE_IXFR) {

doc/Changelog

@@ -1,5 +1,7 @@
 30 November 2018: Wouter
 	- Patch for typo in unbound.conf man page.
+	- log-tag-queryreply: yes in unbound.conf tags the log-queries and
+	  log-replies in the log file for easier log filter maintenance.
 
 29 November 2018: Wouter
 	- iana portlist updated.

doc/example.conf.in

@@ -322,6 +322,10 @@ server:
 	# timetoresolve, fromcache and responsesize.
 	# log-replies: no
 
+	# log with tag 'query' and 'reply' instead of 'info' for
+	# filtering log-queries and log-replies from the log.
+	# log-tag-queryreply: no
+
 	# log the local-zone actions, like local-zone type inform is enabled
 	# also for the other local zone types.
 	# log-local-actions: no

doc/unbound.conf.5.in

@@ -661,6 +661,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\-tag\-queryreply: \fI<yes or no>
+Prints the word 'query' and 'reply' with log\-queries and log\-replies.
+This makes filtering logs easier.  The default is off (for backwards
+compatibility).
+.TP
 .B log\-local\-actions: \fI<yes or no>
 Print log lines to inform about local zone actions.  These lines are like the
 local\-zone type inform prints out, but they are also printed for the other

util/config_file.c

@@ -119,6 +119,7 @@ config_create(void)
 	cfg->log_time_ascii = 0;
 	cfg->log_queries = 0;
 	cfg->log_replies = 0;
+	cfg->log_tag_queryreply = 0;
 	cfg->log_local_actions = 0;
 	cfg->log_servfail = 0;
 #ifndef USE_WINSOCK
@@ -560,6 +561,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-tag-queryreply:", log_tag_queryreply)
 	else S_YNO("log-local-actions:", log_local_actions)
 	else S_YNO("log-servfail:", log_servfail)
 	else S_YNO("val-permissive-mode:", val_permissive_mode)
@@ -925,6 +927,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-tag-queryreply", log_tag_queryreply)
 	else O_YNO(opt, "log-local-actions", log_local_actions)
 	else O_YNO(opt, "log-servfail", log_servfail)
 	else O_STR(opt, "pidfile", pidfile)
@@ -1903,6 +1906,7 @@ config_apply(struct config_file* config)
 	EDNS_ADVERTISED_SIZE = (uint16_t)config->edns_buffer_size;
 	MINIMAL_RESPONSES = config->minimal_responses;
 	RRSET_ROUNDROBIN = config->rrset_roundrobin;
+	LOG_TAG_QUERYREPLY = config->log_tag_queryreply;
 	UNKNOWN_SERVER_NICENESS = config->unknown_server_time_limit;
 	log_set_time_asc(config->log_time_ascii);
 	autr_permit_small_holddown = config->permit_small_holddown;

util/config_file.h

@@ -286,6 +286,8 @@ struct config_file {
 	int log_queries;
 	/** log replies with one line per reply */
 	int log_replies;
+	/** tag log_queries and log_replies for filtering */
+	int log_tag_queryreply;
 	/** log every local-zone hit **/
 	int log_local_actions;
 	/** log servfails with a reason */

util/configlexer.lex

@@ -377,6 +377,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-tag-queryreply{COLON}	{ YDVAR(1, VAR_LOG_TAG_QUERYREPLY) }
 log-local-actions{COLON}       { YDVAR(1, VAR_LOG_LOCAL_ACTIONS) }
 log-servfail{COLON}		{ YDVAR(1, VAR_LOG_SERVFAIL) }
 local-zone{COLON}		{ YDVAR(2, VAR_LOCAL_ZONE) }

util/configparser.h

@@ -303,7 +303,8 @@ extern int yydebug;
     VAR_STUB_NO_CACHE = 513,
     VAR_LOG_SERVFAIL = 514,
     VAR_DENY_ANY = 515,
-    VAR_UNKNOWN_SERVER_TIME_LIMIT = 516
+    VAR_UNKNOWN_SERVER_TIME_LIMIT = 516,
+    VAR_LOG_TAG_QUERYREPLY = 517
   };
 #endif
 /* Tokens.  */
@@ -566,6 +567,7 @@ extern int yydebug;
 #define VAR_LOG_SERVFAIL 514
 #define VAR_DENY_ANY 515
 #define VAR_UNKNOWN_SERVER_TIME_LIMIT 516
+#define VAR_LOG_TAG_QUERYREPLY 517
 
 /* Value type.  */
 #if ! defined YYSTYPE && ! defined YYSTYPE_IS_DECLARED
@@ -576,7 +578,7 @@ union YYSTYPE
 
 	char*	str;
 
-#line 580 "util/configparser.h" /* yacc.c:1909  */
+#line 582 "util/configparser.h" /* yacc.c:1909  */
 };
 
 typedef union YYSTYPE YYSTYPE;

util/configparser.y

@@ -164,7 +164,7 @@ extern struct config_parser_state* cfg_parser;
 %token VAR_FAST_SERVER_PERMIL VAR_FAST_SERVER_NUM
 %token VAR_ALLOW_NOTIFY VAR_TLS_WIN_CERT VAR_TCP_CONNECTION_LIMIT
 %token VAR_FORWARD_NO_CACHE VAR_STUB_NO_CACHE VAR_LOG_SERVFAIL VAR_DENY_ANY
-%token VAR_UNKNOWN_SERVER_TIME_LIMIT
+%token VAR_UNKNOWN_SERVER_TIME_LIMIT VAR_LOG_TAG_QUERYREPLY
 
 %%
 toplevelvars: /* empty */ | toplevelvars toplevelvar ;
@@ -263,7 +263,7 @@ content_server: server_num_threads | server_verbosity | server_port |
 	server_tls_cert_bundle | server_tls_additional_port | server_low_rtt |
 	server_fast_server_permil | server_fast_server_num  | server_tls_win_cert |
 	server_tcp_connection_limit | server_log_servfail | server_deny_any |
-	server_unknown_server_time_limit
+	server_unknown_server_time_limit | server_log_tag_queryreply
 	;
 stubstart: VAR_STUB_ZONE
 	{
@@ -877,6 +877,15 @@ server_log_replies: VAR_LOG_REPLIES STRING_ARG
   	free($2);
   }
   ;
+server_log_tag_queryreply: VAR_LOG_TAG_QUERYREPLY STRING_ARG
+  {
+  	OUTYY(("P(server_log_tag_queryreply:%s)\n", $2));
+  	if(strcmp($2, "yes") != 0 && strcmp($2, "no") != 0)
+  		yyerror("expected yes or no.");
+  	else cfg_parser->cfg->log_tag_queryreply = (strcmp($2, "yes")==0);
+  	free($2);
+  }
+  ;
 server_log_servfail: VAR_LOG_SERVFAIL STRING_ARG
 	{
 		OUTYY(("P(server_log_servfail:%s)\n", $2));

util/data/msgreply.c

@@ -853,7 +853,9 @@ log_reply_info(enum verbosity_value v, struct query_info *qinf,
 	addr_to_str(addr, addrlen, clientip_buf, sizeof(clientip_buf));
 	if(rcode == LDNS_RCODE_FORMERR)
 	{
-		log_info("%s - - - %s - - - ", clientip_buf, rcode_buf);
+		if(LOG_TAG_QUERYREPLY)
+			log_reply("%s - - - %s - - - ", clientip_buf, rcode_buf);
+		else	log_info("%s - - - %s - - - ", clientip_buf, rcode_buf);
 	} else {
 		if(qinf->qname)
 			dname_str(qinf->qname, qname_buf);
@@ -861,7 +863,11 @@ log_reply_info(enum verbosity_value v, struct query_info *qinf,
 		pktlen = sldns_buffer_limit(rmsg);
 		sldns_wire2str_type_buf(qinf->qtype, type_buf, sizeof(type_buf));
 		sldns_wire2str_class_buf(qinf->qclass, class_buf, sizeof(class_buf));
-		log_info("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d",
+		if(LOG_TAG_QUERYREPLY)
+		     log_reply("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d",
+			clientip_buf, qname_buf, type_buf, class_buf,
+			rcode_buf, (long long)dur.tv_sec, (int)dur.tv_usec, cached, (int)pktlen);
+		else log_info("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d",
 			clientip_buf, qname_buf, type_buf, class_buf,
 			rcode_buf, (long long)dur.tv_sec, (int)dur.tv_usec, cached, (int)pktlen);
 	}

util/log.c

@@ -382,6 +382,24 @@ log_hex(const char* msg, void* data, size_t length)
 	log_hex_f(verbosity, msg, data, length);
 }
 
+void
+log_query(const char *format, ...)
+{
+	va_list args;
+	va_start(args, format);
+	log_vmsg(LOG_INFO, "query", format, args);
+	va_end(args);
+}
+
+void
+log_reply(const char *format, ...)
+{
+	va_list args;
+	va_start(args, format);
+	log_vmsg(LOG_INFO, "reply", format, args);
+	va_end(args);
+}
+
 void log_buf(enum verbosity_value level, const char* msg, sldns_buffer* buf)
 {
 	if(verbosity < level)

util/log.h

@@ -153,6 +153,20 @@ void log_warn(const char* format, ...) ATTR_FORMAT(printf, 1, 2);
  */
 void log_hex(const char* msg, void* data, size_t length);
 
+/**
+ * Log query.
+ * Pass printf formatted arguments. No trailing newline is needed.
+ * @param format: printf-style format string. Arguments follow.
+ */
+void log_query(const char* format, ...) ATTR_FORMAT(printf, 1, 2);
+
+/**
+ * Log reply.
+ * Pass printf formatted arguments. No trailing newline is needed.
+ * @param format: printf-style format string. Arguments follow.
+ */
+void log_reply(const char* format, ...) ATTR_FORMAT(printf, 1, 2);
+
 /**
  * Easy alternative for log_hex, takes a sldns_buffer.
  * @param level: verbosity level for this message, compared to global 

util/net_help.c

@@ -67,6 +67,9 @@ int MINIMAL_RESPONSES = 0;
 /** rrset order roundrobin: default is no */
 int RRSET_ROUNDROBIN = 0;
 
+/** log tag queries with name instead of 'info' for filtering */
+int LOG_TAG_QUERYREPLY = 0;
+
 /* returns true is string addr is an ip6 specced address */
 int
 str_is_ip6(const char* str)
@@ -361,6 +364,37 @@ log_nametypeclass(enum verbosity_value v, const char* str, uint8_t* name,
 	log_info("%s %s %s %s", str, buf, ts, cs);
 }
 
+void
+log_query_in(const char* str, uint8_t* name, uint16_t type, uint16_t dclass)
+{
+	char buf[LDNS_MAX_DOMAINLEN+1];
+	char t[12], c[12];
+	const char *ts, *cs; 
+	dname_str(name, buf);
+	if(type == LDNS_RR_TYPE_TSIG) ts = "TSIG";
+	else if(type == LDNS_RR_TYPE_IXFR) ts = "IXFR";
+	else if(type == LDNS_RR_TYPE_AXFR) ts = "AXFR";
+	else if(type == LDNS_RR_TYPE_MAILB) ts = "MAILB";
+	else if(type == LDNS_RR_TYPE_MAILA) ts = "MAILA";
+	else if(type == LDNS_RR_TYPE_ANY) ts = "ANY";
+	else if(sldns_rr_descript(type) && sldns_rr_descript(type)->_name)
+		ts = sldns_rr_descript(type)->_name;
+	else {
+		snprintf(t, sizeof(t), "TYPE%d", (int)type);
+		ts = t;
+	}
+	if(sldns_lookup_by_id(sldns_rr_classes, (int)dclass) &&
+		sldns_lookup_by_id(sldns_rr_classes, (int)dclass)->name)
+		cs = sldns_lookup_by_id(sldns_rr_classes, (int)dclass)->name;
+	else {
+		snprintf(c, sizeof(c), "CLASS%d", (int)dclass);
+		cs = c;
+	}
+	if(LOG_TAG_QUERYREPLY)
+		log_query("%s %s %s %s", str, buf, ts, cs);
+	else	log_info("%s %s %s %s", str, buf, ts, cs);
+}
+
 void log_name_addr(enum verbosity_value v, const char* str, uint8_t* zone, 
 	struct sockaddr_storage* addr, socklen_t addrlen)
 {

util/net_help.h

@@ -99,6 +99,9 @@ extern int MINIMAL_RESPONSES;
 /** rrset order roundrobin */
 extern int RRSET_ROUNDROBIN;
 
+/** log tag queries with name instead of 'info' for filtering */
+extern int LOG_TAG_QUERYREPLY;
+
 /**
  * See if string is ip4 or ip6.
  * @param str: IP specification.
@@ -235,6 +238,12 @@ void sockaddr_store_port(struct sockaddr_storage* addr, socklen_t addrlen,
 void log_nametypeclass(enum verbosity_value v, const char* str, 
 	uint8_t* name, uint16_t type, uint16_t dclass);
 
+/**
+ * Like log_nametypeclass, but logs with log_query for query logging
+ */
+void log_query_in(const char* str, uint8_t* name, uint16_t type,
+	uint16_t dclass);
+
 /**
  * Compare two sockaddrs. Imposes an ordering on the addresses.
  * Compares address and port.