- auth-load-thread, print time taken during auth load processing.

diff --git a/services/authload.c b/services/authload.c
index 01ccd94303fd8deb57b83a1d836d48d7a97383ff..16d36e4c7108a23d52189b8a3a8c9a35cd593f78 100644 (file)
--- a/services/authload.c
+++ b/services/authload.c
@@ -50,6 +50,7 @@
 #include "util/net_help.h"
 #include "util/log.h"
 #include "util/ub_event.h"
+#include "util/timeval_func.h"
 #include "util/data/dname.h"
 
 /** Auth load notification to string, for descriptive purposes. */
@@ -574,6 +575,9 @@ static int
 auth_load_thread_process(struct auth_load_thread* thr)
 {
        struct auth_load_task* task = thr->task;
+       struct timeval start, end;
+       if(gettimeofday(&start, NULL) < 0)
+               log_err("gettimeofday: %s", strerror(errno));
 
        /* apply data */
        if(task->on_http) {
@@ -586,6 +590,10 @@ auth_load_thread_process(struct auth_load_thread* thr)
                if(!auth_load_process_axfr(thr))
                        return 0;
        }
+
+       if(gettimeofday(&end, NULL) < 0)
+               log_err("gettimeofday: %s", strerror(errno));
+       timeval_subtract(&thr->task->time_taken, &end, &start);
        return 1;
 }
 
@@ -674,6 +682,7 @@ worker_auth_load_service_cb(int ATTR_UNUSED(fd), short ATTR_UNUSED(bits),
        struct auth_chunk* chunk_list;
        struct module_env* env = &thr->task->worker->env;
        int ixfr_fail;
+       struct timeval time_taken;
 
        log_assert(thr->commpair[0] >= 0);
        ret = recv(thr->commpair[0], &recv_item, 1, 0);
@@ -725,6 +734,7 @@ worker_auth_load_service_cb(int ATTR_UNUSED(fd), short ATTR_UNUSED(bits),
        lock_basic_lock(&xfr->lock);
        lock_rw_unlock(&thr->task->worker->env.auth_zones->lock);
        ixfr_fail = thr->task->ixfr_fail;
+       time_taken = thr->task->time_taken;
        if(thr->task->on_http) {
                chunk_list = thr->task->chunks_first;
                thr->task->chunks_first = NULL;
@@ -736,7 +746,7 @@ worker_auth_load_service_cb(int ATTR_UNUSED(fd), short ATTR_UNUSED(bits),
        auth_load_thread_delete(thr);
        auth_load_info_release_thread(env);
        xfr_process_load_end_transfer(xfr, env, recv_item, ixfr_fail,
-               chunk_list);
+               &time_taken, chunk_list);
 }
 
 /** Attach worker to the auth load thread. */

diff --git a/services/authload.h b/services/authload.h
index 718cb5d0d55417281b2cbaec042179f89f5d19bf..c76c835699760382ea77820cecc82d4617e242e7 100644 (file)
--- a/services/authload.h
+++ b/services/authload.h
@@ -155,6 +155,9 @@ struct auth_load_task {
        struct auth_chunk* chunks_last;
        /** size of data in data chunks. */
        size_t chunks_total;
+
+       /** time taken for the task */
+       struct timeval time_taken;
 };
 
 /**

diff --git a/services/authzone.c b/services/authzone.c
index 503347440aa71527bbd355dd5d54b8ffae61af79..99edb7d4233db635e2192f75d214cd17939deb64 100644 (file)
--- a/services/authzone.c
+++ b/services/authzone.c
@@ -6421,7 +6421,7 @@ process_list_end_transfer(struct auth_xfer* xfr, struct module_env* env)
  * ends holding xfr lock. */
 static int
 xfr_process_loaded_transfer(struct auth_xfer* xfr, struct module_env* env,
-       int* gone)
+       int* gone, struct timeval* time_taken)
 {
        struct auth_zone* z = NULL;
        verbose(VERB_ALGO, "xfr_process_loaded_transfer");
@@ -6502,8 +6502,11 @@ xfr_process_loaded_transfer(struct auth_xfer* xfr, struct module_env* env,
        if(verbosity >= VERB_QUERY && xfr->have_zone) {
                char zname[LDNS_MAX_DOMAINLEN];
                dname_str(xfr->name, zname);
-               verbose(VERB_QUERY, "auth zone %s updated to serial %u", zname,
-                       (unsigned)xfr->serial);
+               verbose(VERB_QUERY, "auth zone %s updated to serial %u",
+                       zname, (unsigned)xfr->serial);
+               verbose(VERB_ALGO, "auth zone %s processing time was %d.%6.6ds",
+                       zname, (int)time_taken->tv_sec,
+                       (int)time_taken->tv_usec);
        }
        verbose(VERB_ALGO, "xfr_process_loaded_transfer: write after update");
        /* see if we need to write to a zonefile */
@@ -6514,14 +6517,14 @@ xfr_process_loaded_transfer(struct auth_xfer* xfr, struct module_env* env,
 
 void xfr_process_load_end_transfer(struct auth_xfer* xfr,
        struct module_env* env, uint8_t status, int ixfr_fail,
-       struct auth_chunk* chunk_list)
+       struct timeval* time_taken, struct auth_chunk* chunk_list)
 {
        /* Chunks are put here for the auth zone write for the http case. */
        verbose(VERB_ALGO, "xfr_process_load_end_transfer");
        xfr->task_transfer->chunks_first = chunk_list;
        if(status) {
                int gone = 0;
-               if(!xfr_process_loaded_transfer(xfr, env, &gone)) {
+               if(!xfr_process_loaded_transfer(xfr, env, &gone, time_taken)) {
                        status = 0;
                        if(gone) {
                                /* the zone is gone from the authzones. */

diff --git a/services/authzone.h b/services/authzone.h
index 3e9521dc0305d1c59ed9a264ef307e0e20080c6d..e653a8fc32bd27b6e49c51bd1e14e6b13f9d3a78 100644 (file)
--- a/services/authzone.h
+++ b/services/authzone.h
@@ -868,7 +868,7 @@ void auth_data_del(rbnode_type* n, void* arg);
 /** Handle the end of an auth load task. */
 void xfr_process_load_end_transfer(struct auth_xfer* xfr,
        struct module_env* env, uint8_t status, int ixfr_fail,
-       struct auth_chunk* chunk_list);
+       struct timeval* time_taken, struct auth_chunk* chunk_list);
 
 /** Log preview of http transfer */
 void xfr_http_preview(const char* file, struct auth_chunk* chunk_list);