On 9/23/24 12:22, LIU Yulong via discuss wrote: > Hi there, > > In an OVS-DPDK environment, we noticed that the ovs flow installation > is too slow to finish the process of our VM NIC configuration. > > Here are some logs [1], you may see some text like this: > > 20482 flow_mods in the last 59 s (20362 adds, 120 deletes) > 20265 flow_mods in the last 59 s (19888 adds, 377 deletes) > > When concurrent port creation comes, 59s for many ports are not so efficient.
Hi. In general, this log message doesn't mean that it took 59 seconds to perform 20K flow modifications. It means that in the last 59 seconds there were 20K flow modifications, i.e. the process might have slept most of that time waking up periodically to process some updates. And you may see that even when the process was busy waking up on RCU, it was not using 100% of CPU. In order to better track the rate of incoming flow modifications, you may look at coverage counters instead. Stats of the OVS threads also do nott indicate any high load on the main ovs-vswitchd thread that is responsible for the flow mods. Revalidator threads also do not seem to be particularly busy. Best regards, Ilya Maximets. > > So here I wonder what is the benchmark performance for OVS flow table > installation? How to perform performance tuning for flow installation? > > Ovs version is 2.17.2, and dpdk is 20.11. > ovs-vswitchd threads are [2]. > > > > > > Regards, > > LIU Yulong > > > > > > [1] LOGs from ovs-vswitchd: > 2024-09-23T10:21:29.168Z|08389|poll_loop|INFO|Dropped 256 log messages > in last 27 seconds (most recently, 27 seconds ago) due to excessive > rate > 2024-09-23T10:21:29.168Z|08390|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (52% CPU usage) > 2024-09-23T10:21:29.168Z|08391|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (52% CPU usage) > 2024-09-23T10:21:29.168Z|08392|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (52% CPU usage) > 2024-09-23T10:21:29.168Z|08393|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (52% CPU usage) > 2024-09-23T10:21:32.136Z|08394|poll_loop|INFO|Dropped 40909 log > messages in last 3 seconds (most recently, 0 seconds ago) due to > excessive rate > 2024-09-23T10:21:32.136Z|08395|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (52% CPU usage) > 2024-09-23T10:22:08.981Z|08396|connmgr|INFO|br-int<->tcp:127.0.0.1:6633: > 20265 flow_mods in the last 59 s (19888 adds, 377 deletes) > 2024-09-23T10:22:14.820Z|08397|connmgr|INFO|br-dpdk<->tcp:127.0.0.1:6633: > 103 flow_mods 10 s ago (103 adds) > 2024-09-23T10:22:35.211Z|08398|poll_loop|INFO|Dropped 392 log messages > in last 63 seconds (most recently, 63 seconds ago) due to excessive > rate > 2024-09-23T10:22:35.211Z|08399|poll_loop|INFO|wakeup due to [POLLIN] > on fd 184 (127.0.0.1:55906<->127.0.0.1:6633) at lib/stream-fd.c:157 > (57% CPU usage) > 2024-09-23T10:22:35.211Z|08400|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08401|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08402|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08403|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08404|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08405|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08406|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08407|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:22:35.211Z|08408|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (57% CPU usage) > 2024-09-23T10:23:08.981Z|08409|connmgr|INFO|br-int<->tcp:127.0.0.1:6633: > 20112 flow_mods in the last 59 s (19860 adds, 252 deletes) > 2024-09-23T10:23:14.821Z|08410|connmgr|INFO|br-dpdk<->tcp:127.0.0.1:6633: > 103 flow_mods 10 s ago (103 adds) > 2024-09-23T10:23:44.223Z|08411|poll_loop|INFO|Dropped 35966 log > messages in last 69 seconds (most recently, 66 seconds ago) due to > excessive rate > 2024-09-23T10:23:44.224Z|08412|poll_loop|INFO|wakeup due to [POLLIN] > on fd 184 (127.0.0.1:55906<->127.0.0.1:6633) at lib/stream-fd.c:157 > (81% CPU usage) > 2024-09-23T10:23:44.224Z|08413|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08414|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08415|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08416|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08417|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08418|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08419|poll_loop|INFO|wakeup due to 0-ms > timeout at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08420|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:44.224Z|08421|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at lib/ovs-rcu.c:249 (81% CPU usage) > 2024-09-23T10:23:50.225Z|08422|poll_loop|INFO|Dropped 13989 log > messages in last 6 seconds (most recently, 0 seconds ago) due to > excessive rate > 2024-09-23T10:23:50.225Z|08423|poll_loop|INFO|wakeup due to 0-ms > timeout at ofproto/ofproto-dpif.c:2001 (88% CPU usage) > 2024-09-23T10:23:56.625Z|08424|poll_loop|INFO|Dropped 28118 log > messages in last 6 seconds (most recently, 0 seconds ago) due to > excessive rate > 2024-09-23T10:23:56.625Z|08425|poll_loop|INFO|wakeup due to [POLLIN] > on fd 314 (FIFO pipe:[872871807]) at vswitchd/bridge.c:423 (59% CPU > usage) > 2024-09-23T10:24:08.122Z|08426|connmgr|INFO|br-meta<->tcp:127.0.0.1:6633: > 108 flow_mods in the 7 s starting 10 s ago (108 deletes) > 2024-09-23T10:24:08.981Z|08427|connmgr|INFO|br-int<->tcp:127.0.0.1:6633: > 14552 flow_mods in the 56 s starting 59 s ago (11093 adds, 3459 > deletes) > 2024-09-23T10:24:14.821Z|08428|connmgr|INFO|br-dpdk<->tcp:127.0.0.1:6633: > 589 flow_mods in the 7 s starting 16 s ago (103 adds, 486 deletes) > 2024-09-23T10:25:14.821Z|08429|connmgr|INFO|br-dpdk<->tcp:127.0.0.1:6633: > 103 flow_mods 10 s ago (103 adds) > 2024-09-23T10:26:14.821Z|08430|connmgr|INFO|br-dpdk<->tcp:127.0.0.1:6633: > 103 flow_mods 10 s ago (103 adds) > > [2] Threads of the ovs-vswitchd: > PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ > COMMAND > 13148 root 10 -10 241.2g 1.3g 33016 R 99.9 0.3 124:04.40 > pmd-c37/id:20 > 13156 root 10 -10 241.2g 1.3g 33016 R 80.0 0.3 124:06.10 > pmd-c50/id:28 > 13144 root 10 -10 241.2g 1.3g 33016 R 73.3 0.3 124:06.07 > pmd-c53/id:16 > 13151 root 10 -10 241.2g 1.3g 33016 R 73.3 0.3 124:06.09 > pmd-c51/id:23 > 13155 root 10 -10 241.2g 1.3g 33016 R 73.3 0.3 124:06.09 > pmd-c52/id:27 > 13111 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 9:38.57 > ovs-vswitchd > 13112 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > eal-intr-thread > 13113 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > rte_mp_handle > 13118 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > ovs-vswitchd > 13119 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > dpdk_watchdog1 > 13120 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 4:31.23 > urcu2 > 13127 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.04 > ct_clean3 > 13128 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > ipf_clean4 > 13141 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:05.98 > pmd-c20/id:13 > 13142 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:05.98 > pmd-c18/id:14 > 13143 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.25 > pmd-c35/id:15 > 13145 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:05.99 > pmd-c21/id:17 > 13146 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.41 > pmd-c05/id:18 > 13147 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:05.98 > pmd-c19/id:19 > 13149 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.24 > pmd-c36/id:21 > 13150 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.32 > pmd-c02/id:22 > 13152 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.44 > pmd-c04/id:24 > 13153 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.24 > pmd-c34/id:25 > 13154 root 10 -10 241.2g 1.3g 33016 R 0.0 0.3 124:04.46 > pmd-c03/id:26 > 13157 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.04 > vhost_reconn > 13158 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.69 > vhost-events > 19115 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > handler54 > 19116 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > handler55 > 19117 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > handler56 > 19118 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > handler61 > 19119 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 0:00.00 > handler57 > 19120 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 1:49.58 > revalidator58 > 19121 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 1:43.02 > revalidator59 > 19122 root 10 -10 241.2g 1.3g 33016 S 0.0 0.3 1:40.94 > revalidator60 > _______________________________________________ > discuss mailing list > disc...@openvswitch.org > https://mail.openvswitch.org/mailman/listinfo/ovs-discuss > _______________________________________________ discuss mailing list disc...@openvswitch.org https://mail.openvswitch.org/mailman/listinfo/ovs-discuss
