stats output text nice.

git-svn-id: file:///svn/unbound/trunk@943 be551aaa-1e26-0410-a405-d3ace91eadb9

daemon/stats.c

@@ -59,10 +59,12 @@ void server_stats_querymiss(struct server_stats* stats, struct worker* worker)
 
 void server_stats_log(struct server_stats* stats, int threadnum)
 {
-	log_info("server stats for thread %d: %u queries, %u from cache", 
+	log_info("server stats for thread %d: %u queries, "
+		"%u answers from cache, %u recursions", 
 		threadnum, (unsigned)stats->num_queries, 
 		(unsigned)(stats->num_queries - 
-			stats->num_queries_missed_cache));
+			stats->num_queries_missed_cache),
+		(unsigned)stats->num_queries_missed_cache);
 	log_info("server stats for thread %d: requestlist max %u avg %g "
 		"exceeded %u", threadnum, (unsigned)stats->max_query_list_size,
 		stats->num_queries_missed_cache?

daemon/worker.c

@@ -874,8 +874,8 @@ worker_restart_timer(struct worker* worker)
 void worker_stat_timer_cb(void* arg)
 {
 	struct worker* worker = (struct worker*)arg;
-	mesh_stats(worker->env.mesh, "mesh has");
 	server_stats_log(&worker->stats, worker->thread_num);
+	mesh_stats(worker->env.mesh, "mesh has");
 	worker_mem_report(worker, NULL);
 	server_stats_init(&worker->stats);
 	mesh_stats_clear(worker->env.mesh);
@@ -1046,8 +1046,8 @@ worker_delete(struct worker* worker)
 	if(!worker) 
 		return;
 	if(worker->env.mesh && verbosity >= VERB_OPS) {
-		mesh_stats(worker->env.mesh, "mesh has");
 		server_stats_log(&worker->stats, worker->thread_num);
+		mesh_stats(worker->env.mesh, "mesh has");
 		worker_mem_report(worker, NULL);
 	}
 	mesh_delete(worker->env.mesh);

doc/Changelog

@@ -1,5 +1,6 @@
 11 February 2008: Wouter
 	- changed library to use ub_ instead of ub_val_ as prefix.
+	- statistics output text nice.
 
 8 February 2008: Wouter
 	- test program for multiple queries over a TCP channel.

services/mesh.c

@@ -768,20 +768,21 @@ mesh_log_list(struct mesh_area* mesh)
 void 
 mesh_stats(struct mesh_area* mesh, const char* str)
 {
-	log_info("%s %u states (%u with reply, %u detached), "
-		"%u waiting replies", str, (unsigned)mesh->all.count, 
+	verbose(VERB_DETAIL, "%s %u recursion states (%u with reply, "
+		"%u detached), %u waiting replies, %u recursion replies "
+		"sent", str, (unsigned)mesh->all.count, 
 		(unsigned)mesh->num_reply_states,
 		(unsigned)mesh->num_detached_states,
-		(unsigned)mesh->num_reply_addrs);
+		(unsigned)mesh->num_reply_addrs,
+		(unsigned)mesh->replies_sent);
 	if(mesh->replies_sent > 0) {
 		struct timeval avg;
 		timeval_divide(&avg, &mesh->replies_sum_wait, 
 			mesh->replies_sent);
-		log_info("sent %u replies, with average wait "
-			"of %d.%6.6d sec", (unsigned)mesh->replies_sent,
-			(int)avg.tv_sec, (int)avg.tv_usec);
-		log_info("histogram of reply wait times");
-		timehist_log(mesh->histogram);
+		log_info("average recursion processing time "
+			"%d.%6.6d sec", (int)avg.tv_sec, (int)avg.tv_usec);
+		log_info("histogram of recursion processing times");
+		timehist_log(mesh->histogram, "recursions");
 	}
 }
 

util/timehist.c

@@ -156,7 +156,7 @@ void timehist_print(struct timehist* hist)
 #endif
 }
 
-void timehist_log(struct timehist* hist)
+void timehist_log(struct timehist* hist, const char* name)
 {
 #ifndef S_SPLINT_S
 	size_t i;
@@ -165,7 +165,7 @@ void timehist_log(struct timehist* hist)
 		timehist_quartile(hist, 0.50),
 		timehist_quartile(hist, 0.75));
 	/*        0000.000000 0000.000000 0 */
-	log_info("lower(secs) upper(secs) replycount");
+	log_info("lower(secs) upper(secs) %s", name);
 	for(i=0; i<hist->num; i++) {
 		if(hist->buckets[i].count != 0) {
 			log_info("%4d.%6.6d %4d.%6.6d %u",

util/timehist.h

@@ -108,7 +108,8 @@ void timehist_print(struct timehist* hist);
 /**
  * Log histogram, print it to the logfile.
  * @param hist: histogram
+ * @param name: the name of the value column
  */
-void timehist_log(struct timehist* hist);
+void timehist_log(struct timehist* hist, const char* name);
 
 #endif /* UTIL_TIMEHIST_H */