Measuring the Latency of a Linux Bridge

As you can see I am working at the moment with a Linux Bridge and try to figure out how good it does its job ;) Therefore I had to measure the latency (or simply the time) a packet needs to go from one port of the bridge (IN) to the other (OUT). My test setup looks like this:

To measure the latency I just have to send a single packet from my test machine's first Ethernet interface and wait until it arrives at the other one. So I started two instances of tcpdump to listen on both interfaces and compared the timestamps when they catch the packet. It's pretty straight forward:

First timestamp (eth0): 1396835791.679071s
Second timestamp (eth1): 1396835791.679389s
Latency is 1396835791.679389s - 1396835791.679071s = 318 microseconds

Notice that you have to start tcpdump with the option "-tt" to get this format of timestamps. If you just want the time the packet spends in the bridging device, you just have to do this measurement a second time but without the device (eth0 and eth1 short-circuit). Then you can estimate the time spend in the device by again subtracting your 2 measurements.

To get meaningful results you definitely want to do this procedure more than once and calculate the average. And then you want to vary the size of the packet, the protocol and so on to see how it's effecting the result. So at this point I decided to automate the whole procedure with a shell script. This has the big advantage that you can do this measurement again in the exact same way after doing some optimization on the bridge.

As always I started with a simple script but after tweaking this and that it got bigger and way more complex xD Nevertheless I want to share it, so maybe someone will find it useful too. Tools needed are of course tcpdump to capture the packets, as well as hping3 and arping to generate the packets.

I split the script into two: One that does exactly one measurement and another that calls this script in a loop to get the average values.

measureLatency.sh:

#!/bin/bash
#
# Simple script to send an arbitrary packet via an interface
# and measure how long it takes til it arrives on another
# interface (so both interfaces have to be connected to the same
# subnet. Of course you want to put a bridge or something
# similar in between to test its performance!
#
# Dennis Mantz <dennis.mantz@googlemail.com> - 2014 Lantzville

# function to translate the timestamp into microseconds:
function tstampToMicro()
{
# Don't forget to remove leading zeros or you do octa ^^
seconds=`echo $1 | cut -d "." -f 1 | sed 's/^0*//'`
microseconds=`echo $1 | cut -d "." -f 2 | sed 's/^0*//'`

echo $(($seconds * 1000000 + $microseconds))
}

# Function to show the usage:
function show_usage()
{
echo "Usage: $cmdname -s <src iface> -d <dst iface> [-m <arp|ip|icmp|udp|tcp>] [-p <size>] [-v] [-h]"
exit -1
}

# Set default values:
cmdname=$0
ifs=
ifd=
size=0
mode="tcp"
verbose=
arpingVerbose="-q"
hping3Verbose="-q"

# Parse cmd line args:
while getopts "s:d:m:p:vhc:" opt; do
case "$opt" in
s)
ifs=$OPTARG
;;
d)
ifd=$OPTARG
;;
m)
mode=$OPTARG
;;
v)
verbose="-v"
arpingVerbose=
hping3Verbose="-V"
;;
h)
show_usage
;;
p)
size=$OPTARG
;;
c)
# This is just for compatibility with the averageLatency script. Do nothing with it...
;;
esac
done

# Check args:
if [ -z "$ifs" -o -z "$ifd" ]
  then
    show_usage
fi

# Check root
if [ `whoami` != "root" ]
  then
    echo "Must be root!"
    exit -1
fi

# Parse mode
case $mode in
arp)
filter='arp'
;;
ip)
filter='ip'
;;
icmp)
filter='icmp'
;;
tcp)
filter='tcp port 5000'
;;
udp)
filter='udp port 5000'
;;
*)
echo "$mode is not allowed for mode"
show_usage
;;
esac

# Start tcpdump two times:
(tcpdump -tt -i $ifs -c 1 $filter 2> /tmp/measureLatencyTcpdump1.err > /tmp/measureLatencyCap1.tmp)&
pid1=$!
(tcpdump -tt -i $ifd -c 1 $filter 2> /tmp/measureLatencyTcpdump2.err > /tmp/measureLatencyCap2.tmp)&
pid2=$!

# wait for them to get ready:
sleep 3

# Send a packet on the first interface:
case $mode in
        arp)
                arping -I $ifs -c 1 111.111.111.111 -s 127.0.0.1 $arpingVerbose
                ;;
        ip)
                ifconfig $ifs 111.111.111.1 netmask 255.255.255.0 broadcast 111.111.111.254 # add a route
                arp -i $ifs -s 111.111.111.111 00:01:11:11:11:11 $verbose # dummy arp entry..
                hping3 --rawip 111.111.111.111 -H 99 -c 1 -d $size $hping3Verbose > /tmp/measureLatencyHPing3.out 2> /tmp/measureLatencyHPing3.err
                ;;
icmp)
ifconfig $ifs 111.111.111.1 netmask 255.255.255.0 broadcast 111.111.111.254 # add a route
                arp -i $ifs -s 111.111.111.111 00:01:11:11:11:11 $verbose # dummy arp entry..
                hping3 --icmp 111.111.111.111 -c 1 -d $size $hping3Verbose > /tmp/measureLatencyHPing3.out 2> /tmp/measureLatencyHPing3.err
                ;;
        tcp)
                ifconfig $ifs 111.111.111.1 netmask 255.255.255.0 broadcast 111.111.111.254 # add a route
                arp -i $ifs -s 111.111.111.111 00:01:11:11:11:11 $verbose # dummy arp entry..
                hping3 -s 5000 111.111.111.111 -c 1 -d $size $hping3Verbose > /tmp/measureLatencyHPing3.out 2> /tmp/measureLatencyHPing3.err
                ;;
        udp)
                ifconfig $ifs 111.111.111.1 netmask 255.255.255.0 broadcast 111.111.111.254 # add a route
                arp -i $ifs -s 111.111.111.111 00:01:11:11:11:11 $verbose # dummy arp entry..
                hping3 --udp -s 5000 111.111.111.111 -c 1 -d $size $hping3Verbose > /tmp/measureLatencyHPing3.out 2> /tmp/measureLatencyHPing3.err
                ;;
esac

# wait for both tcpdumps to finish:
(sleep 10; kill $pid1 2> /dev/null; kill $pid2 2> /dev/null; echo "Didn't receive the packet!")&
killerpid=$!
wait $pid1
wait $pid2
kill $killerpid 2> /dev/null
wait $killerpid 2> /dev/null

# get the timestamps:
time1=`cat /tmp/measureLatencyCap1.tmp | sed 's/\([0-9]*\.[0-9]*\)\(.*\)/\1/'`
time2=`cat /tmp/measureLatencyCap2.tmp | sed 's/\([0-9]*\.[0-9]*\)\(.*\)/\1/'`

if [ "a$verbose" = "a-v" ]
  then
    echo "time1 = $time1"
    echo "time2 = $time2"
    cat /tmp/measureLatency*
fi

if [ -z "$time1" -o -z "$time2" ]
  then
    echo "Timestamps aren't set. exiting..."
    exit -1
fi

# Check if it's the same packet!
pack1=`cat /tmp/measureLatencyCap1.tmp | sed 's/\([0-9]*\.[0-9]*\)\(.*\)/\2/'`
pack2=`cat /tmp/measureLatencyCap2.tmp | sed 's/\([0-9]*\.[0-9]*\)\(.*\)/\2/'`
if [ "${pack1:0:60}" != "${pack2:0:60}" ]
  then
    echo "Seems like we've captured two different packets. Is the link free?"
    exit -1
fi

# calculate the difference:
diff=$((`tstampToMicro $time2` - `tstampToMicro $time1`))
echo "latency is $diff microseconds"

# clean up:
rm /tmp/measureLatency*

avgLatency.sh:

#!/bin/bash
# Simple script to send an arbitrary packet via an interface
# and measure how long it takes in AVERAGE til it arrives on another
# interface (so both interfaces have to be connected to the same
# subnet. Of course you want to put a bridge or something
# similar in between to test its performance!
#
# Dennis Mantz <dennis.mantz@googlemail.com> - 2014 Lantzville

# Function to calculate the average:

function calc_avg() {
avg=$(($sum / $((i-1))))
range=$(($max - $min))
echo "Average Latency is $avg microseconds!"
echo "Min: $min  Max: $max  Range (max-min): $range"
}

# Signalhandler for SIGINT calls calc and exits
trap "echo 'signal causing interrupt..'; calc_avg; exit" SIGHUP SIGINT SIGTERM

# Set Vars:
sum=0
min=10000
max=0
cmdline=$*
n=5

# Parse cmd line args:
while getopts "s:d:m:p:vhc:" opt; do
        case "$opt" in
        c)
                n=$OPTARG
                ;;
*)
# All other args are passed with the $cmdline to measureLatency. Do nothing with them..
;;
        esac
done

# Run measureLatency
for i in `seq $n`
  do
echo -n "Round $i: "
latency=`./measureLatency.sh $cmdline | grep "latency" | cut -d " " -f 3`
echo "$latency us"
sum=$(($sum + $latency))
if [ $latency -lt $min ]
 then
   min=$latency
fi
if [ $latency -gt $max ]
          then
            max=$latency
        fi
  done

i=$((i+1))
calc_avg

As I said, they are a bit more complex than I wanted them to be. After I finished my measurements I also thought about optimizing this whole procedure with a c program using raw sockets. Because as you will discover by yourself: tcpdump is so damn slow when you tell it to just capture one packet and exit. A self written program would be much faster and 'nicer' :) But unfortunately until now I didn't had time to start working on it and so it goes straight do my ToDo list for the future ;)