Commit d2f33b6a authored by Marek Vavrusa's avatar Marek Vavrusa

Logging for outgoing transfers.

parent f6a66d72
......@@ -136,13 +136,14 @@ static int tcp_handle(ns_proc_context_t *query_ctx, int fd,
int state = ns_proc_in(rx->iov_base, rx->iov_len, query_ctx);
/* Resolve until NOOP or finished. */
ret = KNOT_EOK;
while (state == NS_PROC_FULL || state == NS_PROC_FAIL) {
state = ns_proc_out(tx->iov_base, &tx_len, query_ctx);
/* If it has response, send it. */
if (state == NS_PROC_DONE || state == NS_PROC_FULL) {
if (tcp_send(fd, tx->iov_base, tx_len) != tx_len) {
ret = KNOT_ECONN;
ret = KNOT_ECONNREFUSED;
break;
}
tx_len = tx->iov_len; /* Reset size. */
......
......@@ -8,6 +8,7 @@
#include "common/lists.h"
#include "knot/server/zones.h"
/* AXFR context. */
struct axfr_proc {
struct xfr_proc proc;
hattrie_iter_t *i;
......@@ -93,6 +94,7 @@ static int axfr_answer_init(struct query_data *qdata)
}
memset(xfer, 0, sizeof(struct axfr_proc));
init_list(&xfer->nodes);
gettimeofday(&xfer->tstamp, NULL);
qdata->ext = xfer;
/* Put data to process. */
......@@ -123,6 +125,7 @@ int xfr_process_list(knot_pkt_t *pkt, xfr_put_cb process_item, struct query_data
ptrnode_t *head = HEAD(xfer->nodes);
ret = process_item(pkt, head->d, xfer);
if (ret == KNOT_EOK) { /* Finished. */
/* Complete change set. */
rem_node((node_t *)head);
mm->free(head);
} else { /* Packet full or other error. */
......@@ -142,6 +145,10 @@ int xfr_process_list(knot_pkt_t *pkt, xfr_put_cb process_item, struct query_data
return ret;
}
/* AXFR-specific logging (internal, expects 'qdata' variable set). */
#define AXFR_LOG(severity, msg...) \
XFER_LOG(severity, qdata, "Outgoing AXFR", msg)
int axfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata)
{
assert(pkt);
......@@ -150,8 +157,8 @@ int axfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
int ret = KNOT_EOK;
mm_ctx_t *mm = qdata->mm;
struct timeval now = {0};
/*! \todo Log messages. */
/* Initialize on first call. */
if (qdata->ext == NULL) {
......@@ -165,8 +172,10 @@ int axfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
ret = axfr_answer_init(qdata);
if (ret != KNOT_EOK) {
dbg_ns("%s: init => %s\n", __func__, knot_strerror(ret));
AXFR_LOG(LOG_ERR, "Failed to start (%s).", knot_strerror(ret));
return ret;
} else {
AXFR_LOG(LOG_INFO, "Started (serial %u).", knot_zone_serial(qdata->zone->contents));
}
}
......@@ -180,12 +189,14 @@ int axfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
case KNOT_ESPACE: /* Couldn't write more, send packet and continue. */
return NS_PROC_FULL; /* Check for more. */
case KNOT_EOK: /* Last response. */
dbg_ns("%s: finished AXFR, %u pkts, ~%.01fkB\n", __func__,
xfer->npkts, xfer->nbytes/1024.0);
gettimeofday(&now, NULL);
AXFR_LOG(LOG_INFO, "Finished in %.02fs (%u messages, ~%.01fkB).",
time_diff(&xfer->tstamp, &now) / 1000.0,
xfer->npkts, xfer->nbytes / 1024.0);
ret = NS_PROC_DONE;
break;
default: /* Generic error. */
dbg_ns("%s: answered with ret = %s\n", __func__, knot_strerror(ret));
AXFR_LOG(LOG_ERR, "%s", knot_strerror(ret));
ret = NS_PROC_FAIL;
break;
}
......@@ -197,3 +208,5 @@ int axfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
return ret;
}
#undef AXFR_LOG
......@@ -33,11 +33,23 @@
struct query_data;
/*! \brief Transfers logging common base. */
#define XFER_LOG(severity, qdata, what, msg, ...) do { \
zonedata_t *zone_data = (zonedata_t *)knot_zone_data((qdata)->zone); \
sockaddr_t *addr = &(qdata)->param->query_source; \
char addr_str[SOCKADDR_STRLEN]; \
sockaddr_tostr(addr, addr_str, sizeof(addr_str)); \
log_msg(LOG_SERVER, severity, what " of '%s' to '%s:%d': " msg "\n", \
zone_data->conf->name, addr_str, sockaddr_portnum(addr), \
##__VA_ARGS__); \
} while (0)
/*! \brief Generic transfer processing state. */
struct xfr_proc {
list_t nodes; /* Items to process (ptrnode_t). */
unsigned npkts; /* Packets processed. */
unsigned nbytes; /* Bytes processed. */
struct timeval tstamp; /* Start time. */
};
/*! \brief Generic transfer processing (reused for IXFR).
......
......@@ -23,8 +23,13 @@ struct ixfr_proc {
node_t *cur;
unsigned state;
knot_changesets_t *changesets;
struct query_data *qdata;
};
/* IXFR-specific logging (internal, expects 'qdata' variable set). */
#define IXFR_LOG(severity, msg...) \
XFER_LOG(severity, qdata, "Outgoing IXFR", msg)
/*! \brief Helper macro for putting RRs into packet. */
#define IXFR_SAFE_PUT(pkt, rr) \
ret = knot_pkt_put((pkt), 0, (rr), KNOT_PF_NOTRUNC); \
......@@ -107,6 +112,10 @@ static int ixfr_process_item(knot_pkt_t *pkt, const void *item, struct xfr_proc
dbg_ns("%s: put 'ADD' RRs\n", __func__);
ixfr->state = SOA_REMOVE;
}
/* Finished change set. */
struct query_data *qdata = ixfr->qdata;
IXFR_LOG(LOG_INFO, "Serial %u -> %u.", chgset->serial_from, chgset->serial_to);
return ret;
}
......@@ -190,8 +199,10 @@ static int ixfr_answer_init(struct query_data *qdata)
return KNOT_ENOMEM;
}
memset(xfer, 0, sizeof(struct ixfr_proc));
gettimeofday(&xfer->proc.tstamp, NULL);
init_list(&xfer->proc.nodes);
qdata->ext = xfer;
xfer->qdata = qdata;
/* Put all changesets to process. */
xfer->changesets = chgsets;
......@@ -240,24 +251,29 @@ int ixfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
int ret = KNOT_EOK;
mm_ctx_t *mm = qdata->mm;
/*! \todo Log messages. */
struct timeval now = {0};
const knot_pktsection_t *authority = knot_pkt_section(qdata->query, KNOT_AUTHORITY);
const knot_rrset_t *their_soa = authority->rr[0];
/* Initialize on first call. */
if (qdata->ext == NULL) {
ret = ixfr_answer_init(qdata);
switch(ret) {
case KNOT_EOK: /* OK */
IXFR_LOG(LOG_INFO, "Started (serial %u -> %u).",
knot_rdata_soa_serial(their_soa),
knot_zone_serial(qdata->zone->contents));
break;
case KNOT_EUPTODATE: /* Our zone is same age/older, send SOA. */
dbg_ns("%s: nothing new => SOA response\n", __func__);
IXFR_LOG(LOG_INFO, "Zone is up-to-date.");
return ixfr_answer_soa(pkt, ns, qdata);
case KNOT_ERANGE: /* No history -> AXFR. */
case KNOT_ENOENT:
dbg_ns("%s: not enough history => AXFR answer\n", __func__);
IXFR_LOG(LOG_INFO, "Incomplete history, fallback to AXFR.");
qdata->packet_type = KNOT_QUERY_AXFR; /* Solve as AXFR. */
return axfr_answer(pkt, ns, qdata);
default: /* Server errors. */
dbg_ns("%s: init => %s\n", __func__, knot_strerror(ret));
IXFR_LOG(LOG_ERR, "Failed to start (%s).", knot_strerror(ret));
return NS_PROC_FAIL;
}
}
......@@ -272,12 +288,14 @@ int ixfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
case KNOT_ESPACE: /* Couldn't write more, send packet and continue. */
return NS_PROC_FULL; /* Check for more. */
case KNOT_EOK: /* Last response. */
dbg_ns("%s: finished IXFR, %u pkts, %.01fkB\n", __func__,
ixfr->proc.npkts, ixfr->proc.nbytes/1024.0);
gettimeofday(&now, NULL);
IXFR_LOG(LOG_INFO, "Finished in %.02fs (%u messages, ~%.01fkB).",
time_diff(&ixfr->proc.tstamp, &now) / 1000.0,
ixfr->proc.npkts, ixfr->proc.nbytes / 1024.0);
ret = NS_PROC_DONE;
break;
default: /* Generic error. */
dbg_ns("%s: answered with ret = %s\n", __func__, knot_strerror(ret));
IXFR_LOG(LOG_ERR, "%s", knot_strerror(ret));
ret = NS_PROC_FAIL;
break;
}
......@@ -290,3 +308,5 @@ int ixfr_answer(knot_pkt_t *pkt, knot_nameserver_t *ns, struct query_data *qdata
return ret;
}
#undef IXFR_LOG
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment