2274. [func] Log zone transfer statistics. [RT #17161]

diff --git a/CHANGES b/CHANGES
index 62b17399d02a225da20c6a460dfd17d6402cfda8..4b1ade82b4fd1686c3dd59d16127ceb4ff240017 100644 (file)
--- a/CHANGES
+++ b/CHANGES
@@ -1,3 +1,5 @@
+2274.  [func]          Log zone transfer statistics. [RT #17161]
+
 2273.  [bug]           Adjust log level to WARNING when saving inconsistant
                        stub/slave master and journal files. [RT# 17279]
 

diff --git a/lib/dns/xfrin.c b/lib/dns/xfrin.c
index 0c0993bbefc6595dc6fc6932a83d9e9a956e55da..c4e72cafe054ac4f0ed480ca6230a9cd467cd380 100644 (file)
--- a/lib/dns/xfrin.c
+++ b/lib/dns/xfrin.c
@@ -15,7 +15,7 @@
  * PERFORMANCE OF THIS SOFTWARE.
  */
 
-/* $Id: xfrin.c,v 1.154 2007/10/31 01:56:47 marka Exp $ */
+/* $Id: xfrin.c,v 1.155 2007/12/02 23:21:19 marka Exp $ */
 
 /*! \file */
 
@@ -142,6 +142,11 @@ struct dns_xfrin_ctx {
        isc_boolean_t           is_ixfr;
 
        unsigned int            nmsg;           /*%< Number of messages recvd */
+       unsigned int            nrecs;          /*%< Number of records recvd */
+       isc_uint64_t            nbytes;         /*%< Number of bytes received */
+
+       isc_time_t              start;          /*%< Start time of the transfer */
+       isc_time_t              end;            /*%< End time of the transfer */
 
        dns_tsigkey_t           *tsigkey;       /*%< Key used to create TSIG */
        isc_buffer_t            *lasttsig;      /*%< The last TSIG */
@@ -426,6 +431,8 @@ xfr_rr(dns_xfrin_ctx_t *xfr, dns_name_t *name, isc_uint32_t ttl,
 {
        isc_result_t result;
 
+       xfr->nrecs++;
+
  redo:
        switch (xfr->state) {
        case XFRST_SOAQUERY:
@@ -800,6 +807,9 @@ xfrin_create(isc_mem_t *mctx,
        /* end_serial */
 
        xfr->nmsg = 0;
+       xfr->nrecs = 0;
+       xfr->nbytes = 0;
+       isc_time_now(&xfr->start);
 
        xfr->tsigkey = NULL;
        if (tsigkey != NULL)
@@ -1060,6 +1070,9 @@ xfrin_send_request(dns_xfrin_ctx_t *xfr) {
        xfr->checkid = ISC_TRUE;
        xfr->id++;
        xfr->nmsg = 0;
+       xfr->nrecs = 0;
+       xfr->nbytes = 0;
+       isc_time_now(&xfr->start);
        msg->id = xfr->id;
 
        CHECK(render(msg, xfr->mctx, &xfr->qbuffer));
@@ -1308,6 +1321,11 @@ xfrin_recv_done(isc_task_t *task, isc_event_t *ev) {
         */
        xfr->nmsg++;
 
+       /*
+        * Update the number of bytes received.
+        */
+       xfr->nbytes += tcpmsg->buffer.used;
+
        /*
         * Copy the context back.
         */
@@ -1372,6 +1390,8 @@ xfrin_timeout(isc_task_t *task, isc_event_t *event) {
 
 static void
 maybe_free(dns_xfrin_ctx_t *xfr) {
+       isc_uint64_t secs;
+
        REQUIRE(VALID_XFRIN(xfr));
 
        if (! xfr->shuttingdown || xfr->refcount != 0 ||
@@ -1379,7 +1399,20 @@ maybe_free(dns_xfrin_ctx_t *xfr) {
            xfr->recvs != 0)
                return;
 
-       xfrin_log(xfr, ISC_LOG_INFO, "end of transfer");
+       /*
+        * Calculate the length of time the transfer took,
+        * and print a log message with the bytes and rate.
+        */
+       isc_time_now(&xfr->end);
+       secs = isc_time_microdiff(&xfr->end, &xfr->start) / 1000000;
+       if (secs == 0)
+               secs = 1;
+       xfrin_log(xfr, ISC_LOG_INFO, 
+                 "Transfer completed: %d messages, %d records, "
+                 "%" ISC_PRINT_QUADFORMAT "u bytes, "
+                 "%" ISC_PRINT_QUADFORMAT "u secs (%0.1f bytes/sec)",
+                 xfr->nmsg, xfr->nrecs, xfr->nbytes, secs,
+                 (float) (xfr->nbytes / secs));
 
        if (xfr->socket != NULL)
                isc_socket_detach(&xfr->socket);
@@ -1448,7 +1481,7 @@ xfrin_logv(int level, const char *zonetext, isc_sockaddr_t *masteraddr,
 
 static void
 xfrin_log1(int level, const char *zonetext, isc_sockaddr_t *masteraddr,
-           const char *fmt, ...)
+          const char *fmt, ...)
 {
        va_list ap;