diff mbox series

[ovs-dev,v2] ofctrl: Track the OvS flow update time

Message ID 20231205111823.118868-1-amusil@redhat.com
State Deferred
Delegated to: Dumitru Ceara
Headers show
Series [ovs-dev,v2] ofctrl: Track the OvS flow update time | expand

Checks

Context Check Description
ovsrobot/apply-robot success apply and check: success
ovsrobot/github-robot-_Build_and_Test success github build: passed
ovsrobot/github-robot-_ovn-kubernetes success github build: passed

Commit Message

Ales Musil Dec. 5, 2023, 11:18 a.m. UTC
Add unixctl command called "ofctrl/flow-install-time"
that returns the last time it took OvS to process
and install all flows. The initial time is taken right
before controller queues the updates to rconn.
The end is marked when we receive barrier reply with
corresponding xid.

Reported-at: https://issues.redhat.com/browse/FDP-134
Signed-off-by: Ales Musil <amusil@redhat.com>
---
v2: Address comments from Dumitru:
    - Add NEWS and ovn-controller.8.xml entry.
---
 NEWS                            |  2 ++
 controller/ofctrl.c             | 31 +++++++++++++++++++++++++++++--
 controller/ovn-controller.8.xml |  6 ++++++
 3 files changed, 37 insertions(+), 2 deletions(-)

Comments

Dumitru Ceara Jan. 9, 2024, 10:59 a.m. UTC | #1
On 12/5/23 12:18, Ales Musil wrote:
> Add unixctl command called "ofctrl/flow-install-time"
> that returns the last time it took OvS to process
> and install all flows. The initial time is taken right
> before controller queues the updates to rconn.
> The end is marked when we receive barrier reply with
> corresponding xid.
> 
> Reported-at: https://issues.redhat.com/browse/FDP-134

This seems to point to a completely different issue.  It should've been
this other one, right?

https://issues.redhat.com/browse/FDP-137

Which brings me to the note I had left there: "NOTE: ovn-controller
should not include the time it takes to run its own processing (e.g.,
engine_run()) into the time it reports for installing flows.".

I'm not sure anymore that we can have a relevant metric that we report
from within ovn-controller itself.  Results will always be including I-P
engine run times which will make them hard (impossible) to interpret.

Maybe we should consider reporting flow installation time from
ovs-vswitchd instead.

I'm going to archive this patch for now until we get more clarity on the
right approach.

Regards,
Dumitru
diff mbox series

Patch

diff --git a/NEWS b/NEWS
index acb3b854f..b2ece860f 100644
--- a/NEWS
+++ b/NEWS
@@ -10,6 +10,8 @@  Post v23.09.0
     external_ids:ovn-openflow-probe-interval configuration option for
     ovn-controller no longer matters and is ignored.
   - Enable PMTU discovery on geneve tunnels for E/W traffic.
+  - Add "ovn-appctl ofctrl/flow-install-time" that returns how long the last
+    flow processing and installation took in OvS.
 
 OVN v23.09.0 - 15 Sep 2023
 --------------------------
diff --git a/controller/ofctrl.c b/controller/ofctrl.c
index 7aac0128b..ef5afe662 100644
--- a/controller/ofctrl.c
+++ b/controller/ofctrl.c
@@ -51,6 +51,7 @@ 
 #include "openvswitch/rconn.h"
 #include "socket-util.h"
 #include "timeval.h"
+#include "unixctl.h"
 #include "util.h"
 #include "vswitch-idl.h"
 
@@ -323,6 +324,7 @@  struct ofctrl_flow_update {
     struct ovs_list list_node;  /* In 'flow_updates'. */
     ovs_be32 xid;               /* OpenFlow transaction ID for barrier. */
     uint64_t req_cfg;           /* Requested sequence number. */
+    long long start_msec;       /* Timestamp when the update started. */
 };
 
 static struct ofctrl_flow_update *
@@ -402,6 +404,10 @@  static enum mf_field_id mff_ovn_geneve;
  * (e.g. after OVS restart). */
 static bool ofctrl_initial_clear;
 
+/* The time in ms it took for the last flow installation to be processed
+ * by OvS. */
+static long long last_flow_install_time_ms = 0;
+
 static ovs_be32 queue_msg(struct ofpbuf *);
 
 static struct ofpbuf *encode_flow_mod(struct ofputil_flow_mod *);
@@ -413,6 +419,8 @@  static struct ofpbuf *encode_meter_mod(const struct ofputil_meter_mod *);
 static void ovn_installed_flow_table_clear(void);
 static void ovn_installed_flow_table_destroy(void);
 
+static void flow_install_time_report(struct unixctl_conn *conn, int argc,
+                                     const char *argv[], void *param);
 
 static void ofctrl_recv(const struct ofp_header *, enum ofptype);
 
@@ -429,6 +437,8 @@  ofctrl_init(struct ovn_extend_table *group_table,
     groups = group_table;
     meters = meter_table;
     shash_init(&meter_bands);
+    unixctl_command_register("ofctrl/flow-install-time", "", 0, 0,
+                             flow_install_time_report, NULL);
 }
 
 /* S_NEW, for a new connection.
@@ -729,9 +739,12 @@  recv_S_UPDATE_FLOWS(const struct ofp_header *oh, enum ofptype type,
         struct ofctrl_flow_update *fup = ofctrl_flow_update_from_list_node(
             ovs_list_front(&flow_updates));
         if (fup->xid == oh->xid) {
+            last_flow_install_time_ms = time_msec() - fup->start_msec;
+
             if (fup->req_cfg >= cur_cfg) {
                 cur_cfg = fup->req_cfg;
             }
+
             mem_stats.oflow_update_usage -= ofctrl_flow_update_size(fup);
             ovs_list_remove(&fup->list_node);
             free(fup);
@@ -2900,6 +2913,7 @@  ofctrl_put(struct ovn_desired_flow_table *lflow_table,
         const struct ofp_header *oh = barrier->data;
         ovs_be32 xid_ = oh->xid;
         ovs_list_push_back(&msgs, &barrier->list_node);
+        long long flow_update_start = time_msec();
 
         /* Queue the messages. */
         struct ofpbuf *msg;
@@ -2945,9 +2959,13 @@  ofctrl_put(struct ovn_desired_flow_table *lflow_table,
 
         /* Add a flow update. */
         fup = xmalloc(sizeof *fup);
+        *fup = (struct ofctrl_flow_update) {
+            .xid = xid_,
+            .req_cfg = req_cfg,
+            .start_msec = flow_update_start,
+        };
+
         ovs_list_push_back(&flow_updates, &fup->list_node);
-        fup->xid = xid_;
-        fup->req_cfg = req_cfg;
         mem_stats.oflow_update_usage += ofctrl_flow_update_size(fup);
     done:;
     } else if (!ovs_list_is_empty(&flow_updates)) {
@@ -3090,3 +3108,12 @@  ofctrl_get_memory_usage(struct simap *usage)
                    ROUND_UP(rconn_packet_counter_n_bytes(tx_counter), 1024)
                    / 1024);
 }
+
+static void
+flow_install_time_report(struct unixctl_conn *conn, int argc OVS_UNUSED,
+                         const char *argv[] OVS_UNUSED, void *param OVS_UNUSED)
+{
+    char *msg = xasprintf("%lld ms", last_flow_install_time_ms);
+    unixctl_command_reply(conn, msg);
+    free(msg);
+}
diff --git a/controller/ovn-controller.8.xml b/controller/ovn-controller.8.xml
index 735bc1221..a5ed8fcd5 100644
--- a/controller/ovn-controller.8.xml
+++ b/controller/ovn-controller.8.xml
@@ -770,6 +770,12 @@ 
       <dd>
         Reset <code>ovn-controller</code> engine counters.
       </dd>
+
+        <dt><code>ofctrl/flow-install-time</code></dt>
+        <dd>
+          Returns how long the last flow processing and installation took
+          in OvS.
+        </dd>
       </dl>
     </p>