ofproto/trace is one of the most useful debugging tools OVS provides.
However, it's "offline" nature comes with limitations:
- Users need to know exactly what their packets look like
- Runtime information such as conntrack states has to be guessed
This RFC introduces the idea of upcall (live) tracing. In a nutshell,
the idea is:
- The user activates upcall tracing by specifying an openflow filter
- When packet is upcalled, OVS checks if it matches the filter and if it
does, it collects traces from the xlate layer (same traces as
ofproto/trace emits).
- If a frozen state is created from this upcall, an ID is stored in it
so if a subsequent upcall resumes the frozen state, it inherits its
ID, the "trace_id".
- Traces are stored in some kind of ring-buffer or fixed-size list
arranged by these tracing IDs.
- Traces are accessed (printed) by the user after the experiment has
ended.
The code in this RFC is in early state but it can be used to play
around. I'm sending it out early to get some feedback.
The following topics are not clear to me at the moment:
- Naming ana layering: I have called the thing "upcall-tracing", and
unixctl commands are "upcall/trace/{create,list,get,show}". I tried to
differentiate from "ofproto/trace" but maybe this is not very
intuitive? A (kind of crazy) idea that I have as a followup is to
persist the trace_id into the udpif_key so we can also trace
revalidations associated with an upcall. In such scenario,
"upcall/trace" might fall semantically short.
- ofproto vs dpif: Connected to the previous topic. The tracing
infrastructure is bound to the "udpif", the upcall engine, which is
part of the datapath (dpif), not the bridge. However, ofproto flows
are easier to write and more familiar to users so from their PoV,
specifying a bridge and a ofp filter is nicer. Writing
"upcall/trace/create br0 in_port=myport,ip" and then visualizing a
trace associated with `system@ovs-system` feels weird.
- Trace ID != Packet ID: The RFC generates a trace_id for each new
upcall that matches the filter and persistes the trace_id inside the
frozen_state. If the same packet gets recirculated and upcalled, it
will (nicely) inherit the same trace_id and be grouped together. We
see all the recirculation rounds of the same packet (same as with
ofproto/trace but for real!). BUT, frozen_states are shared. If
another packet hits it, it will also inherit that ID and be printed
alongside the first. Is this good? bad? acceptable? Do we need to
the packet's metadata instead of the frozen_state to persist this
trace_id?
- Another idea that I considered is binding the tracing to a specific
port, i.e: "upcall/trace/create br0 p1 {ofp_filter}". Although this
would deviate from the ofproto/trace syntax, it would make it easier
to avoid an extra flow match on traffic that is not from the
"port-under-test".
Of course any other feedback is hugely appreciated.
This RFC contains the core feature but lacks and some configurability
that might be interesting for the actual patch. Additionally, I would
like to measure the performance impact of enabling it in a loaded
system.
Example: a simple scenario with 2 veths pairs connected through OVS
with some ct. It ilustrates the fozen state reuse mentioned above.
$ ovs-ofctl dump-flows ktest
cookie=0x0, duration=2.104s, table=0, n_packets=0, n_bytes=0, priority=100,arp
actions=NORMAL
cookie=0x0, duration=2.104s, table=0, n_packets=0, n_bytes=0,
priority=10,ip,in_port="p1_l" actions=ct(table=1,zone=1)
cookie=0x0, duration=2.104s, table=0, n_packets=0, n_bytes=0,
priority=10,ip,in_port="p2_l" actions=ct(table=1,zone=1)
cookie=0x0, duration=5.096s, table=0, n_packets=0, n_bytes=0, priority=0
actions=NORMAL
cookie=0x0, duration=2.104s, table=0, n_packets=0, n_bytes=0, priority=1
actions=drop
cookie=0x0, duration=2.104s, table=1, n_packets=0, n_bytes=0,
priority=10,ct_state=+new+trk,ip,in_port="p1_l"
actions=ct(commit,zone=1),output:"p2_l"
cookie=0x0, duration=2.103s, table=1, n_packets=0, n_bytes=0,
priority=10,ct_state=+est+trk,ip,in_port="p1_l" actions=output:"p2_l"
cookie=0x0, duration=2.103s, table=1, n_packets=0, n_bytes=0,
priority=10,ct_state=+est+trk,ip,in_port="p2_l" actions=output:"p1_l"
cookie=0x0, duration=2.103s, table=1, n_packets=0, n_bytes=0, priority=1
actions=drop
$ ovs-appctl upcall/trace/show
system@ovs-system: disabled
$ ovs-appctl upcall/trace/create ktest "in_port=1,icmp"
$ sudo ip netns exec ns1 ping -c 2 172.200.0.3
PING 172.200.0.3 (172.200.0.3) 56(84) bytes of data.
64 bytes from 172.200.0.3: icmp_seq=1 ttl=64 time=0.847 ms
64 bytes from 172.200.0.3: icmp_seq=2 ttl=64 time=0.599 ms
--- 172.200.0.3 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1005ms
rtt min/avg/max/mdev = 0.599/0.723/0.847/0.124 ms
$ ovs-appctl upcall/trace/show
system@ovs-system: enabled, max_traces=64, current=1, filter:
priority=0,icmp,in_port=1
$ ovs-appctl upcall/trace/list
system@ovs-system:
trace_id=0x1 ts=11:16:25.380 nodes=3
flow=icmp,in_port=1,vlan_tci=0x0000,dl_src=0a:58:0a:f4:00:01,dl_dst=0a:58:0a:f4:00:02,nw_src=172.200.0.2,nw_dst=172.200.0.3,nw_tos=0,nw_ecn=0,nw_ttl=64,nw_frag=no,icmp_type=8,icmp_code=0
$ ovs-appctl upcall/trace/get 0x1
=== Trace 0x1 ===
--- recirc_id=0x0 [11:16:25.380] ---
Initial flow:
icmp,in_port=1,vlan_tci=0x0000,dl_src=0a:58:0a:f4:00:01,dl_dst=0a:58:0a:f4:00:02,nw_src=172.200.0.2,nw_dst=172.200.0.3,nw_tos=0,nw_ecn=0,nw_ttl=64,nw_frag=no,icmp_type=8,icmp_code=0
bridge("ktest")
---------------
0. ip,in_port=1, priority 10
ct(table=1,zone=1)
drop
-> Sets the packet to an untracked state, and clears all the conntrack
fields.
--- recirc_id=0x1 [11:16:25.381] ---
Initial flow:
recirc_id=0x1,ct_state=new|trk,ct_zone=1,ct_nw_src=172.200.0.2,ct_nw_dst=172.200.0.3,ct_nw_proto=1,ct_tp_src=8,ct_tp_dst=0,eth,icmp,in_port=1,vlan_tci=0x0000,dl_src=0a:58:0a:f4:00:01,dl_dst=0a:58:0a:f4:00:02,nw_src=172.200.0.2,nw_dst=172.200.0.3,nw_tos=0,nw_ecn=0,nw_ttl=64,nw_frag=no,icmp_type=8,icmp_code=0
bridge("ktest")
---------------
thaw
Resuming from table 1
1. ct_state=+new+trk,ip,in_port=1, priority 10
ct(commit,zone=1)
drop
-> Sets the packet to an untracked state, and clears all the conntrack
fields.
output:2
--- recirc_id=0x1 [11:16:26.385] ---
Initial flow:
recirc_id=0x1,ct_state=est|trk,ct_zone=1,ct_nw_src=172.200.0.2,ct_nw_dst=172.200.0.3,ct_nw_proto=1,ct_tp_src=8,ct_tp_dst=0,eth,icmp,in_port=1,vlan_tci=0x0000,dl_src=0a:58:0a:f4:00:01,dl_dst=0a:58:0a:f4:00:02,nw_src=172.200.0.2,nw_dst=172.200.0.3,nw_tos=0,nw_ecn=0,nw_ttl=64,nw_frag=no,icmp_type=8,icmp_code=0
bridge("ktest")
---------------
thaw
Resuming from table 1
1. ct_state=+est+trk,ip,in_port=1, priority 10
output:2
Adrian Moreno (2):
ofproto-dpif-upcall: Introduce tracing scheleton.
ofproto-dpif_upcall: Implement upcall tracing.
ofproto/automake.mk | 2 +
ofproto/ofproto-dpif-rid.h | 1 +
ofproto/ofproto-dpif-trace.c | 4 +-
ofproto/ofproto-dpif-trace.h | 4 +-
ofproto/ofproto-dpif-upcall-trace.c | 442 ++++++++++++++++++++++++++++
ofproto/ofproto-dpif-upcall-trace.h | 56 ++++
ofproto/ofproto-dpif-upcall.c | 211 +++++++++++++
ofproto/ofproto-dpif-xlate.c | 5 +-
ofproto/ofproto-dpif-xlate.h | 4 +
9 files changed, 725 insertions(+), 4 deletions(-)
create mode 100644 ofproto/ofproto-dpif-upcall-trace.c
create mode 100644 ofproto/ofproto-dpif-upcall-trace.h
--
2.53.0
_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev
