Measure the latency

[Description]

Based on Monitoring latency with OpenFlow, I will how to measure the latency in the POX controller. The example topology is shown as below.

where C is controller, S0 and S1 are switches, and H0 and H1 are hosts. Due to some reasons, e.g. varying traffic load, the delay from S0 to S1 may vary. So the controller should try to measure the delay and decide whether to route the traffic from S0 to S1 or change to other path. So the controller may instruct the S0 to send the probe packet to S1 and then forward back to C. Then the controller can get the delay from S0 to S1 (T3). The total time consumed is Ttotal=T1+T3+T2. T1 = 0.5 * ( Tb – Ta), where Ta is the time when sending out port_stats_request packet and Tb is the time when receiving port_stats_received packet. Similarly, the same method can be applied to get T2. As a consequence, T3 = Ttotal – T1 – T2.

[Simulation Script]

Generate simulated topology: Mininet11.py

#!/usr/bin/python

from mininet.net import Mininet

from mininet.node import Node

from mininet.link import TCLink

from mininet.log import setLogLevel, info

from threading import Timer

from mininet.util import quietRun

from time import sleep

def myNet(cname='controller', cargs='-v ptcp:'):

"Create network from scratch using Open vSwitch."

info( "*** Creating nodes\n" )

controller = Node( 'c0', inNamespace=False )

switch = Node( 's0', inNamespace=False )

switch1 = Node( 's1', inNamespace=False )

h0 = Node( 'h0' )

h1 = Node( 'h1' )

info( "*** Creating links\n" )

linkopts0=dict(bw=100, delay='1ms', loss=0)

linkopts1=dict(bw=100, delay='10ms', loss=0)

link0=TCLink( h0, switch, **linkopts0)

#initially, the delay from switch to switch1 is 10ms

link1 = TCLink( switch, switch1, **linkopts1)

link2 = TCLink( h1, switch1, **linkopts0)

#print link0.intf1, link0.intf2

link0.intf2.setMAC("0:0:0:0:0:1")

link1.intf1.setMAC("0:0:0:0:0:2")

link1.intf2.setMAC("0:1:0:0:0:1")

link2.intf2.setMAC("0:1:0:0:0:2")

info( "*** Configuring hosts\n" )

h0.setIP( '192.168.123.1/24' )

h1.setIP( '192.168.123.2/24' )

h0.setMAC("a:a:a:a:a:a")

h1.setMAC("8:8:8:8:8:8")

info( "*** Starting network using Open vSwitch\n" )

switch.cmd( 'ovs-vsctl del-br dp0' )

switch.cmd( 'ovs-vsctl add-br dp0' )

switch1.cmd( 'ovs-vsctl del-br dp1' )

switch1.cmd( 'ovs-vsctl add-br dp1' )

controller.cmd( cname + ' ' + cargs + '&' )

for intf in switch.intfs.values():

print intf

print switch.cmd( 'ovs-vsctl add-port dp0 %s' % intf )

for intf in switch1.intfs.values():

print intf

print switch1.cmd( 'ovs-vsctl add-port dp1 %s' % intf )

# Note: controller and switch are in root namespace, and we

# can connect via loopback interface

switch.cmd( 'ovs-vsctl set-controller dp0 tcp:127.0.0.1:6633' )

switch1.cmd( 'ovs-vsctl set-controller dp1 tcp:127.0.0.1:6633' )

info( '*** Waiting for switch to connect to controller' )

while 'is_connected' not in quietRun( 'ovs-vsctl show' ):

sleep( 1 )

info( '.' )

info( '\n' )

def cDelay1():

switch.cmdPrint('ethtool -K s0-eth1 gro off')

switch.cmdPrint('tc qdisc del dev s0-eth1 root')

switch.cmdPrint('tc qdisc add dev s0-eth1 root handle 10: netem delay 50ms')

switch1.cmdPrint('ethtool -K s1-eth0 gro off')

switch1.cmdPrint('tc qdisc del dev s1-eth0 root')

switch1.cmdPrint('tc qdisc add dev s1-eth0 root handle 10: netem delay 50ms')

def cDelay2():

switch.cmdPrint('ethtool -K s0-eth1 gro off')

switch.cmdPrint('tc qdisc del dev s0-eth1 root')

switch.cmdPrint('tc qdisc add dev s0-eth1 root handle 10: netem delay 200ms')

switch1.cmdPrint('ethtool -K s1-eth0 gro off')

switch1.cmdPrint('tc qdisc del dev s1-eth0 root')

switch1.cmdPrint('tc qdisc add dev s1-eth0 root handle 10: netem delay 200ms')

# 15 seconds later, the delay from switch to switch 1 will change to 50ms

t1=Timer(15, cDelay1)

t1.start()

# 30 seconds later, the delay from switch to switch 1 will change to 200ms

t2=Timer(30,cDelay2)

t2.start()

#info( "*** Running test\n" )

h0.cmdPrint( 'ping -i 1 -c 45 ' + h1.IP() )

sleep( 1 )

info( "*** Stopping network\n" )

controller.cmd( 'kill %' + cname )

switch.cmd( 'ovs-vsctl del-br dp0' )

switch.deleteIntfs()

switch1.cmd( 'ovs-vsctl del-br dp1' )

switch1.deleteIntfs()

info( '\n' )

if __name__ == '__main__':

setLogLevel( 'info' )

info( '*** Scratch network demo (kernel datapath)\n' )

Mininet.init()

myNet()

Controller program: measure_delay.py

from pox.core import core

from pox.lib.util import dpidToStr

import pox.openflow.libopenflow_01 as of

from pox.lib.addresses import IPAddr, EthAddr

import pox.lib.packet as pkt

from pox.openflow.of_json import *

from pox.lib.recoco import Timer

import time

from pox.lib.packet.packet_base import packet_base

from pox.lib.packet.packet_utils import *

import struct

log = core.getLogger()

#global variables

start_time = 0.0

sent_time1=0.0

sent_time2=0.0

received_time1 = 0.0

received_time2 = 0.0

src_dpid=0

dst_dpid=0

mytimer = 0

OWD1=0.0

OWD2=0.0

#probe protocol, only timestamp field

class myproto(packet_base):

"My Protocol packet struct"

def __init__(self):

packet_base.__init__(self)

self.timestamp=0

def hdr(self, payload):

return struct.pack('!I', self.timestamp)

def _handle_ConnectionDown (event):

global mytimer

print "ConnectionDown: ", dpidToStr(event.connection.dpid)

mytimer.cancel()

def _handle_ConnectionUp (event):

global src_dpid, dst_dpid, mytimer

print "ConnectionUp: ", dpidToStr(event.connection.dpid)

#remember the connection dpid for switch to controller (src_dpid) and switch1 to controller(dst_dpid)

for m in event.connection.features.ports:

if m.name == "s0-eth0":

src_dpid = event.connection.dpid

elif m.name == "s1-eth0":

dst_dpid = event.connection.dpid

# when the controller knows both src_dpid and dst_dpid, the probe packet is sent out every 2 seconds

if src_dpid<>0 and dst_dpid<>0:

mytimer=Timer(2, _timer_func, recurring=True)

mytimer.start()

def _handle_portstats_received (event):

global start_time, sent_time1, sent_time2, received_time1, received_time2, src_dpid, dst_dpid,OWD1,OWD2

received_time = time.time() * 1000 - start_time

#measure T1

if event.connection.dpid == src_dpid:

OWD1=0.5*(received_time - sent_time1)

#print "OWD1: ", OWD1, "ms"

#measure T2

elif event.connection.dpid == dst_dpid:

OWD2=0.5*(received_time - sent_time1)

#print "OWD2: ", OWD2, "ms"

def _handle_PacketIn (event):

global start_time,OWD1,OWD2

packet = event.parsed

#print packet

received_time = time.time() * 1000 - start_time

if packet.type==0x5577 and event.connection.dpid==dst_dpid:

c=packet.find('ethernet').payload

d,=struct.unpack('!I', c)

print "delay:", received_time - d - OWD1-OWD2, "ms"

a=packet.find('ipv4')

b=packet.find('arp')

if a:

#print "IPv4 Packet:", packet

msg = of.ofp_flow_mod()

msg.priority =1

msg.idle_timeout = 0

msg.match.in_port =1

msg.match.dl_type=0x0800

msg.actions.append(of.ofp_action_output(port = 2))

event.connection.send(msg)

msg = of.ofp_flow_mod()

msg.priority =1

msg.idle_timeout = 0

msg.match.in_port =2

msg.match.dl_type=0x0800

msg.actions.append(of.ofp_action_output(port = 1))

event.connection.send(msg)

if b and b.opcode==1:

#print "ARP Request Packet:", packet

msg = of.ofp_flow_mod()

msg.priority =1

msg.idle_timeout = 0

msg.match.in_port =1

msg.match.dl_type=0x0806

msg.actions.append(of.ofp_action_output(port = 2))

if event.connection.dpid == src_dpid:

#print "send to switch"

event.connection.send(msg)

elif event.connection.dpid == dst_dpid:

#print "send to switch1"

event.connection.send(msg)

if b and b.opcode==2:

#print "ARP Reply Packet:", packet

msg = of.ofp_flow_mod()

msg.priority =1

msg.idle_timeout = 0

msg.match.in_port =2

msg.match.dl_type=0x0806

msg.actions.append(of.ofp_action_output(port = 1))

if event.connection.dpid == src_dpid:

#print "send to switch"

event.connection.send(msg)

elif event.connection.dpid == dst_dpid:

#print "send to switch1"

event.connection.send(msg)

def _timer_func ():

global start_time, sent_time1, sent_time2, src_dpid, dst_dpid

if src_dpid <>0:

sent_time1=time.time() * 1000 - start_time

#print "sent_time1:", sent_time1

#send out port_stats_request packet through src_dpid

core.openflow.getConnection(src_dpid).send(of.ofp_stats_request(body=of.ofp_port_stats_request()))

f = myproto()

f.timestamp = int(time.time()*1000 - start_time)

#print f.timestamp

e = pkt.ethernet()

e.src=EthAddr("0:0:0:0:0:2")

e.dst=EthAddr("0:1:0:0:0:1")

e.type=0x5577

e.payload = f

msg = of.ofp_packet_out()

msg.data = e.pack()

msg.actions.append(of.ofp_action_output(port=2))

core.openflow.getConnection(src_dpid).send(msg)

if dst_dpid <>0:

sent_time2=time.time() * 1000 - start_time

#print "sent_time2:", sent_time2

#send out port_stats_request packet through dst_dpid

core.openflow.getConnection(dst_dpid).send(of.ofp_stats_request(body=of.ofp_port_stats_request()))

def launch ():

global start_time

start_time = time.time() * 1000

print "start_time:", start_time

core.openflow.addListenerByName("ConnectionUp", _handle_ConnectionUp)

core.openflow.addListenerByName("ConnectionDown", _handle_ConnectionDown)

core.openflow.addListenerByName("PortStatsReceived",

_handle_portstats_received)

core.openflow.addListenerByName("PacketIn",

_handle_PacketIn)

[Results]

From the ping results, we can see the RTT varying from H0 to H1.

From the controller results, we can also see the delay varying from H0 to H1.

Dr. Chih-Heng Ke (smallko@gmail.com)

Department of Computer Science and Information Engineering,

National Quemoy University, Kinmen, Taiwan.