1 /* 2 * daemon/stats.c - collect runtime performance indicators. 3 * 4 * Copyright (c) 2007, NLnet Labs. All rights reserved. 5 * 6 * This software is open source. 7 * 8 * Redistribution and use in source and binary forms, with or without 9 * modification, are permitted provided that the following conditions 10 * are met: 11 * 12 * Redistributions of source code must retain the above copyright notice, 13 * this list of conditions and the following disclaimer. 14 * 15 * Redistributions in binary form must reproduce the above copyright notice, 16 * this list of conditions and the following disclaimer in the documentation 17 * and/or other materials provided with the distribution. 18 * 19 * Neither the name of the NLNET LABS nor the names of its contributors may 20 * be used to endorse or promote products derived from this software without 21 * specific prior written permission. 22 * 23 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS 24 * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 25 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR 26 * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT 27 * HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, 28 * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED 29 * TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR 30 * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF 31 * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING 32 * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS 33 * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. 34 */ 35 36 /** 37 * \file 38 * 39 * This file describes the data structure used to collect runtime performance 40 * numbers. These 'statistics' may be of interest to the operator. 41 */ 42 #include "config.h" 43 #ifdef HAVE_TIME_H 44 #include <time.h> 45 #endif 46 #include <sys/time.h> 47 #include <sys/types.h> 48 #include "daemon/stats.h" 49 #include "daemon/worker.h" 50 #include "daemon/daemon.h" 51 #include "services/mesh.h" 52 #include "services/outside_network.h" 53 #include "services/listen_dnsport.h" 54 #include "util/config_file.h" 55 #include "util/tube.h" 56 #include "util/timehist.h" 57 #include "util/net_help.h" 58 #include "validator/validator.h" 59 #include "iterator/iterator.h" 60 #include "sldns/sbuffer.h" 61 #include "services/cache/rrset.h" 62 #include "services/cache/infra.h" 63 #include "validator/val_kcache.h" 64 65 /** add timers and the values do not overflow or become negative */ 66 static void 67 stats_timeval_add(long long* d_sec, long long* d_usec, long long add_sec, long long add_usec) 68 { 69 #ifndef S_SPLINT_S 70 (*d_sec) += add_sec; 71 (*d_usec) += add_usec; 72 if((*d_usec) > 1000000) { 73 (*d_usec) -= 1000000; 74 (*d_sec)++; 75 } 76 #endif 77 } 78 79 void server_stats_init(struct ub_server_stats* stats, struct config_file* cfg) 80 { 81 memset(stats, 0, sizeof(*stats)); 82 stats->extended = cfg->stat_extended; 83 } 84 85 void server_stats_querymiss(struct ub_server_stats* stats, struct worker* worker) 86 { 87 stats->num_queries_missed_cache++; 88 stats->sum_query_list_size += worker->env.mesh->all.count; 89 if((long long)worker->env.mesh->all.count > stats->max_query_list_size) 90 stats->max_query_list_size = (long long)worker->env.mesh->all.count; 91 } 92 93 void server_stats_prefetch(struct ub_server_stats* stats, struct worker* worker) 94 { 95 stats->num_queries_prefetch++; 96 /* changes the query list size so account that, like a querymiss */ 97 stats->sum_query_list_size += worker->env.mesh->all.count; 98 if((long long)worker->env.mesh->all.count > stats->max_query_list_size) 99 stats->max_query_list_size = (long long)worker->env.mesh->all.count; 100 } 101 102 void server_stats_log(struct ub_server_stats* stats, struct worker* worker, 103 int threadnum) 104 { 105 log_info("server stats for thread %d: %u queries, " 106 "%u answers from cache, %u recursions, %u prefetch, %u rejected by " 107 "ip ratelimiting", 108 threadnum, (unsigned)stats->num_queries, 109 (unsigned)(stats->num_queries - 110 stats->num_queries_missed_cache), 111 (unsigned)stats->num_queries_missed_cache, 112 (unsigned)stats->num_queries_prefetch, 113 (unsigned)stats->num_queries_ip_ratelimited); 114 log_info("server stats for thread %d: requestlist max %u avg %g " 115 "exceeded %u jostled %u", threadnum, 116 (unsigned)stats->max_query_list_size, 117 (stats->num_queries_missed_cache+stats->num_queries_prefetch)? 118 (double)stats->sum_query_list_size/ 119 (double)(stats->num_queries_missed_cache+ 120 stats->num_queries_prefetch) : 0.0, 121 (unsigned)worker->env.mesh->stats_dropped, 122 (unsigned)worker->env.mesh->stats_jostled); 123 } 124 125 /** get rrsets bogus number from validator */ 126 static size_t 127 get_rrset_bogus(struct worker* worker, int reset) 128 { 129 int m = modstack_find(&worker->env.mesh->mods, "validator"); 130 struct val_env* ve; 131 size_t r; 132 if(m == -1) 133 return 0; 134 ve = (struct val_env*)worker->env.modinfo[m]; 135 lock_basic_lock(&ve->bogus_lock); 136 r = ve->num_rrset_bogus; 137 if(reset && !worker->env.cfg->stat_cumulative) 138 ve->num_rrset_bogus = 0; 139 lock_basic_unlock(&ve->bogus_lock); 140 return r; 141 } 142 143 /** get number of ratelimited queries from iterator */ 144 static size_t 145 get_queries_ratelimit(struct worker* worker, int reset) 146 { 147 int m = modstack_find(&worker->env.mesh->mods, "iterator"); 148 struct iter_env* ie; 149 size_t r; 150 if(m == -1) 151 return 0; 152 ie = (struct iter_env*)worker->env.modinfo[m]; 153 lock_basic_lock(&ie->queries_ratelimit_lock); 154 r = ie->num_queries_ratelimited; 155 if(reset && !worker->env.cfg->stat_cumulative) 156 ie->num_queries_ratelimited = 0; 157 lock_basic_unlock(&ie->queries_ratelimit_lock); 158 return r; 159 } 160 161 #ifdef USE_DNSCRYPT 162 /** get the number of shared secret cache miss */ 163 static size_t 164 get_dnscrypt_cache_miss(struct worker* worker, int reset) 165 { 166 size_t r; 167 struct dnsc_env* de = worker->daemon->dnscenv; 168 if(!de) return 0; 169 170 lock_basic_lock(&de->shared_secrets_cache_lock); 171 r = de->num_query_dnscrypt_secret_missed_cache; 172 if(reset && !worker->env.cfg->stat_cumulative) 173 de->num_query_dnscrypt_secret_missed_cache = 0; 174 lock_basic_unlock(&de->shared_secrets_cache_lock); 175 return r; 176 } 177 178 /** get the number of replayed queries */ 179 static size_t 180 get_dnscrypt_replay(struct worker* worker, int reset) 181 { 182 size_t r; 183 struct dnsc_env* de = worker->daemon->dnscenv; 184 185 lock_basic_lock(&de->nonces_cache_lock); 186 r = de->num_query_dnscrypt_replay; 187 if(reset && !worker->env.cfg->stat_cumulative) 188 de->num_query_dnscrypt_replay = 0; 189 lock_basic_unlock(&de->nonces_cache_lock); 190 return r; 191 } 192 #endif /* USE_DNSCRYPT */ 193 194 void 195 server_stats_compile(struct worker* worker, struct ub_stats_info* s, int reset) 196 { 197 int i; 198 struct listen_list* lp; 199 200 s->svr = worker->stats; 201 s->mesh_num_states = (long long)worker->env.mesh->all.count; 202 s->mesh_num_reply_states = (long long)worker->env.mesh->num_reply_states; 203 s->mesh_jostled = (long long)worker->env.mesh->stats_jostled; 204 s->mesh_dropped = (long long)worker->env.mesh->stats_dropped; 205 s->mesh_replies_sent = (long long)worker->env.mesh->replies_sent; 206 s->mesh_replies_sum_wait_sec = (long long)worker->env.mesh->replies_sum_wait.tv_sec; 207 s->mesh_replies_sum_wait_usec = (long long)worker->env.mesh->replies_sum_wait.tv_usec; 208 s->mesh_time_median = timehist_quartile(worker->env.mesh->histogram, 209 0.50); 210 211 /* add in the values from the mesh */ 212 s->svr.ans_secure += (long long)worker->env.mesh->ans_secure; 213 s->svr.ans_bogus += (long long)worker->env.mesh->ans_bogus; 214 s->svr.ans_rcode_nodata += (long long)worker->env.mesh->ans_nodata; 215 for(i=0; i<16; i++) 216 s->svr.ans_rcode[i] += (long long)worker->env.mesh->ans_rcode[i]; 217 timehist_export(worker->env.mesh->histogram, s->svr.hist, 218 NUM_BUCKETS_HIST); 219 /* values from outside network */ 220 s->svr.unwanted_replies = (long long)worker->back->unwanted_replies; 221 s->svr.qtcp_outgoing = (long long)worker->back->num_tcp_outgoing; 222 223 /* get and reset validator rrset bogus number */ 224 s->svr.rrset_bogus = (long long)get_rrset_bogus(worker, reset); 225 226 /* get and reset iterator query ratelimit number */ 227 s->svr.queries_ratelimited = (long long)get_queries_ratelimit(worker, reset); 228 229 /* get cache sizes */ 230 s->svr.msg_cache_count = (long long)count_slabhash_entries(worker->env.msg_cache); 231 s->svr.rrset_cache_count = (long long)count_slabhash_entries(&worker->env.rrset_cache->table); 232 s->svr.infra_cache_count = (long long)count_slabhash_entries(worker->env.infra_cache->hosts); 233 if(worker->env.key_cache) 234 s->svr.key_cache_count = (long long)count_slabhash_entries(worker->env.key_cache->slab); 235 else s->svr.key_cache_count = 0; 236 237 #ifdef USE_DNSCRYPT 238 if(worker->daemon->dnscenv) { 239 s->svr.num_query_dnscrypt_secret_missed_cache = 240 (long long)get_dnscrypt_cache_miss(worker, reset); 241 s->svr.shared_secret_cache_count = (long long)count_slabhash_entries( 242 worker->daemon->dnscenv->shared_secrets_cache); 243 s->svr.nonce_cache_count = (long long)count_slabhash_entries( 244 worker->daemon->dnscenv->nonces_cache); 245 s->svr.num_query_dnscrypt_replay = 246 (long long)get_dnscrypt_replay(worker, reset); 247 } else { 248 s->svr.num_query_dnscrypt_secret_missed_cache = 0; 249 s->svr.shared_secret_cache_count = 0; 250 s->svr.nonce_cache_count = 0; 251 s->svr.num_query_dnscrypt_replay = 0; 252 } 253 #else 254 s->svr.num_query_dnscrypt_secret_missed_cache = 0; 255 s->svr.shared_secret_cache_count = 0; 256 s->svr.nonce_cache_count = 0; 257 s->svr.num_query_dnscrypt_replay = 0; 258 #endif /* USE_DNSCRYPT */ 259 260 /* get tcp accept usage */ 261 s->svr.tcp_accept_usage = 0; 262 for(lp = worker->front->cps; lp; lp = lp->next) { 263 if(lp->com->type == comm_tcp_accept) 264 s->svr.tcp_accept_usage += (long long)lp->com->cur_tcp_count; 265 } 266 267 if(reset && !worker->env.cfg->stat_cumulative) { 268 worker_stats_clear(worker); 269 } 270 } 271 272 void server_stats_obtain(struct worker* worker, struct worker* who, 273 struct ub_stats_info* s, int reset) 274 { 275 uint8_t *reply = NULL; 276 uint32_t len = 0; 277 if(worker == who) { 278 /* just fill it in */ 279 server_stats_compile(worker, s, reset); 280 return; 281 } 282 /* communicate over tube */ 283 verbose(VERB_ALGO, "write stats cmd"); 284 if(reset) 285 worker_send_cmd(who, worker_cmd_stats); 286 else worker_send_cmd(who, worker_cmd_stats_noreset); 287 verbose(VERB_ALGO, "wait for stats reply"); 288 if(!tube_read_msg(worker->cmd, &reply, &len, 0)) 289 fatal_exit("failed to read stats over cmd channel"); 290 if(len != (uint32_t)sizeof(*s)) 291 fatal_exit("stats on cmd channel wrong length %d %d", 292 (int)len, (int)sizeof(*s)); 293 memcpy(s, reply, (size_t)len); 294 free(reply); 295 } 296 297 void server_stats_reply(struct worker* worker, int reset) 298 { 299 struct ub_stats_info s; 300 server_stats_compile(worker, &s, reset); 301 verbose(VERB_ALGO, "write stats replymsg"); 302 if(!tube_write_msg(worker->daemon->workers[0]->cmd, 303 (uint8_t*)&s, sizeof(s), 0)) 304 fatal_exit("could not write stat values over cmd channel"); 305 } 306 307 void server_stats_add(struct ub_stats_info* total, struct ub_stats_info* a) 308 { 309 total->svr.num_queries += a->svr.num_queries; 310 total->svr.num_queries_ip_ratelimited += a->svr.num_queries_ip_ratelimited; 311 total->svr.num_queries_missed_cache += a->svr.num_queries_missed_cache; 312 total->svr.num_queries_prefetch += a->svr.num_queries_prefetch; 313 total->svr.sum_query_list_size += a->svr.sum_query_list_size; 314 #ifdef USE_DNSCRYPT 315 total->svr.num_query_dnscrypt_crypted += a->svr.num_query_dnscrypt_crypted; 316 total->svr.num_query_dnscrypt_cert += a->svr.num_query_dnscrypt_cert; 317 total->svr.num_query_dnscrypt_cleartext += \ 318 a->svr.num_query_dnscrypt_cleartext; 319 total->svr.num_query_dnscrypt_crypted_malformed += \ 320 a->svr.num_query_dnscrypt_crypted_malformed; 321 #endif /* USE_DNSCRYPT */ 322 /* the max size reached is upped to higher of both */ 323 if(a->svr.max_query_list_size > total->svr.max_query_list_size) 324 total->svr.max_query_list_size = a->svr.max_query_list_size; 325 326 if(a->svr.extended) { 327 int i; 328 total->svr.qtype_big += a->svr.qtype_big; 329 total->svr.qclass_big += a->svr.qclass_big; 330 total->svr.qtcp += a->svr.qtcp; 331 total->svr.qtcp_outgoing += a->svr.qtcp_outgoing; 332 total->svr.qipv6 += a->svr.qipv6; 333 total->svr.qbit_QR += a->svr.qbit_QR; 334 total->svr.qbit_AA += a->svr.qbit_AA; 335 total->svr.qbit_TC += a->svr.qbit_TC; 336 total->svr.qbit_RD += a->svr.qbit_RD; 337 total->svr.qbit_RA += a->svr.qbit_RA; 338 total->svr.qbit_Z += a->svr.qbit_Z; 339 total->svr.qbit_AD += a->svr.qbit_AD; 340 total->svr.qbit_CD += a->svr.qbit_CD; 341 total->svr.qEDNS += a->svr.qEDNS; 342 total->svr.qEDNS_DO += a->svr.qEDNS_DO; 343 total->svr.ans_rcode_nodata += a->svr.ans_rcode_nodata; 344 total->svr.zero_ttl_responses += a->svr.zero_ttl_responses; 345 total->svr.ans_secure += a->svr.ans_secure; 346 total->svr.ans_bogus += a->svr.ans_bogus; 347 total->svr.unwanted_replies += a->svr.unwanted_replies; 348 total->svr.unwanted_queries += a->svr.unwanted_queries; 349 total->svr.tcp_accept_usage += a->svr.tcp_accept_usage; 350 for(i=0; i<UB_STATS_QTYPE_NUM; i++) 351 total->svr.qtype[i] += a->svr.qtype[i]; 352 for(i=0; i<UB_STATS_QCLASS_NUM; i++) 353 total->svr.qclass[i] += a->svr.qclass[i]; 354 for(i=0; i<UB_STATS_OPCODE_NUM; i++) 355 total->svr.qopcode[i] += a->svr.qopcode[i]; 356 for(i=0; i<UB_STATS_RCODE_NUM; i++) 357 total->svr.ans_rcode[i] += a->svr.ans_rcode[i]; 358 for(i=0; i<NUM_BUCKETS_HIST; i++) 359 total->svr.hist[i] += a->svr.hist[i]; 360 } 361 362 total->mesh_num_states += a->mesh_num_states; 363 total->mesh_num_reply_states += a->mesh_num_reply_states; 364 total->mesh_jostled += a->mesh_jostled; 365 total->mesh_dropped += a->mesh_dropped; 366 total->mesh_replies_sent += a->mesh_replies_sent; 367 stats_timeval_add(&total->mesh_replies_sum_wait_sec, &total->mesh_replies_sum_wait_usec, a->mesh_replies_sum_wait_sec, a->mesh_replies_sum_wait_usec); 368 /* the medians are averaged together, this is not as accurate as 369 * taking the median over all of the data, but is good and fast 370 * added up here, division later*/ 371 total->mesh_time_median += a->mesh_time_median; 372 } 373 374 void server_stats_insquery(struct ub_server_stats* stats, struct comm_point* c, 375 uint16_t qtype, uint16_t qclass, struct edns_data* edns, 376 struct comm_reply* repinfo) 377 { 378 uint16_t flags = sldns_buffer_read_u16_at(c->buffer, 2); 379 if(qtype < UB_STATS_QTYPE_NUM) 380 stats->qtype[qtype]++; 381 else stats->qtype_big++; 382 if(qclass < UB_STATS_QCLASS_NUM) 383 stats->qclass[qclass]++; 384 else stats->qclass_big++; 385 stats->qopcode[ LDNS_OPCODE_WIRE(sldns_buffer_begin(c->buffer)) ]++; 386 if(c->type != comm_udp) 387 stats->qtcp++; 388 if(repinfo && addr_is_ip6(&repinfo->addr, repinfo->addrlen)) 389 stats->qipv6++; 390 if( (flags&BIT_QR) ) 391 stats->qbit_QR++; 392 if( (flags&BIT_AA) ) 393 stats->qbit_AA++; 394 if( (flags&BIT_TC) ) 395 stats->qbit_TC++; 396 if( (flags&BIT_RD) ) 397 stats->qbit_RD++; 398 if( (flags&BIT_RA) ) 399 stats->qbit_RA++; 400 if( (flags&BIT_Z) ) 401 stats->qbit_Z++; 402 if( (flags&BIT_AD) ) 403 stats->qbit_AD++; 404 if( (flags&BIT_CD) ) 405 stats->qbit_CD++; 406 if(edns->edns_present) { 407 stats->qEDNS++; 408 if( (edns->bits & EDNS_DO) ) 409 stats->qEDNS_DO++; 410 } 411 } 412 413 void server_stats_insrcode(struct ub_server_stats* stats, sldns_buffer* buf) 414 { 415 if(stats->extended && sldns_buffer_limit(buf) != 0) { 416 int r = (int)LDNS_RCODE_WIRE( sldns_buffer_begin(buf) ); 417 stats->ans_rcode[r] ++; 418 if(r == 0 && LDNS_ANCOUNT( sldns_buffer_begin(buf) ) == 0) 419 stats->ans_rcode_nodata ++; 420 } 421 } 422