In the previous blog post, network latency problems with SAP/HANA workload, we provided techniques to get an initial estimate of the latency of the Linux networking stack.

We made some assumptions in that blog while computing the latency. That was good enough for a first level approximation. In this blog, we remove those assumptions and provide techniques to derive the latency of each packet.

First level approximation of latency

Here is a snippet from the previous blog:

The assumption was that the second occurrence of napi_gro_receive() and the first occurrence of tcp_rcv_established() were part of the same stream. It means that we assumed the following snippet to be part of the same Transmission Control Protocol (TCP) packet and computed the receive latency as 2us.

This was good as a first level approximation, but there was no way to correlate that these traces were for the same TCP packet. In this blog, we will dive deep into the Linux tracing techniques to ascertain just that.

Multiple TCP sessions

We will start by using netperf to generate traffic for a single TCP Request & Response (RR) session. Let us use a variant of the tracing techniques described in the previous blog, network latency problems with SAP/HANA workload, and start with trace-cmd. Following is a snippet of the single TCP RR session:

Some interesting questions that crop up looking at the trace data in the snippet, are:

1. As the inline commentary mentions, why did tcp_sendmsg() precede tcp_recvmsg()?
2. Are there multiple TCP connections even if we only ran a single TCP RR session?

Let us take a step back and look at the TCP sessions on an idle system. Maybe that will provide some clues. Following is an example of an idle LPAR with a netperf server running but with no traffic flowing.

Note: The entry *:netperf in the snippet is the netserver daemon listening for connections. The ss -lt command was run on the server side of a netperf connection.

With that, we can answer both the questions presented earlier. It is now obvious that there could be other TCP sessions even if we are not actively running a netperf client against the server. That answers question #2.

Now we can answer question #1 also. It is very likely that one of the other TCP connections performed tcp_sendmsg() just before the tcp_recvmsg() of interest.

This brings up another interesting question – how can we distinguish between packets of different TCP connections? We will explore that next.

Perf probe

Each packet is assigned an skb by the Linux networking stack. We can use skb address to distinguish between TCP connections, but we need to use perf probe to do that. The perf probe command requires debuginfo packages to be installed. Next, verify if that is installed on the system:

This confirms that the necessary packages are installed.

Print the skb address at the entry point of the following four functions:

• napi_gro_receive()
• tcp_v4_rcv()
• __tcp_transmit_skb()
• __dev_queue_xmit()

This is similar to what we used previously – one each at the bottom and top of the receive stack, as well as on the transmit side.

Let us confirm the probe points are in place, as expected.

When we run netperf, we print the skb addresses as shown in the following snippet:

From the skb addresses, we can state that the first and third entries highlighted in the snippet belong to the same TCP stream. The middle napi_gro_receive(), could belong to a different connection.

This is good progress, but can we correlate the send and receive sides of a single TCP connection? The send and receive sides use different skbs, so clearly skb addresses are not enough. Let us explore that in the next section.

Mark skb

The solution to the question in the previous section is to mark the skbs. Let us illustrate that with an example. Lp3 and lp4 are different logical partitions (LPARs) as illustrated in Figure 1.

Figure 1: Logical partitions

Run the following command on the netperf server to mark packets on egress with 0xdeadbeef:

Run the following command on the netperf server to mark packets on ingress with 0xdeadbeef:

Delete the probes that were inserted previously.

Next, reinsert the probes on the Rx side:

Reinsert the probes on the Tx side:

Confirm that the inserted probes are indeed in place.

Let us focus on the four highlighted lines in the snippet. As discussed earlier, napi_gro_receive() and tcp_v4_rcv() have the same skb address. Look at the skb address of __dev_queue_xmit() which has the mark of 0xdeadbeef. It is the same skb address as the previous _tcp_transmit_skb(), so we can infer it is the same packet. Using the marker of 0xdeadbeef, we can link the Rx and Tx sides. We can also assert that both Rx and Tx latencies in this particular case were 2 Us.

There is still one question that needs to be addressed. Why does the packet have mark=0x0 at napi_gro_receive() and __tcp_transmit_skb() and not 0xdeadbeef?

Recollect that we used iptables to mark the skb. On the packet ingress, when we hit napi_gro_receive(), we did not go up to the IP layer. Thus, the skb has not been marked and so it will still be set to 0. A similar logic applies on the egress side; the packet is still at the TCP layer and has not reached the IP layer.

Summary

This blog provided techniques to identify packets from different TCP streams. We no longer need to make the assumptions made in the previous blog. We were able to make that assertion based on skb addresses and skb markings visible in the perf reports.