Hi all,

i'm looking for some help/hints to solve a issue in our current Openvswitch
implementation.

We are using OVS 2.4.0 with a 3.12.49 kernel on a Gentoo instalation. We
upgraded from OVS 2.3.1 when started to see the following log entries:

Jul 29 16:01:40 XXXXXXXX ovs-vswitchd[4027]:
ovs|839572|poll_loop|INFO|Dropped 254414 log messages in last 6 seconds
(most recently, 0 seconds ago) due to excessive rate
Jul 29 16:01:40 XXXXXXXX ovs-vswitchd[4027]:
ovs|839573|poll_loop|INFO|wakeup due to 0-ms timeout at ofproto/bond.c:670
(100% CPU usage)

This server hosts some KVM guests, and can't see any significant impact on
VMs traffic.
If we restart ovs-vswitchd daemon, it restores normal behaviour (<1% CPU
USAGE), with almost no downtime for the VMs.

Noticed the following discrepancies in ovs-appctl coverage/show between a
normal and a overloading ovs-vswitchd:

NORMAL
Event coverage, avg rate over last: 5 seconds, last minute, last hour,
hash=889f5af7:
bridge_reconfigure         0.0/sec     0.000/sec        0.0000/sec   total:
314
ofproto_flush              0.0/sec     0.000/sec        0.0000/sec   total:
1
ofproto_update_port        0.0/sec     0.000/sec        0.0000/sec   total:
985
rev_reconfigure            0.0/sec     0.000/sec        0.0000/sec   total:
314
rev_bond                   0.2/sec     0.050/sec        0.0758/sec   total:
1589338
rev_port_toggled           0.0/sec     0.000/sec        0.0000/sec   total:
148
rev_flow_table             0.0/sec     0.000/sec        0.0000/sec   total:
1
rev_mac_learning           0.2/sec     0.300/sec        0.1072/sec   total:
3437557
upcall_duplicate_flow      0.0/sec     0.000/sec        0.0000/sec   total:
984
revalidate_missed_dp_flow   0.0/sec     0.000/sec        0.0000/sec
total: 41
xlate_actions             51.2/sec    43.683/sec       31.9928/sec   total:
808498224
dpif_port_add              0.0/sec     0.000/sec        0.0000/sec   total:
173
dpif_port_del              0.0/sec     0.000/sec        0.0000/sec   total:
146
dpif_flow_flush            0.0/sec     0.000/sec        0.0000/sec   total:
2
dpif_flow_get              0.0/sec     0.000/sec        0.0000/sec   total:
41
dpif_flow_put              0.0/sec     0.000/sec        0.0000/sec   total:
2
dpif_execute               0.0/sec     0.067/sec        0.0661/sec   total:
2264609
flow_extract              18.4/sec    15.067/sec       13.7744/sec   total:
351987574
hmap_pathological          0.2/sec     0.200/sec        0.1986/sec   total:
837758
hmap_expand              206.4/sec   204.800/sec      217.6553/sec   total:
4876008590
mac_learning_learned       0.2/sec     0.167/sec        0.0556/sec   total:
1866789
mac_learning_expired       0.0/sec     0.133/sec        0.0556/sec   total:
1866539
netdev_get_stats           5.4/sec     5.400/sec        5.3625/sec   total:
126324309
txn_unchanged              0.0/sec     0.033/sec        0.0336/sec   total:
1207021
txn_incomplete            25.0/sec    24.967/sec       27.5658/sec   total:
585261994
txn_success                0.2/sec     0.200/sec        0.1986/sec   total:
6787886
poll_fd_wait             378.6/sec   364.733/sec      380.9808/sec   total:
9170727560
poll_zero_timeout          1.2/sec     1.233/sec        0.9994/sec   total:
48207850
pstream_open               0.0/sec     0.000/sec        0.0000/sec   total:
3
stream_open                0.0/sec     0.000/sec        0.0000/sec   total:
1
unixctl_received           0.0/sec     0.000/sec        0.0000/sec   total:
1
unixctl_replied            0.0/sec     0.000/sec        0.0000/sec   total:
1
util_xalloc              4538.4/sec  4475.117/sec     4451.5161/sec
total: 103745028151
netdev_set_policing        0.0/sec     0.000/sec        0.0000/sec   total:
381
netdev_get_ifindex         0.0/sec     0.000/sec        0.0000/sec   total:
173
netdev_get_hwaddr          0.0/sec     0.000/sec        0.0000/sec   total:
173
netdev_set_hwaddr          0.0/sec     0.000/sec        0.0000/sec   total:
1
netdev_get_ethtool         0.0/sec     0.000/sec        0.0000/sec   total:
1341
netdev_set_ethtool         0.0/sec     0.000/sec        0.0000/sec   total:
170
netlink_overflow           0.0/sec     0.000/sec        0.0000/sec   total:
2
netlink_received          63.8/sec    57.850/sec       54.0611/sec   total:
1416808896
netlink_recv_jumbo         4.8/sec     4.900/sec        4.9406/sec   total:
114101816
netlink_sent              67.2/sec    59.117/sec       55.1072/sec   total:
1421497106

HEAVY CPU USAGE:
Event coverage, avg rate over last: 5 seconds, last minute, last hour,
hash=3931ff09:
bridge_reconfigure         0.0/sec     0.000/sec        0.0000/sec   total:
145
ofproto_flush              0.0/sec     0.000/sec        0.0000/sec   total:
1
ofproto_update_port        0.0/sec     0.000/sec        0.0000/sec   total:
525
rev_reconfigure            0.0/sec     0.000/sec        0.0000/sec   total:
144
rev_bond                   0.2/sec     0.100/sec        0.0742/sec   total:
259897
rev_port_toggled           0.0/sec     0.000/sec        0.0000/sec   total:
144
rev_flow_table             0.0/sec     0.000/sec        0.0000/sec   total:
1
rev_mac_learning           0.4/sec     0.067/sec        0.0642/sec   total:
271810
dumped_duplicate_flow      0.0/sec     0.000/sec        0.0000/sec   total:
28
dumped_new_flow            7.4/sec     6.050/sec        6.6106/sec   total:
24098359
handler_duplicate_upcall   0.8/sec     0.167/sec        0.1608/sec   total:
684029
upcall_ukey_contention     0.0/sec     0.000/sec        0.0000/sec   total:
5
*xlate_actions            127.8/sec    42.750/sec       38.7953/sec
total: 141927626*
cmap_expand                0.0/sec     0.000/sec        0.0028/sec   total:
6326
cmap_shrink                0.0/sec     0.000/sec        0.0022/sec   total:
6289
dpif_port_add              0.0/sec     0.000/sec        0.0000/sec   total:
74
dpif_port_del              0.0/sec     0.000/sec        0.0000/sec   total:
70
dpif_flow_flush            0.0/sec     0.000/sec        0.0000/sec   total:
2
dpif_flow_get              0.0/sec     0.000/sec        0.0000/sec   total:
11
dpif_flow_put              7.6/sec     6.100/sec        6.6983/sec   total:
24297230
dpif_flow_del              7.0/sec     6.383/sec        6.6661/sec   total:
24212719
dpif_execute               8.4/sec     6.200/sec        6.7706/sec   total:
24653492
flow_extract               8.4/sec     6.333/sec        6.9253/sec   total:
25230279
hmap_pathological          0.6/sec     0.583/sec        0.5508/sec   total:
1374378
*hmap_expand              252810.4/sec 249762.900/sec   249585.4436/sec
total: 17087164310*
mac_learning_learned       0.2/sec     0.033/sec        0.0333/sec   total:
146348
mac_learning_expired       0.2/sec     0.033/sec        0.0333/sec   total:
146167
netdev_get_stats           5.0/sec     5.000/sec        4.9583/sec   total:
18047326
txn_unchanged              0.0/sec     0.033/sec        0.0333/sec   total:
130655
txn_incomplete            34.0/sec    33.067/sec       31.7069/sec   total:
3659156
txn_success                0.2/sec     0.200/sec        0.1983/sec   total:
746041

*poll_create_node         1179714.8/sec 1165493.267/sec  1164671.7744/sec
total: 79459857041poll_zero_timeout        42145.2/sec 41637.017/sec
41608.4875/sec   total: 2854512787*
pstream_open               0.0/sec     0.000/sec        0.0000/sec   total:
3
stream_open                0.0/sec     0.000/sec        0.0000/sec   total:
1
unixctl_received           0.0/sec     0.000/sec        0.0003/sec   total:
10
unixctl_replied            0.0/sec     0.000/sec        0.0003/sec   total:
10
*util_xalloc              1394122.2/sec 1377139.033/sec   183074.2267/sec
total: 106249487139*
netdev_set_policing        0.0/sec     0.000/sec        0.0000/sec   total:
193
netdev_get_ifindex         0.0/sec     0.000/sec        0.0000/sec   total:
95
netdev_get_hwaddr          0.0/sec     0.000/sec        0.0000/sec   total:
95
netdev_get_ethtool         0.0/sec     0.000/sec        0.0000/sec   total:
692
netdev_set_ethtool         0.0/sec     0.000/sec        0.0000/sec   total:
74
netlink_received          66.4/sec    57.200/sec       58.1303/sec   total:
210269856
netlink_recv_jumbo         5.2/sec     4.533/sec        4.5214/sec   total:
16457662
netlink_sent              39.0/sec    33.350/sec       34.8475/sec   total:
127157369
nln_changed                0.0/sec     0.000/sec        0.0000/sec   total:
854


Best regards,
Mário Reis
_______________________________________________
discuss mailing list
discuss@openvswitch.org
http://openvswitch.org/mailman/listinfo/discuss

Reply via email to