Hey Rahul, I do not have bandwidth for doing the test your asked,
You haven't answered the questions asked, so please answer them first before we can have this conversation continuing, 1. Did you use vm or bare metal machine for testing, 2. Did you make any modification to ovs, if so, what did you modify, 3. Repeat your test and show me the full `mpstat -P ALL` output, 4. Run 'modinfo openvswitch' and show me the output, Also, please do not cross-post anymore without providing more details about your experiment, Thanks, Alex Wang, On Wed, Dec 10, 2014 at 1:08 AM, Rahul Arora <rahul1991.ar...@gmail.com> wrote: > Hello Alex, > > Thanks for your immediate reply. > > Alex, > > Can you please test the same performance with the same flow by enabling 2 > cores of the server only.And share the performance report with me of OVS VS > Kernel Bridge. > > > > > On Wed, Dec 10, 2014 at 1:10 PM, Alex Wang <al...@nicira.com> wrote: > >> Hey Rahul, >> >> The warning means the handler threads was busying running for 16 seconds >> before calling time_poll() again (in other words, before trying to sleep >> again). >> >> The log showed suspiciously long system running. Definitely not expected, >> >> Could you confirm the ovs kernel module version via 'modinfo openvswitch'? >> Never seen such warning with 2.3 kernel module, >> >> Thanks, >> Alex Wang, >> >> On Tue, Dec 9, 2014 at 10:47 PM, Rahul Arora <rahul1991.ar...@gmail.com> >> wrote: >> >>> Alex, >>> >>> I am getting these logs when i am getting 100% CPU usage. >>> >>> Please have a look on the RED part. >>> >>> ====================================== >>> 2014-11-25T06:04:37.604Z|00095|timeval(handler5)|WARN|Unreasonably long >>> 16127ms poll interval (260ms user, 17320ms system) >>> 2014-11-25T06:04:37.604Z|00096|timeval(handler5)|WARN|faults: 8062 >>> minor, 0 major >>> 2014-11-25T06:04:37.604Z|00097|timeval(handler5)|WARN|context switches: >>> 2424 voluntary, 670 involuntary >>> 2014-11-25T06:04:37.604Z|00098|coverage(handler5)|INFO|Event coverage, >>> avg rate over last: 5 seconds, last minute, last hour, hash=9b29cbda: >>> 2014-11-25T06:04:37.604Z|00099|coverage(handler5)|INFO|netlink_sent >>> 211.0/sec 77.300/sec 3.8958/sec total: 15051 >>> 2014-11-25T06:04:37.604Z|00100|coverage(handler5)|INFO|netlink_recv_jumbo >>> 0.4/sec 0.400/sec 0.0536/sec total: 195 >>> 2014-11-25T06:04:37.604Z|00101|coverage(handler5)|INFO|netlink_received >>> 213.0/sec 78.983/sec 4.1219/sec total: 15873 >>> 2014-11-25T06:04:37.604Z|00102|coverage(handler5)|INFO|netlink_overflow >>> 0.0/sec 0.033/sec 0.0011/sec total: 4 >>> 2014-11-25T06:04:37.604Z|00103|coverage(handler5)|INFO|netdev_set_ethtool >>> 0.0/sec 0.000/sec 0.0006/sec total: 2 >>> 2014-11-25T06:04:37.604Z|00104|coverage(handler5)|INFO|netdev_get_ethtool >>> 0.0/sec 0.000/sec 0.0028/sec total: 10 >>> 2014-11-25T06:04:37.605Z|00105|coverage(handler5)|INFO|netdev_set_hwaddr >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00106|coverage(handler5)|INFO|netdev_get_hwaddr >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00107|coverage(handler5)|INFO|netdev_get_ifindex >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00108|coverage(handler5)|INFO|netdev_set_policing >>> 0.0/sec 0.000/sec 0.0017/sec total: 6 >>> 2014-11-25T06:04:37.605Z|00109|coverage(handler5)|INFO|vconn_sent >>> 0.0/sec 0.000/sec 0.0014/sec total: 5 >>> 2014-11-25T06:04:37.605Z|00110|coverage(handler5)|INFO|vconn_received >>> 0.0/sec 0.000/sec 0.0019/sec total: 7 >>> 2014-11-25T06:04:37.605Z|00111|coverage(handler5)|INFO|util_xalloc >>> 396.6/sec 367.317/sec 50.7611/sec total: 184603 >>> 2014-11-25T06:04:37.605Z|00112|coverage(handler5)|INFO|stream_open >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00113|coverage(handler5)|INFO|pstream_open >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00114|coverage(handler5)|INFO|rconn_sent >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00115|coverage(handler5)|INFO|rconn_queued >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00116|coverage(handler5)|INFO|poll_zero_timeout >>> 0.0/sec 0.000/sec 0.0031/sec total: 11 >>> 2014-11-25T06:04:37.605Z|00117|coverage(handler5)|INFO|poll_fd_wait >>> 30.0/sec 29.617/sec 4.1908/sec total: 15201 >>> 2014-11-25T06:04:37.605Z|00118|coverage(handler5)|INFO|txn_success >>> 0.0/sec 0.000/sec 0.0017/sec total: 6 >>> 2014-11-25T06:04:37.605Z|00119|coverage(handler5)|INFO|txn_incomplete >>> 0.2/sec 0.183/sec 0.0278/sec total: 101 >>> 2014-11-25T06:04:37.605Z|00120|coverage(handler5)|INFO|txn_unchanged >>> 0.0/sec 0.017/sec 0.0075/sec total: 27 >>> 2014-11-25T06:04:37.605Z|00121|coverage(handler5)|INFO|netdev_get_stats >>> 0.6/sec 0.600/sec 0.0811/sec total: 295 >>> 2014-11-25T06:04:37.605Z|00122|coverage(handler5)|INFO|mac_learning_expired >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00123|coverage(handler5)|INFO|mac_learning_learned >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00124|coverage(handler5)|INFO|hmap_expand >>> 18.4/sec 17.883/sec 2.5731/sec total: 9337 >>> 2014-11-25T06:04:37.605Z|00125|coverage(handler5)|INFO|hmap_pathological >>> 0.0/sec 0.000/sec 0.0053/sec total: 19 >>> 2014-11-25T06:04:37.605Z|00126|coverage(handler5)|INFO|flow_extract >>> 200.0/sec 70.417/sec 3.1047/sec total: 12150 >>> 2014-11-25T06:04:37.605Z|00127|coverage(handler5)|INFO|dpif_execute >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00128|coverage(handler5)|INFO|dpif_flow_put >>> 0.0/sec 0.000/sec 0.0006/sec total: 2 >>> 2014-11-25T06:04:37.605Z|00129|coverage(handler5)|INFO|dpif_flow_flush >>> 0.0/sec 0.000/sec 0.0006/sec total: 2 >>> 2014-11-25T06:04:37.605Z|00130|coverage(handler5)|INFO|dpif_port_add >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00131|coverage(handler5)|INFO|xlate_actions >>> 4.0/sec 1.433/sec 0.0656/sec total: 256 >>> 2014-11-25T06:04:37.605Z|00132|coverage(handler5)|INFO|rev_mac_learning >>> 0.0/sec 0.000/sec 0.0006/sec total: 2 >>> 2014-11-25T06:04:37.605Z|00133|coverage(handler5)|INFO|rev_flow_table >>> 0.0/sec 0.000/sec 0.0006/sec total: 2 >>> 2014-11-25T06:04:37.605Z|00134|coverage(handler5)|INFO|rev_port_toggled >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00135|coverage(handler5)|INFO|rev_reconfigure >>> 0.0/sec 0.000/sec 0.0008/sec total: 3 >>> 2014-11-25T06:04:37.605Z|00136|coverage(handler5)|INFO|ofproto_update_port >>> 0.0/sec 0.000/sec 0.0025/sec total: 9 >>> 2014-11-25T06:04:37.605Z|00137|coverage(handler5)|INFO|ofproto_recv_openflow >>> 0.0/sec 0.000/sec 0.0014/sec total: 5 >>> 2014-11-25T06:04:37.605Z|00138|coverage(handler5)|INFO|ofproto_flush >>> 0.0/sec 0.000/sec 0.0003/sec total: 1 >>> 2014-11-25T06:04:37.605Z|00139|coverage(handler5)|INFO|bridge_reconfigure >>> 0.0/sec 0.000/sec 0.0011/sec total: 4 >>> 2014-11-25T06:04:37.605Z|00140|coverage(handler5)|INFO|49 events never >>> hit >>> ======================================================================== >>> >>> >>> Do you have some idea how i can optimize it? >>> >>> On Wed, Dec 10, 2014 at 11:41 AM, Alex Wang <al...@nicira.com> wrote: >>> >>>> >>>> I believe it has 16 cores, with hyperthreading disabled, >>>> >>>> On Tue, Dec 9, 2014 at 9:37 PM, Rahul Arora <rahul1991.ar...@gmail.com> >>>> wrote: >>>> >>>>> Hi Alex, >>>>> >>>>> The platform which you are using for your performance testing is of >>>>> how many cores?? >>>>> >>>>> On Tue, Dec 9, 2014 at 10:45 PM, Alex Wang <al...@nicira.com> wrote: >>>>> >>>>>> Hey Rahul, >>>>>> >>>>>> The kernel version should not make a difference, >>>>>> >>>>>> I'm curious, since ovs-2.3.0 is multithreaded, not sure how do you >>>>>> measure >>>>>> the cpu usage to be 100%? >>>>>> >>>>>> Also, could you post the full `mpstat -P ALL` output, so we can see >>>>>> the >>>>>> distribution of cpu usage, >>>>>> >>>>>> >>>>>> Thanks, >>>>>> Alex Wang, >>>>>> >>>>>> >>>>>> >>>>>> On Tue, Dec 9, 2014 at 1:49 AM, Rahul Arora < >>>>>> rahul1991.ar...@gmail.com> wrote: >>>>>> >>>>>>> Hi Alex, >>>>>>> >>>>>>> Thanks for your help. >>>>>>> >>>>>>> I am using the following command to test CPU usage. >>>>>>> >>>>>>> mpstat -P ALL 1 >>>>>>> >>>>>>> I was using 3.12 kernel version and you are using 3.13.0-30-generic >>>>>>> version.Please let me know if this can be the issue?? >>>>>>> >>>>>>> >>>>>>> >>>>>>> On Sat, Dec 6, 2014 at 5:04 AM, Alex Wang <al...@nicira.com> wrote: >>>>>>> >>>>>>>> Hey Rahul, >>>>>>>> >>>>>>>> Could you help confirm the following: >>>>>>>> >>>>>>>> 1. did you use vm or bare metal machine for testing? >>>>>>>> >>>>>>>> 2. how do you measure the cpu utilization of ovs and kernel bridge? >>>>>>>> >>>>>>>> >>>>>>>> We ran some throughput tests, and we observed constant better >>>>>>>> performance over the Linux bridge. >>>>>>>> >>>>>>>> Below is a set of our own throughput test result using ovs >>>>>>>> branch-2.3. >>>>>>>> >>>>>>>> Plateform: >>>>>>>> Server Dell R620, running Ubuntu 14.04 (3.13.0-30-generic), NIC is >>>>>>>> Intel X540. >>>>>>>> >>>>>>>> Flow: >>>>>>>> Single flow, "in_port=1,actions:output=2" >>>>>>>> >>>>>>>> Traffic type: >>>>>>>> - unidirectional TCP throughput using Spirent (1 flow and 128 >>>>>>>> flows). >>>>>>>> >>>>>>>> >>>>>>>> *Throughput view (unit: Gbit/s):* >>>>>>>> >>>>>>>> Linux Bridge, >>>>>>>> Frame Size1 flow128 flow780.6021.5121280.9812.1892561.8155.433512 >>>>>>>> 3.2525.29910246.65810.015149.6849.98790009.92110.0 >>>>>>>> >>>>>>>> OVS Branch-2.3: >>>>>>>> Frame Size1 flow128 flow780.78.2581281.09810.02561.89810.05123.694 >>>>>>>> 10.010247.1910.015149.8849.98790009.89910.0 >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> *Frame Per Second view (unit: Frames/s):* >>>>>>>> >>>>>>>> Linux Bridge, >>>>>>>> Frame Size1 flow128 flow7876805719290121288289121849112256822070 >>>>>>>> 246063051276405812450201024797193119731815147891418138029000137491 >>>>>>>> 138581 >>>>>>>> >>>>>>>> OVS Branch-2.3: >>>>>>>> Frame Size1 flow128 flow78892857105337071289272998445946256859386 >>>>>>>> 452898551286805523496241024860881119731815148054128138029000137181 >>>>>>>> 138581 >>>>>>>> >>>>>>>> >>>>>>>> Thanks, >>>>>>>> Alex Wang, >>>>>>>> >>>>>>>> On Wed, Nov 26, 2014 at 10:35 PM, Rahul Arora < >>>>>>>> rahul1991.ar...@gmail.com> wrote: >>>>>>>> >>>>>>>>> Hi Team, >>>>>>>>> >>>>>>>>> We are doing comparison of throughput and CPU consumption between >>>>>>>>> OVS 2.3.0 and kernel bridge with different packet size. >>>>>>>>> >>>>>>>>> We are observing huge difference in performance. With frame size >>>>>>>>> 64 and 128 bytes unidirectional traffic from port1 to port2 below are >>>>>>>>> the >>>>>>>>> numbers. >>>>>>>>> >>>>>>>>> >>>>>>>>> *OVS 2.3.0 (Dual core with matching flow in kernel space, kernel >>>>>>>>> 3.12)* >>>>>>>>> >>>>>>>>> * kernel bridge(Dual Core System, kernel 3.12) * *FRAME SIZE* >>>>>>>>> *Throughput >>>>>>>>> unidirectional (Mbps)* *CPU Usage %* *VS* *FRAME SIZE* *Throughput >>>>>>>>> (Mbps)* *CPU Usage %* 64 375 100 64 487 100 128 747 100 128 864 >>>>>>>>> 40 256 927 10 256 927 5 320 941 8 320 941 4 384 950 6 384 950 4 >>>>>>>>> 448 957 4 448 957 3 512 962 3 512 962 3 1024 980 1 1024 980 1 >>>>>>>>> 1500 986 1 1500 986 1 >>>>>>>>> We have matching flow in kernel space with in_port=1 and >>>>>>>>> action=output:2 and flow is matching in kernel space >>>>>>>>> >>>>>>>>> How we can improve the performance of OVS i.e. increasing the >>>>>>>>> throughput and decrease CPU consumption with lower frame size. >>>>>>>>> >>>>>>>>> _______________________________________________ >>>>>>>>> discuss mailing list >>>>>>>>> discuss@openvswitch.org >>>>>>>>> http://openvswitch.org/mailman/listinfo/discuss >>>>>>>>> >>>>>>>>> >>>>>>>> >>>>>>> >>>>>> >>>>> >>>> >>> >> >
_______________________________________________ discuss mailing list discuss@openvswitch.org http://openvswitch.org/mailman/listinfo/discuss
