keep track of round trip times of UDP pings
authorvolth <volth@volth.com>
Tue, 12 Jun 2018 21:17:30 +0000 (21:17 +0000)
committervolth <volth@volth.com>
Wed, 13 Jun 2018 14:49:50 +0000 (14:49 +0000)
src/info.c
src/net_packet.c
src/node.c
src/node.h
src/tincctl.c

index 09e6580..652c4ae 100644 (file)
@@ -70,15 +70,16 @@ static int info_node(int fd, const char *item) {
        } status_union;
        node_status_t status;
        long int last_state_change;
        } status_union;
        node_status_t status;
        long int last_state_change;
+       long int udp_ping_rtt;
 
        while(recvline(fd, line, sizeof(line))) {
 
        while(recvline(fd, line, sizeof(line))) {
-               int n = sscanf(line, "%d %d %4095s %4095s %4095s port %4095s %d %d %d %d %x %"PRIx32" %4095s %4095s %d %hd %hd %hd %ld", &code, &req, node, id, host, port, &cipher, &digest, &maclength, &compression, &options, &status_union.raw, nexthop, via, &distance, &pmtu, &minmtu, &maxmtu, &last_state_change);
+               int n = sscanf(line, "%d %d %4095s %4095s %4095s port %4095s %d %d %d %d %x %"PRIx32" %4095s %4095s %d %hd %hd %hd %ld %ld", &code, &req, node, id, host, port, &cipher, &digest, &maclength, &compression, &options, &status_union.raw, nexthop, via, &distance, &pmtu, &minmtu, &maxmtu, &last_state_change, &udp_ping_rtt);
 
                if(n == 2) {
                        break;
                }
 
 
                if(n == 2) {
                        break;
                }
 
-               if(n != 19) {
+               if(n != 20) {
                        fprintf(stderr, "Unable to parse node dump from tincd.\n");
                        return 1;
                }
                        fprintf(stderr, "Unable to parse node dump from tincd.\n");
                        return 1;
                }
@@ -143,6 +144,8 @@ static int info_node(int fd, const char *item) {
 
        if(status.udp_confirmed) {
                printf(" udp_confirmed");
 
        if(status.udp_confirmed) {
                printf(" udp_confirmed");
+               if(udp_ping_rtt != -1)
+                       printf(" (rtt %ld.%03ld)", udp_ping_rtt/1000, udp_ping_rtt%1000);
        }
 
        printf("\n");
        }
 
        printf("\n");
index 8ade057..6ce6431 100644 (file)
@@ -102,6 +102,7 @@ static void udp_probe_timeout_handler(void *data) {
 
        logger(DEBUG_TRAFFIC, LOG_INFO, "Too much time has elapsed since last UDP ping response from %s (%s), stopping UDP communication", n->name, n->hostname);
        n->status.udp_confirmed = false;
 
        logger(DEBUG_TRAFFIC, LOG_INFO, "Too much time has elapsed since last UDP ping response from %s (%s), stopping UDP communication", n->name, n->hostname);
        n->status.udp_confirmed = false;
+       n->udp_ping_rtt = -1;
        n->maxrecentlen = 0;
        n->mtuprobes = 0;
        n->minmtu = 0;
        n->maxrecentlen = 0;
        n->mtuprobes = 0;
        n->minmtu = 0;
@@ -151,7 +152,15 @@ static void udp_probe_h(node_t *n, vpn_packet_t *packet, length_t len) {
                len = ntohs(len16);
        }
 
                len = ntohs(len16);
        }
 
-       logger(DEBUG_TRAFFIC, LOG_INFO, "Got type %d UDP probe reply %d from %s (%s)", DATA(packet)[0], len, n->name, n->hostname);
+       if (n->udp_ping_sent.tv_sec != 0) { // a probe in flight
+               gettimeofday(&now, NULL);
+               struct timeval rtt;
+               timersub(&now, &n->udp_ping_sent, &rtt);
+               n->udp_ping_rtt = rtt.tv_sec*1000000L + rtt.tv_usec;
+               logger(DEBUG_TRAFFIC, LOG_INFO, "Got type %d UDP probe reply %d from %s (%s) rtt=%ld.%03ld", DATA(packet)[0], len, n->name, n->hostname, n->udp_ping_rtt/1000, n->udp_ping_rtt%1000);
+       } else {
+               logger(DEBUG_TRAFFIC, LOG_INFO, "Got type %d UDP probe reply %d from %s (%s)", DATA(packet)[0], len, n->name, n->hostname);
+       }
 
        /* It's a valid reply: now we know bidirectional communication
           is possible using the address and socket that the reply
 
        /* It's a valid reply: now we know bidirectional communication
           is possible using the address and socket that the reply
@@ -167,8 +176,8 @@ static void udp_probe_h(node_t *n, vpn_packet_t *packet, length_t len) {
                reset_address_cache(n->address_cache, &n->address);
        }
 
                reset_address_cache(n->address_cache, &n->address);
        }
 
-       // Reset the UDP ping timer.
-       n->udp_ping_sent = now;
+       // Reset the UDP ping timer. (no probe in flight)
+       n->udp_ping_sent.tv_sec = 0;
 
        if(udp_discovery) {
                timeout_del(&n->udp_ping_timeout);
 
        if(udp_discovery) {
                timeout_del(&n->udp_ping_timeout);
@@ -1119,8 +1128,9 @@ static void try_udp(node_t *n) {
        int interval = n->status.udp_confirmed ? udp_discovery_keepalive_interval : udp_discovery_interval;
 
        if(ping_tx_elapsed.tv_sec >= interval) {
        int interval = n->status.udp_confirmed ? udp_discovery_keepalive_interval : udp_discovery_interval;
 
        if(ping_tx_elapsed.tv_sec >= interval) {
+               gettimeofday(&now, NULL);
+               n->udp_ping_sent = now; // a probe in flight
                send_udp_probe_packet(n, MIN_PROBE_SIZE);
                send_udp_probe_packet(n, MIN_PROBE_SIZE);
-               n->udp_ping_sent = now;
 
                if(localdiscovery && !n->status.udp_confirmed && n->prevedge) {
                        n->status.send_locally = true;
 
                if(localdiscovery && !n->status.udp_confirmed && n->prevedge) {
                        n->status.send_locally = true;
index bea23c7..c3f2ab5 100644 (file)
@@ -80,6 +80,7 @@ node_t *new_node(void) {
        n->edge_tree = new_edge_tree();
        n->mtu = MTU;
        n->maxmtu = MTU;
        n->edge_tree = new_edge_tree();
        n->mtu = MTU;
        n->maxmtu = MTU;
+       n->udp_ping_rtt = -1;
 
        return n;
 }
 
        return n;
 }
@@ -211,7 +212,7 @@ bool dump_nodes(connection_t *c) {
                }
 
                id[sizeof(id) - 1] = 0;
                }
 
                id[sizeof(id) - 1] = 0;
-               send_request(c, "%d %d %s %s %s %d %d %d %d %x %x %s %s %d %d %d %d %ld", CONTROL, REQ_DUMP_NODES,
+               send_request(c, "%d %d %s %s %s %d %d %d %d %x %x %s %s %d %d %d %d %ld %ld", CONTROL, REQ_DUMP_NODES,
                             n->name, id, n->hostname ? : "unknown port unknown",
 #ifdef DISABLE_LEGACY
                             0, 0, 0,
                             n->name, id, n->hostname ? : "unknown port unknown",
 #ifdef DISABLE_LEGACY
                             0, 0, 0,
@@ -220,7 +221,7 @@ bool dump_nodes(connection_t *c) {
 #endif
                             n->outcompression, n->options, bitfield_to_int(&n->status, sizeof(n->status)),
                             n->nexthop ? n->nexthop->name : "-", n->via ? n->via->name ? : "-" : "-", n->distance,
 #endif
                             n->outcompression, n->options, bitfield_to_int(&n->status, sizeof(n->status)),
                             n->nexthop ? n->nexthop->name : "-", n->via ? n->via->name ? : "-" : "-", n->distance,
-                            n->mtu, n->minmtu, n->maxmtu, (long)n->last_state_change);
+                            n->mtu, n->minmtu, n->maxmtu, (long)n->last_state_change, (long)n->udp_ping_rtt);
        }
 
        return send_request(c, "%d %d", CONTROL, REQ_DUMP_NODES);
        }
 
        return send_request(c, "%d %d", CONTROL, REQ_DUMP_NODES);
index 496880f..0cdac3f 100644 (file)
@@ -92,6 +92,7 @@ typedef struct node_t {
 
        struct timeval udp_reply_sent;          /* Last time a (gratuitous) UDP probe reply was sent */
        struct timeval udp_ping_sent;           /* Last time a UDP probe was sent */
 
        struct timeval udp_reply_sent;          /* Last time a (gratuitous) UDP probe reply was sent */
        struct timeval udp_ping_sent;           /* Last time a UDP probe was sent */
+       long int udp_ping_rtt;                  /* Round trip time of UDP ping (in microseconds) */
        timeout_t udp_ping_timeout;             /* Ping timeout event */
 
        struct timeval mtu_ping_sent;           /* Last time a MTU probe was sent */
        timeout_t udp_ping_timeout;             /* Ping timeout event */
 
        struct timeval mtu_ping_sent;           /* Last time a MTU probe was sent */
index cf19d48..76ff374 100644 (file)
@@ -1298,12 +1298,13 @@ static int cmd_dump(int argc, char *argv[]) {
                unsigned int options, status_int;
                node_status_t status;
                long int last_state_change;
                unsigned int options, status_int;
                node_status_t status;
                long int last_state_change;
+               long int udp_ping_rtt;
 
                switch(req) {
                case REQ_DUMP_NODES: {
 
                switch(req) {
                case REQ_DUMP_NODES: {
-                       int n = sscanf(line, "%*d %*d %4095s %4095s %4095s port %4095s %d %d %d %d %x %x %4095s %4095s %d %hd %hd %hd %ld", node, id, host, port, &cipher, &digest, &maclength, &compression, &options, &status_int, nexthop, via, &distance, &pmtu, &minmtu, &maxmtu, &last_state_change);
+                       int n = sscanf(line, "%*d %*d %4095s %4095s %4095s port %4095s %d %d %d %d %x %x %4095s %4095s %d %hd %hd %hd %ld %ld", node, id, host, port, &cipher, &digest, &maclength, &compression, &options, &status_int, nexthop, via, &distance, &pmtu, &minmtu, &maxmtu, &last_state_change, &udp_ping_rtt);
 
 
-                       if(n != 17) {
+                       if(n != 18) {
                                fprintf(stderr, "Unable to parse node dump from tincd: %s\n", line);
                                return 1;
                        }
                                fprintf(stderr, "Unable to parse node dump from tincd: %s\n", line);
                                return 1;
                        }
@@ -1331,8 +1332,11 @@ static int cmd_dump(int argc, char *argv[]) {
                                        continue;
                                }
 
                                        continue;
                                }
 
-                               printf("%s id %s at %s port %s cipher %d digest %d maclength %d compression %d options %x status %04x nexthop %s via %s distance %d pmtu %d (min %d max %d)\n",
+                               printf("%s id %s at %s port %s cipher %d digest %d maclength %d compression %d options %x status %04x nexthop %s via %s distance %d pmtu %d (min %d max %d)",
                                       node, id, host, port, cipher, digest, maclength, compression, options, status_int, nexthop, via, distance, pmtu, minmtu, maxmtu);
                                       node, id, host, port, cipher, digest, maclength, compression, options, status_int, nexthop, via, distance, pmtu, minmtu, maxmtu);
+                               if (udp_ping_rtt != -1)
+                                       printf(" rtt %ld.%03ld", udp_ping_rtt/1000, udp_ping_rtt%1000);
+                               printf("\n");
                        }
                }
                break;
                        }
                }
                break;