Timeval structs: negative delay with libpcap

1
votes

I'm trying to calculate delay from a captured packet to a previous packet, both coming from the same connection. I'm using a single linked list, each node corresponding to a connection; I discern packets coming from IP1 to IP2 from the ones coming from IP2 to IP1: I use a node to express the direction of the connection (IP1 to IP2) and another node to express the opposite direction of the connection (IP2 to IP1). I always add at the end of the list.

My struct node is the following:

typedef struct node {
    unsigned int num_pkt; // number of packets coming/going in this connection
    u_int8_t protocol;
    u_int32_t saddr;
    u_int32_t daddr;
    u_int16_t sport;
    u_int16_t dport;
    struct timeval time_begin; // first timestamp when I got pkt from this connection
    struct timeval time_end;   // last timestamp when I got pkt from this connection
    struct timeval old_ts;  // temporary timestamp to calculate delay
    struct node *next;
} node;

Global pointers variables, for getting the first and the last node of the list:

node *head = NULL;
node *current = NULL;

And here's the pseudocode for the callback function called by pcap_loop every time I get a packet:

void my_callback(u_char *arg, const struct pcap_pkthdr* pkthdr, const u_char* packet) 
{ 
    ++count;
    int length_packet = sizeof(packet);
    const struct ether_header *ethh;
    const struct iphdr *iph;
    const struct tcphdr *tcph;
    const struct udphdr *udph;  
    unsigned short int iphdrlen;
    node *tmp; // to iterate over the list
    int protocol, sport, dport;
    unsigned long int delay;

    ethh = (struct ether_header *)packet;
    if (ntohs(ethh->ether_type) == ETHERTYPE_IP) {
        iph = (struct iphdr*)(packet + sizeof(struct ether_header));
        iphdrlen = iph->ihl*4;
        protocol = (iph->protocol);
        switch (protocol) {
            case 6:
                tcph = (struct tcphdr *)(packet + sizeof(struct ether_header) + iphdrlen);
                sport = ntohs(tcph->th_sport);
                dport = ntohs(tcph->th_dport);
                break;
            case 17:
                udph = (struct udphdr *)(packet + sizeof(struct ether_header) + iphdrlen);
                sport = ntohs(udph->uh_sport);
                dport = ntohs(udph->uh_dport);
                break;
            default:
                break;
        }
        /* If the list is empty, add first node, fill it and update pointers */
        if (head == NULL ) {
            node *new_node = (node *)malloc(sizeof(node));
            if (new_node == NULL) {
                printf("MALLOC ERROR\n");
                exit(1);
            }
            new_node->time_begin.tv_sec = pkthdr->ts.tv_sec;
            new_node->time_begin.tv_usec = pkthdr->ts.tv_usec;
            new_node->old_ts.tv_sec = pkthdr->ts.tv_sec;
            new_node->old_ts.tv_usec = pkthdr->ts.tv_usec;
            new_node->time_end.tv_sec = 0;
            new_node->time_end.tv_usec = 0;
            new_node->num_pkt = 1;
            new_node->protocol = protocol;
            new_node->saddr = ntohl(iph->saddr);
            new_node->daddr = ntohl(iph->daddr);
            new_node->sport = sport;
            new_node->dport = dport;
            new_node->next = NULL;
            head = current = new_node;
        } else {
            tmp = head;
            while (tmp != NULL) {
                if ((tmp->saddr == ntohl(iph->saddr)) && (tmp->daddr == ntohl(iph->daddr)) && 
                    (tmp->protocol == protocol) && (tmp->sport == sport) && (tmp->dport == dport)) {
                    tmp->bts = tmp->bts + length_packet;
                    tmp->num_pkt = tmp->num_pkt+1;

                    char src_addr[INET_ADDRSTRLEN], dst_addr[INET_ADDRSTRLEN];
                    /* Function I made, it uses inet_ntop */
                    get_src_addr(src_addr, iph);
                    get_dst_addr(dst_addr, iph);
                    /* How do I calculate delay: getting the total amount of microsecs 
                    from the timeval inside pcap_pkthdr which contains the timestamp 
                    of the caught packet and subtracting to it the total amount of microsecs 
                    from the old_ts timeval, which contains the timestamp of the previous packet 
                    coming from the same connection */
                    delay = ((long)(pkthdr->ts.tv_sec*1000000)+pkthdr->ts.tv_usec) - ((long)(tmp->old_ts.tv_sec*1000000)+tmp->old_ts.tv_usec);
                    printf("%d; %s:%u > %s:%u update timeval: %ld <- %ld (secs), %ld <- %ld (microsecs); delay = %ld\n",
                        tmp->num_pkt, src_addr, tmp->sport, dst_addr, tmp->dport, tmp->old_ts.tv_sec, pkthdr->ts.tv_sec, 
                        tmp->old_ts.tv_usec, pkthdr->ts.tv_usec, delay);
                    /* updating old timestamp */
                    tmp->old_ts.tv_sec = pkthdr->ts.tv_sec;
                    tmp->old_ts.tv_usec = pkthdr->ts.tv_usec;
                    tmp->time_end.tv_sec = pkthdr->ts.tv_sec;
                    tmp->time_end.tv_usec = pkthdr->ts.tv_usec;
                    return;
                } else {
                    tmp = tmp->next;
                }
            }
            /* If we are here, we are at the end of the list and since
 none of the previous packets matches IP address and ports of the new one
caught, we have a new connection. Allocating new node and filling it */
            node *new_node = (node *)malloc(sizeof(node));
            if (new_node == NULL) {
                printf("MALLOC ERROR\n");
                exit(1);
            }
            new_node->time_begin.tv_sec = pkthdr->ts.tv_sec;
            new_node->time_begin.tv_usec = pkthdr->ts.tv_usec;
            new_node->old_ts.tv_sec = pkthdr->ts.tv_sec;
            new_node->old_ts.tv_usec = pkthdr->ts.tv_usec;
            new_node->num_pkt = 1;
            new_node->protocol = protocol;
            new_node->saddr = ntohl(iph->saddr);
            new_node->daddr = ntohl(iph->daddr);
            new_node->sport = sport;
            new_node->dport = dport;
            new_node->time_end.tv_sec = 0;
            new_node->time_end.tv_usec = 0;
            new_node->next = NULL;
            current->next = new_node;
            current = new_node;
        }
    }

Here's a fragment of the output, just for one connection:

996; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 133332 <- 133334 (microsecs); delay = 2
997; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 133334 <- 133334 (microsecs); delay = 0
998; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 133334 <- 133336 (microsecs); delay = 2
999; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 133336 <- 133507 (microsecs); delay = 171
1000; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 133507 <- 135646 (microsecs); delay = 2139
1001; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 135646 <- 135652 (microsecs); delay = 6
1002; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 135652 <- 135852 (microsecs); delay = 200
1003; 93.62.101.12:443 > 10.0.0.12:55653 update timeval: 1445773040 <- 1445773040 (secs), 135852 <- 135654 (microsecs); delay = -198

In the packet number 1003 I get a negative delay of -198 microseconds; that's because the timestamp inside pcap_pkthdr struct has less microseconds of the old timestamp, resulting in a negative value. Any clue why a more recent timestamp has less microseconds than an old one?

2
cdelaylibpcaptimeval

2 Answers

2
votes

Sometimes the OS's packet capture mechanism, as used by libpcap, and networking stack can deliver packets to libpcap out of order, unfortunately. This can happen if two packets are processed by two separate processor cores, and the first packet to be timestamped (thus having an earlier time stamp) might be the second packet to be handed to the capture mechanism (thus showing up after the other packet), so that libpcap sees the packet with the later time stamp before it sees the packet with the earlier time stamp.

Take a look at the pcap-tstamp man page for details on the timestamp behaviour.

0
votes

I assume you are on Linux. Then read time(7)

Notice that time might not be monotonic, e.g. because it was adjusted (perhaps by ntpd) using adjtimex(2).

(this also applies to kernel time, including timestamp of networking layers)

See also the documentation of clock_gettime(2) and notice the difference between CLOCK_REALTIME and CLOCK_MONOTONIC