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 "services/authzone.h" 64#include "validator/val_kcache.h" 65#include "validator/val_neg.h" 66#ifdef CLIENT_SUBNET 67#include "edns-subnet/subnetmod.h" 68#endif 69#ifdef HAVE_SSL 70#include <openssl/ssl.h> 71#endif 72 73/** add timers and the values do not overflow or become negative */ 74static void 75stats_timeval_add(long long* d_sec, long long* d_usec, long long add_sec, long long add_usec) 76{ 77#ifndef S_SPLINT_S 78 (*d_sec) += add_sec; 79 (*d_usec) += add_usec; 80 if((*d_usec) >= 1000000) { 81 (*d_usec) -= 1000000; 82 (*d_sec)++; 83 } 84#endif 85} 86 87void server_stats_init(struct ub_server_stats* stats, struct config_file* cfg) 88{ 89 memset(stats, 0, sizeof(*stats)); 90 stats->extended = cfg->stat_extended; 91} 92 93void server_stats_querymiss(struct ub_server_stats* stats, struct worker* worker) 94{ 95 stats->num_queries_missed_cache++; 96 stats->sum_query_list_size += worker->env.mesh->all.count; 97 if((long long)worker->env.mesh->all.count > stats->max_query_list_size) 98 stats->max_query_list_size = (long long)worker->env.mesh->all.count; 99} 100 101void server_stats_prefetch(struct ub_server_stats* stats, struct worker* worker) 102{ 103 stats->num_queries_prefetch++; 104 /* changes the query list size so account that, like a querymiss */ 105 stats->sum_query_list_size += worker->env.mesh->all.count; 106 if((long long)worker->env.mesh->all.count > stats->max_query_list_size) 107 stats->max_query_list_size = (long long)worker->env.mesh->all.count; 108} 109 110void server_stats_log(struct ub_server_stats* stats, struct worker* worker, 111 int threadnum) 112{ 113 log_info("server stats for thread %d: %u queries, " 114 "%u answers from cache, %u recursions, %u prefetch, %u rejected by " 115 "ip ratelimiting", 116 threadnum, (unsigned)stats->num_queries, 117 (unsigned)(stats->num_queries - 118 stats->num_queries_missed_cache), 119 (unsigned)stats->num_queries_missed_cache, 120 (unsigned)stats->num_queries_prefetch, 121 (unsigned)stats->num_queries_ip_ratelimited); 122 log_info("server stats for thread %d: requestlist max %u avg %g " 123 "exceeded %u jostled %u", threadnum, 124 (unsigned)stats->max_query_list_size, 125 (stats->num_queries_missed_cache+stats->num_queries_prefetch)? 126 (double)stats->sum_query_list_size/ 127 (double)(stats->num_queries_missed_cache+ 128 stats->num_queries_prefetch) : 0.0, 129 (unsigned)worker->env.mesh->stats_dropped, 130 (unsigned)worker->env.mesh->stats_jostled); 131} 132 133 134#ifdef CLIENT_SUBNET 135/** Set the EDNS Subnet stats. */ 136static void 137set_subnet_stats(struct worker* worker, struct ub_server_stats* svr, 138 int reset) 139{ 140 int m = modstack_find(&worker->env.mesh->mods, "subnet"); 141 struct subnet_env* sne; 142 if(m == -1) 143 return; 144 sne = (struct subnet_env*)worker->env.modinfo[m]; 145 if(reset && !worker->env.cfg->stat_cumulative) { 146 lock_rw_wrlock(&sne->biglock); 147 } else { 148 lock_rw_rdlock(&sne->biglock); 149 } 150 svr->num_query_subnet = (long long)(sne->num_msg_nocache + sne->num_msg_cache); 151 svr->num_query_subnet_cache = (long long)sne->num_msg_cache; 152 if(reset && !worker->env.cfg->stat_cumulative) { 153 sne->num_msg_cache = 0; 154 sne->num_msg_nocache = 0; 155 } 156 lock_rw_unlock(&sne->biglock); 157} 158#endif /* CLIENT_SUBNET */ 159 160/** Set the neg cache stats. */ 161static void 162set_neg_cache_stats(struct worker* worker, struct ub_server_stats* svr, 163 int reset) 164{ 165 int m = modstack_find(&worker->env.mesh->mods, "validator"); 166 struct val_env* ve; 167 struct val_neg_cache* neg; 168 if(m == -1) 169 return; 170 ve = (struct val_env*)worker->env.modinfo[m]; 171 if(!ve->neg_cache) 172 return; 173 neg = ve->neg_cache; 174 lock_basic_lock(&neg->lock); 175 svr->num_neg_cache_noerror = (long long)neg->num_neg_cache_noerror; 176 svr->num_neg_cache_nxdomain = (long long)neg->num_neg_cache_nxdomain; 177 if(reset && !worker->env.cfg->stat_cumulative) { 178 neg->num_neg_cache_noerror = 0; 179 neg->num_neg_cache_nxdomain = 0; 180 } 181 lock_basic_unlock(&neg->lock); 182} 183 184/** get rrsets bogus number from validator */ 185static size_t 186get_rrset_bogus(struct worker* worker, int reset) 187{ 188 int m = modstack_find(&worker->env.mesh->mods, "validator"); 189 struct val_env* ve; 190 size_t r; 191 if(m == -1) 192 return 0; 193 ve = (struct val_env*)worker->env.modinfo[m]; 194 lock_basic_lock(&ve->bogus_lock); 195 r = ve->num_rrset_bogus; 196 if(reset && !worker->env.cfg->stat_cumulative) 197 ve->num_rrset_bogus = 0; 198 lock_basic_unlock(&ve->bogus_lock); 199 return r; 200} 201 202/** get number of ratelimited queries from iterator */ 203static size_t 204get_queries_ratelimit(struct worker* worker, int reset) 205{ 206 int m = modstack_find(&worker->env.mesh->mods, "iterator"); 207 struct iter_env* ie; 208 size_t r; 209 if(m == -1) 210 return 0; 211 ie = (struct iter_env*)worker->env.modinfo[m]; 212 lock_basic_lock(&ie->queries_ratelimit_lock); 213 r = ie->num_queries_ratelimited; 214 if(reset && !worker->env.cfg->stat_cumulative) 215 ie->num_queries_ratelimited = 0; 216 lock_basic_unlock(&ie->queries_ratelimit_lock); 217 return r; 218} 219 220#ifdef USE_DNSCRYPT 221/** get the number of shared secret cache miss */ 222static size_t 223get_dnscrypt_cache_miss(struct worker* worker, int reset) 224{ 225 size_t r; 226 struct dnsc_env* de = worker->daemon->dnscenv; 227 if(!de) return 0; 228 229 lock_basic_lock(&de->shared_secrets_cache_lock); 230 r = de->num_query_dnscrypt_secret_missed_cache; 231 if(reset && !worker->env.cfg->stat_cumulative) 232 de->num_query_dnscrypt_secret_missed_cache = 0; 233 lock_basic_unlock(&de->shared_secrets_cache_lock); 234 return r; 235} 236 237/** get the number of replayed queries */ 238static size_t 239get_dnscrypt_replay(struct worker* worker, int reset) 240{ 241 size_t r; 242 struct dnsc_env* de = worker->daemon->dnscenv; 243 244 lock_basic_lock(&de->nonces_cache_lock); 245 r = de->num_query_dnscrypt_replay; 246 if(reset && !worker->env.cfg->stat_cumulative) 247 de->num_query_dnscrypt_replay = 0; 248 lock_basic_unlock(&de->nonces_cache_lock); 249 return r; 250} 251#endif /* USE_DNSCRYPT */ 252 253void 254server_stats_compile(struct worker* worker, struct ub_stats_info* s, int reset) 255{ 256 int i; 257 struct listen_list* lp; 258 259 s->svr = worker->stats; 260 s->mesh_num_states = (long long)worker->env.mesh->all.count; 261 s->mesh_num_reply_states = (long long)worker->env.mesh->num_reply_states; 262 s->mesh_jostled = (long long)worker->env.mesh->stats_jostled; 263 s->mesh_dropped = (long long)worker->env.mesh->stats_dropped; 264 s->mesh_replies_sent = (long long)worker->env.mesh->replies_sent; 265 s->mesh_replies_sum_wait_sec = (long long)worker->env.mesh->replies_sum_wait.tv_sec; 266 s->mesh_replies_sum_wait_usec = (long long)worker->env.mesh->replies_sum_wait.tv_usec; 267 s->mesh_time_median = timehist_quartile(worker->env.mesh->histogram, 268 0.50); 269 270 /* add in the values from the mesh */ 271 s->svr.ans_secure += (long long)worker->env.mesh->ans_secure; 272 s->svr.ans_bogus += (long long)worker->env.mesh->ans_bogus; 273 s->svr.ans_rcode_nodata += (long long)worker->env.mesh->ans_nodata; 274 s->svr.ans_expired += (long long)worker->env.mesh->ans_expired; 275 for(i=0; i<UB_STATS_RCODE_NUM; i++) 276 s->svr.ans_rcode[i] += (long long)worker->env.mesh->ans_rcode[i]; 277 for(i=0; i<UB_STATS_RPZ_ACTION_NUM; i++) 278 s->svr.rpz_action[i] += (long long)worker->env.mesh->rpz_action[i]; 279 timehist_export(worker->env.mesh->histogram, s->svr.hist, 280 NUM_BUCKETS_HIST); 281 /* values from outside network */ 282 s->svr.unwanted_replies = (long long)worker->back->unwanted_replies; 283 s->svr.qtcp_outgoing = (long long)worker->back->num_tcp_outgoing; 284 285 /* get and reset validator rrset bogus number */ 286 s->svr.rrset_bogus = (long long)get_rrset_bogus(worker, reset); 287 288 /* get and reset iterator query ratelimit number */ 289 s->svr.queries_ratelimited = (long long)get_queries_ratelimit(worker, reset); 290 291 /* get cache sizes */ 292 s->svr.msg_cache_count = (long long)count_slabhash_entries(worker->env.msg_cache); 293 s->svr.rrset_cache_count = (long long)count_slabhash_entries(&worker->env.rrset_cache->table); 294 s->svr.infra_cache_count = (long long)count_slabhash_entries(worker->env.infra_cache->hosts); 295 if(worker->env.key_cache) 296 s->svr.key_cache_count = (long long)count_slabhash_entries(worker->env.key_cache->slab); 297 else s->svr.key_cache_count = 0; 298 299#ifdef USE_DNSCRYPT 300 if(worker->daemon->dnscenv) { 301 s->svr.num_query_dnscrypt_secret_missed_cache = 302 (long long)get_dnscrypt_cache_miss(worker, reset); 303 s->svr.shared_secret_cache_count = (long long)count_slabhash_entries( 304 worker->daemon->dnscenv->shared_secrets_cache); 305 s->svr.nonce_cache_count = (long long)count_slabhash_entries( 306 worker->daemon->dnscenv->nonces_cache); 307 s->svr.num_query_dnscrypt_replay = 308 (long long)get_dnscrypt_replay(worker, reset); 309 } else { 310 s->svr.num_query_dnscrypt_secret_missed_cache = 0; 311 s->svr.shared_secret_cache_count = 0; 312 s->svr.nonce_cache_count = 0; 313 s->svr.num_query_dnscrypt_replay = 0; 314 } 315#else 316 s->svr.num_query_dnscrypt_secret_missed_cache = 0; 317 s->svr.shared_secret_cache_count = 0; 318 s->svr.nonce_cache_count = 0; 319 s->svr.num_query_dnscrypt_replay = 0; 320#endif /* USE_DNSCRYPT */ 321 if(worker->env.auth_zones) { 322 if(reset && !worker->env.cfg->stat_cumulative) { 323 lock_rw_wrlock(&worker->env.auth_zones->lock); 324 } else { 325 lock_rw_rdlock(&worker->env.auth_zones->lock); 326 } 327 s->svr.num_query_authzone_up = (long long)worker->env. 328 auth_zones->num_query_up; 329 s->svr.num_query_authzone_down = (long long)worker->env. 330 auth_zones->num_query_down; 331 if(reset && !worker->env.cfg->stat_cumulative) { 332 worker->env.auth_zones->num_query_up = 0; 333 worker->env.auth_zones->num_query_down = 0; 334 } 335 lock_rw_unlock(&worker->env.auth_zones->lock); 336 } 337 s->svr.mem_stream_wait = 338 (long long)tcp_req_info_get_stream_buffer_size(); 339 s->svr.mem_http2_query_buffer = 340 (long long)http2_get_query_buffer_size(); 341 s->svr.mem_http2_response_buffer = 342 (long long)http2_get_response_buffer_size(); 343 344 /* Set neg cache usage numbers */ 345 set_neg_cache_stats(worker, &s->svr, reset); 346#ifdef CLIENT_SUBNET 347 /* EDNS Subnet usage numbers */ 348 set_subnet_stats(worker, &s->svr, reset); 349#else 350 s->svr.num_query_subnet = 0; 351 s->svr.num_query_subnet_cache = 0; 352#endif 353 354 /* get tcp accept usage */ 355 s->svr.tcp_accept_usage = 0; 356 for(lp = worker->front->cps; lp; lp = lp->next) { 357 if(lp->com->type == comm_tcp_accept) 358 s->svr.tcp_accept_usage += (long long)lp->com->cur_tcp_count; 359 } 360 361 if(reset && !worker->env.cfg->stat_cumulative) { 362 worker_stats_clear(worker); 363 } 364} 365 366void server_stats_obtain(struct worker* worker, struct worker* who, 367 struct ub_stats_info* s, int reset) 368{ 369 uint8_t *reply = NULL; 370 uint32_t len = 0; 371 if(worker == who) { 372 /* just fill it in */ 373 server_stats_compile(worker, s, reset); 374 return; 375 } 376 /* communicate over tube */ 377 verbose(VERB_ALGO, "write stats cmd"); 378 if(reset) 379 worker_send_cmd(who, worker_cmd_stats); 380 else worker_send_cmd(who, worker_cmd_stats_noreset); 381 verbose(VERB_ALGO, "wait for stats reply"); 382 if(!tube_read_msg(worker->cmd, &reply, &len, 0)) 383 fatal_exit("failed to read stats over cmd channel"); 384 if(len != (uint32_t)sizeof(*s)) 385 fatal_exit("stats on cmd channel wrong length %d %d", 386 (int)len, (int)sizeof(*s)); 387 memcpy(s, reply, (size_t)len); 388 free(reply); 389} 390 391void server_stats_reply(struct worker* worker, int reset) 392{ 393 struct ub_stats_info s; 394 server_stats_compile(worker, &s, reset); 395 verbose(VERB_ALGO, "write stats replymsg"); 396 if(!tube_write_msg(worker->daemon->workers[0]->cmd, 397 (uint8_t*)&s, sizeof(s), 0)) 398 fatal_exit("could not write stat values over cmd channel"); 399} 400 401void server_stats_add(struct ub_stats_info* total, struct ub_stats_info* a) 402{ 403 total->svr.num_queries += a->svr.num_queries; 404 total->svr.num_queries_ip_ratelimited += a->svr.num_queries_ip_ratelimited; 405 total->svr.num_queries_missed_cache += a->svr.num_queries_missed_cache; 406 total->svr.num_queries_prefetch += a->svr.num_queries_prefetch; 407 total->svr.sum_query_list_size += a->svr.sum_query_list_size; 408 total->svr.ans_expired += a->svr.ans_expired; 409#ifdef USE_DNSCRYPT 410 total->svr.num_query_dnscrypt_crypted += a->svr.num_query_dnscrypt_crypted; 411 total->svr.num_query_dnscrypt_cert += a->svr.num_query_dnscrypt_cert; 412 total->svr.num_query_dnscrypt_cleartext += \ 413 a->svr.num_query_dnscrypt_cleartext; 414 total->svr.num_query_dnscrypt_crypted_malformed += \ 415 a->svr.num_query_dnscrypt_crypted_malformed; 416#endif /* USE_DNSCRYPT */ 417 /* the max size reached is upped to higher of both */ 418 if(a->svr.max_query_list_size > total->svr.max_query_list_size) 419 total->svr.max_query_list_size = a->svr.max_query_list_size; 420 421 if(a->svr.extended) { 422 int i; 423 total->svr.qtype_big += a->svr.qtype_big; 424 total->svr.qclass_big += a->svr.qclass_big; 425 total->svr.qtcp += a->svr.qtcp; 426 total->svr.qtcp_outgoing += a->svr.qtcp_outgoing; 427 total->svr.qtls += a->svr.qtls; 428 total->svr.qtls_resume += a->svr.qtls_resume; 429 total->svr.qhttps += a->svr.qhttps; 430 total->svr.qipv6 += a->svr.qipv6; 431 total->svr.qbit_QR += a->svr.qbit_QR; 432 total->svr.qbit_AA += a->svr.qbit_AA; 433 total->svr.qbit_TC += a->svr.qbit_TC; 434 total->svr.qbit_RD += a->svr.qbit_RD; 435 total->svr.qbit_RA += a->svr.qbit_RA; 436 total->svr.qbit_Z += a->svr.qbit_Z; 437 total->svr.qbit_AD += a->svr.qbit_AD; 438 total->svr.qbit_CD += a->svr.qbit_CD; 439 total->svr.qEDNS += a->svr.qEDNS; 440 total->svr.qEDNS_DO += a->svr.qEDNS_DO; 441 total->svr.ans_rcode_nodata += a->svr.ans_rcode_nodata; 442 total->svr.ans_secure += a->svr.ans_secure; 443 total->svr.ans_bogus += a->svr.ans_bogus; 444 total->svr.unwanted_replies += a->svr.unwanted_replies; 445 total->svr.unwanted_queries += a->svr.unwanted_queries; 446 total->svr.tcp_accept_usage += a->svr.tcp_accept_usage; 447 for(i=0; i<UB_STATS_QTYPE_NUM; i++) 448 total->svr.qtype[i] += a->svr.qtype[i]; 449 for(i=0; i<UB_STATS_QCLASS_NUM; i++) 450 total->svr.qclass[i] += a->svr.qclass[i]; 451 for(i=0; i<UB_STATS_OPCODE_NUM; i++) 452 total->svr.qopcode[i] += a->svr.qopcode[i]; 453 for(i=0; i<UB_STATS_RCODE_NUM; i++) 454 total->svr.ans_rcode[i] += a->svr.ans_rcode[i]; 455 for(i=0; i<NUM_BUCKETS_HIST; i++) 456 total->svr.hist[i] += a->svr.hist[i]; 457 for(i=0; i<UB_STATS_RPZ_ACTION_NUM; i++) 458 total->svr.rpz_action[i] += a->svr.rpz_action[i]; 459 } 460 461 total->mesh_num_states += a->mesh_num_states; 462 total->mesh_num_reply_states += a->mesh_num_reply_states; 463 total->mesh_jostled += a->mesh_jostled; 464 total->mesh_dropped += a->mesh_dropped; 465 total->mesh_replies_sent += a->mesh_replies_sent; 466 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); 467 /* the medians are averaged together, this is not as accurate as 468 * taking the median over all of the data, but is good and fast 469 * added up here, division later*/ 470 total->mesh_time_median += a->mesh_time_median; 471} 472 473void server_stats_insquery(struct ub_server_stats* stats, struct comm_point* c, 474 uint16_t qtype, uint16_t qclass, struct edns_data* edns, 475 struct comm_reply* repinfo) 476{ 477 uint16_t flags = sldns_buffer_read_u16_at(c->buffer, 2); 478 if(qtype < UB_STATS_QTYPE_NUM) 479 stats->qtype[qtype]++; 480 else stats->qtype_big++; 481 if(qclass < UB_STATS_QCLASS_NUM) 482 stats->qclass[qclass]++; 483 else stats->qclass_big++; 484 stats->qopcode[ LDNS_OPCODE_WIRE(sldns_buffer_begin(c->buffer)) ]++; 485 if(c->type != comm_udp) { 486 stats->qtcp++; 487 if(c->ssl != NULL) { 488 stats->qtls++; 489#ifdef HAVE_SSL 490 if(SSL_session_reused(c->ssl)) 491 stats->qtls_resume++; 492#endif 493 if(c->type == comm_http) 494 stats->qhttps++; 495 } 496 } 497 if(repinfo && addr_is_ip6(&repinfo->addr, repinfo->addrlen)) 498 stats->qipv6++; 499 if( (flags&BIT_QR) ) 500 stats->qbit_QR++; 501 if( (flags&BIT_AA) ) 502 stats->qbit_AA++; 503 if( (flags&BIT_TC) ) 504 stats->qbit_TC++; 505 if( (flags&BIT_RD) ) 506 stats->qbit_RD++; 507 if( (flags&BIT_RA) ) 508 stats->qbit_RA++; 509 if( (flags&BIT_Z) ) 510 stats->qbit_Z++; 511 if( (flags&BIT_AD) ) 512 stats->qbit_AD++; 513 if( (flags&BIT_CD) ) 514 stats->qbit_CD++; 515 if(edns->edns_present) { 516 stats->qEDNS++; 517 if( (edns->bits & EDNS_DO) ) 518 stats->qEDNS_DO++; 519 } 520} 521 522void server_stats_insrcode(struct ub_server_stats* stats, sldns_buffer* buf) 523{ 524 if(stats->extended && sldns_buffer_limit(buf) != 0) { 525 int r = (int)LDNS_RCODE_WIRE( sldns_buffer_begin(buf) ); 526 stats->ans_rcode[r] ++; 527 if(r == 0 && LDNS_ANCOUNT( sldns_buffer_begin(buf) ) == 0) 528 stats->ans_rcode_nodata ++; 529 } 530} 531