lib: inc-proc-eng: Add more debug info to recompute events.

Introduce the get_compute_failure_info callback used to report info about
the input node that triggers the parent node recompute.
This patch sets the callback just for DB nodes dumping the table name and
the row UUID that triggers the recompute when the parent node does not
support incremental processing for this input. Following patches will
specify get_compute_failure_info callback even for non-DB nodes.

Reported-at: https://issues.redhat.com/browse/FDP-1396
Signed-off-by: Lorenzo Bianconi <lorenzo.bianconi@redhat.com>
Signed-off-by: Ales Musil <amusil@redhat.com>

Author: LorenzoBianconi

lib/inc-proc-eng.c

@@ -192,6 +192,12 @@ engine_set_log_timeout_cmd(struct unixctl_conn *conn, int argc OVS_UNUSED,
     unixctl_command_reply(conn, NULL);
 }
 
+static void
+engine_get_compute_failure_info(struct engine_node *node)
+{
+    VLOG_DBG("Node \"%s\" is missing compute failure debug info.", node->name);
+}
+
 void
 engine_init(struct engine_node *node, struct engine_arg *arg)
 {
@@ -204,6 +210,11 @@ engine_init(struct engine_node *node, struct engine_arg *arg)
         } else {
             sorted_node->data = NULL;
         }
+        if (!sorted_node->get_compute_failure_info) {
+            /* Provide default get_compute_failure_info implementation. */
+            sorted_node->get_compute_failure_info =
+                engine_get_compute_failure_info;
+        }
     }
 
     unixctl_command_register("inc-engine/show-stats", "", 0, 2,
@@ -264,6 +275,17 @@ engine_add_input(struct engine_node *node, struct engine_node *input,
     node->n_inputs ++;
 }
 
+void
+engine_add_input_with_compute_debug(
+        struct engine_node *node, struct engine_node *input,
+        enum engine_input_handler_result (*change_handler)
+            (struct engine_node *, void *),
+        void (*get_compute_failure_info)(struct engine_node *))
+{
+    engine_add_input(node, input, change_handler);
+    node->get_compute_failure_info = get_compute_failure_info;
+}
+
 struct ovsdb_idl_index *
 engine_ovsdb_node_get_index(struct engine_node *node, const char *name)
 {
@@ -440,8 +462,10 @@ static bool
 engine_compute(struct engine_node *node, bool recompute_allowed)
 {
     for (size_t i = 0; i < node->n_inputs; i++) {
+        struct engine_node *input_node = node->inputs[i].node;
+
         /* If the input node data changed call its change handler. */
-        if (node->inputs[i].node->state == EN_UPDATED) {
+        if (input_node->state == EN_UPDATED) {
             /* If the input change can't be handled incrementally, run
              * the node handler.
              */
@@ -453,25 +477,24 @@ engine_compute(struct engine_node *node, bool recompute_allowed)
                 static struct vlog_rate_limit rl =
                     VLOG_RATE_LIMIT_INIT(20, 10);
                 VLOG_INFO_RL(&rl, "node: %s, handler for input %s took %lldms",
-                             node->name, node->inputs[i].node->name,
-                             delta_time);
+                             node->name, input_node->name, delta_time);
             } else {
                 VLOG_DBG("node: %s, handler for input %s took %lldms",
-                         node->name, node->inputs[i].node->name, delta_time);
+                         node->name, input_node->name, delta_time);
             }
             if (handled == EN_UNHANDLED) {
+                input_node->get_compute_failure_info(input_node);
                 engine_recompute(node, recompute_allowed,
                                  "failed handler for input %s",
-                                 node->inputs[i].node->name);
+                                 input_node->name);
                 return (node->state != EN_CANCELED);
             } else if (!engine_node_changed(node)) {
                 /* We only want to update the state if the node is unchanged.
                  * Otherwise, handlers might change the state from EN_UPDATED
                  * back to EN_UNCHANGED.
                  */
                 engine_set_node_state(node, (enum engine_node_state) handled,
-                                      "input %s updated",
-                                      node->inputs[i].node->name);
+                                      "input %s updated", input_node->name);
             }
         }
     }
@@ -501,14 +524,16 @@ engine_run_node(struct engine_node *node, bool recompute_allowed)
      */
     bool need_compute = false;
     for (size_t i = 0; i < node->n_inputs; i++) {
-        if (node->inputs[i].node->state == EN_UPDATED) {
+        struct engine_node *input_node = node->inputs[i].node;
+        if (input_node->state == EN_UPDATED) {
             need_compute = true;
 
             /* Trigger a recompute if we don't have a change handler. */
             if (!node->inputs[i].change_handler) {
                 engine_recompute(node, recompute_allowed,
                                  "missing handler for input %s",
-                                 node->inputs[i].node->name);
+                                 input_node->name);
+                input_node->get_compute_failure_info(input_node);
                 return;
             }
         }

lib/inc-proc-eng.h

@@ -265,6 +265,11 @@ struct engine_node {
      * engine 'data'. It may be NULL. */
     void (*clear_tracked_data)(void *tracked_data);
 
+    /* Method used to dump info about node input compute failues. It may be
+     * NULL.
+     */
+    void (*get_compute_failure_info)(struct engine_node *);
+
     /* Engine stats. */
     struct engine_stats stats;
 };
@@ -308,6 +313,11 @@ void *engine_get_input_data(const char *input_name, struct engine_node *);
 void engine_add_input(struct engine_node *node, struct engine_node *input,
                       enum engine_input_handler_result (*change_handler)
                           (struct engine_node *, void *));
+void engine_add_input_with_compute_debug(
+        struct engine_node *node, struct engine_node *input,
+        enum engine_input_handler_result (*change_handler)
+            (struct engine_node *, void *),
+        void (*get_compute_failure_info)(struct engine_node *));
 
 /* Force the engine to recompute everything. It is used
  * in circumstances when we are not sure there is change or not, or
@@ -422,6 +432,9 @@ void engine_ovsdb_node_add_index(struct engine_node *, const char *name,
 #define IS_VALID(NAME) \
     .is_valid = en_##NAME##_is_valid
 
+#define COMPUTE_FAIL_INFO(NAME) \
+        .get_compute_failure_info = en_##NAME##_compute_failure_info,
+
 #define ENGINE_NODE2(NAME, ARG1) \
     ENGINE_NODE_DEF_START(NAME, #NAME) \
     ARG1(NAME), \
@@ -460,6 +473,42 @@ static void *en_##DB_NAME##_##TBL_NAME##_init( \
 } \
 static void en_##DB_NAME##_##TBL_NAME##_cleanup(void *data OVS_UNUSED) \
 { \
+} \
+static void \
+en_##DB_NAME##_##TBL_NAME##_compute_failure_info(struct engine_node *node)  \
+{                                                                           \
+    if (!VLOG_IS_DBG_ENABLED()) {                                           \
+        return;                                                             \
+    }                                                                       \
+    const struct ovsdb_idl *table = EN_OVSDB_GET(node);                     \
+    const struct ovsdb_idl_row *row;                                        \
+    struct ds s = DS_EMPTY_INITIALIZER;                                     \
+    ds_put_format(&s, "Node \"%s\" compute failure info:\n", node->name);   \
+    for ((row) = ovsdb_idl_track_get_first(table,                           \
+                                           &DB_NAME##rec_table_##TBL_NAME); \
+         (row); (row) = ovsdb_idl_track_get_next(row)) {                    \
+        if (ovsdb_idl_row_get_seqno((row), OVSDB_IDL_CHANGE_INSERT) > 0) {  \
+            ds_put_format(&s, "%s (New) "UUID_FMT"\n",                      \
+                          #DB_NAME"_"#TBL_NAME, UUID_ARGS(&row->uuid));     \
+        } else if (ovsdb_idl_row_get_seqno((row),                           \
+                                           OVSDB_IDL_CHANGE_DELETE) > 0) {  \
+            ds_put_format(&s, "%s (Deleted) "UUID_FMT"\n",                  \
+                          #DB_NAME"_"#TBL_NAME, UUID_ARGS(&row->uuid));     \
+        } else {                                                            \
+            ds_put_format(&s, "%s (Updated) "UUID_FMT" columns:",           \
+                          #DB_NAME"_"#TBL_NAME, UUID_ARGS(&row->uuid));     \
+            for (size_t i = 0; i < row->table->class_->n_columns; i++) {    \
+                struct ovsdb_idl_column *col =                              \
+                    &DB_NAME##rec_##TBL_NAME##_columns[i];                  \
+                if (ovsdb_idl_track_is_updated(row, col)) {                 \
+                    ds_put_format(&s, " %s,", col->name);                   \
+                }                                                           \
+            }                                                               \
+            ds_chomp(&s, ',');                                              \
+        }                                                                   \
+    }                                                                       \
+    VLOG_DBG("%s", ds_cstr(&s));                                            \
+    ds_destroy(&s);                                                         \
 }
 
 /* Macro to define member functions of an engine node which represents
@@ -480,6 +529,7 @@ static void en_##DB_NAME##_##TBL_NAME##_cleanup(void *data OVS_UNUSED) \
 /* Macro to define an engine node which represents a table of OVSDB */
 #define ENGINE_NODE_OVSDB(DB_NAME, DB_NAME_STR, TBL_NAME, TBL_NAME_STR) \
     ENGINE_NODE_DEF_START(DB_NAME##_##TBL_NAME, DB_NAME_STR"_"TBL_NAME_STR) \
+    COMPUTE_FAIL_INFO(DB_NAME##_##TBL_NAME) \
     ENGINE_NODE_DEF_END
 
 /* Macro to define an engine node which represents a table of OVN SB DB */