From 3d1bc143af8631ec8fd079a0bb11ab72fb7fd1b2 Mon Sep 17 00:00:00 2001 From: "W.C.A. Wijngaards" Date: Tue, 5 Dec 2023 10:05:51 +0100 Subject: [PATCH] - Fix #969: [FR] distinguish Do53, DoT and DoH in the logs. --- daemon/worker.c | 8 +++++-- doc/Changelog | 1 + doc/example.conf.in | 3 +++ doc/unbound.conf.5.in | 5 ++++ services/mesh.c | 10 +++++++- util/config_file.c | 3 +++ util/config_file.h | 2 ++ util/configlexer.lex | 1 + util/configparser.y | 13 ++++++++++- util/data/msgreply.c | 53 +++++++++++++++++++++++++++++++++++++------ util/data/msgreply.h | 6 ++++- 11 files changed, 93 insertions(+), 12 deletions(-) diff --git a/daemon/worker.c b/daemon/worker.c index e7d3cec61..e52513f74 100644 --- a/daemon/worker.c +++ b/daemon/worker.c @@ -1967,11 +1967,15 @@ send_reply_rc: qinfo.qname = qinfo.local_alias->rrset->rk.dname; log_reply_info(NO_VERBOSE, &qinfo, &repinfo->client_addr, repinfo->client_addrlen, - tv, 1, c->buffer); + tv, 1, c->buffer, + (worker->env.cfg->log_destaddr?(void*)repinfo->c->socket->addr->ai_addr:NULL), + c->type); } else { log_reply_info(NO_VERBOSE, &qinfo, &repinfo->client_addr, repinfo->client_addrlen, - tv, 1, c->buffer); + tv, 1, c->buffer, + (worker->env.cfg->log_destaddr?(void*)repinfo->c->socket->addr->ai_addr:NULL), + c->type); } } #ifdef USE_DNSCRYPT diff --git a/doc/Changelog b/doc/Changelog index b22951921..f42d19837 100644 --- a/doc/Changelog +++ b/doc/Changelog @@ -1,5 +1,6 @@ 5 December 2023: Wouter - Merge #971: fix 'WARNING: Message has 41 extra bytes at end'. + - Fix #969: [FR] distinguish Do53, DoT and DoH in the logs. 27 November 2023: Yorgos - Merge #968: Replace the obsolescent fgrep with grep -F in tests. diff --git a/doc/example.conf.in b/doc/example.conf.in index 6bf1c668e..547b35500 100644 --- a/doc/example.conf.in +++ b/doc/example.conf.in @@ -441,6 +441,9 @@ server: # filtering log-queries and log-replies from the log. # log-tag-queryreply: no + # log with destination address, port and type for log-replies. + # log-destaddr: no + # log the local-zone actions, like local-zone type inform is enabled # also for the other local zone types. # log-local-actions: no diff --git a/doc/unbound.conf.5.in b/doc/unbound.conf.5.in index 76cfa2383..903bd27d5 100644 --- a/doc/unbound.conf.5.in +++ b/doc/unbound.conf.5.in @@ -913,6 +913,11 @@ 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\-destaddr: \fI +Prints the destination address, port and type in the log\-replies output. +This disambiguates what type of traffic, eg. udp or tcp, and to what local +port the traffic was sent to. +.TP .B log\-local\-actions: \fI 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 diff --git a/services/mesh.c b/services/mesh.c index 509bee36a..47cfb0424 100644 --- a/services/mesh.c +++ b/services/mesh.c @@ -69,6 +69,12 @@ #include "edns-subnet/subnetmod.h" #include "edns-subnet/edns-subnet.h" #endif +#ifdef HAVE_SYS_TYPES_H +# include +#endif +#ifdef HAVE_NETDB_H +#include +#endif /** * Compare two response-ip client info entries for the purpose of mesh state @@ -1429,7 +1435,9 @@ mesh_send_reply(struct mesh_state* m, int rcode, struct reply_info* rep, if(m->s.env->cfg->log_replies) { log_reply_info(NO_VERBOSE, &m->s.qinfo, &r->query_reply.client_addr, - r->query_reply.client_addrlen, duration, 0, r_buffer); + r->query_reply.client_addrlen, duration, 0, r_buffer, + (m->s.env->cfg->log_destaddr?(void*)r->query_reply.c->socket->addr->ai_addr:NULL), + r->query_reply.c->type); } } diff --git a/util/config_file.c b/util/config_file.c index 31ae8c808..26185da02 100644 --- a/util/config_file.c +++ b/util/config_file.c @@ -142,6 +142,7 @@ config_create(void) cfg->log_tag_queryreply = 0; cfg->log_local_actions = 0; cfg->log_servfail = 0; + cfg->log_destaddr = 0; #ifndef USE_WINSOCK # ifdef USE_MINI_EVENT /* select max 1024 sockets */ @@ -690,6 +691,7 @@ int config_set_option(struct config_file* cfg, const char* opt, 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("log-destaddr:", log_destaddr) else S_YNO("val-permissive-mode:", val_permissive_mode) else S_YNO("aggressive-nsec:", aggressive_nsec) else S_YNO("ignore-cd-flag:", ignore_cd) @@ -1127,6 +1129,7 @@ config_get_option(struct config_file* cfg, const char* opt, 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_YNO(opt, "log-destaddr", log_destaddr) else O_STR(opt, "pidfile", pidfile) else O_YNO(opt, "hide-identity", hide_identity) else O_YNO(opt, "hide-version", hide_version) diff --git a/util/config_file.h b/util/config_file.h index ad22b8330..491109833 100644 --- a/util/config_file.h +++ b/util/config_file.h @@ -349,6 +349,8 @@ struct config_file { int log_servfail; /** log identity to report */ char* log_identity; + /** log dest addr for log_replies */ + int log_destaddr; /** do not report identity (id.server, hostname.bind) */ int hide_identity; diff --git a/util/configlexer.lex b/util/configlexer.lex index fdc267434..e1ab76e25 100644 --- a/util/configlexer.lex +++ b/util/configlexer.lex @@ -434,6 +434,7 @@ 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) } +log-destaddr{COLON} { YDVAR(1, VAR_LOG_DESTADDR) } 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) } diff --git a/util/configparser.y b/util/configparser.y index da5d6608f..0e4cd5960 100644 --- a/util/configparser.y +++ b/util/configparser.y @@ -200,6 +200,7 @@ extern struct config_parser_state* cfg_parser; %token VAR_INTERFACE_TAG_ACTION VAR_INTERFACE_TAG_DATA %token VAR_PROXY_PROTOCOL_PORT VAR_STATISTICS_INHIBIT_ZERO %token VAR_HARDEN_UNKNOWN_ADDITIONAL VAR_DISABLE_EDNS_DO VAR_CACHEDB_NO_STORE +%token VAR_LOG_DESTADDR %% toplevelvars: /* empty */ | toplevelvars toplevelvar ; @@ -333,7 +334,8 @@ content_server: server_num_threads | server_verbosity | server_port | server_tcp_reuse_timeout | server_tcp_auth_query_timeout | server_interface_automatic_ports | server_ede | server_proxy_protocol_port | server_statistics_inhibit_zero | - server_harden_unknown_additional | server_disable_edns_do + server_harden_unknown_additional | server_disable_edns_do | + server_log_destaddr ; stubstart: VAR_STUB_ZONE { @@ -1250,6 +1252,15 @@ server_log_servfail: VAR_LOG_SERVFAIL STRING_ARG free($2); } ; +server_log_destaddr: VAR_LOG_DESTADDR STRING_ARG + { + OUTYY(("P(server_log_destaddr:%s)\n", $2)); + if(strcmp($2, "yes") != 0 && strcmp($2, "no") != 0) + yyerror("expected yes or no."); + else cfg_parser->cfg->log_destaddr = (strcmp($2, "yes")==0); + free($2); + } + ; server_log_local_actions: VAR_LOG_LOCAL_ACTIONS STRING_ARG { OUTYY(("P(server_log_local_actions:%s)\n", $2)); diff --git a/util/data/msgreply.c b/util/data/msgreply.c index 920a0a939..2286d46bc 100644 --- a/util/data/msgreply.c +++ b/util/data/msgreply.c @@ -918,13 +918,15 @@ log_dns_msg(const char* str, struct query_info* qinfo, struct reply_info* rep) void log_reply_info(enum verbosity_value v, struct query_info *qinf, struct sockaddr_storage *addr, socklen_t addrlen, struct timeval dur, - int cached, struct sldns_buffer *rmsg) + int cached, struct sldns_buffer *rmsg, struct sockaddr_storage* daddr, + enum comm_point_type tp) { char qname_buf[LDNS_MAX_DOMAINLEN+1]; char clientip_buf[128]; char rcode_buf[16]; char type_buf[16]; char class_buf[16]; + char dest_buf[160]; size_t pktlen; uint16_t rcode = FLAGS_GET_RCODE(sldns_buffer_read_u16_at(rmsg, 2)); @@ -933,11 +935,46 @@ log_reply_info(enum verbosity_value v, struct query_info *qinf, sldns_wire2str_rcode_buf((int)rcode, rcode_buf, sizeof(rcode_buf)); addr_to_str(addr, addrlen, clientip_buf, sizeof(clientip_buf)); + if(daddr) { + char da[128]; + int port = 0; + char* comm; + if(daddr->ss_family == AF_INET6) { + struct sockaddr_in6 *d = (struct sockaddr_in6 *)daddr; + if(inet_ntop(d->sin6_family, &d->sin6_addr, da, + sizeof(*d)) == 0) + snprintf(dest_buf, sizeof(dest_buf), + "(inet_ntop_error)"); + port = ntohs(d->sin6_port); + } else if(daddr->ss_family == AF_INET) { + struct sockaddr_in *d = (struct sockaddr_in *)daddr; + if(inet_ntop(d->sin_family, &d->sin_addr, da, + sizeof(*d)) == 0) + snprintf(dest_buf, sizeof(dest_buf), + "(inet_ntop_error)"); + port = ntohs(d->sin_port); + } else { + snprintf(da, sizeof(da), "socket%d", + (int)daddr->ss_family); + } + comm = "udp"; + if(tp == comm_tcp) comm = "tcp"; + else if(tp == comm_tcp_accept) comm = "tcp"; + else if(tp == comm_http) comm = "dot"; + else if(tp == comm_local) comm = "unix"; + else if(tp == comm_raw) comm = "raw"; + snprintf(dest_buf, sizeof(dest_buf), " on %s %s %d", + comm, da, port); + } else { + dest_buf[0]=0; + } if(rcode == LDNS_RCODE_FORMERR) { if(LOG_TAG_QUERYREPLY) - log_reply("%s - - - %s - - - ", clientip_buf, rcode_buf); - else log_info("%s - - - %s - - - ", clientip_buf, rcode_buf); + log_reply("%s - - - %s - - -%s", clientip_buf, + rcode_buf, dest_buf); + else log_info("%s - - - %s - - -%s", clientip_buf, + rcode_buf, dest_buf); } else { if(qinf->qname) dname_str(qinf->qname, qname_buf); @@ -946,12 +983,14 @@ log_reply_info(enum verbosity_value v, struct query_info *qinf, sldns_wire2str_type_buf(qinf->qtype, type_buf, sizeof(type_buf)); sldns_wire2str_class_buf(qinf->qclass, class_buf, sizeof(class_buf)); if(LOG_TAG_QUERYREPLY) - log_reply("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d", + log_reply("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d%s", 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", + rcode_buf, (long long)dur.tv_sec, (int)dur.tv_usec, + cached, (int)pktlen, dest_buf); + else log_info("%s %s %s %s %s " ARG_LL "d.%6.6d %d %d%s", clientip_buf, qname_buf, type_buf, class_buf, - rcode_buf, (long long)dur.tv_sec, (int)dur.tv_usec, cached, (int)pktlen); + rcode_buf, (long long)dur.tv_sec, (int)dur.tv_usec, + cached, (int)pktlen, dest_buf); } } diff --git a/util/data/msgreply.h b/util/data/msgreply.h index a9af3d7e6..4b93b12c8 100644 --- a/util/data/msgreply.h +++ b/util/data/msgreply.h @@ -58,6 +58,7 @@ struct msg_parse; struct rrset_parse; struct local_rrset; struct dns_msg; +enum comm_point_type; /** calculate the prefetch TTL as 90% of original. Calculation * without numerical overflow (uin32_t) */ @@ -520,10 +521,13 @@ void log_dns_msg(const char* str, struct query_info* qinfo, * @param cached: whether or not the reply is coming from * the cache, or an outside network. * @param rmsg: sldns buffer packet. + * @param daddr: if not NULL, the destination address and port are logged. + * @param tp: type of the comm point for logging destination connection type. */ void log_reply_info(enum verbosity_value v, struct query_info *qinf, struct sockaddr_storage *addr, socklen_t addrlen, struct timeval dur, - int cached, struct sldns_buffer *rmsg); + int cached, struct sldns_buffer *rmsg, struct sockaddr_storage* daddr, + enum comm_point_type tp); /** * Print string with neat domain name, type, class from query info. -- 2.47.2