userspace: Improved packet drop statistics.

Currently OVS maintains explicit packet drop/error counters only on port
level.  Packets that are dropped as part of normal OpenFlow processing
are counted in flow stats of “drop” flows or as table misses in table
stats. These can only be interpreted by controllers that know the
semantics of the configured OpenFlow pipeline.  Without that knowledge,
it is impossible for an OVS user to obtain e.g. the total number of
packets dropped due to OpenFlow rules.

Furthermore, there are numerous other reasons for which packets can be
dropped by OVS slow path that are not related to the OpenFlow pipeline.
The generated datapath flow entries include a drop action to avoid
further expensive upcalls to the slow path, but subsequent packets
dropped by the datapath are not accounted anywhere.

Finally, the datapath itself drops packets in certain error situations.
Also, these drops are today not accounted for.This makes it difficult
for OVS users to monitor packet drop in an OVS instance and to alert a
management system in case of a unexpected increase of such drops.
Also OVS trouble-shooters face difficulties in analysing packet drops.

With this patch we implement following changes to address the issues
mentioned above.

1. Identify and account all the silent packet drop scenarios
2. Display these drops in ovs-appctl coverage/show

Co-authored-by: Rohith Basavaraja <rohith.basavaraja@gmail.com>
Co-authored-by: Keshav Gupta <keshugupta1@gmail.com>
Signed-off-by: Anju Thomas <anju.thomas@ericsson.com>
Signed-off-by: Rohith Basavaraja <rohith.basavaraja@gmail.com>
Signed-off-by: Keshav Gupta <keshugupta1@gmail.com>
Acked-by: Eelco Chaudron <echaudro@redhat.com
Acked-by: Ben Pfaff <blp@ovn.org>
Signed-off-by: Ilya Maximets <i.maximets@ovn.org>

7 files changed, 241 insertions, 7 deletions

diff --git a/tests/automake.mk b/tests/automake.mk
index e98030fce..9c7ebdce9 100644
--- a/tests/automake.mk
+++ b/tests/automake.mk
@@ -105,7 +105,8 @@ TESTSUITE_AT = \
 	tests/auto-attach.at \
 	tests/mcast-snooping.at \
 	tests/packet-type-aware.at \
-	tests/nsh.at
+	tests/nsh.at \
+	tests/drop-stats.at
 
 EXTRA_DIST += $(FUZZ_REGRESSION_TESTS)
 FUZZ_REGRESSION_TESTS = \
diff --git a/tests/dpif-netdev.at b/tests/dpif-netdev.at
index ef521ddb8..0aeb4e788 100644
--- a/tests/dpif-netdev.at
+++ b/tests/dpif-netdev.at
@@ -349,6 +349,14 @@ meter:2 flow_count:1 packet_in_count:10 byte_in_count:600 duration:0.0s bands:
 0: packet_count:5 byte_count:300
 ])
 
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter datapath_drop_meter
+], [0], [dnl
+14
+])
+
 AT_CHECK([cat ovs-vswitchd.log | filter_flow_install | strip_xout_keep_actions], [0], [dnl
 recirc_id(0),in_port(1),packet_type(ns=0,id=0),eth_type(0x0800),ipv4(frag=no), actions:meter(0),7
 recirc_id(0),in_port(2),packet_type(ns=0,id=0),eth_type(0x0800),ipv4(frag=no), actions:8
diff --git a/tests/drop-stats.at b/tests/drop-stats.at
new file mode 100644
index 000000000..94528f556
--- /dev/null
+++ b/tests/drop-stats.at
@@ -0,0 +1,190 @@
+AT_BANNER([drop-stats])
+
+AT_SETUP([drop-stats - cli tests])
+
+OVS_VSWITCHD_START([dnl
+    set bridge br0 datapath_type=dummy \
+        protocols=OpenFlow10,OpenFlow13,OpenFlow14,OpenFlow15 -- \
+    add-port br0 p1 -- set Interface p1 type=dummy ofport_request=1])
+
+AT_DATA([flows.txt], [dnl
+table=0,in_port=1,actions=drop
+])
+
+AT_CHECK([
+    ovs-ofctl del-flows br0
+    ovs-ofctl -Oopenflow13 add-flows br0 flows.txt
+    ovs-ofctl -Oopenflow13 dump-flows br0 | ofctl_strip | sort | grep actions ], [0], [dnl
+ in_port=1 actions=drop
+])
+
+AT_CHECK([
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+], [0], [ignore])
+
+AT_CHECK([ovs-appctl dpctl/dump-flows | sed 's/used:[[0-9]].[[0-9]]*s/used:0.0/' | sort], [0], [flow-dump from the main thread:
+recirc_id(0),in_port(1),packet_type(ns=0,id=0),eth_type(0x0800),ipv4(frag=no), packets:2, bytes:212, used:0.0, actions:drop
+])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_of_pipeline
+], [0], [dnl
+3
+])
+
+
+OVS_VSWITCHD_STOP
+AT_CLEANUP
+
+AT_SETUP([drop-stats - pipeline and recurssion drops])
+
+OVS_VSWITCHD_START([dnl
+    set bridge br0 datapath_type=dummy \
+        protocols=OpenFlow10,OpenFlow13,OpenFlow14,OpenFlow15 -- \
+    add-port br0 p1 -- set Interface p1 type=dummy ofport_request=1 -- \
+    add-port br0 p2 -- set Interface p2 type=dummy ofport_request=2])
+
+AT_DATA([flows.txt], [dnl
+table=0,in_port=1,actions=drop
+])
+
+AT_CHECK([
+    ovs-ofctl del-flows br0
+    ovs-ofctl -Oopenflow13 add-flows br0 flows.txt
+    ovs-ofctl -Oopenflow13 dump-flows br0 | ofctl_strip | sort | grep actions ], [0], [dnl
+ in_port=1 actions=drop
+])
+
+AT_CHECK([
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+], [0], [ignore])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_of_pipeline
+], [0], [dnl
+1
+])
+
+
+AT_DATA([flows.txt], [dnl
+table=0, in_port=1, actions=goto_table:1
+table=1, in_port=1, actions=goto_table:2
+table=2, in_port=1, actions=resubmit(,1)
+])
+
+AT_CHECK([
+    ovs-ofctl del-flows br0
+    ovs-ofctl -Oopenflow13 add-flows br0 flows.txt
+    ovs-ofctl -Oopenflow13 dump-flows br0 | ofctl_strip | sort | grep actions ], [0], [ignore])
+
+AT_CHECK([
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+], [0], [ignore])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_recursion_too_deep
+], [0], [dnl
+1
+])
+
+
+OVS_VSWITCHD_STOP(["/|WARN|/d"])
+AT_CLEANUP
+
+AT_SETUP([drop-stats - too many resubmit])
+OVS_VSWITCHD_START
+add_of_ports br0 1
+(for i in `seq 1 64`; do
+     j=`expr $i + 1`
+     echo "in_port=$i, actions=resubmit:$j, resubmit:$j, local"
+ done
+ echo "in_port=65, actions=local") > flows.txt
+
+AT_CHECK([
+    ovs-ofctl del-flows br0
+    ovs-ofctl -Oopenflow13 add-flows br0 flows.txt ], [0], [ignore])
+
+ovs-appctl netdev-dummy/receive p1 'in_port(1),eth(src=50:54:00:00:00:09,dst=50:54:00:00:00:0a),eth_type(0x1234)'
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_too_many_resubmit
+], [0], [dnl
+1
+])
+
+OVS_VSWITCHD_STOP(["/|WARN|/d"])
+AT_CLEANUP
+
+
+AT_SETUP([drop-stats - stack too deep])
+OVS_VSWITCHD_START
+add_of_ports br0 1
+(for i in `seq 1 12`; do
+     j=`expr $i + 1`
+     echo "in_port=$i, actions=resubmit:$j, resubmit:$j, local"
+ done
+ push="push:NXM_NX_REG0[[]]"
+ echo "in_port=13, actions=$push,$push,$push,$push,$push,$push,$push,$push") > flows
+
+AT_CHECK([ovs-ofctl add-flows br0 flows])
+
+ovs-appctl netdev-dummy/receive p1 'in_port(1),eth(src=50:54:00:00:00:09,dst=50:54:00:00:00:0a),eth_type(0x1234)'
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_stack_too_deep
+], [0], [dnl
+1
+])
+
+
+OVS_VSWITCHD_STOP(["/resubmits yielded over 64 kB of stack/d"])
+AT_CLEANUP
+
+AT_SETUP([drop-stats - too many mpls labels])
+
+OVS_VSWITCHD_START([dnl
+    set bridge br0 datapath_type=dummy \
+        protocols=OpenFlow10,OpenFlow13,OpenFlow14,OpenFlow15 -- \
+    add-port br0 p1 -- set Interface p1 type=dummy ofport_request=1 -- \
+    add-port br0 p2 -- set Interface p2 type=dummy ofport_request=2])
+
+AT_DATA([flows.txt], [dnl
+table=0, in_port=1, actions=push_mpls:0x8847, resubmit:3
+table=0, in_port=3, actions=push_mpls:0x8847, set_field:10->mpls_label, set_field:15->mpls_label, resubmit:4
+table=0, in_port=4, actions=push_mpls:0x8847, set_field:11->mpls_label, resubmit:5
+table=0, in_port=5, actions=push_mpls:0x8847, set_field:12->mpls_label, resubmit:6
+table=0, in_port=6, actions=push_mpls:0x8847, set_field:13->mpls_label, output:2
+])
+
+AT_CHECK([
+    ovs-ofctl del-flows br0
+    ovs-ofctl -Oopenflow13 add-flows br0 flows.txt
+])
+
+AT_CHECK([
+    ovs-appctl netdev-dummy/receive p1 'in_port(1),packet_type(ns=0,id=0),eth(src=3a:6d:d2:09:9c:ab,dst=1e:2c:e9:2a:66:9e),ipv4(src=192.168.10.10,dst=192.168.10.30,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)'
+], [0], [ignore])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_too_many_mpls_labels
+], [0], [dnl
+1
+])
+
+
+OVS_VSWITCHD_STOP(["/|WARN|/d"])
+AT_CLEANUP
diff --git a/tests/ofproto-dpif.at b/tests/ofproto-dpif.at
index 511d861c5..88acc4b1a 100644
--- a/tests/ofproto-dpif.at
+++ b/tests/ofproto-dpif.at
@@ -9425,7 +9425,7 @@ recirc_id(0),in_port(1),packet_type(ns=0,id=0),eth_type(0x8100),vlan(vid=99,pcp=
 # are wildcarded.
 AT_CHECK([grep '\(modify\)\|\(flow_add\)' ovs-vswitchd.log | strip_ufid ], [0], [dnl
 dpif_netdev|DBG|flow_add: recirc_id(0),in_port(1),packet_type(ns=0,id=0),eth_type(0x1234), actions:100
-dpif|DBG|dummy@ovs-dummy: put[[modify]] skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label(0/0),recirc_id(0),dp_hash(0/0),in_port(1),packet_type(ns=0,id=0),eth(src=50:54:00:00:00:09/00:00:00:00:00:00,dst=50:54:00:00:00:0a/00:00:00:00:00:00),eth_type(0x1234)
+dpif|DBG|dummy@ovs-dummy: put[[modify]] skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label(0/0),recirc_id(0),dp_hash(0/0),in_port(1),packet_type(ns=0,id=0),eth(src=50:54:00:00:00:09/00:00:00:00:00:00,dst=50:54:00:00:00:0a/00:00:00:00:00:00),eth_type(0x1234), actions:drop
 dpif|DBG|dummy@ovs-dummy: put[[modify]] skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label(0/0),recirc_id(0),dp_hash(0/0),in_port(1),packet_type(ns=0,id=0),eth(src=50:54:00:00:00:09/00:00:00:00:00:00,dst=50:54:00:00:00:0a/00:00:00:00:00:00),eth_type(0x1234), actions:100
 dpif_netdev|DBG|flow_add: recirc_id(0),in_port(1),packet_type(ns=0,id=0),eth_type(0x8100),vlan(vid=99,pcp=7/0x0),encap(eth_type(0x1234)), actions:drop
 ])
diff --git a/tests/testsuite.at b/tests/testsuite.at
index e75912300..73699918d 100644
--- a/tests/testsuite.at
+++ b/tests/testsuite.at
@@ -76,3 +76,4 @@ m4_include([tests/auto-attach.at])
 m4_include([tests/mcast-snooping.at])
 m4_include([tests/packet-type-aware.at])
 m4_include([tests/nsh.at])
+m4_include([tests/drop-stats.at])
diff --git a/tests/tunnel-push-pop.at b/tests/tunnel-push-pop.at
index f7172433e..b92c23fde 100644
--- a/tests/tunnel-push-pop.at
+++ b/tests/tunnel-push-pop.at
@@ -447,6 +447,27 @@ AT_CHECK([ovs-ofctl dump-ports int-br | grep 'port  7'], [0], [dnl
   port  7: rx pkts=3, bytes=252, drop=?, errs=?, frame=?, over=?, crc=?
 ])
 
+AT_CHECK([ovs-appctl netdev-dummy/receive p0 'aa55aa550000001b213cab6408004500007079464000402fba600101025c0101025820000800000001c845000054ba200000400184861e0000011e00000200004227e75400030af3195500000000f265010000000000101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f3031323334353637'])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter datapath_drop_tunnel_pop_error
+], [0], [dnl
+1
+])
+
+AT_CHECK([ovs-appctl netdev-dummy/receive p0 'aa55aa550000001b213cab6408004503007079464000402fba600101025c0101025820000800000001c845000054ba200000400184861e0000011e00000200004227e75400030af3195500000000f265010000000000101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f3031323334353637'])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter drop_action_congestion
+], [0], [dnl
+1
+])
+
+
 dnl Check GREL3 only accepts non-fragmented packets?
 AT_CHECK([ovs-appctl netdev-dummy/receive p0 'aa55aa550000001b213cab6408004500007e79464000402fba550101025c0101025820000800000001c8fe71d883724fbeb6f4e1494a080045000054ba200000400184861e0000011e00000200004227e75400030af3195500000000f265010000000000101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f3031323334353637'])
 
@@ -455,7 +476,7 @@ ovs-appctl time/warp 1000
 
 AT_CHECK([ovs-ofctl dump-ports int-br | grep 'port  [[37]]' | sort], [0], [dnl
   port  3: rx pkts=3, bytes=294, drop=?, errs=?, frame=?, over=?, crc=?
-  port  7: rx pkts=4, bytes=350, drop=?, errs=?, frame=?, over=?, crc=?
+  port  7: rx pkts=5, bytes=434, drop=?, errs=?, frame=?, over=?, crc=?
 ])
 
 dnl Check decapsulation of Geneve packet with options
@@ -478,7 +499,7 @@ AT_CHECK([ovs-ofctl dump-ports int-br | grep 'port  5'], [0], [dnl
   port  5: rx pkts=1, bytes=98, drop=?, errs=?, frame=?, over=?, crc=?
 ])
 AT_CHECK([ovs-appctl dpif/dump-flows int-br | grep 'in_port(6081)'], [0], [dnl
-tunnel(tun_id=0x7b,src=1.1.2.92,dst=1.1.2.88,geneve({class=0xffff,type=0x80,len=4,0xa/0xf}{class=0xffff,type=0,len=4}),flags(-df-csum+key)),recirc_id(0),in_port(6081),packet_type(ns=0,id=0),eth_type(0x0800),ipv4(frag=no), packets:0, bytes:0, used:never, actions:userspace(pid=0,controller(reason=1,dont_send=0,continuation=0,recirc_id=3,rule_cookie=0,controller_id=0,max_len=65535))
+tunnel(tun_id=0x7b,src=1.1.2.92,dst=1.1.2.88,geneve({class=0xffff,type=0x80,len=4,0xa/0xf}{class=0xffff,type=0,len=4}),flags(-df-csum+key)),recirc_id(0),in_port(6081),packet_type(ns=0,id=0),eth_type(0x0800),ipv4(frag=no), packets:0, bytes:0, used:never, actions:userspace(pid=0,controller(reason=1,dont_send=0,continuation=0,recirc_id=2,rule_cookie=0,controller_id=0,max_len=65535))
 ])
 
 ovs-appctl time/warp 10000
@@ -510,7 +531,8 @@ AT_CHECK([ovs-appctl tnl/ports/show |sort], [0], [dnl
 Listening ports:
 ])
 
-OVS_VSWITCHD_STOP
+OVS_VSWITCHD_STOP(["/dropping tunnel packet marked ECN CE but is not ECN capable/d
+/ip packet has invalid checksum/d"])
 AT_CLEANUP
 
 AT_SETUP([tunnel_push_pop - packet_out])
diff --git a/tests/tunnel.at b/tests/tunnel.at
index faffb4149..ce000a25e 100644
--- a/tests/tunnel.at
+++ b/tests/tunnel.at
@@ -102,8 +102,9 @@ Datapath actions: set(ipv4(tos=0x3/0x3)),2
 
 dnl Tunnel CE and encapsulated packet Non-ECT
 AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'tunnel(src=1.1.1.1,dst=2.2.2.2,tos=0x3,ttl=64,flags()),in_port(1),eth(src=50:54:00:00:00:05,dst=50:54:00:00:00:07),eth_type(0x0800),ipv4(src=192.168.0.1,dst=192.168.0.2,proto=6,tos=0,ttl=64,frag=no),tcp(src=8,dst=9)'], [0], [stdout])
-AT_CHECK([tail -2 stdout], [0],
-  [Megaflow: recirc_id=0,eth,ip,tun_id=0,tun_src=1.1.1.1,tun_dst=2.2.2.2,tun_tos=3,tun_flags=-df-csum-key,in_port=1,nw_ecn=0,nw_frag=no
+AT_CHECK([tail -3 stdout], [0],
+  [Final flow: unchanged
+Megaflow: recirc_id=0,eth,ip,tun_id=0,tun_src=1.1.1.1,tun_dst=2.2.2.2,tun_tos=3,tun_flags=-df-csum-key,in_port=1,nw_ecn=0,nw_frag=no
 Datapath actions: drop
 ])
 OVS_VSWITCHD_STOP(["/dropping tunnel packet marked ECN CE but is not ECN capable/d"])
@@ -193,6 +194,17 @@ AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'in_port(2),eth(src=50:54:00:00:00:
 AT_CHECK([tail -1 stdout], [0],
   [Datapath actions: set(tunnel(tun_id=0x5,src=2.2.2.2,dst=1.1.1.1,ttl=64,flags(df|key))),set(skb_mark(0x2)),1
 ])
+
+AT_CHECK([ovs-appctl netdev-dummy/receive p2 'aa55aa550001f8bc124434b6080045000054ba20000040018486010103580101037001004227e75400030af3195500000000f265010000000000101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f3031323334353637'])
+
+ovs-appctl time/warp 5000
+
+AT_CHECK([
+ovs-appctl coverage/read-counter datapath_drop_invalid_port
+], [0], [dnl
+1
+])
+
 OVS_VSWITCHD_STOP
 AT_CLEANUP