diff --git a/lib/ns/xfrout.c b/lib/ns/xfrout.c index 0212887e91..f98ab6b7f5 100644 --- a/lib/ns/xfrout.c +++ b/lib/ns/xfrout.c @@ -645,11 +645,22 @@ static rrstream_methods_t compound_rrstream_methods = { }; /**************************************************************************/ -/* + +/*% + * Structure holding outgoing transfer statistics + */ +struct xfr_stats { + uint64_t nmsg; /*%< Number of messages sent */ + uint64_t nrecs; /*%< Number of records sent */ + uint64_t nbytes; /*%< Number of bytes sent */ + isc_time_t start; /*%< Start time of the transfer */ + isc_time_t end; /*%< End time of the transfer */ +}; + +/*% * An 'xfrout_ctx_t' contains the state of an outgoing AXFR or IXFR * in progress. */ - typedef struct { isc_mem_t *mctx; ns_client_t *client; @@ -670,7 +681,6 @@ typedef struct { isc_buffer_t txbuf; /* Transmit message buffer */ void *txmem; unsigned int txmemlen; - unsigned int nmsg; /* Number of messages sent */ dns_tsigkey_t *tsigkey; /* Key used to create TSIG */ isc_buffer_t *lasttsig; /* the last TSIG */ bool verified_tsig; /* verified request MAC */ @@ -678,6 +688,7 @@ typedef struct { int sends; /* Send in progress */ bool shuttingdown; const char *mnemonic; /* Style of transfer */ + struct xfr_stats stats; /*%< Transfer statistics */ } xfrout_ctx_t; static isc_result_t @@ -1186,7 +1197,6 @@ xfrout_ctx_create(isc_mem_t *mctx, ns_client_t *client, unsigned int id, xfr->tsigkey = tsigkey; xfr->lasttsig = lasttsig; xfr->verified_tsig = verified_tsig; - xfr->nmsg = 0; xfr->many_answers = many_answers; xfr->sends = 0; xfr->shuttingdown = false; @@ -1198,6 +1208,11 @@ xfrout_ctx_create(isc_mem_t *mctx, ns_client_t *client, unsigned int id, xfr->stream = NULL; xfr->quota = NULL; + xfr->stats.nmsg = 0; + xfr->stats.nrecs = 0; + xfr->stats.nbytes = 0; + isc_time_now(&xfr->stats.start); + /* * Allocate a temporary buffer for the uncompressed response * message data. The size should be no more than 65535 bytes @@ -1483,6 +1498,8 @@ sendstream(xfrout_ctx_t *xfr) { dns_message_addname(msg, msgname, DNS_SECTION_ANSWER); msgname = NULL; + xfr->stats.nrecs++; + result = xfr->stream->methods->next(xfr->stream); if (result == ISC_R_NOMORE) { xfr->end_of_stream = true; @@ -1537,8 +1554,6 @@ sendstream(xfrout_ctx_t *xfr) { /* Advance lasttsig to be the last TSIG generated */ CHECK(dns_message_getquerytsig(msg, xfr->mctx, &xfr->lasttsig)); - xfr->nmsg++; - failure: if (msgname != NULL) { if (msgrds != NULL) { @@ -1621,10 +1636,20 @@ xfrout_senddone(isc_task_t *task, isc_event_t *event) { INSIST(event->ev_type == ISC_SOCKEVENT_SENDDONE); - isc_event_free(&event); xfr->sends--; INSIST(xfr->sends == 0); + /* + * Update transfer statistics if sending succeeded, accounting for the + * two-byte TCP length prefix included in the number of bytes sent. + */ + if (evresult == ISC_R_SUCCESS) { + xfr->stats.nmsg++; + xfr->stats.nbytes += sev->region.length - 2; + } + + isc_event_free(&event); + (void)isc_timer_touch(xfr->client->timer); if (xfr->shuttingdown == true) { xfrout_maybe_destroy(xfr); @@ -1634,8 +1659,28 @@ xfrout_senddone(isc_task_t *task, isc_event_t *event) { sendstream(xfr); } else { /* End of zone transfer stream. */ + uint64_t msecs, persec; + inc_stats(xfr->client, xfr->zone, ns_statscounter_xfrdone); - xfrout_log(xfr, ISC_LOG_INFO, "%s ended", xfr->mnemonic); + isc_time_now(&xfr->stats.end); + msecs = isc_time_microdiff(&xfr->stats.end, &xfr->stats.start); + msecs /= 1000; + if (msecs == 0) { + msecs = 1; + } + persec = (xfr->stats.nbytes * 1000) / msecs; + xfrout_log(xfr, ISC_LOG_INFO, + "%s ended: " + "%" PRIu64 " messages, %" PRIu64 " records, " + "%" PRIu64 " bytes, " + "%u.%03u secs (%u bytes/sec)", + xfr->mnemonic, + xfr->stats.nmsg, xfr->stats.nrecs, + xfr->stats.nbytes, + (unsigned int) (msecs / 1000), + (unsigned int) (msecs % 1000), + (unsigned int) persec); + ns_client_next(xfr->client, ISC_R_SUCCESS); xfrout_ctx_destroy(&xfr); }