[ovs-dev] [PATCH v2 4/4] ofproto-dpif: Make ofproto/trace output easier to read.
Ben Pfaff
blp at ovn.org
Wed Dec 21 07:03:09 UTC 2016
"ovs-appctl ofproto/trace" is invaluable for debugging, but as the users of
Open vSwitch have evolved it has failed to keep up with the times. It's
pretty easy to design OpenFlow tables and pipelines that resubmit dozens of
times. Each resubmit causes an additional tab of indentation, so the
output wraps around, sometimes again and again, and makes the output close
to unreadable.
ovn-trace pioneered better formatting for tracing in OVN logical datapaths,
mostly by not increasing indentation for tail recursion, which in practice
gets rid of almost all indentation.
This commit experiments with redoing ofproto/trace the same way. Try
looking at, for example, the testsuite output for test 2282 "ovn -- 3 HVs,
3 LRs connected via LS, source IP based routes". Without this commit, it
indents 61 levels (488 spaces!). With this commit, it indents 1 level
(4 spaces) and it's possible to actually understand what's going on almost
at a glance.
To see this for yourself, try the following command either with or without
this commit (but be sure to keep the change to ovn.at that adds an
ofproto/trace to the test):
make check TESTSUITEFLAGS='-d 2282' && less tests/testsuite.dir/2282/testsuite.log
Signed-off-by: Ben Pfaff <blp at ovn.org>
---
Documentation/tutorials/ovs-advanced.rst | 268 +++++++----
lib/nx-match.c | 29 +-
lib/nx-match.h | 6 +-
ofproto/ofproto-dpif-trace.c | 278 ++++-------
ofproto/ofproto-dpif-trace.h | 25 +
ofproto/ofproto-dpif-xlate.c | 790 ++++++++++++++++++++-----------
ofproto/ofproto-dpif-xlate.h | 26 +-
ofproto/ofproto-dpif.c | 6 +-
ofproto/ofproto-dpif.h | 2 +-
tests/ofproto-dpif.at | 41 +-
tests/ovn.at | 4 +-
tests/rstp.at | 4 +-
tests/stp.at | 4 +-
13 files changed, 848 insertions(+), 635 deletions(-)
diff --git a/Documentation/tutorials/ovs-advanced.rst b/Documentation/tutorials/ovs-advanced.rst
index 4ae27ce..39cb476 100644
--- a/Documentation/tutorials/ovs-advanced.rst
+++ b/Documentation/tutorials/ovs-advanced.rst
@@ -329,22 +329,28 @@ Try this command::
The output should look something like this::
- Flow: metadata=0,in_port=1,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=01:80:c2:00:00:05,dl_type=0x0000
- Rule: table=0 cookie=0 dl_dst=01:80:c2:00:00:00/ff:ff:ff:ff:ff:f0
- OpenFlow actions=drop
+ Flow: in_port=1,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=01:80:c2:00:00:05,dl_type=0x0000
+
+ bridge("br0")
+ -------------
+ 0. dl_dst=01:80:c2:00:00:00/ff:ff:ff:ff:ff:f0, priority 32768
+ drop
Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=1,dl_src=00:00:00:00:00:00/01:00:00:00:00:00,dl_dst=01:80:c2:00:00:00/ff:ff:ff:ff:ff:f0,dl_type=0x0000
Datapath actions: drop
-The first block of lines describes an OpenFlow table lookup. The first line
-shows the fields used for the table lookup (which is mostly zeros because
-that's the default if we don't specify everything). The second line gives the
-OpenFlow flow that the fields matched (called a "rule" because that is the name
-used inside Open vSwitch for an OpenFlow flow). In this case, we see that this
-packet that has a reserved multicast destination address matches the rule that
-drops those packets. The third line gives the rule's OpenFlow actions.
+The first line shows the flow being traced, in slightly greater detail
+than specified on the command line. It is mostly zeros because
+unspecified fields default to zeros.
+
+The second group of lines shows the packet's trip through bridge br0.
+We see, in table 0, the OpenFlow flow that the fields matched, along
+with its priority, followed by its actions, one per line. In this
+case, we see that this packet that has a reserved multicast
+destination address matches the flow that drops those packets.
-The second block of lines summarizes the results, which are not very
+The final block of lines summarizes the results, which are not very
interesting here.
Example 2
@@ -356,26 +362,27 @@ Try another command::
The output should be::
- Flow: metadata=0,in_port=1,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=01:80:c2:00:00:10,dl_type=0x0000
- Rule: table=0 cookie=0 priority=0
- OpenFlow actions=resubmit(,1)
+ Flow: in_port=1,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=01:80:c2:00:00:10,dl_type=0x0000
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- No match
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. No match.
+ drop
Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=1,dl_src=00:00:00:00:00:00/01:00:00:00:00:00,dl_dst=01:80:c2:00:00:10/ff:ff:ff:ff:ff:f0,dl_type=0x0000
Datapath actions: drop
-This time the flow we handed to ``ofproto/trace`` doesn't match any of our
-"drop" rules, so it falls through to the low-priority "resubmit" rule, which we
-see in the rule and the actions selected in the first block. The "resubmit"
-causes a second lookup in OpenFlow table 1, described by the additional block
-of indented text in the output. We haven't yet added any flows to OpenFlow
-table 1, so no flow actually matches in the second lookup. Therefore, the
-packet is still actually dropped, which means that the externally observable
-results would be identical to our first example.
+This time the flow we handed to ``ofproto/trace`` doesn't match any of
+our "drop" flows in table 0, so it falls through to the low-priority
+"resubmit" flow. The "resubmit" causes a second lookup in OpenFlow
+table 1, described by the block of text that starts with "1." We
+haven't yet added any flows to OpenFlow table 1, so no flow actually
+matches in the second lookup. Therefore, the packet is still actually
+dropped, which means that the externally observable results would be
+identical to our first example.
Implementing Table 1: VLAN Input Processing
-------------------------------------------
@@ -389,7 +396,7 @@ being part of the VLAN header, reducing special cases.
Let's start by adding a low-priority flow that drops all packets, before we add
flows that pass through acceptable packets. You can think of this as a
-"default drop" rule::
+"default drop" flow::
$ ovs-ofctl add-flow br0 "table=1, priority=0, actions=drop"
@@ -410,8 +417,8 @@ stage::
table=1, priority=99, in_port=4, vlan_tci=0, actions=mod_vlan_vid:30, resubmit(,2)
EOF
-We don't write any rules that match packets with 802.1Q that enter this stage
-on any of the access ports, so the "default drop" rule we added earlier causes
+We don't write any flows that match packets with 802.1Q that enter this stage
+on any of the access ports, so the "default drop" flow we added earlier causes
them to be dropped, which is ordinarily what we want for access ports.
.. note::
@@ -422,7 +429,7 @@ them to be dropped, which is ordinarily what we want for access ports.
Testing Table 1
---------------
-``ofproto/trace`` allows us to test the ingress VLAN rules that we added above.
+``ofproto/trace`` allows us to test the ingress VLAN flows that we added above.
Example 1: Packet on Trunk Port
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
@@ -435,22 +442,19 @@ The output shows the lookup in table 0, the resubmit to table 1, and the
resubmit to table 2 (which does nothing because we haven't put anything there
yet)::
- Flow: metadata=0,in_port=1,vlan_tci=0x0005,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Rule: table=0 cookie=0 priority=0
- OpenFlow actions=resubmit(,1)
+ Flow: in_port=1,vlan_tci=0x0005,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=1 cookie=0 priority=99,in_port=1
- OpenFlow actions=resubmit(,2)
-
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- No match
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=1, priority 99
+ resubmit(,2)
+ 2. No match.
+ drop
Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=1,dl_src=00:00:00:00:00:00/01:00:00:00:00:00,dl_dst=00:00:00:00:00:00/ff:ff:ff:ff:ff:f0,dl_type=0x0000
Datapath actions: drop
Example 2: Valid Packet on Access Port
@@ -465,22 +469,20 @@ The output is similar to that for the previous case, except that it
additionally tags the packet with ``p2``'s VLAN 20 before it passes it along to
table 2::
- Flow: metadata=0,in_port=2,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Rule: table=0 cookie=0 priority=0
- OpenFlow actions=resubmit(,1)
-
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=1 cookie=0 priority=99,in_port=2,vlan_tci=0x0000
- OpenFlow actions=mod_vlan_vid:20,resubmit(,2)
+ Flow: in_port=2,vlan_tci=0x0000,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Resubmitted flow: metadata=0,in_port=2,dl_vlan=20,dl_vlan_pcp=0,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- No match
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=2,vlan_tci=0x0000, priority 99
+ mod_vlan_vid:20
+ resubmit(,2)
+ 2. No match.
+ drop
- Final flow: unchanged
+ Final flow: in_port=2,dl_vlan=20,dl_vlan_pcp=0,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
+ Megaflow: recirc_id=0,in_port=2,vlan_tci=0x0000,dl_src=00:00:00:00:00:00/01:00:00:00:00:00,dl_dst=00:00:00:00:00:00/ff:ff:ff:ff:ff:f0,dl_type=0x0000
Datapath actions: drop
Example 3: Invalid Packet on Access Port
@@ -491,19 +493,19 @@ access port ``p2``::
$ ovs-appctl ofproto/trace br0 in_port=2,vlan_tci=5
-The output shows the packet matching the default drop rule::
+The output shows the packet matching the default drop flow::
- Flow: metadata=0,in_port=2,vlan_tci=0x0005,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Rule: table=0 cookie=0 priority=0
- OpenFlow actions=resubmit(,1)
+ Flow: in_port=2,vlan_tci=0x0005,dl_src=00:00:00:00:00:00,dl_dst=00:00:00:00:00:00,dl_type=0x0000
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=1 cookie=0 priority=0
- OpenFlow actions=drop
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. priority 0
+ drop
Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=2,vlan_tci=0x0005,dl_src=00:00:00:00:00:00/01:00:00:00:00:00,dl_dst=00:00:00:00:00:00/ff:ff:ff:ff:ff:f0,dl_type=0x0000
Datapath actions: drop
Implementing Table 2: MAC+VLAN Learning for Ingress Port
@@ -571,8 +573,27 @@ Try the following test command::
$ ovs-appctl ofproto/trace br0 \
in_port=1,vlan_tci=20,dl_src=50:00:00:00:00:01 -generate
-The output shows that "learn" was executed, but it isn't otherwise informative,
-so we won't include it here.
+The output shows that "learn" was executed in table 2 and the
+particular flow that was added:
+
+ Flow: in_port=1,vlan_tci=0x0014,dl_src=50:00:00:00:00:01,dl_dst=00:00:00:00:00:00,dl_type=0x0000
+
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=1, priority 99
+ resubmit(,2)
+ 2. priority 32768
+ learn(table=10,NXM_OF_VLAN_TCI[0..11],NXM_OF_ETH_DST[]=NXM_OF_ETH_SRC[],load:NXM_OF_IN_PORT[]->NXM_NX_REG0[0..15])
+ -> table=10 vlan_tci=0x0014/0x0fff,dl_dst=50:00:00:00:00:01 priority=32768 actions=load:0x1->NXM_NX_REG0[0..15]
+ resubmit(,3)
+ 3. No match.
+ drop
+
+ Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=1,vlan_tci=0x0014/0x1fff,dl_src=50:00:00:00:00:01,dl_dst=00:00:00:00:00:00/ff:ff:ff:ff:ff:f0,dl_type=0x0000
+ Datapath actions: drop
The ``-generate`` keyword is new. Ordinarily, ``ofproto/trace`` has no side
effects: "output" actions do not actually output packets, "learn" actions do
@@ -662,22 +683,35 @@ on ``p1`` in VLAN ``20``::
in_port=1,dl_vlan=20,dl_src=f0:00:00:00:00:01,dl_dst=90:00:00:00:00:01 \
-generate
-Here's an excerpt from the output that shows (from the "no match" looking up
-the resubmit to table 10) that the flow's destination was unknown::
+The output shows (from the "no match" looking up the resubmit to
+table 10) that the flow's destination was unknown::
+
+ Flow: in_port=1,dl_vlan=20,dl_vlan_pcp=0,dl_src=f0:00:00:00:00:01,dl_dst=90:00:00:00:00:01,dl_type=0x0000
+
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=1, priority 99
+ resubmit(,2)
+ 2. priority 32768
+ learn(table=10,NXM_OF_VLAN_TCI[0..11],NXM_OF_ETH_DST[]=NXM_OF_ETH_SRC[],load:NXM_OF_IN_PORT[]->NXM_NX_REG0[0..15])
+ -> table=10 vlan_tci=0x0014/0x0fff,dl_dst=f0:00:00:00:00:01 priority=32768 actions=load:0x1->NXM_NX_REG0[0..15]
+ resubmit(,3)
+ 3. priority 50
+ resubmit(,10)
+ 10. No match.
+ drop
+ resubmit(,4)
+ 4. No match.
+ drop
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=3 cookie=0 priority=50
- OpenFlow actions=resubmit(,10),resubmit(,4)
-
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- No match
+ Final flow: unchanged
+ Megaflow: recirc_id=0,in_port=1,dl_vlan=20,dl_src=f0:00:00:00:00:01,dl_dst=90:00:00:00:00:01,dl_type=0x0000
+ Datapath actions: drop
-You can verify that the packet's source was learned two ways. The most direct
-way is to dump the learning table with::
+There are two ways that you can verify that the packet's source was
+learned. The most direct way is to dump the learning table with::
$ ovs-ofctl dump-flows br0 table=10
@@ -698,16 +732,35 @@ that we just learned on p1:
$ ovs-appctl ofproto/trace br0 \
in_port=2,dl_src=90:00:00:00:00:01,dl_dst=f0:00:00:00:00:01 -generate
-Here's an interesting excerpt from that command's output. This group of lines
-traces the ``resubmit(,10)``, showing that the packet matched the learned flow
-for the first MAC we used, loading the OpenFlow port number for the learned
-port ``p1`` into register ``0``::
-
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=10 cookie=0 vlan_tci=0x0014/0x0fff,dl_dst=f0:00:00:00:00:01
- OpenFlow actions=load:0x1->NXM_NX_REG0[0..15]
+Here is this command's output. Take a look at the lines that trace
+the ``resubmit(,10)``, showing that the packet matched the learned
+flow for the first MAC we used, loading the OpenFlow port number for
+the learned port ``p1`` into register ``0``::
+
+ Flow: in_port=2,vlan_tci=0x0000,dl_src=90:00:00:00:00:01,dl_dst=f0:00:00:00:00:01,dl_type=0x0000
+
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=2,vlan_tci=0x0000, priority 99
+ mod_vlan_vid:20
+ resubmit(,2)
+ 2. priority 32768
+ learn(table=10,NXM_OF_VLAN_TCI[0..11],NXM_OF_ETH_DST[]=NXM_OF_ETH_SRC[],load:NXM_OF_IN_PORT[]->NXM_NX_REG0[0..15])
+ -> table=10 vlan_tci=0x0014/0x0fff,dl_dst=90:00:00:00:00:01 priority=32768 actions=load:0x2->NXM_NX_REG0[0..15]
+ resubmit(,3)
+ 3. priority 50
+ resubmit(,10)
+ 10. vlan_tci=0x0014/0x0fff,dl_dst=f0:00:00:00:00:01, priority 32768
+ load:0x1->NXM_NX_REG0[0..15]
+ resubmit(,4)
+ 4. No match.
+ drop
+
+ Final flow: reg0=0x1,in_port=2,dl_vlan=20,dl_vlan_pcp=0,dl_src=90:00:00:00:00:01,dl_dst=f0:00:00:00:00:01,dl_type=0x0000
+ Megaflow: recirc_id=0,in_port=2,vlan_tci=0x0000,dl_src=90:00:00:00:00:01,dl_dst=f0:00:00:00:00:01,dl_type=0x0000
+ Datapath actions: drop
If you read the commands above carefully, then you might have noticed that they
simply have the Ethernet source and destination addresses exchanged. That
@@ -717,13 +770,28 @@ means that if we now rerun the first ``ovs-appctl`` command above, e.g.:
in_port=1,dl_vlan=20,dl_src=f0:00:00:00:00:01,dl_dst=90:00:00:00:00:01 \
-generate
-then we see in the output that the destination has now been learned::
-
- Resubmitted flow: unchanged
- Resubmitted regs: reg0=0x0 reg1=0x0 reg2=0x0 reg3=0x0 reg4=0x0 reg5=0x0 reg6=0x0 reg7=0x0
- Resubmitted odp: drop
- Rule: table=10 cookie=0 vlan_tci=0x0014/0x0fff,dl_dst=90:00:00:00:00:01
- OpenFlow actions=load:0x2->NXM_NX_REG0[0..15]
+then we see in the output, looking at the indented "load" action
+executed in table 10, that the destination has now been learned::
+
+ Flow: in_port=1,dl_vlan=20,dl_vlan_pcp=0,dl_src=f0:00:00:00:00:01,dl_dst=90:00:00:00:00:01,dl_type=0x0000
+
+ bridge("br0")
+ -------------
+ 0. priority 0
+ resubmit(,1)
+ 1. in_port=1, priority 99
+ resubmit(,2)
+ 2. priority 32768
+ learn(table=10,NXM_OF_VLAN_TCI[0..11],NXM_OF_ETH_DST[]=NXM_OF_ETH_SRC[],load:NXM_OF_IN_PORT[]->NXM_NX_REG0[0..15])
+ -> table=10 vlan_tci=0x0014/0x0fff,dl_dst=f0:00:00:00:00:01 priority=32768 actions=load:0x1->NXM_NX_REG0[0..15]
+ resubmit(,3)
+ 3. priority 50
+ resubmit(,10)
+ 10. vlan_tci=0x0014/0x0fff,dl_dst=90:00:00:00:00:01, priority 32768
+ load:0x2->NXM_NX_REG0[0..15]
+ resubmit(,4)
+ 4. No match.
+ drop
Implementing Table 4: Output Processing
@@ -761,7 +829,7 @@ in copies output to access ports::
EOF
.. note::
- Our rules rely on the standard OpenFlow behavior that an output action will
+ Our flows rely on the standard OpenFlow behavior that an output action will
not forward a packet back out the port it came in on. That is, if a packet
comes in on p1, and we've learned that the packet's destination MAC is also
on p1, so that we end up with ``actions=1`` as our actions, the switch will
diff --git a/lib/nx-match.c b/lib/nx-match.c
index 9201aae..d606a4a 100644
--- a/lib/nx-match.c
+++ b/lib/nx-match.c
@@ -1740,30 +1740,21 @@ nxm_execute_stack_push(const struct ofpact_stack *push,
nx_stack_push(stack, &dst_value);
}
-void
+bool
nxm_execute_stack_pop(const struct ofpact_stack *pop,
struct flow *flow, struct flow_wildcards *wc,
struct ofpbuf *stack)
{
- union mf_subvalue *src_value;
-
- src_value = nx_stack_pop(stack);
-
- /* Only pop if stack is not empty. Otherwise, give warning. */
- if (src_value) {
- union mf_subvalue mask_value;
-
- memset(&mask_value, 0xff, sizeof mask_value);
- mf_write_subfield_flow(&pop->subfield, &mask_value, &wc->masks);
- mf_write_subfield_flow(&pop->subfield, src_value, flow);
- } else {
- if (!VLOG_DROP_WARN(&rl)) {
- char *flow_str = flow_to_string(flow);
- VLOG_WARN_RL(&rl, "Failed to pop from an empty stack. On flow\n"
- " %s", flow_str);
- free(flow_str);
- }
+ union mf_subvalue *src_value = nx_stack_pop(stack);
+ if (!src_value) {
+ return false;
}
+
+ union mf_subvalue mask_value;
+ memset(&mask_value, 0xff, sizeof mask_value);
+ mf_write_subfield_flow(&pop->subfield, &mask_value, &wc->masks);
+ mf_write_subfield_flow(&pop->subfield, src_value, flow);
+ return true;
}
/* Formats 'sf' into 's' in a format normally acceptable to
diff --git a/lib/nx-match.h b/lib/nx-match.h
index a86cceb..72185c1 100644
--- a/lib/nx-match.h
+++ b/lib/nx-match.h
@@ -129,9 +129,9 @@ enum ofperr nxm_stack_pop_check(const struct ofpact_stack *,
void nxm_execute_stack_push(const struct ofpact_stack *,
const struct flow *, struct flow_wildcards *,
struct ofpbuf *);
-void nxm_execute_stack_pop(const struct ofpact_stack *,
- struct flow *, struct flow_wildcards *,
- struct ofpbuf *);
+bool nxm_execute_stack_pop(const struct ofpact_stack *,
+ struct flow *, struct flow_wildcards *,
+ struct ofpbuf *);
ovs_be64 oxm_bitmap_from_mf_bitmap(const struct mf_bitmap *, enum ofp_version);
struct mf_bitmap oxm_bitmap_to_mf_bitmap(ovs_be64 oxm_bitmap,
diff --git a/ofproto/ofproto-dpif-trace.c b/ofproto/ofproto-dpif-trace.c
index 52c1758..017fbb1 100644
--- a/ofproto/ofproto-dpif-trace.c
+++ b/ofproto/ofproto-dpif-trace.c
@@ -23,165 +23,82 @@
#include "openvswitch/ofp-parse.h"
#include "unixctl.h"
-struct trace_ctx {
- struct xlate_out xout;
- struct xlate_in xin;
- const struct flow *key;
- struct flow flow;
- struct ds *result;
- struct flow_wildcards wc;
- struct ofpbuf odp_actions;
-};
-
static void ofproto_trace(struct ofproto_dpif *, struct flow *,
const struct dp_packet *packet,
const struct ofpact[], size_t ofpacts_len,
struct ds *);
-static void
-trace_format_rule(struct ofproto *ofproto, struct ds *result, int level,
- const struct rule_dpif *rule)
-{
- const struct rule_actions *actions;
- ovs_be64 cookie;
-
- ds_put_char_multiple(result, '\t', level);
- if (!rule) {
- ds_put_cstr(result, "No match\n");
- return;
- }
-
- ovs_mutex_lock(&rule->up.mutex);
- cookie = rule->up.flow_cookie;
- ovs_mutex_unlock(&rule->up.mutex);
-
- ds_put_format(result, "Rule: table=%"PRIu8" cookie=%#"PRIx64" ",
- rule ? rule->up.table_id : 0, ntohll(cookie));
- cls_rule_format(&rule->up.cr, ofproto_get_tun_tab(ofproto), result);
- ds_put_char(result, '\n');
-
- actions = rule_get_actions(&rule->up);
-
- ds_put_char_multiple(result, '\t', level);
- ds_put_cstr(result, "OpenFlow actions=");
- ofpacts_format(actions->ofpacts, actions->ofpacts_len, result);
- ds_put_char(result, '\n');
-}
-
-static void
-trace_format_flow(struct ds *result, int level, const char *title,
- struct trace_ctx *trace)
+struct oftrace_node *
+oftrace_report(struct ovs_list *super, enum oftrace_node_type type,
+ const char *text)
{
- ds_put_char_multiple(result, '\t', level);
- ds_put_format(result, "%s: ", title);
- /* Do not report unchanged flows for resubmits. */
- if ((level > 0 && flow_equal(&trace->xin.flow, &trace->flow))
- || (level == 0 && flow_equal(&trace->xin.flow, trace->key))) {
- ds_put_cstr(result, "unchanged");
- } else {
- flow_format(result, &trace->xin.flow);
- trace->flow = trace->xin.flow;
- }
- ds_put_char(result, '\n');
+ struct oftrace_node *node = xmalloc(sizeof *node);
+ ovs_list_push_back(super, &node->node);
+ node->type = type;
+ node->name = xstrdup(text);
+ node->always_indent = false;
+ ovs_list_init(&node->subs);
+
+ return node;
}
-static void
-trace_format_regs(struct ds *result, int level, const char *title,
- struct trace_ctx *trace)
+static bool
+oftrace_node_type_is_terminal(enum oftrace_node_type type)
{
- size_t i;
-
- ds_put_char_multiple(result, '\t', level);
- ds_put_format(result, "%s:", title);
- for (i = 0; i < FLOW_N_REGS; i++) {
- ds_put_format(result, " reg%"PRIuSIZE"=0x%"PRIx32, i, trace->flow.regs[i]);
+ switch (type) {
+ case OFT_ACTION:
+ case OFT_DETAIL:
+ case OFT_WARN:
+ case OFT_ERROR:
+ return true;
+
+ case OFT_BRIDGE:
+ case OFT_TABLE:
+ case OFT_THAW:
+ return false;
}
- ds_put_char(result, '\n');
-}
-static void
-trace_format_odp(struct ds *result, int level, const char *title,
- struct trace_ctx *trace)
-{
- struct ofpbuf *odp_actions = &trace->odp_actions;
-
- ds_put_char_multiple(result, '\t', level);
- ds_put_format(result, "%s: ", title);
- format_odp_actions(result, odp_actions->data, odp_actions->size);
- ds_put_char(result, '\n');
+ OVS_NOT_REACHED();
}
static void
-trace_format_megaflow(struct ds *result, int level, const char *title,
- struct trace_ctx *trace)
+oftrace_node_print_details(struct ds *output,
+ const struct ovs_list *nodes, int level)
{
- struct match match;
-
- ds_put_char_multiple(result, '\t', level);
- ds_put_format(result, "%s: ", title);
- match_init(&match, trace->key, &trace->wc);
- match_format(&match, result, OFP_DEFAULT_PRIORITY);
- ds_put_char(result, '\n');
-}
-
-static void trace_report(struct xlate_in *, int indentation,
- const char *format, ...)
- OVS_PRINTF_FORMAT(3, 4);
-static void trace_report_valist(struct xlate_in *, int indentation,
- const char *format, va_list args)
- OVS_PRINTF_FORMAT(3, 0);
+ const struct oftrace_node *sub;
+ LIST_FOR_EACH (sub, node, nodes) {
+ bool more = sub->node.next != nodes || sub->always_indent || oftrace_node_type_is_terminal(sub->type);
+ bool title = sub->type == OFT_BRIDGE;
-static void
-trace_resubmit(struct xlate_in *xin, struct rule_dpif *rule, int indentation)
-{
- struct trace_ctx *trace = CONTAINER_OF(xin, struct trace_ctx, xin);
- struct ds *result = trace->result;
-
- if (!indentation) {
- if (rule == xin->ofproto->miss_rule) {
- trace_report(xin, indentation,
- "No match, flow generates \"packet in\"s.");
- } else if (rule == xin->ofproto->no_packet_in_rule) {
- trace_report(xin, indentation, "No match, packets dropped because "
- "OFPPC_NO_PACKET_IN is set on in_port.");
- } else if (rule == xin->ofproto->drop_frags_rule) {
- trace_report(xin, indentation,
- "Packets dropped because they are IP fragments and "
- "the fragment handling mode is \"drop\".");
+ if (title) {
+ ds_put_char(output, '\n');
+ }
+ ds_put_char_multiple(output, ' ', (level + more) * 4);
+ switch (sub->type) {
+ case OFT_DETAIL:
+ ds_put_format(output, " -> %s\n", sub->name);
+ break;
+ case OFT_WARN:
+ ds_put_format(output, " >> %s\n", sub->name);
+ break;
+ case OFT_ERROR:
+ ds_put_format(output, " >>>> %s <<<<\n", sub->name);
+ break;
+ case OFT_BRIDGE:
+ ds_put_format(output, "%s\n", sub->name);
+ ds_put_char_multiple(output, ' ', (level + more) * 4);
+ ds_put_char_multiple(output, '-', strlen(sub->name));
+ ds_put_char(output, '\n');
+ break;
+ case OFT_TABLE:
+ case OFT_THAW:
+ case OFT_ACTION:
+ ds_put_format(output, "%s\n", sub->name);
+ break;
}
- }
- ds_put_char(result, '\n');
- if (indentation) {
- trace_format_flow(result, indentation, "Resubmitted flow", trace);
- trace_format_regs(result, indentation, "Resubmitted regs", trace);
- trace_format_odp(result, indentation, "Resubmitted odp", trace);
- trace_format_megaflow(result, indentation, "Resubmitted megaflow",
- trace);
+ oftrace_node_print_details(output, &sub->subs, level + more + more);
}
- trace_format_rule(&xin->ofproto->up, result, indentation, rule);
-}
-
-static void
-trace_report_valist(struct xlate_in *xin, int indentation,
- const char *format, va_list args)
-{
- struct trace_ctx *trace = CONTAINER_OF(xin, struct trace_ctx, xin);
- struct ds *result = trace->result;
-
- ds_put_char_multiple(result, '\t', indentation);
- ds_put_format_valist(result, format, args);
- ds_put_char(result, '\n');
-}
-
-static void
-trace_report(struct xlate_in *xin, int indentation, const char *format, ...)
-{
- va_list args;
-
- va_start(args, format);
- trace_report_valist(xin, indentation, format, args);
- va_end(args);
}
/* Parses the 'argc' elements of 'argv', ignoring argv[0]. The following
@@ -466,7 +383,7 @@ exit:
}
/* Implements a "trace" through 'ofproto''s flow table, appending a textual
- * description of the results to 'ds'.
+ * description of the results to 'output'.
*
* The trace follows a packet with the specified 'flow' through the flow
* table. 'packet' may be nonnull to trace an actual packet, with consequent
@@ -478,61 +395,74 @@ static void
ofproto_trace(struct ofproto_dpif *ofproto, struct flow *flow,
const struct dp_packet *packet,
const struct ofpact ofpacts[], size_t ofpacts_len,
- struct ds *ds)
+ struct ds *output)
{
- struct trace_ctx trace;
- enum xlate_error error;
-
- ds_put_format(ds, "Bridge: %s\n", ofproto->up.name);
- ds_put_cstr(ds, "Flow: ");
- flow_format(ds, flow);
- ds_put_char(ds, '\n');
-
- ofpbuf_init(&trace.odp_actions, 0);
+ struct ofpbuf odp_actions;
+ ofpbuf_init(&odp_actions, 0);
- trace.result = ds;
- trace.key = flow; /* Original flow key, used for megaflow. */
- trace.flow = *flow; /* May be modified by actions. */
- xlate_in_init(&trace.xin, ofproto,
+ struct xlate_in xin;
+ struct flow_wildcards wc;
+ struct ovs_list trace = OVS_LIST_INITIALIZER(&trace);
+ xlate_in_init(&xin, ofproto,
ofproto_dpif_get_tables_version(ofproto), flow,
flow->in_port.ofp_port, NULL, ntohs(flow->tcp_flags),
- packet, &trace.wc, &trace.odp_actions);
- trace.xin.ofpacts = ofpacts;
- trace.xin.ofpacts_len = ofpacts_len;
- trace.xin.resubmit_hook = trace_resubmit;
- trace.xin.report_hook = trace_report_valist;
+ packet, &wc, &odp_actions);
+ xin.ofpacts = ofpacts;
+ xin.ofpacts_len = ofpacts_len;
+ xin.trace = &trace;
+
+ /* Copy initial flow out of xin.flow. It differs from '*flow' because
+ * xlate_in_init() initializes actset_output to OFPP_UNSET. */
+ struct flow initial_flow = xin.flow;
+ ds_put_cstr(output, "Flow: ");
+ flow_format(output, &initial_flow);
+ ds_put_char(output, '\n');
- error = xlate_actions(&trace.xin, &trace.xout);
- ds_put_char(ds, '\n');
- trace.xin.flow.actset_output = 0;
- trace_format_flow(ds, 0, "Final flow", &trace);
- trace_format_megaflow(ds, 0, "Megaflow", &trace);
+ struct xlate_out xout;
+ enum xlate_error error = xlate_actions(&xin, &xout);
+
+ oftrace_node_print_details(output, &trace, 0);
+
+ ds_put_cstr(output, "\nFinal flow: ");
+ if (flow_equal(&initial_flow, &xin.flow)) {
+ ds_put_cstr(output, "unchanged");
+ } else {
+ flow_format(output, &xin.flow);
+ }
+ ds_put_char(output, '\n');
+
+ ds_put_cstr(output, "Megaflow: ");
+ struct match match;
+ match_init(&match, flow, &wc);
+ match_format(&match, output, OFP_DEFAULT_PRIORITY);
+ ds_put_char(output, '\n');
- ds_put_cstr(ds, "Datapath actions: ");
- format_odp_actions(ds, trace.odp_actions.data, trace.odp_actions.size);
+ ds_put_cstr(output, "Datapath actions: ");
+ format_odp_actions(output, odp_actions.data, odp_actions.size);
if (error != XLATE_OK) {
- ds_put_format(ds, "\nTranslation failed (%s), packet is dropped.\n",
+ ds_put_format(output,
+ "\nTranslation failed (%s), packet is dropped.\n",
xlate_strerror(error));
- } else if (trace.xout.slow) {
+ } else if (xout.slow) {
enum slow_path_reason slow;
- ds_put_cstr(ds, "\nThis flow is handled by the userspace "
+ ds_put_cstr(output, "\nThis flow is handled by the userspace "
"slow path because it:");
- slow = trace.xout.slow;
+ slow = xout.slow;
while (slow) {
enum slow_path_reason bit = rightmost_1bit(slow);
- ds_put_format(ds, "\n\t- %s.",
+ ds_put_format(output, "\n\t- %s.",
slow_path_reason_to_explanation(bit));
slow &= ~bit;
}
}
- xlate_out_uninit(&trace.xout);
- ofpbuf_uninit(&trace.odp_actions);
+ xlate_out_uninit(&xout);
+ ofpbuf_uninit(&odp_actions);
}
void
diff --git a/ofproto/ofproto-dpif-trace.h b/ofproto/ofproto-dpif-trace.h
index 06d63f8..04acca7 100644
--- a/ofproto/ofproto-dpif-trace.h
+++ b/ofproto/ofproto-dpif-trace.h
@@ -15,6 +15,31 @@
#ifndef OFPROTO_DPIF_TRACE_H
#define OFPROTO_DPIF_TRACE_H 1
+#include "openvswitch/compiler.h"
+#include "openvswitch/list.h"
+
+enum oftrace_node_type {
+ OFT_BRIDGE, /* Packet travel through an OpenFlow switch. */
+ OFT_TABLE, /* Packet travel through a flow table. */
+ OFT_THAW, /* Thawing a frozen state. */
+ OFT_ACTION, /* An action. */
+ OFT_DETAIL, /* Some detail of an action. */
+ OFT_WARN, /* A worrisome situation. */
+ OFT_ERROR, /* An erroneous situation, worth logging. */
+};
+
+struct oftrace_node {
+ struct ovs_list node; /* In parent. */
+
+ enum oftrace_node_type type;
+ const char *name;
+ bool always_indent;
+ struct ovs_list subs; /* List of "struct oftrace_node" children. */
+};
+
void ofproto_dpif_trace_init(void);
+struct oftrace_node *oftrace_report(struct ovs_list *, enum oftrace_node_type,
+ const char *text);
+
#endif /* ofproto-dpif-trace.h */
diff --git a/ofproto/ofproto-dpif-xlate.c b/ofproto/ofproto-dpif-xlate.c
index 51e8f04..5fafa00 100644
--- a/ofproto/ofproto-dpif-xlate.c
+++ b/ofproto/ofproto-dpif-xlate.c
@@ -46,6 +46,7 @@
#include "ofproto/ofproto-dpif-mirror.h"
#include "ofproto/ofproto-dpif-monitor.h"
#include "ofproto/ofproto-dpif-sflow.h"
+#include "ofproto/ofproto-dpif-trace.h"
#include "ofproto/ofproto-dpif-xlate-cache.h"
#include "ofproto/ofproto-dpif.h"
#include "ofproto/ofproto-provider.h"
@@ -203,10 +204,7 @@ struct xlate_ctx {
/* Statistics maintained by xlate_table_action().
*
- * 'indentation' is the nesting level for resubmits. It is used to indent
- * the output of resubmit_hook (e.g. for the "ofproto/trace" feature).
- *
- * The other statistics limit the amount of work that a single flow
+ * These statistics limit the amount of work that a single flow
* translation can perform. The goal of the first of these, 'depth', is
* primarily to prevent translation from performing an infinite amount of
* work. It counts the current depth of nested "resubmit"s (and a few
@@ -224,7 +222,6 @@ struct xlate_ctx {
* translation can perform. Translation aborts when 'resubmits' exceeds
* MAX_RESUBMITS (which is much larger than MAX_DEPTH).
*/
- int indentation; /* Indentation level for resubmit_hook. */
int depth; /* Current resubmit nesting depth. */
int resubmits; /* Total number of resubmits. */
bool in_group; /* Currently translating ofgroup, if true. */
@@ -483,12 +480,11 @@ static bool may_receive(const struct xport *, struct xlate_ctx *);
static void do_xlate_actions(const struct ofpact *, size_t ofpacts_len,
struct xlate_ctx *);
static void xlate_normal(struct xlate_ctx *);
-static inline void xlate_report(struct xlate_ctx *, const char *, ...)
- OVS_PRINTF_FORMAT(2, 3);
static void xlate_table_action(struct xlate_ctx *, ofp_port_t in_port,
uint8_t table_id, bool may_packet_in,
bool honor_table_miss);
-static bool input_vid_is_valid(uint16_t vid, struct xbundle *, bool warn);
+static bool input_vid_is_valid(const struct xlate_ctx *,
+ uint16_t vid, struct xbundle *);
static uint16_t input_vid_to_vlan(const struct xbundle *, uint16_t vid);
static void output_normal(struct xlate_ctx *, const struct xbundle *,
uint16_t vlan);
@@ -552,43 +548,166 @@ static void xlate_xport_copy(struct xbridge *, struct xbundle *,
struct xport *);
static void xlate_xcfg_free(struct xlate_cfg *);
-static inline void
-xlate_report(struct xlate_ctx *ctx, const char *format, ...)
+static struct ovs_list * OVS_PRINTF_FORMAT(3, 4)
+xlate_report(const struct xlate_ctx *ctx, enum oftrace_node_type type,
+ const char *format, ...)
{
- if (OVS_UNLIKELY(ctx->xin->report_hook)) {
+ struct ovs_list *subtrace = NULL;
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
va_list args;
-
va_start(args, format);
- ctx->xin->report_hook(ctx->xin, ctx->indentation, format, args);
+ char *text = xvasprintf(format, args);
+ subtrace = &oftrace_report(ctx->xin->trace, type, text)->subs;
va_end(args);
}
+ return subtrace;
+}
+
+/* This is like xlate_report() for errors that are serious enough that we
+ * should log them even if we are not tracing. */
+static void OVS_PRINTF_FORMAT(2, 3)
+xlate_report_error(const struct xlate_ctx *ctx, const char *format, ...)
+{
+ static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
+ if (!OVS_UNLIKELY(ctx->xin->trace) && VLOG_DROP_WARN(&rl)) {
+ return;
+ }
+
+ struct ds s = DS_EMPTY_INITIALIZER;
+ va_list args;
+ va_start(args, format);
+ ds_put_format_valist(&s, format, args);
+ va_end(args);
+
+ if (ctx->xin->trace) {
+ oftrace_report(ctx->xin->trace, OFT_ERROR, ds_cstr(&s));
+ } else {
+ ds_put_cstr(&s, " while processing ");
+ flow_format(&s, &ctx->base_flow);
+ ds_put_format(&s, " on bridge %s", ctx->xbridge->name);
+ VLOG_WARN("%s", ds_cstr(&s));
+ }
+ ds_destroy(&s);
}
-static struct vlog_rate_limit error_report_rl = VLOG_RATE_LIMIT_INIT(1, 5);
+/* This is like xlate_report() for messages that should be logged at debug
+ * level (even if we are not tracing) because they can be valuable for
+ * debugging. */
+static void OVS_PRINTF_FORMAT(3, 4)
+xlate_report_debug(const struct xlate_ctx *ctx, enum oftrace_node_type type,
+ const char *format, ...)
+{
+ static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(30, 300);
+ if (!OVS_UNLIKELY(ctx->xin->trace) && VLOG_DROP_DBG(&rl)) {
+ return;
+ }
+
+ struct ds s = DS_EMPTY_INITIALIZER;
+ va_list args;
+ va_start(args, format);
+ ds_put_format_valist(&s, format, args);
+ va_end(args);
-#define XLATE_REPORT_ERROR(CTX, ...) \
- do { \
- if (OVS_UNLIKELY((CTX)->xin->report_hook)) { \
- xlate_report(CTX, __VA_ARGS__); \
- } else { \
- struct ds ds = DS_EMPTY_INITIALIZER; \
- \
- ds_put_format(&ds, __VA_ARGS__); \
- ds_put_cstr(&ds, ": "); \
- flow_format(&ds, &(CTX)->base_flow); \
- VLOG_ERR_RL(&error_report_rl, "%s", ds_cstr(&ds)); \
- ds_destroy(&ds); \
- } \
- } while (0)
+ if (ctx->xin->trace) {
+ oftrace_report(ctx->xin->trace, type, ds_cstr(&s));
+ } else {
+ VLOG_DBG("bridge %s: %s", ctx->xbridge->name, ds_cstr(&s));
+ }
+ ds_destroy(&s);
+}
-static inline void
-xlate_report_actions(struct xlate_ctx *ctx, const char *title,
+static struct ovs_list *
+xlate_report_actions(const struct xlate_ctx *ctx, enum oftrace_node_type type,
+ const char *title,
const struct ofpact *ofpacts, size_t ofpacts_len)
{
- if (OVS_UNLIKELY(ctx->xin->report_hook)) {
+ struct ovs_list *subtrace = NULL;
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
struct ds s = DS_EMPTY_INITIALIZER;
+ ds_put_format(&s, "%s: ", title);
ofpacts_format(ofpacts, ofpacts_len, &s);
- xlate_report(ctx, "%s: %s", title, ds_cstr(&s));
+ subtrace = &oftrace_report(ctx->xin->trace, type, ds_cstr(&s))->subs;
+ ds_destroy(&s);
+ }
+ return subtrace;
+}
+
+static void
+xlate_report_action_set(const struct xlate_ctx *ctx, const char *verb)
+{
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
+ struct ofpbuf action_list;
+ ofpbuf_init(&action_list, 0);
+ ofpacts_execute_action_set(&action_list, &ctx->action_set);
+ if (action_list.size) {
+ struct ds s = DS_EMPTY_INITIALIZER;
+ ofpacts_format(action_list.data, action_list.size, &s);
+ xlate_report(ctx, OFT_DETAIL, "action set %s: %s",
+ verb, ds_cstr(&s));
+ ds_destroy(&s);
+ } else {
+ xlate_report(ctx, OFT_DETAIL, "action set %s empty", verb);
+ }
+ ofpbuf_uninit(&action_list);
+ }
+}
+
+static void
+xlate_report_table(const struct xlate_ctx *ctx, struct rule_dpif *rule,
+ uint8_t table_id)
+{
+ if (OVS_LIKELY(!ctx->xin->trace)) {
+ return;
+ }
+
+ struct ds s = DS_EMPTY_INITIALIZER;
+ ds_put_format(&s, "%2d. ", table_id);
+ if (rule == ctx->xin->ofproto->miss_rule) {
+ ds_put_cstr(&s, "No match, and a \"packet-in\" is called for.");
+ } else if (rule == ctx->xin->ofproto->no_packet_in_rule) {
+ ds_put_cstr(&s, "No match.");
+ } else if (rule == ctx->xin->ofproto->drop_frags_rule) {
+ ds_put_cstr(&s, "Packets are IP fragments and "
+ "the fragment handling mode is \"drop\".");
+ } else {
+ minimatch_format(&rule->up.cr.match,
+ ofproto_get_tun_tab(&ctx->xin->ofproto->up),
+ &s, OFP_DEFAULT_PRIORITY);
+ if (ds_last(&s) != ' ') {
+ ds_put_cstr(&s, ", ");
+ }
+ ds_put_format(&s, "priority %d", rule->up.cr.priority);
+ if (rule->up.flow_cookie) {
+ ds_put_format(&s, ", cookie %#"PRIx64,
+ ntohll(rule->up.flow_cookie));
+ }
+ }
+ ctx->xin->trace = &oftrace_report(ctx->xin->trace, OFT_TABLE,
+ ds_cstr(&s))->subs;
+ ds_destroy(&s);
+}
+
+static void
+xlate_report_subfield(const struct xlate_ctx *ctx,
+ const struct mf_subfield *sf)
+{
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
+ struct ds s = DS_EMPTY_INITIALIZER;
+ mf_format_subfield(sf, &s);
+ ds_put_cstr(&s, " is now ");
+
+ if (sf->ofs == 0 && sf->n_bits >= sf->field->n_bits) {
+ union mf_value value;
+ mf_get_value(sf->field, &ctx->xin->flow, &value);
+ mf_format(sf->field, &value, NULL, &s);
+ } else {
+ union mf_subvalue cst;
+ mf_read_subfield(sf, &ctx->xin->flow, &cst);
+ ds_put_hex(&s, &cst, sizeof cst);
+ }
+
+ xlate_report(ctx, OFT_DETAIL, "%s", ds_cstr(&s));
+
ds_destroy(&s);
}
}
@@ -1465,10 +1584,8 @@ bucket_is_alive(const struct xlate_ctx *ctx,
struct ofputil_bucket *bucket, int depth)
{
if (depth >= MAX_LIVENESS_RECURSION) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
-
- VLOG_WARN_RL(&rl, "bucket chaining exceeded %d links",
- MAX_LIVENESS_RECURSION);
+ xlate_report_error(ctx, "bucket chaining exceeded %d links",
+ MAX_LIVENESS_RECURSION);
return false;
}
@@ -1554,8 +1671,8 @@ xbundle_mirror_dst(const struct xbridge *xbridge, struct xbundle *xbundle)
}
static struct xbundle *
-lookup_input_bundle(const struct xbridge *xbridge, ofp_port_t in_port,
- bool warn, struct xport **in_xportp)
+lookup_input_bundle__(const struct xbridge *xbridge,
+ ofp_port_t in_port, struct xport **in_xportp)
{
struct xport *xport;
@@ -1574,27 +1691,33 @@ lookup_input_bundle(const struct xbridge *xbridge, ofp_port_t in_port,
if (in_port == OFPP_CONTROLLER || in_port == OFPP_NONE) {
return &ofpp_none_bundle;
}
+ return NULL;
+}
- /* Odd. A few possible reasons here:
- *
- * - We deleted a port but there are still a few packets queued up
- * from it.
- *
- * - Someone externally added a port (e.g. "ovs-dpctl add-if") that
- * we don't know about.
- *
- * - The ofproto client didn't configure the port as part of a bundle.
- * This is particularly likely to happen if a packet was received on the
- * port after it was created, but before the client had a chance to
- * configure its bundle.
- */
- if (warn) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
-
- VLOG_WARN_RL(&rl, "bridge %s: received packet on unknown "
- "port %"PRIu16, xbridge->name, in_port);
+static struct xbundle *
+lookup_input_bundle(const struct xlate_ctx *ctx,
+ ofp_port_t in_port, struct xport **in_xportp)
+{
+ struct xbundle *xbundle = lookup_input_bundle__(ctx->xbridge,
+ in_port, in_xportp);
+ if (!xbundle) {
+ /* Odd. A few possible reasons here:
+ *
+ * - We deleted a port but there are still a few packets queued up
+ * from it.
+ *
+ * - Someone externally added a port (e.g. "ovs-dpctl add-if") that
+ * we don't know about.
+ *
+ * - The ofproto client didn't configure the port as part of a bundle.
+ * This is particularly likely to happen if a packet was received on
+ * the port after it was created, but before the client had a chance
+ * to configure its bundle.
+ */
+ xlate_report_error(ctx, "received packet on unknown port %"PRIu16,
+ in_port);
}
- return NULL;
+ return xbundle;
}
/* Mirrors the packet represented by 'ctx' to appropriate mirror destinations,
@@ -1606,9 +1729,8 @@ mirror_packet(struct xlate_ctx *ctx, struct xbundle *xbundle,
{
/* Figure out what VLAN the packet is in (because mirrors can select
* packets on basis of VLAN). */
- bool warn = ctx->xin->packet != NULL;
uint16_t vid = vlan_tci_to_vid(ctx->xin->flow.vlan_tci);
- if (!input_vid_is_valid(vid, xbundle, warn)) {
+ if (!input_vid_is_valid(ctx, vid, xbundle)) {
return;
}
uint16_t vlan = input_vid_to_vlan(xbundle, vid);
@@ -1697,9 +1819,8 @@ static void
mirror_ingress_packet(struct xlate_ctx *ctx)
{
if (mbridge_has_mirrors(ctx->xbridge->mbridge)) {
- bool warn = ctx->xin->packet != NULL;
struct xbundle *xbundle = lookup_input_bundle(
- ctx->xbridge, ctx->xin->flow.in_port.ofp_port, warn, NULL);
+ ctx, ctx->xin->flow.in_port.ofp_port, NULL);
if (xbundle) {
mirror_packet(ctx, xbundle,
xbundle_mirror_src(ctx->xbridge, xbundle));
@@ -1734,14 +1855,14 @@ input_vid_to_vlan(const struct xbundle *in_xbundle, uint16_t vid)
}
/* Checks whether a packet with the given 'vid' may ingress on 'in_xbundle'.
- * If so, returns true. Otherwise, returns false and, if 'warn' is true, logs
- * a warning.
+ * If so, returns true. Otherwise, returns false.
*
* 'vid' should be the VID obtained from the 802.1Q header that was received as
* part of a packet (specify 0 if there was no 802.1Q header), in the range
* 0...4095. */
static bool
-input_vid_is_valid(uint16_t vid, struct xbundle *in_xbundle, bool warn)
+input_vid_is_valid(const struct xlate_ctx *ctx,
+ uint16_t vid, struct xbundle *in_xbundle)
{
/* Allow any VID on the OFPP_NONE port. */
if (in_xbundle == &ofpp_none_bundle) {
@@ -1751,13 +1872,10 @@ input_vid_is_valid(uint16_t vid, struct xbundle *in_xbundle, bool warn)
switch (in_xbundle->vlan_mode) {
case PORT_VLAN_ACCESS:
if (vid) {
- if (warn) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "dropping VLAN %"PRIu16" tagged "
- "packet received on port %s configured as VLAN "
- "%"PRIu16" access port", vid, in_xbundle->name,
- in_xbundle->vlan);
- }
+ xlate_report_error(ctx, "dropping VLAN %"PRIu16" tagged "
+ "packet received on port %s configured as VLAN "
+ "%"PRIu16" access port", vid, in_xbundle->name,
+ in_xbundle->vlan);
return false;
}
return true;
@@ -1771,12 +1889,10 @@ input_vid_is_valid(uint16_t vid, struct xbundle *in_xbundle, bool warn)
/* Fall through. */
case PORT_VLAN_TRUNK:
if (!xbundle_includes_vlan(in_xbundle, vid)) {
- if (warn) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "dropping VLAN %"PRIu16" packet "
- "received on port %s not configured for trunking "
- "VLAN %"PRIu16, vid, in_xbundle->name, vid);
- }
+ xlate_report_error(ctx, "dropping VLAN %"PRIu16" packet "
+ "received on port %s not configured for "
+ "trunking VLAN %"PRIu16,
+ vid, in_xbundle->name, vid);
return false;
}
return true;
@@ -1946,7 +2062,8 @@ is_admissible(struct xlate_ctx *ctx, struct xport *in_port,
/* Drop frames for reserved multicast addresses
* only if forward_bpdu option is absent. */
if (!xbridge->forward_bpdu && eth_addr_is_reserved(flow->dl_dst)) {
- xlate_report(ctx, "packet has reserved destination MAC, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "packet has reserved destination MAC, dropping");
return false;
}
@@ -1959,7 +2076,8 @@ is_admissible(struct xlate_ctx *ctx, struct xport *in_port,
break;
case BV_DROP:
- xlate_report(ctx, "bonding refused admissibility, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "bonding refused admissibility, dropping");
return false;
case BV_DROP_IF_MOVED:
@@ -1970,7 +2088,8 @@ is_admissible(struct xlate_ctx *ctx, struct xport *in_port,
&& (!is_gratuitous_arp(flow, ctx->wc)
|| mac_entry_is_grat_arp_locked(mac))) {
ovs_rwlock_unlock(&xbridge->ml->rwlock);
- xlate_report(ctx, "SLB bond thinks this packet looped back, "
+ xlate_report(ctx, OFT_DETAIL,
+ "SLB bond thinks this packet looped back, "
"dropping");
return false;
}
@@ -1982,39 +2101,41 @@ is_admissible(struct xlate_ctx *ctx, struct xport *in_port,
return true;
}
+static bool
+update_learning_table__(const struct xbridge *xbridge,
+ struct xbundle *in_xbundle, struct eth_addr dl_src,
+ int vlan, bool is_grat_arp)
+{
+ return (in_xbundle == &ofpp_none_bundle
+ || !mac_learning_update(xbridge->ml, dl_src, vlan,
+ is_grat_arp,
+ in_xbundle->bond != NULL,
+ in_xbundle->ofbundle));
+}
+
static void
-update_learning_table(const struct xbridge *xbridge,
+update_learning_table(const struct xlate_ctx *ctx,
struct xbundle *in_xbundle, struct eth_addr dl_src,
int vlan, bool is_grat_arp)
{
- if (in_xbundle == &ofpp_none_bundle) {
- return;
- }
-
- if (mac_learning_update(xbridge->ml, dl_src, vlan, is_grat_arp,
- in_xbundle->bond != NULL, in_xbundle->ofbundle)) {
- /* The log messages here could actually be useful in debugging,
- * so keep the rate limit relatively high. */
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(30, 300);
-
- VLOG_DBG_RL(&rl, "bridge %s: learned that "ETH_ADDR_FMT" is "
- "on port %s in VLAN %d",
- xbridge->name, ETH_ADDR_ARGS(dl_src), in_xbundle->name,
- vlan);
+ if (!update_learning_table__(ctx->xbridge, in_xbundle, dl_src, vlan,
+ is_grat_arp)) {
+ xlate_report_debug(ctx, OFT_DETAIL, "learned that "ETH_ADDR_FMT" is "
+ "on port %s in VLAN %d",
+ ETH_ADDR_ARGS(dl_src), in_xbundle->name, vlan);
}
}
/* Updates multicast snooping table 'ms' given that a packet matching 'flow'
* was received on 'in_xbundle' in 'vlan' and is either Report or Query. */
static void
-update_mcast_snooping_table4__(const struct xbridge *xbridge,
+update_mcast_snooping_table4__(const struct xlate_ctx *ctx,
const struct flow *flow,
struct mcast_snooping *ms, int vlan,
struct xbundle *in_xbundle,
const struct dp_packet *packet)
OVS_REQ_WRLOCK(ms->rwlock)
{
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(60, 30);
int count;
ovs_be32 ip4 = flow->igmp_group_ip4;
@@ -2022,56 +2143,55 @@ update_mcast_snooping_table4__(const struct xbridge *xbridge,
case IGMP_HOST_MEMBERSHIP_REPORT:
case IGMPV2_HOST_MEMBERSHIP_REPORT:
if (mcast_snooping_add_group4(ms, ip4, vlan, in_xbundle->ofbundle)) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping learned that "
- IP_FMT" is on port %s in VLAN %d",
- xbridge->name, IP_ARGS(ip4), in_xbundle->name, vlan);
+ xlate_report_debug(ctx, OFT_DETAIL,
+ "multicast snooping learned that "
+ IP_FMT" is on port %s in VLAN %d",
+ IP_ARGS(ip4), in_xbundle->name, vlan);
}
break;
case IGMP_HOST_LEAVE_MESSAGE:
if (mcast_snooping_leave_group4(ms, ip4, vlan, in_xbundle->ofbundle)) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping leaving "
- IP_FMT" is on port %s in VLAN %d",
- xbridge->name, IP_ARGS(ip4), in_xbundle->name, vlan);
+ xlate_report_debug(ctx, OFT_DETAIL, "multicast snooping leaving "
+ IP_FMT" is on port %s in VLAN %d",
+ IP_ARGS(ip4), in_xbundle->name, vlan);
}
break;
case IGMP_HOST_MEMBERSHIP_QUERY:
if (flow->nw_src && mcast_snooping_add_mrouter(ms, vlan,
- in_xbundle->ofbundle)) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping query from "
- IP_FMT" is on port %s in VLAN %d",
- xbridge->name, IP_ARGS(flow->nw_src),
- in_xbundle->name, vlan);
+ in_xbundle->ofbundle)) {
+ xlate_report_debug(ctx, OFT_DETAIL, "multicast snooping query "
+ "from "IP_FMT" is on port %s in VLAN %d",
+ IP_ARGS(flow->nw_src), in_xbundle->name, vlan);
}
break;
case IGMPV3_HOST_MEMBERSHIP_REPORT:
- if ((count = mcast_snooping_add_report(ms, packet, vlan,
- in_xbundle->ofbundle))) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping processed %d "
- "addresses on port %s in VLAN %d",
- xbridge->name, count, in_xbundle->name, vlan);
+ count = mcast_snooping_add_report(ms, packet, vlan,
+ in_xbundle->ofbundle);
+ if (count) {
+ xlate_report_debug(ctx, OFT_DETAIL, "multicast snooping processed "
+ "%d addresses on port %s in VLAN %d",
+ count, in_xbundle->name, vlan);
}
break;
}
}
static void
-update_mcast_snooping_table6__(const struct xbridge *xbridge,
+update_mcast_snooping_table6__(const struct xlate_ctx *ctx,
const struct flow *flow,
struct mcast_snooping *ms, int vlan,
struct xbundle *in_xbundle,
const struct dp_packet *packet)
OVS_REQ_WRLOCK(ms->rwlock)
{
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(60, 30);
int count;
switch (ntohs(flow->tp_src)) {
case MLD_QUERY:
if (!ipv6_addr_equals(&flow->ipv6_src, &in6addr_any)
&& mcast_snooping_add_mrouter(ms, vlan, in_xbundle->ofbundle)) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping query on port %s"
- "in VLAN %d",
- xbridge->name, in_xbundle->name, vlan);
+ xlate_report_debug(ctx, OFT_DETAIL, "multicast snooping query on "
+ "port %s in VLAN %d", in_xbundle->name, vlan);
}
break;
case MLD_REPORT:
@@ -2079,9 +2199,9 @@ update_mcast_snooping_table6__(const struct xbridge *xbridge,
case MLD2_REPORT:
count = mcast_snooping_add_mld(ms, packet, vlan, in_xbundle->ofbundle);
if (count) {
- VLOG_DBG_RL(&rl, "bridge %s: multicast snooping processed %d "
- "addresses on port %s in VLAN %d",
- xbridge->name, count, in_xbundle->name, vlan);
+ xlate_report_debug(ctx, OFT_DETAIL, "multicast snooping processed "
+ "%d addresses on port %s in VLAN %d",
+ count, in_xbundle->name, vlan);
}
break;
}
@@ -2090,12 +2210,12 @@ update_mcast_snooping_table6__(const struct xbridge *xbridge,
/* Updates multicast snooping table 'ms' given that a packet matching 'flow'
* was received on 'in_xbundle' in 'vlan'. */
static void
-update_mcast_snooping_table(const struct xbridge *xbridge,
+update_mcast_snooping_table(const struct xlate_ctx *ctx,
const struct flow *flow, int vlan,
struct xbundle *in_xbundle,
const struct dp_packet *packet)
{
- struct mcast_snooping *ms = xbridge->ms;
+ struct mcast_snooping *ms = ctx->xbridge->ms;
struct xlate_cfg *xcfg;
struct xbundle *mcast_xbundle;
struct mcast_port_bundle *fport;
@@ -2118,10 +2238,10 @@ update_mcast_snooping_table(const struct xbridge *xbridge,
if (!mcast_xbundle || mcast_xbundle != in_xbundle) {
if (flow->dl_type == htons(ETH_TYPE_IP)) {
- update_mcast_snooping_table4__(xbridge, flow, ms, vlan,
+ update_mcast_snooping_table4__(ctx, flow, ms, vlan,
in_xbundle, packet);
} else {
- update_mcast_snooping_table6__(xbridge, flow, ms, vlan,
+ update_mcast_snooping_table6__(ctx, flow, ms, vlan,
in_xbundle, packet);
}
}
@@ -2144,12 +2264,14 @@ xlate_normal_mcast_send_group(struct xlate_ctx *ctx,
LIST_FOR_EACH(b, bundle_node, &grp->bundle_lru) {
mcast_xbundle = xbundle_lookup(xcfg, b->port);
if (mcast_xbundle && mcast_xbundle != in_xbundle) {
- xlate_report(ctx, "forwarding to mcast group port");
+ xlate_report(ctx, OFT_DETAIL, "forwarding to mcast group port");
output_normal(ctx, mcast_xbundle, vlan);
} else if (!mcast_xbundle) {
- xlate_report(ctx, "mcast group port is unknown, dropping");
+ xlate_report(ctx, OFT_WARN,
+ "mcast group port is unknown, dropping");
} else {
- xlate_report(ctx, "mcast group port is input port, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "mcast group port is input port, dropping");
}
}
}
@@ -2170,14 +2292,17 @@ xlate_normal_mcast_send_mrouters(struct xlate_ctx *ctx,
mcast_xbundle = xbundle_lookup(xcfg, mrouter->port);
if (mcast_xbundle && mcast_xbundle != in_xbundle
&& mrouter->vlan == vlan) {
- xlate_report(ctx, "forwarding to mcast router port");
+ xlate_report(ctx, OFT_DETAIL, "forwarding to mcast router port");
output_normal(ctx, mcast_xbundle, vlan);
} else if (!mcast_xbundle) {
- xlate_report(ctx, "mcast router port is unknown, dropping");
+ xlate_report(ctx, OFT_WARN,
+ "mcast router port is unknown, dropping");
} else if (mrouter->vlan != vlan) {
- xlate_report(ctx, "mcast router is on another vlan, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "mcast router is on another vlan, dropping");
} else {
- xlate_report(ctx, "mcast router port is input port, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "mcast router port is input port, dropping");
}
}
}
@@ -2197,12 +2322,14 @@ xlate_normal_mcast_send_fports(struct xlate_ctx *ctx,
LIST_FOR_EACH(fport, node, &ms->fport_list) {
mcast_xbundle = xbundle_lookup(xcfg, fport->port);
if (mcast_xbundle && mcast_xbundle != in_xbundle) {
- xlate_report(ctx, "forwarding to mcast flood port");
+ xlate_report(ctx, OFT_DETAIL, "forwarding to mcast flood port");
output_normal(ctx, mcast_xbundle, vlan);
} else if (!mcast_xbundle) {
- xlate_report(ctx, "mcast flood port is unknown, dropping");
+ xlate_report(ctx, OFT_WARN,
+ "mcast flood port is unknown, dropping");
} else {
- xlate_report(ctx, "mcast flood port is input port, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "mcast flood port is input port, dropping");
}
}
}
@@ -2222,12 +2349,15 @@ xlate_normal_mcast_send_rports(struct xlate_ctx *ctx,
LIST_FOR_EACH(rport, node, &ms->rport_list) {
mcast_xbundle = xbundle_lookup(xcfg, rport->port);
if (mcast_xbundle && mcast_xbundle != in_xbundle) {
- xlate_report(ctx, "forwarding Report to mcast flagged port");
+ xlate_report(ctx, OFT_DETAIL,
+ "forwarding report to mcast flagged port");
output_normal(ctx, mcast_xbundle, vlan);
} else if (!mcast_xbundle) {
- xlate_report(ctx, "mcast port is unknown, dropping the Report");
+ xlate_report(ctx, OFT_WARN,
+ "mcast port is unknown, dropping the report");
} else {
- xlate_report(ctx, "mcast port is input port, dropping the Report");
+ xlate_report(ctx, OFT_DETAIL,
+ "mcast port is input port, dropping the Report");
}
}
}
@@ -2279,10 +2409,9 @@ xlate_normal(struct xlate_ctx *ctx)
memset(&wc->masks.dl_dst, 0xff, sizeof wc->masks.dl_dst);
wc->masks.vlan_tci |= htons(VLAN_VID_MASK | VLAN_CFI);
- in_xbundle = lookup_input_bundle(ctx->xbridge, flow->in_port.ofp_port,
- ctx->xin->packet != NULL, &in_port);
+ in_xbundle = lookup_input_bundle(ctx, flow->in_port.ofp_port, &in_port);
if (!in_xbundle) {
- xlate_report(ctx, "no input bundle, dropping");
+ xlate_report(ctx, OFT_WARN, "no input bundle, dropping");
return;
}
@@ -2290,31 +2419,31 @@ xlate_normal(struct xlate_ctx *ctx)
if (flow->dl_type == htons(ETH_TYPE_VLAN) &&
!(flow->vlan_tci & htons(VLAN_CFI))) {
if (ctx->xin->packet != NULL) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "bridge %s: dropping packet with partial "
- "VLAN tag received on port %s",
- ctx->xbridge->name, in_xbundle->name);
+ xlate_report_error(ctx, "dropping packet with partial "
+ "VLAN tag received on port %s",
+ in_xbundle->name);
}
- xlate_report(ctx, "partial VLAN tag, dropping");
+ xlate_report(ctx, OFT_WARN, "partial VLAN tag, dropping");
return;
}
/* Drop frames on bundles reserved for mirroring. */
if (xbundle_mirror_out(ctx->xbridge, in_xbundle)) {
if (ctx->xin->packet != NULL) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "bridge %s: dropping packet received on port "
- "%s, which is reserved exclusively for mirroring",
- ctx->xbridge->name, in_xbundle->name);
+ xlate_report_error(ctx, "dropping packet received on port %s, "
+ "which is reserved exclusively for mirroring",
+ in_xbundle->name);
}
- xlate_report(ctx, "input port is mirror output port, dropping");
+ xlate_report(ctx, OFT_WARN,
+ "input port is mirror output port, dropping");
return;
}
/* Check VLAN. */
vid = vlan_tci_to_vid(flow->vlan_tci);
- if (!input_vid_is_valid(vid, in_xbundle, ctx->xin->packet != NULL)) {
- xlate_report(ctx, "disallowed VLAN VID for this input port, dropping");
+ if (!input_vid_is_valid(ctx, vid, in_xbundle)) {
+ xlate_report(ctx, OFT_WARN,
+ "disallowed VLAN VID for this input port, dropping");
return;
}
vlan = input_vid_to_vlan(in_xbundle, vid);
@@ -2327,7 +2456,7 @@ xlate_normal(struct xlate_ctx *ctx)
/* Learn source MAC. */
bool is_grat_arp = is_gratuitous_arp(flow, wc);
if (ctx->xin->allow_side_effects) {
- update_learning_table(ctx->xbridge, in_xbundle, flow->dl_src, vlan,
+ update_learning_table(ctx, in_xbundle, flow->dl_src, vlan,
is_grat_arp);
}
if (ctx->xin->xcache && in_xbundle != &ofpp_none_bundle) {
@@ -2355,7 +2484,7 @@ xlate_normal(struct xlate_ctx *ctx)
if (mcast_snooping_is_membership(flow->tp_src) ||
mcast_snooping_is_query(flow->tp_src)) {
if (ctx->xin->allow_side_effects && ctx->xin->packet) {
- update_mcast_snooping_table(ctx->xbridge, flow, vlan,
+ update_mcast_snooping_table(ctx, flow, vlan,
in_xbundle, ctx->xin->packet);
}
/*
@@ -2380,14 +2509,14 @@ xlate_normal(struct xlate_ctx *ctx)
xlate_normal_mcast_send_rports(ctx, ms, in_xbundle, vlan);
ovs_rwlock_unlock(&ms->rwlock);
} else {
- xlate_report(ctx, "multicast traffic, flooding");
+ xlate_report(ctx, OFT_DETAIL, "multicast traffic, flooding");
xlate_normal_flood(ctx, in_xbundle, vlan);
}
return;
} else if (is_mld(flow, wc)) {
ctx->xout->slow |= SLOW_ACTION;
if (ctx->xin->allow_side_effects && ctx->xin->packet) {
- update_mcast_snooping_table(ctx->xbridge, flow, vlan,
+ update_mcast_snooping_table(ctx, flow, vlan,
in_xbundle, ctx->xin->packet);
}
if (is_mld_report(flow, wc)) {
@@ -2396,7 +2525,7 @@ xlate_normal(struct xlate_ctx *ctx)
xlate_normal_mcast_send_rports(ctx, ms, in_xbundle, vlan);
ovs_rwlock_unlock(&ms->rwlock);
} else {
- xlate_report(ctx, "MLD query, flooding");
+ xlate_report(ctx, OFT_DETAIL, "MLD query, flooding");
xlate_normal_flood(ctx, in_xbundle, vlan);
}
} else {
@@ -2404,7 +2533,8 @@ xlate_normal(struct xlate_ctx *ctx)
/* RFC4541: section 2.1.2, item 2: Packets with a dst IP
* address in the 224.0.0.x range which are not IGMP must
* be forwarded on all ports */
- xlate_report(ctx, "RFC4541: section 2.1.2, item 2, flooding");
+ xlate_report(ctx, OFT_DETAIL,
+ "RFC4541: section 2.1.2, item 2, flooding");
xlate_normal_flood(ctx, in_xbundle, vlan);
return;
}
@@ -2423,7 +2553,8 @@ xlate_normal(struct xlate_ctx *ctx)
xlate_normal_mcast_send_mrouters(ctx, ms, in_xbundle, vlan);
} else {
if (mcast_snooping_flood_unreg(ms)) {
- xlate_report(ctx, "unregistered multicast, flooding");
+ xlate_report(ctx, OFT_DETAIL,
+ "unregistered multicast, flooding");
xlate_normal_flood(ctx, in_xbundle, vlan);
} else {
xlate_normal_mcast_send_mrouters(ctx, ms, in_xbundle, vlan);
@@ -2441,15 +2572,18 @@ xlate_normal(struct xlate_ctx *ctx)
struct xlate_cfg *xcfg = ovsrcu_get(struct xlate_cfg *, &xcfgp);
struct xbundle *mac_xbundle = xbundle_lookup(xcfg, mac_port);
if (mac_xbundle && mac_xbundle != in_xbundle) {
- xlate_report(ctx, "forwarding to learned port");
+ xlate_report(ctx, OFT_DETAIL, "forwarding to learned port");
output_normal(ctx, mac_xbundle, vlan);
} else if (!mac_xbundle) {
- xlate_report(ctx, "learned port is unknown, dropping");
+ xlate_report(ctx, OFT_WARN,
+ "learned port is unknown, dropping");
} else {
- xlate_report(ctx, "learned port is input port, dropping");
+ xlate_report(ctx, OFT_DETAIL,
+ "learned port is input port, dropping");
}
} else {
- xlate_report(ctx, "no learned MAC for destination, flooding");
+ xlate_report(ctx, OFT_DETAIL,
+ "no learned MAC for destination, flooding");
xlate_normal_flood(ctx, in_xbundle, vlan);
}
}
@@ -2717,8 +2851,7 @@ compose_table_xlate(struct xlate_ctx *ctx, const struct xport *out_dev,
return ofproto_dpif_execute_actions__(xbridge->ofproto,
ctx->xin->tables_version, &flow,
NULL, &output.ofpact, sizeof output,
- ctx->indentation, ctx->depth,
- ctx->resubmits, packet);
+ ctx->depth, ctx->resubmits, packet);
}
static void
@@ -2767,18 +2900,19 @@ build_tunnel_send(struct xlate_ctx *ctx, const struct xport *xport,
err = tnl_route_lookup_flow(flow, &d_ip6, &s_ip6, &out_dev);
if (err) {
- xlate_report(ctx, "native tunnel routing failed");
+ xlate_report(ctx, OFT_WARN, "native tunnel routing failed");
return err;
}
- xlate_report(ctx, "tunneling to %s via %s",
+ xlate_report(ctx, OFT_DETAIL, "tunneling to %s via %s",
ipv6_string_mapped(buf_dip6, &d_ip6),
netdev_get_name(out_dev->netdev));
/* Use mac addr of bridge port of the peer. */
err = netdev_get_etheraddr(out_dev->netdev, &smac);
if (err) {
- xlate_report(ctx, "tunnel output device lacks Ethernet address");
+ xlate_report(ctx, OFT_WARN,
+ "tunnel output device lacks Ethernet address");
return err;
}
@@ -2789,7 +2923,8 @@ build_tunnel_send(struct xlate_ctx *ctx, const struct xport *xport,
err = tnl_neigh_lookup(out_dev->xbridge->name, &d_ip6, &dmac);
if (err) {
- xlate_report(ctx, "neighbor cache miss for %s on bridge %s, "
+ xlate_report(ctx, OFT_DETAIL,
+ "neighbor cache miss for %s on bridge %s, "
"sending %s request",
buf_dip6, out_dev->xbridge->name, d_ip ? "ARP" : "ND");
if (d_ip) {
@@ -2809,7 +2944,7 @@ build_tunnel_send(struct xlate_ctx *ctx, const struct xport *xport,
entry->tnl_neigh_cache.d_ipv6 = d_ip6;
}
- xlate_report(ctx, "tunneling from "ETH_ADDR_FMT" %s"
+ xlate_report(ctx, OFT_DETAIL, "tunneling from "ETH_ADDR_FMT" %s"
" to "ETH_ADDR_FMT" %s",
ETH_ADDR_ARGS(smac), ipv6_string_mapped(buf_sip6, &s_ip6),
ETH_ADDR_ARGS(dmac), buf_dip6);
@@ -2881,38 +3016,42 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
memset(&flow_tnl, 0, sizeof flow_tnl);
if (!xport) {
- xlate_report(ctx, "Nonexistent output port");
+ xlate_report(ctx, OFT_WARN, "Nonexistent output port");
return;
} else if (xport->config & OFPUTIL_PC_NO_FWD) {
- xlate_report(ctx, "OFPPC_NO_FWD set, skipping output");
+ xlate_report(ctx, OFT_DETAIL, "OFPPC_NO_FWD set, skipping output");
return;
} else if (ctx->mirror_snaplen != 0 && xport->odp_port == ODPP_NONE) {
- xlate_report(ctx, "Mirror truncate to ODPP_NONE, skipping output");
+ xlate_report(ctx, OFT_WARN,
+ "Mirror truncate to ODPP_NONE, skipping output");
return;
} else if (xlate_flow_is_protected(ctx, flow, xport)) {
- xlate_report(ctx, "Flow is between protected ports, skipping output.");
+ xlate_report(ctx, OFT_WARN,
+ "Flow is between protected ports, skipping output.");
return;
} else if (check_stp) {
if (is_stp(&ctx->base_flow)) {
if (!xport_stp_should_forward_bpdu(xport) &&
!xport_rstp_should_manage_bpdu(xport)) {
if (ctx->xbridge->stp != NULL) {
- xlate_report(ctx, "STP not in listening state, "
- "skipping bpdu output");
+ xlate_report(ctx, OFT_WARN,
+ "STP not in listening state, "
+ "skipping bpdu output");
} else if (ctx->xbridge->rstp != NULL) {
- xlate_report(ctx, "RSTP not managing BPDU in this state, "
- "skipping bpdu output");
+ xlate_report(ctx, OFT_WARN,
+ "RSTP not managing BPDU in this state, "
+ "skipping bpdu output");
}
return;
}
} else if (!xport_stp_forward_state(xport) ||
!xport_rstp_forward_state(xport)) {
if (ctx->xbridge->stp != NULL) {
- xlate_report(ctx, "STP not in forwarding state, "
- "skipping output");
+ xlate_report(ctx, OFT_WARN,
+ "STP not in forwarding state, skipping output");
} else if (ctx->xbridge->rstp != NULL) {
- xlate_report(ctx, "RSTP not in forwarding state, "
- "skipping output");
+ xlate_report(ctx, OFT_WARN,
+ "RSTP not in forwarding state, skipping output");
}
return;
}
@@ -2928,6 +3067,7 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
struct ofpbuf old_stack = ctx->stack;
union mf_subvalue new_stack[1024 / sizeof(union mf_subvalue)];
struct ofpbuf old_action_set = ctx->action_set;
+ struct ovs_list *old_trace = ctx->xin->trace;
uint64_t actset_stub[1024 / 8];
ofpbuf_use_stub(&ctx->stack, new_stack, sizeof new_stack);
@@ -2942,6 +3082,8 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
flow->actset_output = OFPP_UNSET;
ctx->conntracked = false;
clear_conntrack(flow);
+ ctx->xin->trace = xlate_report(ctx, OFT_BRIDGE,
+ "bridge(\"%s\")", peer->xbridge->name);
/* When the patch port points to a different bridge, then the mirrors
* for that bridge clearly apply independently to the packet, so we
@@ -2993,6 +3135,7 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
}
}
+ ctx->xin->trace = old_trace;
if (independent_mirrors) {
ctx->mirrors = old_mirrors;
}
@@ -3072,12 +3215,12 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
flow_tnl = flow->tunnel;
odp_port = tnl_port_send(xport->ofport, flow, ctx->wc);
if (odp_port == ODPP_NONE) {
- xlate_report(ctx, "Tunneling decided against output");
+ xlate_report(ctx, OFT_WARN, "Tunneling decided against output");
goto out; /* restore flow_nw_tos */
}
dst = flow_tnl_dst(&flow->tunnel);
if (ipv6_addr_equals(&dst, &ctx->orig_tunnel_ipv6_dst)) {
- xlate_report(ctx, "Not tunneling to our own address");
+ xlate_report(ctx, OFT_WARN, "Not tunneling to our own address");
goto out; /* restore flow_nw_tos */
}
if (ctx->xin->resubmit_stats) {
@@ -3091,10 +3234,10 @@ compose_output_action__(struct xlate_ctx *ctx, ofp_port_t ofp_port,
}
out_port = odp_port;
if (ovs_native_tunneling_is_on(ctx->xbridge->ofproto)) {
- xlate_report(ctx, "output to native tunnel");
+ xlate_report(ctx, OFT_DETAIL, "output to native tunnel");
tnl_push_pop_send = true;
} else {
- xlate_report(ctx, "output to kernel tunnel");
+ xlate_report(ctx, OFT_DETAIL, "output to kernel tunnel");
commit_odp_tunnel_action(flow, &ctx->base_flow, ctx->odp_actions);
flow->tunnel = flow_tnl; /* Restore tunnel metadata */
}
@@ -3203,7 +3346,6 @@ xlate_recursively(struct xlate_ctx *ctx, struct rule_dpif *rule, bool deepens)
ctx->resubmits++;
- ctx->indentation++;
ctx->depth += deepens;
ctx->rule = rule;
ctx->rule_cookie = rule->up.flow_cookie;
@@ -3212,24 +3354,23 @@ xlate_recursively(struct xlate_ctx *ctx, struct rule_dpif *rule, bool deepens)
ctx->rule_cookie = old_cookie;
ctx->rule = old_rule;
ctx->depth -= deepens;
- ctx->indentation--;
}
static bool
xlate_resubmit_resource_check(struct xlate_ctx *ctx)
{
if (ctx->depth >= MAX_DEPTH) {
- XLATE_REPORT_ERROR(ctx, "over max translation depth %d", MAX_DEPTH);
+ xlate_report_error(ctx, "over max translation depth %d", MAX_DEPTH);
ctx->error = XLATE_RECURSION_TOO_DEEP;
} else if (ctx->resubmits >= MAX_RESUBMITS) {
- XLATE_REPORT_ERROR(ctx, "over %d resubmit actions", MAX_RESUBMITS);
+ xlate_report_error(ctx, "over %d resubmit actions", MAX_RESUBMITS);
ctx->error = XLATE_TOO_MANY_RESUBMITS;
} else if (ctx->odp_actions->size > UINT16_MAX) {
- XLATE_REPORT_ERROR(ctx, "resubmits yielded over 64 kB of actions");
+ xlate_report_error(ctx, "resubmits yielded over 64 kB of actions");
/* NOT an error, as we'll be slow-pathing the flow in this case? */
ctx->exit = true; /* XXX: translation still terminated! */
} else if (ctx->stack.size >= 65536) {
- XLATE_REPORT_ERROR(ctx, "resubmits yielded over 64 kB of stack");
+ xlate_report_error(ctx, "resubmits yielded over 64 kB of stack");
ctx->error = XLATE_STACK_TOO_DEEP;
} else {
return true;
@@ -3260,9 +3401,6 @@ xlate_table_action(struct xlate_ctx *ctx, ofp_port_t in_port, uint8_t table_id,
&ctx->table_id, in_port,
may_packet_in, honor_table_miss,
ctx->xin->xcache);
- if (OVS_UNLIKELY(ctx->xin->resubmit_hook)) {
- ctx->xin->resubmit_hook(ctx->xin, rule, ctx->indentation + 1);
- }
if (rule) {
/* Fill in the cache entry here instead of xlate_recursively
@@ -3276,7 +3414,11 @@ xlate_table_action(struct xlate_ctx *ctx, ofp_port_t in_port, uint8_t table_id,
entry->rule = rule;
ofproto_rule_ref(&rule->up);
}
+
+ struct ovs_list *old_trace = ctx->xin->trace;
+ xlate_report_table(ctx, rule, table_id);
xlate_recursively(ctx, rule, table_id <= old_table_id);
+ ctx->xin->trace = old_trace;
}
ctx->table_id = old_table_id;
@@ -3312,11 +3454,9 @@ xlate_group_bucket(struct xlate_ctx *ctx, struct ofputil_bucket *bucket)
bool old_was_mpls = ctx->was_mpls;
ofpacts_execute_action_set(&action_list, &action_set);
- ctx->indentation++;
ctx->depth++;
do_xlate_actions(action_list.data, action_list.size, ctx);
ctx->depth--;
- ctx->indentation--;
ofpbuf_uninit(&action_list);
@@ -3531,6 +3671,8 @@ xlate_group_action(struct xlate_ctx *ctx, uint32_t group_id)
ctx->xin->tables_version, ctx->xin->xcache);
if (!group) {
/* XXX: Should set ctx->error ? */
+ xlate_report(ctx, OFT_WARN, "output to nonexistent group %"PRIu32,
+ group_id);
return true;
}
xlate_group_action__(ctx, group);
@@ -3744,7 +3886,7 @@ finish_freezing__(struct xlate_ctx *ctx, uint8_t table)
* with the udpif key ('ukey') created for each new datapath flow. */
uint32_t id = recirc_alloc_id_ctx(&state);
if (!id) {
- XLATE_REPORT_ERROR(ctx, "Failed to allocate recirculation id");
+ xlate_report_error(ctx, "Failed to allocate recirculation id");
ctx->error = XLATE_NO_RECIRCULATION_CONTEXT;
return;
}
@@ -3799,10 +3941,10 @@ compose_mpls_push_action(struct xlate_ctx *ctx, struct ofpact_push_mpls *mpls)
xlate_commit_actions(ctx);
} else if (n >= FLOW_MAX_MPLS_LABELS) {
if (ctx->xin->packet != NULL) {
- XLATE_REPORT_ERROR(ctx, "bridge %s: dropping packet on which an "
- "MPLS push action can't be performed as it would "
- "have more MPLS LSEs than the %d supported.",
- ctx->xbridge->name, FLOW_MAX_MPLS_LABELS);
+ xlate_report_error(ctx, "dropping packet on which an MPLS push "
+ "action can't be performed as it would have "
+ "more MPLS LSEs than the %d supported.",
+ FLOW_MAX_MPLS_LABELS);
}
ctx->error = XLATE_TOO_MANY_MPLS_LABELS;
return;
@@ -3824,10 +3966,10 @@ compose_mpls_pop_action(struct xlate_ctx *ctx, ovs_be16 eth_type)
}
} else if (n >= FLOW_MAX_MPLS_LABELS) {
if (ctx->xin->packet != NULL) {
- XLATE_REPORT_ERROR(ctx, "bridge %s: dropping packet on which an "
- "MPLS pop action can't be performed as it has "
- "more MPLS LSEs than the %d supported.",
- ctx->xbridge->name, FLOW_MAX_MPLS_LABELS);
+ xlate_report_error(ctx, "dropping packet on which an "
+ "MPLS pop action can't be performed as it has "
+ "more MPLS LSEs than the %d supported.",
+ FLOW_MAX_MPLS_LABELS);
}
ctx->error = XLATE_TOO_MANY_MPLS_LABELS;
ofpbuf_clear(ctx->odp_actions);
@@ -3856,6 +3998,8 @@ compose_dec_ttl(struct xlate_ctx *ctx, struct ofpact_cnt_ids *ids)
}
/* Stop processing for current table. */
+ xlate_report(ctx, OFT_WARN, "IPv%d decrement TTL exception",
+ flow->dl_type == htons(ETH_TYPE_IP) ? 4 : 6);
return true;
}
}
@@ -3907,6 +4051,7 @@ compose_dec_mpls_ttl_action(struct xlate_ctx *ctx)
}
/* Stop processing for current table. */
+ xlate_report(ctx, OFT_WARN, "MPLS decrement TTL exception");
return true;
}
@@ -3949,7 +4094,7 @@ xlate_output_action(struct xlate_ctx *ctx,
if (port != ctx->xin->flow.in_port.ofp_port) {
compose_output_action(ctx, port, NULL);
} else {
- xlate_report(ctx, "skipping output to input port");
+ xlate_report(ctx, OFT_WARN, "skipping output to input port");
}
break;
}
@@ -3970,12 +4115,16 @@ xlate_output_reg_action(struct xlate_ctx *ctx,
{
uint64_t port = mf_get_subfield(&or->src, &ctx->xin->flow);
if (port <= UINT16_MAX) {
+ xlate_report(ctx, OFT_DETAIL, "output port is %"PRIu64, port);
+
union mf_subvalue value;
memset(&value, 0xff, sizeof value);
mf_write_subfield_flow(&or->src, &value, &ctx->wc->masks);
- xlate_output_action(ctx, u16_to_ofp(port),
- or->max_len, false);
+ xlate_output_action(ctx, u16_to_ofp(port), or->max_len, false);
+ } else {
+ xlate_report(ctx, OFT_WARN, "output port %"PRIu64" is out of range",
+ port);
}
}
@@ -3995,7 +4144,8 @@ xlate_output_trunc_action(struct xlate_ctx *ctx,
case OFPP_CONTROLLER:
case OFPP_NONE:
ofputil_port_to_string(port, name, sizeof name);
- xlate_report(ctx, "output_trunc does not support port: %s", name);
+ xlate_report(ctx, OFT_WARN,
+ "output_trunc does not support port: %s", name);
break;
case OFPP_LOCAL:
case OFPP_IN_PORT:
@@ -4008,9 +4158,8 @@ xlate_output_trunc_action(struct xlate_ctx *ctx,
* the output port is a patch port, the behavior is somehow
* unpredicable. For simpilicity, disallow this case. */
ofputil_port_to_string(port, name, sizeof name);
- XLATE_REPORT_ERROR(ctx, "bridge %s: "
- "output_trunc does not support port: %s",
- ctx->xbridge->name, name);
+ xlate_report_error(ctx, "output_trunc does not support "
+ "patch port %s", name);
break;
}
@@ -4023,7 +4172,7 @@ xlate_output_trunc_action(struct xlate_ctx *ctx,
ctx->xout->slow |= SLOW_ACTION;
}
} else {
- xlate_report(ctx, "skipping output to input port");
+ xlate_report(ctx, OFT_WARN, "skipping output to input port");
}
break;
}
@@ -4112,6 +4261,7 @@ xlate_bundle_action(struct xlate_ctx *ctx,
CONST_CAST(struct xbridge *, ctx->xbridge));
if (bundle->dst.field) {
nxm_reg_load(&bundle->dst, ofp_to_u16(port), &ctx->xin->flow, ctx->wc);
+ xlate_report_subfield(ctx, &bundle->dst);
} else {
xlate_output_action(ctx, port, 0, false);
}
@@ -4141,6 +4291,29 @@ xlate_learn_action(struct xlate_ctx *ctx, const struct ofpact_learn *learn)
ofpbuf_use_stub(&ofpacts, ofpacts_stub, sizeof ofpacts_stub);
learn_execute(learn, &ctx->xin->flow, &fm, &ofpacts);
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
+ struct ds s = DS_EMPTY_INITIALIZER;
+ ds_put_format(&s, "table=%"PRIu8" ", fm.table_id);
+ match_format(&fm.match, &s, OFP_DEFAULT_PRIORITY);
+ ds_chomp(&s, ' ');
+ ds_put_format(&s, " priority=%d", fm.priority);
+ if (fm.new_cookie) {
+ ds_put_format(&s, " cookie=%#"PRIx64, ntohll(fm.new_cookie));
+ }
+ if (fm.idle_timeout != OFP_FLOW_PERMANENT) {
+ ds_put_format(&s, " idle=%"PRIu16, fm.idle_timeout);
+ }
+ if (fm.hard_timeout != OFP_FLOW_PERMANENT) {
+ ds_put_format(&s, " hard=%"PRIu16, fm.hard_timeout);
+ }
+ if (fm.flags & NX_LEARN_F_SEND_FLOW_REM) {
+ ds_put_cstr(&s, " send_flow_rem");
+ }
+ ds_put_cstr(&s, " actions=");
+ ofpacts_format(fm.ofpacts, fm.ofpacts_len, &s);
+ xlate_report(ctx, OFT_DETAIL, "%s", ds_cstr(&s));
+ ds_destroy(&s);
+ }
error = ofproto_dpif_flow_mod_init_for_learn(ctx->xbridge->ofproto,
&fm, ofm);
ofpbuf_uninit(&ofpacts);
@@ -4150,10 +4323,12 @@ xlate_learn_action(struct xlate_ctx *ctx, const struct ofpact_learn *learn)
}
if (error) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "%s: LEARN action execution failed (%s).",
- ctx->xbridge->name, ofperr_to_string(error));
+ xlate_report_error(ctx, "LEARN action execution failed (%s).",
+ ofperr_to_string(error));
}
+ } else {
+ xlate_report(ctx, OFT_WARN,
+ "suppressing side effects, so learn action ignored");
}
}
@@ -4206,11 +4381,9 @@ xlate_sample_action(struct xlate_ctx *ctx,
uint32_t probability = (os->probability << 16) | os->probability;
if (!ctx->xbridge->support.variable_length_userdata) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
-
- VLOG_ERR_RL(&rl, "ignoring NXAST_SAMPLE action because datapath "
- "lacks support (needs Linux 3.10+ or kernel module from "
- "OVS 1.11+)");
+ xlate_report_error(ctx, "ignoring NXAST_SAMPLE action because "
+ "datapath lacks support (needs Linux 3.10+ or "
+ "kernel module from OVS 1.11+)");
return;
}
@@ -4221,9 +4394,8 @@ xlate_sample_action(struct xlate_ctx *ctx,
output_odp_port = ofp_port_to_odp_port(ctx->xbridge,
os->sampling_port);
if (output_odp_port == ODPP_NONE) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- VLOG_WARN_RL(&rl, "can't use unknown port %d in flow sample "
- "action", os->sampling_port);
+ xlate_report_error(ctx, "can't use unknown port %d in flow sample "
+ "action", os->sampling_port);
return;
}
@@ -4254,9 +4426,9 @@ xlate_sample_action(struct xlate_ctx *ctx,
flow->tunnel = flow_tnl;
}
} else {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- VLOG_WARN_RL(&rl, "sampling_port:%d should be a tunnel port.",
- os->sampling_port);
+ xlate_report_error(ctx,
+ "sampling_port:%d should be a tunnel port.",
+ os->sampling_port);
}
}
@@ -4342,16 +4514,22 @@ xlate_write_actions(struct xlate_ctx *ctx, const struct ofpact_nest *a)
static void
xlate_action_set(struct xlate_ctx *ctx)
{
- uint64_t action_list_stub[1024 / 64];
- struct ofpbuf action_list;
-
- ctx->in_action_set = true;
- ofpbuf_use_stub(&action_list, action_list_stub, sizeof action_list_stub);
+ uint64_t action_list_stub[1024 / 8];
+ struct ofpbuf action_list = OFPBUF_STUB_INITIALIZER(action_list_stub);
ofpacts_execute_action_set(&action_list, &ctx->action_set);
/* Clear the action set, as it is not needed any more. */
ofpbuf_clear(&ctx->action_set);
- do_xlate_actions(action_list.data, action_list.size, ctx);
- ctx->in_action_set = false;
+ if (action_list.size) {
+ ctx->in_action_set = true;
+
+ struct ovs_list *old_trace = ctx->xin->trace;
+ ctx->xin->trace = xlate_report(ctx, OFT_TABLE,
+ "--. Executing action set:");
+ do_xlate_actions(action_list.data, action_list.size, ctx);
+ ctx->xin->trace = old_trace;
+
+ ctx->in_action_set = false;
+ }
ofpbuf_uninit(&action_list);
}
@@ -4494,13 +4672,14 @@ put_ct_label(const struct flow *flow, struct ofpbuf *odp_actions,
}
static void
-put_ct_helper(struct ofpbuf *odp_actions, struct ofpact_conntrack *ofc)
+put_ct_helper(struct xlate_ctx *ctx,
+ struct ofpbuf *odp_actions, struct ofpact_conntrack *ofc)
{
if (ofc->alg) {
if (ofc->alg == IPPORT_FTP) {
nl_msg_put_string(odp_actions, OVS_CT_ATTR_HELPER, "ftp");
} else {
- VLOG_WARN("Cannot serialize ct_helper %d\n", ofc->alg);
+ xlate_report_error(ctx, "cannot serialize ct_helper %d", ofc->alg);
}
}
}
@@ -4594,7 +4773,7 @@ compose_conntrack_action(struct xlate_ctx *ctx, struct ofpact_conntrack *ofc)
nl_msg_put_u16(ctx->odp_actions, OVS_CT_ATTR_ZONE, zone);
put_ct_mark(&ctx->xin->flow, ctx->odp_actions, ctx->wc);
put_ct_label(&ctx->xin->flow, ctx->odp_actions, ctx->wc);
- put_ct_helper(ctx->odp_actions, ofc);
+ put_ct_helper(ctx, ctx->odp_actions, ofc);
put_ct_nat(ctx);
ctx->ct_nat_action = NULL;
nl_msg_end_nested(ctx->odp_actions, ct_offset);
@@ -4709,6 +4888,34 @@ recirc_for_mpls(const struct ofpact *a, struct xlate_ctx *ctx)
}
static void
+xlate_ofpact_reg_move(struct xlate_ctx *ctx, const struct ofpact_reg_move *a)
+{
+ mf_subfield_copy(&a->src, &a->dst, &ctx->xin->flow, ctx->wc);
+ xlate_report_subfield(ctx, &a->dst);
+}
+
+static void
+xlate_ofpact_stack_pop(struct xlate_ctx *ctx, const struct ofpact_stack *a)
+{
+ if (nxm_execute_stack_pop(a, &ctx->xin->flow, ctx->wc, &ctx->stack)) {
+ xlate_report_subfield(ctx, &a->subfield);
+ } else {
+ xlate_report_error(ctx, "stack underflow");
+ }
+}
+
+/* Restore translation context data that was stored earlier. */
+static void
+xlate_ofpact_unroll_xlate(struct xlate_ctx *ctx,
+ const struct ofpact_unroll_xlate *a)
+{
+ ctx->table_id = a->rule_table_id;
+ ctx->rule_cookie = a->rule_cookie;
+ xlate_report(ctx, OFT_THAW, "restored state: table=%"PRIu8", "
+ "cookie=%#"PRIx64, a->rule_table_id, a->rule_cookie);
+}
+
+static void
do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
struct xlate_ctx *ctx)
{
@@ -4721,6 +4928,11 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
}
/* dl_type already in the mask, not set below. */
+ if (!ofpacts_len) {
+ xlate_report(ctx, OFT_ACTION, "drop");
+ return;
+ }
+
OFPACT_FOR_EACH (a, ofpacts, ofpacts_len) {
struct ofpact_controller *controller;
const struct ofpact_metadata *metadata;
@@ -4743,6 +4955,13 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
break;
}
+ if (OVS_UNLIKELY(ctx->xin->trace)) {
+ struct ds s = DS_EMPTY_INITIALIZER;
+ ofpacts_format(a, OFPACT_ALIGN(a->len), &s);
+ xlate_report(ctx, OFT_ACTION, "%s", ds_cstr(&s));
+ ds_destroy(&s);
+ }
+
switch (a->type) {
case OFPACT_OUTPUT:
xlate_output_action(ctx, ofpact_get_OUTPUT(a)->port,
@@ -4899,12 +5118,15 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
case OFPACT_POP_QUEUE:
memset(&wc->masks.skb_priority, 0xff,
sizeof wc->masks.skb_priority);
- flow->skb_priority = ctx->orig_skb_priority;
+ if (flow->skb_priority != ctx->orig_skb_priority) {
+ flow->skb_priority = ctx->orig_skb_priority;
+ xlate_report(ctx, OFT_DETAIL, "queue = %#"PRIx32,
+ flow->skb_priority);
+ }
break;
case OFPACT_REG_MOVE:
- mf_subfield_copy(&ofpact_get_REG_MOVE(a)->src,
- &ofpact_get_REG_MOVE(a)->dst, flow, wc);
+ xlate_ofpact_reg_move(ctx, ofpact_get_REG_MOVE(a));
break;
case OFPACT_SET_FIELD:
@@ -4917,6 +5139,11 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
mf_set_flow_value_masked(mf, set_field->value,
ofpact_set_field_mask(set_field),
flow);
+ } else {
+ xlate_report(ctx, OFT_WARN,
+ "unmet prerequisites for %s, set_field ignored",
+ mf->name);
+
}
break;
@@ -4926,8 +5153,7 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
break;
case OFPACT_STACK_POP:
- nxm_execute_stack_pop(ofpact_get_STACK_POP(a), flow, wc,
- &ctx->stack);
+ xlate_ofpact_stack_pop(ctx, ofpact_get_STACK_POP(a));
break;
case OFPACT_PUSH_MPLS:
@@ -4970,6 +5196,7 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
case OFPACT_MULTIPATH:
multipath_execute(ofpact_get_MULTIPATH(a), flow, wc);
+ xlate_report_subfield(ctx, &ofpact_get_MULTIPATH(a)->dst);
break;
case OFPACT_BUNDLE:
@@ -4989,34 +5216,29 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
xlate_learn_action(ctx, ofpact_get_LEARN(a));
break;
- case OFPACT_CONJUNCTION: {
+ case OFPACT_CONJUNCTION:
/* A flow with a "conjunction" action represents part of a special
* kind of "set membership match". Such a flow should not actually
* get executed, but it could via, say, a "packet-out", even though
* that wouldn't be useful. Log it to help debugging. */
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- VLOG_INFO_RL(&rl, "executing no-op conjunction action");
+ xlate_report_error(ctx, "executing no-op conjunction action");
break;
- }
case OFPACT_EXIT:
ctx->exit = true;
break;
- case OFPACT_UNROLL_XLATE: {
- struct ofpact_unroll_xlate *unroll = ofpact_get_UNROLL_XLATE(a);
-
- /* Restore translation context data that was stored earlier. */
- ctx->table_id = unroll->rule_table_id;
- ctx->rule_cookie = unroll->rule_cookie;
+ case OFPACT_UNROLL_XLATE:
+ xlate_ofpact_unroll_xlate(ctx, ofpact_get_UNROLL_XLATE(a));
break;
- }
+
case OFPACT_FIN_TIMEOUT:
memset(&wc->masks.nw_proto, 0xff, sizeof wc->masks.nw_proto);
xlate_fin_timeout(ctx, ofpact_get_FIN_TIMEOUT(a));
break;
case OFPACT_CLEAR_ACTIONS:
+ xlate_report_action_set(ctx, "was");
ofpbuf_clear(&ctx->action_set);
ctx->xin->flow.actset_output = OFPP_UNSET;
ctx->action_set_has_group = false;
@@ -5024,6 +5246,7 @@ do_xlate_actions(const struct ofpact *ofpacts, size_t ofpacts_len,
case OFPACT_WRITE_ACTIONS:
xlate_write_actions(ctx, ofpact_get_WRITE_ACTIONS(a));
+ xlate_report_action_set(ctx, "is");
break;
case OFPACT_WRITE_METADATA:
@@ -5098,10 +5321,8 @@ xlate_in_init(struct xlate_in *xin, struct ofproto_dpif *ofproto,
xin->ofpacts = NULL;
xin->ofpacts_len = 0;
xin->tcp_flags = tcp_flags;
- xin->resubmit_hook = NULL;
- xin->report_hook = NULL;
+ xin->trace = NULL;
xin->resubmit_stats = NULL;
- xin->indentation = 0;
xin->depth = 0;
xin->resubmits = 0;
xin->wc = wc;
@@ -5360,7 +5581,6 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
: &(struct flow_wildcards) { .masks = { .dl_type = 0 } }),
.odp_actions = xin->odp_actions ? xin->odp_actions : &scratch_actions,
- .indentation = xin->indentation,
.depth = xin->depth,
.resubmits = xin->resubmits,
.in_group = false,
@@ -5403,17 +5623,17 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
COVERAGE_INC(xlate_actions);
+ xin->trace = xlate_report(&ctx, OFT_BRIDGE, "bridge(\"%s\")",
+ xbridge->name);
if (xin->frozen_state) {
const struct frozen_state *state = xin->frozen_state;
- xlate_report(&ctx, "Thawing frozen state:");
+ struct ovs_list *old_trace = xin->trace;
+ xin->trace = xlate_report(&ctx, OFT_THAW, "thaw");
if (xin->ofpacts_len > 0 || ctx.rule) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- const char *conflict = xin->ofpacts_len ? "actions" : "rule";
-
- VLOG_WARN_RL(&rl, "Recirculation conflict (%s)!", conflict);
- xlate_report(&ctx, "- Recirculation conflict (%s)!", conflict);
+ xlate_report_error(&ctx, "Recirculation conflict (%s)!",
+ xin->ofpacts_len ? "actions" : "rule");
ctx.error = XLATE_RECIRCULATION_CONFLICT;
goto exit;
}
@@ -5426,10 +5646,9 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
if (OVS_UNLIKELY(!new_bridge)) {
/* Drop the packet if the bridge cannot be found. */
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- VLOG_WARN_RL(&rl, "Frozen bridge no longer exists.");
- xlate_report(&ctx, "- Frozen bridge no longer exists.");
+ xlate_report_error(&ctx, "Frozen bridge no longer exists.");
ctx.error = XLATE_BRIDGE_NOT_FOUND;
+ xin->trace = old_trace;
goto exit;
}
ctx.xbridge = new_bridge;
@@ -5441,7 +5660,8 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
/* Set the thawed table id. Note: A table lookup is done only if there
* are no frozen actions. */
ctx.table_id = state->table_id;
- xlate_report(&ctx, "- Resuming from table %"PRIu8, ctx.table_id);
+ xlate_report(&ctx, OFT_THAW,
+ "Resuming from table %"PRIu8, ctx.table_id);
if (!state->conntracked) {
clear_conntrack(flow);
@@ -5462,7 +5682,7 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
/* Restore action set, if any. */
if (state->action_set_len) {
- xlate_report_actions(&ctx, "- Restoring action set",
+ xlate_report_actions(&ctx, OFT_THAW, "Restoring action set",
state->action_set, state->action_set_len);
flow->actset_output = OFPP_UNSET;
@@ -5475,14 +5695,15 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
xin->ofpacts = state->ofpacts;
xin->ofpacts_len = state->ofpacts_len;
if (state->ofpacts_len) {
- xlate_report_actions(&ctx, "- Restoring actions",
+ xlate_report_actions(&ctx, OFT_THAW, "Restoring actions",
xin->ofpacts, xin->ofpacts_len);
}
- } else if (OVS_UNLIKELY(flow->recirc_id)) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 1);
- VLOG_WARN_RL(&rl, "Recirculation context not found for ID %"PRIx32,
- flow->recirc_id);
+ xin->trace = old_trace;
+ } else if (OVS_UNLIKELY(flow->recirc_id)) {
+ xlate_report_error(&ctx,
+ "Recirculation context not found for ID %"PRIx32,
+ flow->recirc_id);
ctx.error = XLATE_NO_RECIRCULATION_CONTEXT;
goto exit;
}
@@ -5497,7 +5718,7 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
&xin->upcall_flow->tunnel,
&flow->tunnel);
if (err) {
- XLATE_REPORT_ERROR(&ctx, "Invalid Geneve tunnel metadata");
+ xlate_report_error(&ctx, "Invalid Geneve tunnel metadata");
ctx.error = XLATE_INVALID_TUNNEL_METADATA;
goto exit;
}
@@ -5525,9 +5746,7 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
ofproto_rule_ref(&ctx.rule->up);
}
- if (OVS_UNLIKELY(ctx.xin->resubmit_hook)) {
- ctx.xin->resubmit_hook(ctx.xin, ctx.rule, 0);
- }
+ xlate_report_table(&ctx, ctx.rule, ctx.table_id);
}
/* Get the proximate input port of the packet. (If xin->frozen_state,
@@ -5559,12 +5778,9 @@ xlate_actions(struct xlate_in *xin, struct xlate_out *xout)
* was done before they were frozen and should not be redone. */
} else if (in_port && in_port->xbundle
&& xbundle_mirror_out(xbridge, in_port->xbundle)) {
- if (ctx.xin->packet != NULL) {
- static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
- VLOG_WARN_RL(&rl, "bridge %s: dropping packet received on port "
- "%s, which is reserved exclusively for mirroring",
- ctx.xbridge->name, in_port->xbundle->name);
- }
+ xlate_report_error(&ctx, "dropping packet received on port "
+ "%s, which is reserved exclusively for mirroring",
+ in_port->xbundle->name);
} else {
/* Sampling is done on initial reception; don't redo after thawing. */
unsigned int user_cookie_offset = 0;
@@ -5833,10 +6049,10 @@ xlate_mac_learning_update(const struct ofproto_dpif *ofproto,
return;
}
- xbundle = lookup_input_bundle(xbridge, in_port, false, NULL);
+ xbundle = lookup_input_bundle__(xbridge, in_port, NULL);
if (!xbundle) {
return;
}
- update_learning_table(xbridge, xbundle, dl_src, vlan, is_grat_arp);
+ update_learning_table__(xbridge, xbundle, dl_src, vlan, is_grat_arp);
}
diff --git a/ofproto/ofproto-dpif-xlate.h b/ofproto/ofproto-dpif-xlate.h
index 51c05ac..fa2b130 100644
--- a/ofproto/ofproto-dpif-xlate.h
+++ b/ofproto/ofproto-dpif-xlate.h
@@ -83,27 +83,10 @@ struct xlate_in {
* timeouts.) */
uint16_t tcp_flags;
- /* If nonnull, flow translation calls this function just before executing a
- * resubmit or OFPP_TABLE action. In addition, disables logging of traces
- * when the recursion depth is exceeded.
- *
- * 'rule' is the rule being submitted into. It will be null if the
- * resubmit or OFPP_TABLE action didn't find a matching rule.
- *
- * 'indentation' is the resubmit recursion depth at time of invocation,
- * suitable for indenting the output.
- *
- * This is normally null so the client has to set it manually after
- * calling xlate_in_init(). */
- void (*resubmit_hook)(struct xlate_in *, struct rule_dpif *rule,
- int indentation);
-
- /* If nonnull, flow translation calls this function to report some
- * significant decision, e.g. to explain why OFPP_NORMAL translation
- * dropped a packet. 'indentation' is the resubmit recursion depth at time
- * of invocation, suitable for indenting the output. */
- void (*report_hook)(struct xlate_in *, int indentation,
- const char *format, va_list args);
+ /* If nonnull, this indicates that the translation is being traced. It
+ * points to the list of oftrace nodes to which the translation should add
+ * tracing information (with oftrace_node_append()). */
+ struct ovs_list *trace;
/* If nonnull, flow translation credits the specified statistics to each
* rule reached through a resubmit or OFPP_TABLE action.
@@ -127,7 +110,6 @@ struct xlate_in {
* These fields are really implementation details; the client doesn't care
* about what they mean. See the corresponding fields in xlate_ctx for
* real documentation. */
- int indentation;
int depth;
int resubmits;
diff --git a/ofproto/ofproto-dpif.c b/ofproto/ofproto-dpif.c
index 3b036a1..3b274ee 100644
--- a/ofproto/ofproto-dpif.c
+++ b/ofproto/ofproto-dpif.c
@@ -3600,7 +3600,7 @@ ofproto_dpif_execute_actions__(struct ofproto_dpif *ofproto,
ovs_version_t version, const struct flow *flow,
struct rule_dpif *rule,
const struct ofpact *ofpacts, size_t ofpacts_len,
- int indentation, int depth, int resubmits,
+ int depth, int resubmits,
struct dp_packet *packet)
{
struct dpif_flow_stats stats;
@@ -3624,7 +3624,6 @@ ofproto_dpif_execute_actions__(struct ofproto_dpif *ofproto,
xin.ofpacts = ofpacts;
xin.ofpacts_len = ofpacts_len;
xin.resubmit_stats = &stats;
- xin.indentation = indentation;
xin.depth = depth;
xin.resubmits = resubmits;
if (xlate_actions(&xin, &xout) != XLATE_OK) {
@@ -3663,8 +3662,7 @@ ofproto_dpif_execute_actions(struct ofproto_dpif *ofproto,
struct dp_packet *packet)
{
return ofproto_dpif_execute_actions__(ofproto, version, flow, rule,
- ofpacts, ofpacts_len, 0, 0, 0,
- packet);
+ ofpacts, ofpacts_len, 0, 0, packet);
}
static void
diff --git a/ofproto/ofproto-dpif.h b/ofproto/ofproto-dpif.h
index d62c730..c4f7baa 100644
--- a/ofproto/ofproto-dpif.h
+++ b/ofproto/ofproto-dpif.h
@@ -288,7 +288,7 @@ int ofproto_dpif_execute_actions(struct ofproto_dpif *, ovs_version_t,
int ofproto_dpif_execute_actions__(struct ofproto_dpif *, ovs_version_t,
const struct flow *, struct rule_dpif *,
const struct ofpact *, size_t ofpacts_len,
- int indentation, int depth, int resubmits,
+ int depth, int resubmits,
struct dp_packet *);
void ofproto_dpif_send_async_msg(struct ofproto_dpif *,
struct ofproto_async_msg *);
diff --git a/tests/ofproto-dpif.at b/tests/ofproto-dpif.at
index 5f594be..6ecc007 100644
--- a/tests/ofproto-dpif.at
+++ b/tests/ofproto-dpif.at
@@ -3823,7 +3823,7 @@ do
AT_CHECK([ovs-appctl ofproto/trace ovs-dummy "$flow"], [0], [stdout])
: > expout
if test $mode = drop && test $type != no; then
- echo 'Packets dropped because they are IP fragments and the fragment handling mode is "drop".' >> expout
+ echo ' 0. Packets are IP fragments and the fragment handling mode is "drop".' >> expout
echo "Datapath actions: $exp_output" >> expout
elif test $type = later; then
echo "Datapath actions: $exp_output" >> expout
@@ -4873,9 +4873,10 @@ AT_CHECK([ovs-appctl ofproto/trace \
AT_CHECK([tail -1 stdout], [0], [dnl
Datapath actions: 2
])
-AT_CHECK([head -n 2 stdout], [0], [dnl
-Bridge: br0
+AT_CHECK([head -n 3 stdout], [0], [dnl
Flow: pkt_mark=0x2,skb_priority=0x1,arp,in_port=1,vlan_tci=0x0000,dl_src=50:54:00:00:00:01,dl_dst=50:54:00:00:00:02,arp_spa=0.0.0.0,arp_tpa=0.0.0.0,arp_op=0,arp_sha=00:00:00:00:00:00,arp_tha=00:00:00:00:00:00
+
+bridge("br0")
])
# Test command: ofproto/trace dp_name odp_flow packet
@@ -4884,9 +4885,10 @@ AT_CHECK([ovs-appctl ofproto/trace ovs-dummy \
AT_CHECK([tail -1 stdout], [0], [dnl
Datapath actions: 2
])
-AT_CHECK([head -n 2 stdout], [0], [dnl
-Bridge: br0
+AT_CHECK([head -n 3 stdout], [0], [dnl
Flow: pkt_mark=0x2,skb_priority=0x1,arp,in_port=1,vlan_tci=0x0000,dl_src=50:54:00:00:00:01,dl_dst=50:54:00:00:00:02,arp_spa=0.0.0.0,arp_tpa=0.0.0.0,arp_op=0,arp_sha=00:00:00:00:00:00,arp_tha=00:00:00:00:00:00
+
+bridge("br0")
])
# Test command: ofproto/trace br_name br_flow packet
@@ -4895,9 +4897,10 @@ AT_CHECK([ovs-appctl ofproto/trace br0 \
AT_CHECK([tail -1 stdout], [0], [dnl
Datapath actions: 1
])
-AT_CHECK([head -n 2 stdout], [0], [dnl
-Bridge: br0
+AT_CHECK([head -n 3 stdout], [0], [dnl
Flow: pkt_mark=0x1,skb_priority=0x2,arp,in_port=2,vlan_tci=0x0000,dl_src=50:54:00:00:00:02,dl_dst=50:54:00:00:00:01,arp_spa=0.0.0.0,arp_tpa=0.0.0.0,arp_op=0,arp_sha=00:00:00:00:00:00,arp_tha=00:00:00:00:00:00
+
+bridge("br0")
])
OVS_VSWITCHD_STOP
@@ -5032,12 +5035,12 @@ AT_CHECK([ovs-appctl dpif/dump-flows -m br0 | sed 's/, packets.*$//' > dp_flows1
odp_flow=`cat dp_flows1.txt`
AT_CHECK([ovs-appctl ofproto/trace "$odp_flow" | sed 's/\([[Ff]]low:\).*/\1 <cleared>/'], [0], [dnl
-Bridge: br0
Flow: <cleared>
-No match, packets dropped because OFPPC_NO_PACKET_IN is set on in_port.
-Rule: table=254 cookie=0 priority=0,reg0=0x2
-OpenFlow actions=drop
+bridge("br0")
+-------------
+ 0. No match.
+ drop
Final flow: <cleared>
Megaflow: <cleared>
@@ -5053,12 +5056,12 @@ AT_CHECK([ovs-appctl dpif/dump-flows -m br0 | sed 's/, packets.*$//' > dp_flows2
odp_flow=`cat dp_flows2.txt`
AT_CHECK([ovs-appctl ofproto/trace "$odp_flow" | sed 's/\([[Ff]]low:\).*/\1 <cleared>/'], [0], [dnl
-Bridge: br0
Flow: <cleared>
-No match, packets dropped because OFPPC_NO_PACKET_IN is set on in_port.
-Rule: table=254 cookie=0 priority=0,reg0=0x2
-OpenFlow actions=drop
+bridge("br0")
+-------------
+ 0. No match.
+ drop
Final flow: <cleared>
Megaflow: <cleared>
@@ -5728,7 +5731,7 @@ AT_CHECK([ovs-appctl ofproto/trace br0 in_port=LOCAL,dl_src=10:20:30:40:50:60],
AT_CHECK([tail -1 stdout], [0], [Datapath actions: 2
])
dnl the output(port=1,max_len=100) fails the translation, only output:2 in datapath
-AT_CHECK([grep "output_trunc does not support port: [[0-9]]*" stdout], [0], [stdout])
+AT_CHECK([grep "output_trunc does not support patch port [[0-9]]*" stdout], [0], [stdout])
OVS_VSWITCHD_STOP
AT_CLEANUP
@@ -7125,11 +7128,11 @@ AT_CHECK([strip_ufid < ovs-vswitchd.log | filter_flow_install | strip_used], [0]
recirc_id(0),in_port(100),eth_type(0x0800),ipv4(src=192.168.0.1,frag=no), actions:101,set(ipv4(src=255.255.255.254)),2
])
-AT_CHECK([grep -e '|nx_match|WARN|' ovs-vswitchd.log | sed "s/^.*|WARN|//"], [0], [dnl
-Failed to pop from an empty stack. On flow
+AT_CHECK([grep -e '|ofproto_dpif_xlate|WARN|' ovs-vswitchd.log | sed "s/^.*|WARN|//"], [0], [dnl
+stack underflow while processing icmp,in_port=LOCAL,vlan_tci=0x0000,dl_src=50:54:00:00:00:05,dl_dst=50:54:00:00:00:07,nw_src=192.168.0.1,nw_dst=192.168.0.2,nw_tos=0,nw_ecn=0,nw_ttl=64,icmp_type=8,icmp_code=0 on bridge br1
])
-OVS_VSWITCHD_STOP(["/Failed to pop from an empty stack/d"])
+OVS_VSWITCHD_STOP(["/stack underflow/d"])
AT_CLEANUP
AT_SETUP([ofproto-dpif - port duration])
diff --git a/tests/ovn.at b/tests/ovn.at
index 3779741..1b69f84 100644
--- a/tests/ovn.at
+++ b/tests/ovn.at
@@ -2298,7 +2298,7 @@ test_arp() {
local request=ffffffffffff${sha}08060001080006040001${sha}${spa}ffffffffffff${tpa}
hv=hv`vif_to_hv $inport`
as $hv ovs-appctl netdev-dummy/receive vif$inport $request
- #as $hv ovs-appctl ofproto/trace br-int in_port=$inport $request
+ as $hv ovs-appctl ofproto/trace br-int in_port=$inport $request
# Expect to receive the broadcast ARP on the other logical switch ports if
# IP address is not configured to the switch patch port.
@@ -5964,7 +5964,7 @@ src_ip=`ip_to_hex 192 168 1 2`
dst_ip=`ip_to_hex 172 16 1 3`
packet=${dst_mac}${src_mac}08004500001c0000000040110000${src_ip}${dst_ip}0035111100080000
as hv1 ovs-appctl netdev-dummy/receive hv1-vif1 $packet
-#as hv1 ovs-appctl ofproto/trace br-int in_port=1 $packet
+as hv1 ovs-appctl ofproto/trace br-int in_port=1 $packet
# Send ip packets between bar1 and bob1
src_mac="f00000010204"
diff --git a/tests/rstp.at b/tests/rstp.at
index ba48c0a..600e85d 100644
--- a/tests/rstp.at
+++ b/tests/rstp.at
@@ -213,10 +213,10 @@ port p2: RSTP state changed from Disabled to Discarding
])
AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'in_port(7),eth(src=50:54:00:00:00:09,dst=50:54:00:00:00:0a),eth_type(0x0800),ipv4(src=10.0.0.2,dst=10.0.0.1,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)' | grep STP], [0], [dnl
-RSTP not in forwarding state, skipping output
+ >> RSTP not in forwarding state, skipping output
])
AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'in_port(8),eth(src=50:54:00:00:00:0b,dst=50:54:00:00:00:0c),eth_type(0x0800),ipv4(src=10.0.0.3,dst=10.0.0.4,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)' | grep STP], [0], [dnl
-RSTP not in forwarding state, skipping output
+ >> RSTP not in forwarding state, skipping output
])
#
diff --git a/tests/stp.at b/tests/stp.at
index c01ad81..8b64218 100644
--- a/tests/stp.at
+++ b/tests/stp.at
@@ -428,10 +428,10 @@ port p2: STP state changed from disabled to listening
])
AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'in_port(7),eth(src=50:54:00:00:00:09,dst=50:54:00:00:00:0a),eth_type(0x0800),ipv4(src=10.0.0.2,dst=10.0.0.1,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)' | grep STP], [0], [dnl
-STP not in forwarding state, skipping output
+ >> STP not in forwarding state, skipping output
])
AT_CHECK([ovs-appctl ofproto/trace ovs-dummy 'in_port(8),eth(src=50:54:00:00:00:0b,dst=50:54:00:00:00:0c),eth_type(0x0800),ipv4(src=10.0.0.3,dst=10.0.0.4,proto=1,tos=0,ttl=64,frag=no),icmp(type=8,code=0)' | grep STP], [0], [dnl
-STP not in forwarding state, skipping output
+ >> STP not in forwarding state, skipping output
])
# give time for STP to synchronize
--
2.10.2
More information about the dev
mailing list