diff mbox series

[ovs-dev] connmgr: Reduce "flow_mods in the last" log severity to DBG.

Message ID 20250608084532.584292-1-roid@nvidia.com
State Changes Requested
Headers show
Series [ovs-dev] connmgr: Reduce "flow_mods in the last" log severity to DBG. | expand

Checks

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

Commit Message

Roi Dayan June 8, 2025, 8:45 a.m. UTC 
From: Eli Britstein <elibr@nvidia.com>

The following messages are reduced to DBG.
  2025-05-11T10:33:26.778Z|07801|connmgr|INFO|br-sfc<->unix#24021: 2 flow_mods in the last 0 s (2 adds)
  2025-05-11T10:33:30.582Z|07802|connmgr|INFO|br-sfc<->unix#24024: 2 flow_mods in the last 0 s (2 adds)
  2025-05-11T10:33:30.648Z|07803|connmgr|INFO|br-sfc<->unix#24027: 2 flow_mods in the last 0 s (2 adds)

Signed-off-by: Eli Britstein <elibr@nvidia.com>
Acked-by: Roi Dayan <roid@nvidia.com>
---
 ofproto/connmgr.c       | 2 +-
 tests/ofproto.at        | 3 ++-
 utilities/checkpatch.py | 2 +-
 3 files changed, 4 insertions(+), 3 deletions(-)

Comments

Ilya Maximets June 8, 2025, 10:14 p.m. UTC | #1 
On 6/8/25 10:45 AM, Roi Dayan via dev wrote:
> From: Eli Britstein <elibr@nvidia.com>
> 
> The following messages are reduced to DBG.
>   2025-05-11T10:33:26.778Z|07801|connmgr|INFO|br-sfc<->unix#24021: 2 flow_mods in the last 0 s (2 adds)
>   2025-05-11T10:33:30.582Z|07802|connmgr|INFO|br-sfc<->unix#24024: 2 flow_mods in the last 0 s (2 adds)
>   2025-05-11T10:33:30.648Z|07803|connmgr|INFO|br-sfc<->unix#24027: 2 flow_mods in the last 0 s (2 adds)

Any justification for this?  These logs are normally pretty useful to see
the change rate.  If you see the constant stream of these messages, then
you probably need to fix the controller that sends so many flow updates.
Flow modifications cause revalidation, which is heavy, and so keeping OVS
in a constant revalidation loop is unlikely to be healthy for the system.

You may also consider having a stable connection instead of reconnecting
for every change, e.g. have a real OF controller instead of invoking
ovs-ofctl for every small change.  This way the messages will be printed
less frequently.

Alternative might be to aggregate across multiple connections and then log
once at lower frequency.  Showing in the log all the accumulated connection
handles might be cumbersome though.

Either way, just demoting the fairly useful log doesn't seem reasonable.

Best regards, Ilya Maximets.
Roi Dayan June 9, 2025, 12:08 p.m. UTC | #2 
On 09/06/2025 1:14, Ilya Maximets wrote:
> On 6/8/25 10:45 AM, Roi Dayan via dev wrote:
>> From: Eli Britstein <elibr@nvidia.com>
>>
>> The following messages are reduced to DBG.
>>   2025-05-11T10:33:26.778Z|07801|connmgr|INFO|br-sfc<->unix#24021: 2 flow_mods in the last 0 s (2 adds)
>>   2025-05-11T10:33:30.582Z|07802|connmgr|INFO|br-sfc<->unix#24024: 2 flow_mods in the last 0 s (2 adds)
>>   2025-05-11T10:33:30.648Z|07803|connmgr|INFO|br-sfc<->unix#24027: 2 flow_mods in the last 0 s (2 adds)
> 
> Any justification for this?  These logs are normally pretty useful to see
> the change rate.  If you see the constant stream of these messages, then
> you probably need to fix the controller that sends so many flow updates.
> Flow modifications cause revalidation, which is heavy, and so keeping OVS
> in a constant revalidation loop is unlikely to be healthy for the system.
> 
> You may also consider having a stable connection instead of reconnecting
> for every change, e.g. have a real OF controller instead of invoking
> ovs-ofctl for every small change.  This way the messages will be printed
> less frequently.
> 
> Alternative might be to aggregate across multiple connections and then log
> once at lower frequency.  Showing in the log all the accumulated connection
> handles might be cumbersome though.
> 
> Either way, just demoting the fairly useful log doesn't seem reasonable.
> 
> Best regards, Ilya Maximets.

Thanks for the response. I'll check your suggestions.
diff mbox series

Patch

diff --git a/ofproto/connmgr.c b/ofproto/connmgr.c
index f7f7b1279960..b007ab8a7b63 100644
--- a/ofproto/connmgr.c
+++ b/ofproto/connmgr.c
@@ -1406,7 +1406,7 @@  ofconn_log_flow_mods(struct ofconn *ofconn)
         s.length -= 2;
         ds_put_char(&s, ')');
 
-        VLOG_INFO("%s: %s", rconn_get_name(ofconn->rconn), ds_cstr(&s));
+        VLOG_DBG("%s: %s", rconn_get_name(ofconn->rconn), ds_cstr(&s));
         ds_destroy(&s);
 
         ofconn->n_add = ofconn->n_delete = ofconn->n_modify = 0;
diff --git a/tests/ofproto.at b/tests/ofproto.at
index 2889f81fb171..847007f9669e 100644
--- a/tests/ofproto.at
+++ b/tests/ofproto.at
@@ -5357,6 +5357,7 @@  AT_SETUP([ofproto - bundle with multiple flow mods (OpenFlow 1.4)])
 OVS_VSWITCHD_START
 
 AT_CHECK([ovs-appctl vlog/set vconn:dbg])
+AT_CHECK([ovs-appctl vlog/set connmgr:dbg])
 
 AT_CHECK([ovs-ofctl --no-names del-flows br0])
 
@@ -5545,7 +5546,7 @@  vconn|DBG|unix: sent (Success): NXST_FLOW reply:
  in_port=2,dl_src=00:66:77:88:99:aa actions=drop
 ])
 
-AT_CHECK([grep " flow_mods in the last " ovs-vswitchd.log | sed -e 's/^.*connmgr|INFO|//' | vconn_sub], [0], [dnl
+AT_CHECK([grep " flow_mods in the last " ovs-vswitchd.log | sed -e 's/^.*connmgr|DBG|//' | vconn_sub], [0], [dnl
 br0<->unix: 1 flow_mods in the last 0 s (1 deletes)
 br0<->unix: 9 flow_mods in the last 0 s (7 adds, 2 deletes)
 br0<->unix: 2 flow_mods in the last 0 s (2 modifications)
diff --git a/utilities/checkpatch.py b/utilities/checkpatch.py
index 566a2bd60b5f..6ccf049d9dd4 100755
--- a/utilities/checkpatch.py
+++ b/utilities/checkpatch.py
@@ -119,7 +119,7 @@  def open_spell_check_dict():
                           'tftp', 'timeval', 'trie', 'tso', 'ubsan', 'ukey',
                           'umask', 'unassociated', 'unixctl', 'uuid'
                           'virtqueue', 'vms', 'vnet', 'vport', 'vports',
-                          'vtep', 'wc', 'wget', 'xenserver', 'util']
+                          'vtep', 'wc', 'wget', 'xenserver', 'util', 'connmgr']
 
         global spell_check_dict