Fix unexpected message ID suppression, and add stat for it

- `dnsperf`:
  - Count and report unexpected message IDs in statistics
    as indication that configured timeout might be too short
  - Fix nonsensical latency values produced by -O suppress=unexpected

Author: pspacek

src/dnsperf.c

@@ -119,6 +119,7 @@ typedef struct {
     uint64_t num_interrupted;
     uint64_t num_timedout;
     uint64_t num_completed;
+    uint64_t num_unexpected;
 
     uint64_t total_request_size;
     uint64_t total_response_size;
@@ -284,6 +285,7 @@ diff_stats(const config_t* config, stats_t* last, stats_t* now, stats_t* diff)
     diff->num_interrupted = now->num_interrupted - last->num_interrupted;
     diff->num_timedout    = now->num_timedout - last->num_timedout;
     diff->num_completed   = now->num_completed - last->num_completed;
+    diff->num_unexpected  = now->num_unexpected - last->num_unexpected;
 
     diff->total_request_size  = now->total_request_size - last->total_request_size;
     diff->total_response_size = now->total_response_size - last->total_response_size;
@@ -381,6 +383,11 @@ print_statistics(const config_t* config, const times_t* times, stats_t* stats, u
         printf("  %s interrupted:  %" PRIu64 " (%.2lf%%)\n",
             units, stats->num_interrupted,
             PERF_SAFE_DIV(100.0 * stats->num_interrupted, stats->num_sent));
+    if (stats->num_unexpected > 0)
+        printf("  Unexpected IDs:       %" PRIu64 " (%.2lf%%)\n",
+            stats->num_unexpected,
+            PERF_SAFE_DIV(100.0 * stats->num_unexpected, stats->num_sent));
+
     printf("\n");
 
     printf("  Response codes:       ");
@@ -500,6 +507,7 @@ sum_stats(const config_t* config, stats_t* total)
         total->num_interrupted += stats->num_interrupted;
         total->num_timedout += stats->num_timedout;
         total->num_completed += stats->num_completed;
+        total->num_unexpected += stats->num_unexpected;
 
         total->total_request_size += stats->total_request_size;
         total->total_response_size += stats->total_response_size;
@@ -1186,11 +1194,14 @@ do_recv(void* arg)
                 perf_log_warning("received short response");
                 continue;
             }
-            if (recvd[i].unexpected && !tinfo->config->suppress.unexpected) {
-                perf_log_warning("received a response with an "
-                                 "unexpected (maybe timed out) "
-                                 "id: %u",
-                    recvd[i].qid);
+            if (recvd[i].unexpected) {
+                if (!tinfo->config->suppress.unexpected) {
+                    perf_log_warning("received a response with an "
+                                     "unexpected (maybe timed out) "
+                                     "id: %u",
+                        recvd[i].qid);
+                }
+                stats->num_unexpected++;
                 continue;
             }
             latency = recvd[i].when - recvd[i].sent;