From: Evan Hunt Date: Thu, 21 Mar 2013 02:14:30 +0000 (-0700) Subject: [master] improvements to queryperf X-Git-Tag: v9.10.0a1~448^2~44 X-Git-Url: http://git.ipfire.org/gitweb/?a=commitdiff_plain;h=384fef003441df4067b773688237700513390f9e;p=thirdparty%2Fbind9.git [master] improvements to queryperf 3530. [contrib] Better RTT tracking in queryperf. [RT #30128] --- diff --git a/CHANGES b/CHANGES index 34e8325f3b3..443693864dd 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,5 @@ +3530. [contrib] Better RTT tracking in queryperf. [RT #30128] + 3529. [func] Named now listens on both IPv4 and IPv6 interfaces by default. Named previously only listened on IPv4 interfaces by default unless named was running in diff --git a/contrib/queryperf/queryperf.c b/contrib/queryperf/queryperf.c index 9bed11b6568..6b153271ae8 100644 --- a/contrib/queryperf/queryperf.c +++ b/contrib/queryperf/queryperf.c @@ -74,6 +74,7 @@ #define HARD_TIMEOUT_EXTRA 5 /* in seconds */ #define RESPONSE_BLOCKING_WAIT_TIME 0.1 /* in seconds */ #define EDNSLEN 11 +#define DNS_HEADERLEN 12 #define FALSE 0 #define TRUE 1 @@ -128,6 +129,14 @@ struct query_status { unsigned short int id; struct timeval sent_timestamp; char *desc; + int qtype; + char qname[MAX_DOMAIN_LEN + 1]; +}; + +struct query_mininfo { /* minimum info for timeout queries */ + int qtype; /* use -1 if N/A */ + struct timeval sent_timestamp; + char qname[MAX_DOMAIN_LEN + 1]; }; /* @@ -208,6 +217,8 @@ unsigned int *rttarray = NULL; unsigned int *rttarray_interval = NULL; unsigned int rtt_overflows; unsigned int rtt_overflows_interval; +unsigned int rtt_counted; +unsigned int rtt_counted_interval; char *rtt_histogram_file = NULL; struct query_status *status; /* init NULL */ @@ -218,6 +229,8 @@ int socket4 = -1, socket6 = -1; static char *rcode_strings[] = RCODE_STRINGS; +static struct query_mininfo *timeout_queries; + /* * get_uint16: * Get an unsigned short integer from a buffer (in network order) @@ -1330,10 +1343,10 @@ update_config(char *config_change_desc) { * Return a non-negative integer otherwise */ int -parse_query(char *input, char *qname, int qnlen, int *qtype) { +parse_query(char *input, char *qname, unsigned int qnlen, int *qtype) { static char *qtype_strings[] = QTYPE_STRINGS; static int qtype_codes[] = QTYPE_CODES; - int num_types, index; + unsigned int num_types, index; int found = FALSE; char incopy[MAX_INPUT_LEN + 1]; char *domain_str, *type_str; @@ -1382,7 +1395,9 @@ parse_query(char *input, char *qname, int qnlen, int *qtype) { * Return a non-negative integer otherwise */ int -dispatch_query(unsigned short int id, char *dom, int qt) { +dispatch_query(unsigned short int id, char *dom, int qt, u_char **pktp, + int *pktlenp) +{ static u_char packet_buffer[PACKETSZ + 1]; int buffer_len = PACKETSZ; int bytes_sent; @@ -1438,6 +1453,9 @@ dispatch_query(unsigned short int id, char *dom, int qt) { fprintf(stderr, "Warning: incomplete packet sent: %s %d\n", dom, qt); + *pktp = packet_buffer; + *pktlenp = buffer_len; + return (0); } @@ -1450,8 +1468,9 @@ send_query(char *query_desc) { static unsigned short int use_query_id = 0; static int qname_len = MAX_DOMAIN_LEN; static char domain[MAX_DOMAIN_LEN + 1]; + u_char *qpkt; char serveraddr[NI_MAXHOST]; - int query_type; + int query_type, qpkt_len; unsigned int count; use_query_id++; @@ -1461,7 +1480,8 @@ send_query(char *query_desc) { return; } - if (dispatch_query(use_query_id, domain, query_type) == -1) { + if (dispatch_query(use_query_id, domain, query_type, + &qpkt, &qpkt_len) == -1) { char *addrstr; if (getnameinfo(server_ai->ai_addr, server_ai->ai_addrlen, @@ -1501,11 +1521,18 @@ send_query(char *query_desc) { } /* Register the query in status[] */ - status[count].in_use = TRUE; status[count].id = use_query_id; if (verbose) status[count].desc = strdup(query_desc); set_timenow(&status[count].sent_timestamp); + status[count].qtype = query_type; + if (dn_expand(qpkt, qpkt + qpkt_len, qpkt + DNS_HEADERLEN, + status[count].qname, MAX_DOMAIN_LEN) == -1) { + fprintf(stderr, "Unexpected error: " + "query message doesn't have qname?\n"); + return; + } + status[count].in_use = TRUE; if (num_queries_sent_interval == 0) set_timenow(&time_of_first_query_interval); @@ -1516,7 +1543,9 @@ send_query(char *query_desc) { } void -register_rtt(struct timeval *timestamp) { +register_rtt(struct timeval *timestamp, char *qname, int qtype, + unsigned int rcode) +{ int i; int oldquery = FALSE; struct timeval now; @@ -1535,6 +1564,7 @@ register_rtt(struct timeval *timestamp) { rtt_min = rtt; rtt_total += rtt; + rtt_counted++; if (!oldquery) { if (rtt_max_interval < 0 || rtt_max_interval < rtt) @@ -1544,6 +1574,7 @@ register_rtt(struct timeval *timestamp) { rtt_min_interval = rtt; rtt_total_interval += rtt; + rtt_counted_interval++; } if (rttarray == NULL) @@ -1555,8 +1586,8 @@ register_rtt(struct timeval *timestamp) { if (!oldquery) rttarray_interval[i]++; } else { - fprintf(stderr, "Warning: RTT is out of range: %.6lf\n", - rtt); + fprintf(stderr, "Warning: RTT is out of range: %.6lf " + "[query=%s/%d, rcode=%u]\n", rtt, qname, qtype, rcode); rtt_overflows++; if (!oldquery) rtt_overflows_interval++; @@ -1571,36 +1602,53 @@ register_rtt(struct timeval *timestamp) { * status[] if any exists. */ void -register_response(unsigned short int id, unsigned int rcode) { +register_response(unsigned short int id, unsigned int rcode, char *qname, + int qtype) +{ unsigned int ct = 0; int found = FALSE; struct timeval now; double rtt; + if (timeout_queries != NULL) { + struct query_mininfo *qi = &timeout_queries[id]; + + if (qi->qtype == qtype && strcasecmp(qi->qname, qname) == 0) { + register_rtt(&qi->sent_timestamp, qname, qtype, rcode); + qi->qtype = -1; + found = TRUE; + } + } + for (; (ct < query_status_allocated) && (found == FALSE); ct++) { - if ((status[ct].in_use == TRUE) && (status[ct].id == id)) { + if (status[ct].in_use == TRUE && status[ct].id == id && + status[ct].qtype == qtype && + strcasecmp(status[ct].qname, qname) == 0) { status[ct].in_use = FALSE; num_queries_outstanding--; found = TRUE; - register_rtt(&status[ct].sent_timestamp); + register_rtt(&status[ct].sent_timestamp, qname, qtype, + rcode); if (status[ct].desc) { printf("> %s %s\n", rcode_strings[rcode], status[ct].desc); free(status[ct].desc); } - if (countrcodes) - rcodecounts[rcode]++; } } + if (countrcodes && (found == TRUE || target_qps > 0)) + rcodecounts[rcode]++; + if (found == FALSE) { if (target_qps > 0) { num_queries_possiblydelayed++; num_queries_possiblydelayed_interval++; } else { - fprintf(stderr, "Warning: Received a response with an " + fprintf(stderr, + "Warning: Received a response with an " "unexpected (maybe timed out) id: %u\n", id); } } @@ -1617,9 +1665,9 @@ process_single_response(int sockfd) { struct sockaddr_storage from_addr_ss; struct sockaddr *from_addr; static unsigned char in_buf[MAX_BUFFER_LEN]; - int numbytes, resp_id; - socklen_t addr_len; - int flags; + char qname[MAX_DOMAIN_LEN + 1]; + int numbytes, addr_len, resp_id, qnamelen; + int qtype, flags; memset(&from_addr_ss, 0, sizeof(from_addr_ss)); from_addr = (struct sockaddr *)&from_addr_ss; @@ -1631,10 +1679,29 @@ process_single_response(int sockfd) { return; } + if (numbytes < DNS_HEADERLEN) { + if (verbose) + fprintf(stderr, "Malformed response\n"); + return; + } resp_id = get_uint16(in_buf); flags = get_uint16(in_buf + 2); + qnamelen = dn_expand(in_buf, in_buf + numbytes, in_buf + DNS_HEADERLEN, + qname, MAX_DOMAIN_LEN); + if (qnamelen == -1) { + if (verbose) + fprintf(stderr, + "Failed to retrieve qname from response\n"); + return; + } + if (numbytes < DNS_HEADERLEN + qnamelen + 2) { + if (verbose) + fprintf(stderr, "Malformed response\n"); + return; + } + qtype = get_uint16(in_buf + DNS_HEADERLEN + qnamelen); - register_response(resp_id, flags & 0xF); + register_response(resp_id, flags & 0xF, qname, qtype); } /* @@ -1785,15 +1852,30 @@ retire_old_queries(int sending) { set_timenow(&curr_time); for (; count < query_status_allocated; count++) { - - if ((status[count].in_use == TRUE) - && (difftv(curr_time, status[count].sent_timestamp) - >= (double)timeout)) { - + if ((status[count].in_use == TRUE) && + (difftv(curr_time, + status[count].sent_timestamp) >= (double)timeout)) + { status[count].in_use = FALSE; num_queries_outstanding--; - num_queries_timed_out++; - num_queries_timed_out_interval++; + + if (timeout_queries != NULL) { + struct query_mininfo *qi; + + qi = &timeout_queries[status[count].id]; + if (qi->qtype != -1) { + /* now really retire this query */ + num_queries_timed_out++; + num_queries_timed_out_interval++; + } + qi->qtype = status[count].qtype; + qi->sent_timestamp = + status[count].sent_timestamp; + strcpy(qi->qname, status[count].qname); + } else { + num_queries_timed_out++; + num_queries_timed_out_interval++; + } if (timeout_reduced == FALSE) { if (status[count].desc) { @@ -1850,7 +1932,7 @@ print_statistics(int intermediate, unsigned int sent, unsigned int timed_out, struct timeval *first_query, struct timeval *program_start, struct timeval *end_perf, struct timeval *end_query, - double rmax, double rmin, double rtotal, + unsigned int rcounted, double rmax, double rmin, double rtotal, unsigned int roverflows, unsigned int *rarray) { unsigned int num_queries_completed; @@ -1896,11 +1978,11 @@ print_statistics(int intermediate, unsigned int sent, unsigned int timed_out, difftv(*end_query, *first_query); } - if (num_queries_completed > 0) { + if (rcounted > 0) { int i; double sum = 0; - rtt_average = rtt_total / (double)num_queries_completed; + rtt_average = rtotal / (double)rcounted; for (i = 0; i < rttarray_size; i++) { if (rarray[i] != 0) { double mean, diff; @@ -1911,7 +1993,7 @@ print_statistics(int intermediate, unsigned int sent, unsigned int timed_out, sum += (diff * diff) * rarray[i]; } } - rtt_stddev = sqrt(sum / (double)num_queries_completed); + rtt_stddev = sqrt(sum / (double)rcounted); } else { rtt_average = 0.0; rtt_stddev = 0.0; @@ -2028,9 +2110,9 @@ print_interval_statistics() { num_queries_possiblydelayed_interval, &time_of_first_query_interval, &time_of_first_query_interval, &time_now, &time_now, - rtt_max_interval, rtt_min_interval, - rtt_total_interval, rtt_overflows_interval, - rttarray_interval); + rtt_counted_interval, rtt_max_interval, + rtt_min_interval, rtt_total_interval, + rtt_overflows_interval, rttarray_interval); /* Reset intermediate counters */ num_queries_sent_interval = 0; @@ -2039,6 +2121,7 @@ print_interval_statistics() { rtt_max_interval = -1; rtt_min_interval = -1; rtt_total_interval = 0.0; + rtt_counted_interval = 0.0; rtt_overflows_interval = 0; if (rttarray_interval != NULL) { memset(rttarray_interval, 0, @@ -2072,6 +2155,18 @@ main(int argc, char **argv) { if (setup(argc, argv) == -1) return (-1); + /* XXX: move this to setup: */ + timeout_queries = malloc(sizeof(struct query_mininfo) * 65536); + if (timeout_queries == NULL) { + fprintf(stderr, + "failed to allocate memory for timeout queries\n"); + return (-1); + } else { + int i; + for (i = 0; i < 65536; i++) + timeout_queries[i].qtype = -1; + } + printf("[Status] Processing input data\n"); while ((sending = keep_sending(&got_eof)) == TRUE || @@ -2126,7 +2221,8 @@ main(int argc, char **argv) { num_queries_possiblydelayed, &time_of_first_query, &time_of_program_start, &time_of_end_of_run, &time_of_stop_sending, - rtt_max, rtt_min, rtt_total, rtt_overflows, rttarray); + rtt_counted, rtt_max, rtt_min, rtt_total, + rtt_overflows, rttarray); return (0); }