From e6c9a444c3d0f6d5013c91cb9e40977eeb6e8395 Mon Sep 17 00:00:00 2001
From: Jan Vcelak <jan.vcelak@nic.cz>
Date: Wed, 8 Jun 2016 17:48:43 +0200
Subject: [PATCH] nameserver: make logging independent on internal variables

---
 src/Makefile.am                      |  1 +
 src/knot/nameserver/axfr.c           | 17 +++------------
 src/knot/nameserver/axfr.h           | 23 ++++++++++++++++++++
 src/knot/nameserver/internet.c       | 15 +++++++------
 src/knot/nameserver/ixfr.c           | 12 +----------
 src/knot/nameserver/log.h            | 32 ++++++++++++++++++++++++++++
 src/knot/nameserver/notify.c         | 29 ++++++++++++-------------
 src/knot/nameserver/process_answer.c |  6 ++++--
 src/knot/nameserver/process_answer.h |  5 -----
 src/knot/nameserver/process_query.h  | 13 -----------
 src/knot/nameserver/update.c         |  8 +++----
 11 files changed, 91 insertions(+), 70 deletions(-)
 create mode 100644 src/knot/nameserver/log.h

diff --git a/src/Makefile.am b/src/Makefile.am
index 5dbaac58a7..083cb6a9af 100644
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -323,6 +323,7 @@ libknotd_la_SOURCES =				\
 	knot/nameserver/internet.h		\
 	knot/nameserver/ixfr.c			\
 	knot/nameserver/ixfr.h			\
+	knot/nameserver/log.h			\
 	knot/nameserver/notify.c		\
 	knot/nameserver/notify.h		\
 	knot/nameserver/nsec_proofs.c		\
diff --git a/src/knot/nameserver/axfr.c b/src/knot/nameserver/axfr.c
index 8e655e0d24..2756b5f7ff 100644
--- a/src/knot/nameserver/axfr.c
+++ b/src/knot/nameserver/axfr.c
@@ -16,14 +16,14 @@
 
 #include <urcu.h>
 
+#include "contrib/mempattern.h"
+#include "contrib/print.h"
+#include "contrib/sockaddr.h"
 #include "knot/common/log.h"
 #include "knot/nameserver/axfr.h"
 #include "knot/nameserver/internet.h"
 #include "knot/zone/zonefile.h"
 #include "libknot/libknot.h"
-#include "contrib/mempattern.h"
-#include "contrib/print.h"
-#include "contrib/sockaddr.h"
 
 /* AXFR context. @note aliasing the generic xfr_proc */
 struct axfr_proc {
@@ -206,10 +206,6 @@ int xfr_process_list(knot_pkt_t *pkt, xfr_put_cb process_item,
 	return ret;
 }
 
-/* AXFR-specific logging (internal, expects 'qdata' variable set). */
-#define AXFROUT_LOG(severity, msg, ...) \
-	QUERY_LOG(severity, qdata, "AXFR, outgoing", msg, ##__VA_ARGS__)
-
 int axfr_process_query(knot_pkt_t *pkt, struct query_data *qdata)
 {
 	if (pkt == NULL || qdata == NULL) {
@@ -261,7 +257,6 @@ int axfr_process_query(knot_pkt_t *pkt, struct query_data *qdata)
 		return KNOT_STATE_FAIL;
 	}
 }
-#undef AXFROUT_LOG
 
 static void axfr_answer_cleanup(struct answer_data *data)
 {
@@ -304,10 +299,6 @@ static int axfr_answer_init(struct answer_data *data)
 	return KNOT_EOK;
 }
 
-/* AXFR-specific logging (internal, expects 'adata' variable set). */
-#define AXFRIN_LOG(severity, msg, ...) \
-	ANSWER_LOG(severity, adata, "AXFR, incoming", msg, ##__VA_ARGS__)
-
 static int axfr_answer_finalize(struct answer_data *adata)
 {
 	struct timeval now;
@@ -432,5 +423,3 @@ int axfr_process_answer(knot_pkt_t *pkt, struct answer_data *adata)
 
 	return ret;
 }
-
-#undef AXFRIN_LOG
diff --git a/src/knot/nameserver/axfr.h b/src/knot/nameserver/axfr.h
index 866e7e00fe..740cadbf42 100644
--- a/src/knot/nameserver/axfr.h
+++ b/src/knot/nameserver/axfr.h
@@ -25,11 +25,34 @@
 #pragma once
 
 #include "libknot/packet/pkt.h"
+#include "knot/nameserver/log.h"
 #include "knot/nameserver/process_answer.h"
 #include "knot/nameserver/process_query.h"
 #include "knot/zone/contents.h"
 #include "contrib/ucw/lists.h"
 
+/*!
+ * \brief Transfer-specific logging (internal, expects 'qdata' variable set).
+ *
+ * Emits a message in the following format:
+ * > [zone] type, outgoing, address: custom formatted message
+ */
+#define TRANSFER_OUT_LOG(type, priority, msg, ...) \
+	NS_PROC_LOG(priority, (qdata)->zone->name, (qdata)->param->remote, \
+	            type ", outgoing", msg, ##__VA_ARGS__)
+#define AXFROUT_LOG(args...) TRANSFER_OUT_LOG("AXFR", args)
+#define IXFROUT_LOG(args...) TRANSFER_OUT_LOG("IXFR", args)
+
+/*!
+ * \brief Transfer-specific logging (internal, expects 'adata' variable set).
+ */
+#define TRANSFER_IN_LOG(type, priority, msg, ...) \
+	NS_PROC_LOG(priority, (adata)->param->zone->name, (adata)->param->remote, \
+	            type ", incoming", msg, ##__VA_ARGS__)
+#define AXFRIN_LOG(args...) TRANSFER_IN_LOG("AXFR", args)
+#define IXFRIN_LOG(args...) TRANSFER_IN_LOG("IXFR", args)
+
+
 /*! \brief Generic transfer processing state. */
 struct xfr_proc {
 	list_t nodes;    /* Items to process (ptrnode_t). */
diff --git a/src/knot/nameserver/internet.c b/src/knot/nameserver/internet.c
index b23f3f7ae4..96737787a0 100644
--- a/src/knot/nameserver/internet.c
+++ b/src/knot/nameserver/internet.c
@@ -823,6 +823,11 @@ int internet_query_plan(struct query_plan *plan)
 	return KNOT_EOK;
 }
 
+#include "knot/nameserver/log.h"
+#define REFRESH_LOG(priority, msg, ...) \
+	NS_PROC_LOG(priority, (data)->param->zone->name, (data)->param->remote, \
+	            "refresh, outgoing", msg, ##__VA_ARGS__)
+
 /*! \brief Process answer to SOA query. */
 static int process_soa_answer(knot_pkt_t *pkt, struct answer_data *data)
 {
@@ -833,8 +838,7 @@ static int process_soa_answer(knot_pkt_t *pkt, struct answer_data *data)
 	if (rcode != KNOT_RCODE_NOERROR) {
 		const knot_lookup_t *lut = knot_lookup_by_id(knot_rcode_names, rcode);
 		if (lut != NULL) {
-			ANSWER_LOG(LOG_WARNING, data, "refresh, outgoing",
-			           "server responded with %s", lut->name);
+			REFRESH_LOG(LOG_WARNING, "server responded with %s", lut->name);
 		}
 		return KNOT_STATE_FAIL;
 	}
@@ -843,7 +847,7 @@ static int process_soa_answer(knot_pkt_t *pkt, struct answer_data *data)
 	const knot_pktsection_t *answer = knot_pkt_section(pkt, KNOT_ANSWER);
 	const knot_rrset_t *first_rr = knot_pkt_rr(answer, 0);
 	if (answer->count < 1 || first_rr->type != KNOT_RRTYPE_SOA) {
-		ANSWER_LOG(LOG_WARNING, data, "refresh, outgoing", "malformed message");
+		REFRESH_LOG(LOG_WARNING, "malformed message");
 		return KNOT_STATE_FAIL;
 	}
 
@@ -858,15 +862,14 @@ static int process_soa_answer(knot_pkt_t *pkt, struct answer_data *data)
 	uint32_t our_serial = knot_soa_serial(soa);
 	uint32_t their_serial =	knot_soa_serial(&first_rr->rrs);
 	if (serial_compare(our_serial, their_serial) >= 0) {
-		ANSWER_LOG(LOG_INFO, data, "refresh, outgoing", "zone is up-to-date");
+		REFRESH_LOG(LOG_INFO, "zone is up-to-date");
 		zone_events_cancel(zone, ZONE_EVENT_EXPIRE);
 		zone_clear_preferred_master(zone);
 		return KNOT_STATE_DONE; /* Our zone is up to date. */
 	}
 
 	/* Our zone is outdated, schedule zone transfer. */
-	ANSWER_LOG(LOG_INFO, data, "refresh, outgoing", "master has newer serial %u -> %u",
-	           our_serial, their_serial);
+	REFRESH_LOG(LOG_INFO, "master has newer serial %u -> %u", our_serial, their_serial);
 	zone_set_preferred_master(zone, data->param->remote);
 	zone_events_schedule(zone, ZONE_EVENT_XFER, ZONE_EVENT_NOW);
 	return KNOT_STATE_DONE;
diff --git a/src/knot/nameserver/ixfr.c b/src/knot/nameserver/ixfr.c
index 9a7b786383..86fd5b0bdc 100644
--- a/src/knot/nameserver/ixfr.c
+++ b/src/knot/nameserver/ixfr.c
@@ -17,8 +17,8 @@
 #include <urcu.h>
 
 #include "knot/common/log.h"
-#include "knot/nameserver/ixfr.h"
 #include "knot/nameserver/axfr.h"
+#include "knot/nameserver/ixfr.h"
 #include "knot/nameserver/internet.h"
 #include "knot/updates/apply.h"
 #include "knot/zone/serial.h"
@@ -57,10 +57,6 @@ struct ixfr_proc {
 	const knot_rrset_t *soa_to;
 };
 
-/* IXFR-out-specific logging (internal, expects 'qdata' variable set). */
-#define IXFROUT_LOG(severity, msg, ...) \
-	QUERY_LOG(severity, qdata, "IXFR, outgoing", msg, ##__VA_ARGS__)
-
 /*! \brief Helper macro for putting RRs into packet. */
 #define IXFR_SAFE_PUT(pkt, rr) \
 	ret = knot_pkt_put((pkt), 0, (rr), KNOT_PF_NOTRUNC); \
@@ -326,10 +322,6 @@ static int ixfr_answer_soa(knot_pkt_t *pkt, struct query_data *qdata)
 
 /* ------------------------- IXFR-in processing ----------------------------- */
 
-/* IXFR-in-specific logging (internal, expects 'adata' variable set). */
-#define IXFRIN_LOG(severity, msg, ...) \
-	ANSWER_LOG(severity, adata, "IXFR, incoming", msg, ##__VA_ARGS__)
-
 /*! \brief Checks whether server responded with AXFR-style IXFR. */
 static bool ixfr_is_axfr(const knot_pkt_t *pkt)
 {
@@ -765,5 +757,3 @@ int ixfr_process_answer(knot_pkt_t *pkt, struct answer_data *adata)
 
 	return ret;
 }
-
-#undef IXFROUT_LOG
diff --git a/src/knot/nameserver/log.h b/src/knot/nameserver/log.h
new file mode 100644
index 0000000000..741fc3987f
--- /dev/null
+++ b/src/knot/nameserver/log.h
@@ -0,0 +1,32 @@
+/*  Copyright (C) 2016 CZ.NIC, z.s.p.o. <knot-dns@labs.nic.cz>
+
+    This program is free software: you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation, either version 3 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ */
+
+#pragma once
+
+#include "contrib/sockaddr.h"
+#include "knot/common/log.h"
+
+/*!
+ * \brief Base log message format for network communication.
+ *
+ * Emits a message in the following format:
+ * > [zone] operation, address: custom formatted message
+ */
+#define NS_PROC_LOG(priority, zone, remote, operation, msg, ...) do { \
+	char addr[SOCKADDR_STRLEN] = ""; \
+	sockaddr_tostr(addr, sizeof(addr), remote); \
+	log_msg_zone(priority, zone, "%s, %s: " msg, operation, addr, ##__VA_ARGS__); \
+	} while (0)
diff --git a/src/knot/nameserver/notify.c b/src/knot/nameserver/notify.c
index c32fa4c4b9..2f36552484 100644
--- a/src/knot/nameserver/notify.c
+++ b/src/knot/nameserver/notify.c
@@ -19,13 +19,20 @@
 #include "knot/common/log.h"
 #include "knot/nameserver/notify.h"
 #include "knot/nameserver/internet.h"
+#include "knot/nameserver/log.h"
 #include "knot/nameserver/tsig_ctx.h"
 #include "dnssec/random.h"
 #include "libknot/libknot.h"
 
 /* NOTIFY-specific logging (internal, expects 'qdata' variable set). */
-#define NOTIFY_QLOG(severity, msg, ...) \
-	QUERY_LOG(severity, qdata, "NOTIFY, incoming", msg, ##__VA_ARGS__)
+#define NOTIFY_IN_LOG(priority, msg, ...) \
+	NS_PROC_LOG(priority, qdata->zone->name, qdata->param->remote, \
+	            "NOTIFY, incoming", msg, ##__VA_ARGS__)
+
+/* NOTIFY-specific logging (internal, expects 'adata' variable set). */
+#define NOTIFY_OUT_LOG(priority, msg, ...) \
+	NS_PROC_LOG(priority, adata->param->zone->name, adata->param->remote, \
+	            "NOTIFY, outgoing", msg, ##__VA_ARGS__)
 
 static int notify_check_query(struct query_data *qdata)
 {
@@ -51,7 +58,7 @@ int notify_process_query(knot_pkt_t *pkt, struct query_data *qdata)
 	if (state == KNOT_STATE_FAIL) {
 		switch (qdata->rcode) {
 		case KNOT_RCODE_NOTAUTH: /* Not authoritative or ACL check failed. */
-			NOTIFY_QLOG(LOG_NOTICE, "unauthorized request");
+			NOTIFY_IN_LOG(LOG_NOTICE, "unauthorized request");
 			break;
 		case KNOT_RCODE_FORMERR: /* Silently ignore bad queries. */
 		default:
@@ -69,12 +76,12 @@ int notify_process_query(knot_pkt_t *pkt, struct query_data *qdata)
 		const knot_rrset_t *soa = knot_pkt_rr(answer, 0);
 		if (soa->type == KNOT_RRTYPE_SOA) {
 			uint32_t serial = knot_soa_serial(&soa->rrs);
-			NOTIFY_QLOG(LOG_INFO, "received serial %u", serial);
+			NOTIFY_IN_LOG(LOG_INFO, "received serial %u", serial);
 		} else { /* Complain, but accept N/A record. */
-			NOTIFY_QLOG(LOG_NOTICE, "received, bad record in answer section");
+			NOTIFY_IN_LOG(LOG_NOTICE, "received, bad record in answer section");
 		}
 	} else {
-		NOTIFY_QLOG(LOG_INFO, "received, doesn't have SOA");
+		NOTIFY_IN_LOG(LOG_INFO, "received, doesn't have SOA");
 	}
 
 	/* Incoming NOTIFY expires REFRESH timer and renews EXPIRE timer. */
@@ -85,12 +92,6 @@ int notify_process_query(knot_pkt_t *pkt, struct query_data *qdata)
 	return KNOT_STATE_DONE;
 }
 
-#undef NOTIFY_QLOG
-
-/* NOTIFY-specific logging (internal, expects 'adata' variable set). */
-#define NOTIFY_RLOG(severity, msg, ...) \
-	ANSWER_LOG(severity, adata, "NOTIFY, outgoing", msg, ##__VA_ARGS__)
-
 int notify_process_answer(knot_pkt_t *pkt, struct answer_data *adata)
 {
 	if (pkt == NULL || adata == NULL) {
@@ -102,7 +103,7 @@ int notify_process_answer(knot_pkt_t *pkt, struct answer_data *adata)
 	if (rcode != KNOT_RCODE_NOERROR) {
 		const knot_lookup_t *lut = knot_lookup_by_id(knot_rcode_names, rcode);
 		if (lut != NULL) {
-			NOTIFY_RLOG(LOG_WARNING, "server responded with %s", lut->name);
+			NOTIFY_OUT_LOG(LOG_WARNING, "server responded with %s", lut->name);
 		}
 		return KNOT_STATE_FAIL;
 	}
@@ -111,5 +112,3 @@ int notify_process_answer(knot_pkt_t *pkt, struct answer_data *adata)
 
 	return KNOT_STATE_DONE; /* No processing. */
 }
-
-#undef NOTIFY_RLOG
diff --git a/src/knot/nameserver/process_answer.c b/src/knot/nameserver/process_answer.c
index dacd2f22b3..780b859c69 100644
--- a/src/knot/nameserver/process_answer.c
+++ b/src/knot/nameserver/process_answer.c
@@ -20,6 +20,7 @@
 #include "knot/nameserver/internet.h"
 #include "knot/nameserver/ixfr.h"
 #include "knot/nameserver/notify.h"
+#include "knot/nameserver/log.h"
 #include "contrib/mempattern.h"
 
 /*! \brief Accessor to query-specific data. */
@@ -115,8 +116,9 @@ static int process_answer(knot_layer_t *ctx, knot_pkt_t *pkt)
 	/* Verify incoming packet. */
 	int ret = tsig_verify_packet(&data->param->tsig_ctx, pkt);
 	if (ret != KNOT_EOK) {
-		ANSWER_LOG(LOG_WARNING, data, "response", "denied (%s)",
-		           knot_strerror(ret));
+		// XXX: "response" operation sounds like placeholder
+		NS_PROC_LOG(LOG_WARNING, data->param->zone->name, data->param->remote,
+		            "response", "denied (%s)", knot_strerror(ret));
 		return KNOT_STATE_FAIL;
 	}
 
diff --git a/src/knot/nameserver/process_answer.h b/src/knot/nameserver/process_answer.h
index 2ed5b705c9..f7aa5a21d2 100644
--- a/src/knot/nameserver/process_answer.h
+++ b/src/knot/nameserver/process_answer.h
@@ -34,11 +34,6 @@
 const knot_layer_api_t *process_answer_layer(void);
 #define KNOT_STATE_ANSWER process_answer_layer()
 
-/*! \brief Answer processing logging base. */
-#define ANSWER_LOG(severity, data, operation, msg, ...) \
-	NS_PROC_LOG(severity, (data)->param->remote, (data)->param->zone->name, \
-	            operation, msg, ##__VA_ARGS__);
-
 /*!
  * \brief Processing module parameters.
  */
diff --git a/src/knot/nameserver/process_query.h b/src/knot/nameserver/process_query.h
index a2a17e647e..518e2e5661 100644
--- a/src/knot/nameserver/process_query.h
+++ b/src/knot/nameserver/process_query.h
@@ -33,19 +33,6 @@
 const knot_layer_api_t *process_query_layer(void);
 #define NS_PROC_QUERY process_query_layer()
 
-/*! \brief Query processing logging common base. */
-#define NS_PROC_LOG(severity, remote, zone_name, operation, msg, ...) do { \
-	char addr_str[SOCKADDR_STRLEN] = {0}; \
-	sockaddr_tostr(addr_str, sizeof(addr_str), remote); \
-	log_msg_zone(severity, zone_name, operation ", %s: " msg, \
-	             addr_str, ##__VA_ARGS__); \
-	} while (0)
-
-/*! \brief Query logging common base. */
-#define QUERY_LOG(severity, qdata, operation, msg, ...) \
-	NS_PROC_LOG(severity, (qdata)->param->remote, knot_pkt_qname((qdata)->query), \
-	            operation, msg, ##__VA_ARGS__);
-
 /* Query processing specific flags. */
 enum process_query_flag {
 	NS_QUERY_NO_AXFR    = 1 << 0, /* Don't process AXFR */
diff --git a/src/knot/nameserver/update.c b/src/knot/nameserver/update.c
index e2072d45ff..3e7b0d7865 100644
--- a/src/knot/nameserver/update.c
+++ b/src/knot/nameserver/update.c
@@ -22,16 +22,18 @@
 #include "knot/nameserver/capture.h"
 #include "knot/nameserver/internet.h"
 #include "knot/nameserver/process_query.h"
+#include "knot/nameserver/log.h"
 #include "knot/updates/ddns.h"
 #include "knot/updates/apply.h"
-#include "knot/zone/events/events.h"
+#include "knot/events/events.h"
 #include "libknot/libknot.h"
 #include "contrib/net.h"
 #include "contrib/print.h"
 
 /* UPDATE-specific logging (internal, expects 'qdata' variable set). */
 #define UPDATE_LOG(severity, msg, ...) \
-	QUERY_LOG(severity, qdata, "DDNS", msg, ##__VA_ARGS__)
+	NS_PROC_LOG(severity, qdata->zone->name, qdata->param->remote, \
+	            "DDNS", msg, ##__VA_ARGS__)
 
 static void init_qdata_from_request(struct query_data *qdata,
                                     const zone_t *zone,
@@ -336,8 +338,6 @@ static bool update_tsig_check(conf_t *conf, struct query_data *qdata, struct kno
 	return true;
 }
 
-#undef UPDATE_LOG
-
 static void send_update_response(conf_t *conf, const zone_t *zone, struct knot_request *req)
 {
 	if (req->resp) {
-- 
GitLab