[ovs-dev] [PATCHv2 2/2] xlate: add backward resubmit trace log.

[William Tu]

When hitting max translation depth of 64, printing the full
ofproto trace is huge and consumes too much log.  The patch
adds a short trace log, which prints the 64 backward resubmit
table IDs during the translation.

VMWare-BZ: #2054659
Signed-off-by: William Tu <u9012063 at gmail.com>
---
An example output:
2018-02-14T18:13:09.723Z|00084|ofproto_dpif_xlate|WARN|over max translation depth 64, table ID: [9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2, 9, 8, 7, 6, 5, 4, 3, 2] while processing in_port=1,vlan_tci=0x0000,dl_src=50:54:00:00:00:01,dl_dst=50:54:00:00:00:ff,dl_type=0x1234 on bridge br0
---
 ofproto/ofproto-dpif-xlate.c | 20 ++++++++++++++++++--
 tests/ofproto-dpif.at        |  3 +++
 2 files changed, 21 insertions(+), 2 deletions(-)

diff --git a/ofproto/ofproto-dpif-xlate.c b/ofproto/ofproto-dpif-xlate.c
index cc450a896948..4bc91549798e 100644
--- a/ofproto/ofproto-dpif-xlate.c
+++ b/ofproto/ofproto-dpif-xlate.c
@@ -237,6 +237,7 @@ struct xlate_ctx {
      */
     int depth;                  /* Current resubmit nesting depth. */
     int resubmits;              /* Total number of resubmits. */
+    uint8_t bw_resubmit[MAX_DEPTH]; /* Track backward resubmit table IDs. */
     bool in_group;              /* Currently translating ofgroup, if true. */
     bool in_action_set;         /* Currently translating action_set, if true. */
     bool in_packet_out;         /* Currently translating a packet_out msg, if
@@ -3912,8 +3913,11 @@ xlate_recursively(struct xlate_ctx *ctx, struct rule_dpif *rule,
         rule_dpif_credit_stats(rule, ctx->xin->resubmit_stats);
     }
 
-    ctx->resubmits++;
+    if (deepens) {
+        ctx->bw_resubmit[ctx->depth] = ctx->table_id;
+    }
 
+    ctx->resubmits++;
     ctx->depth += deepens;
     ctx->rule = rule;
     ctx->rule_cookie = rule->up.flow_cookie;
@@ -3929,7 +3933,19 @@ 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);
+        struct ds output;
+        int i;
+
+        ds_init(&output);
+        for (i = 0; i < MAX_DEPTH - 1; i++) {
+            ds_put_format(&output, "%d, ", ctx->bw_resubmit[i]);
+        }
+        ds_put_format(&output, "%d", ctx->bw_resubmit[i]);
+
+        xlate_report_error(ctx, "over max translation depth %d, "
+                                "table ID: [%s]",
+                                MAX_DEPTH, ds_cstr(&output));
+        ds_destroy(&output);
         ctx->error = XLATE_RECURSION_TOO_DEEP;
     } else if (ctx->resubmits >= MAX_RESUBMITS) {
         xlate_report_error(ctx, "over %d resubmit actions", MAX_RESUBMITS);
diff --git a/tests/ofproto-dpif.at b/tests/ofproto-dpif.at
index fd78c5d9b593..b00faee5cf44 100644
--- a/tests/ofproto-dpif.at
+++ b/tests/ofproto-dpif.at
@@ -8494,6 +8494,9 @@ AT_CHECK([grep -c "^ *resubmit" ovs-vswitchd.log],
   [0], [66
 ])
 
+dnl make sure the short backward table trace is present
+AT_CHECK([grep "65, 64, 63, 62, 61, 60, 59, 58, 57, 56, 55, 54, 53, 52, 51, 50, 49, 48, 47, 46, 45, 44, 43, 42, 41, 40, 39, 38, 37, 36, 35, 34, 33, 32, 31, 30, 29, 28, 27, 26, 25, 24, 23, 22, 21, 20, 19, 18, 17, 16, 15, 14, 13, 12, 11, 10, 9, 8, 7, 6, 5, 4, 3, 2" ovs-vswitchd.log], [0], [stdout])
+
 OVS_VSWITCHD_STOP(["/over max translation depth/d
 /ofproto_dpif_upcall/d"])
 AT_CLEANUP
-- 
2.7.4