[ovs-discuss] ovn-controller taking lot of time to process logical flows

Numan Siddique nusiddiq at redhat.com
Fri Jul 5 18:46:55 UTC 2019


Hello,

Daniel and Lucas were doing some scale testing with OpenShift
deployed on top of OpenStack with OVN (OVS/OVN 2.9) in last
couple of weeks. They noticed very high CPU usage during the test runs.

Below are some of the observations we found
 -  ovn-controller is taking a lot of time in processing the logical flows.
 -  The setup had close to 37000 logical flows and the function lflow_run()
    was taking ~10 seconds to complete.
 -  Since main loop took > 5 seconds to complete, poll_block() was returning
    immediately to handle the probe inactivity for the openflow unix socket
connection.
    This caused continuous 100% CPU usage. After applying this patch -
https://patchwork.ozlabs.org/patch/1125106/
    and configuring higher inactivity probe value, the CPU usage settled
down.

We wanted to understand why lflow_run() is taking so much time. So
we did some dirty hacks and did the following in the function
consider_logical_flow() in lflow.c
and measured the time taken for the lflow_run()

  - returned just before calling expr_parse_string() - The time taken for
lflow_run was 40 msec
  - returned just after calling expr_parse_string()  - The time taken was
~425 msec
  - returned just after expr_annotate()              - The time taken was
~1800 msec
  - returned just after expr_normalize()             - The time taken was
~4900 msec
  - returned just after expr_to_matches()            - The time taken was
~8900 msec

Looks like these expr_*() functions are doing lots of mallocs and string
operations.

Below is the output of "perf top -t `pidof ovn-controller` -K"

*******
16.30%  libc-2.17.so        [.] _int_malloc



  11.74%  libc-2.17.so        [.] _int_free



   6.38%  libc-2.17.so        [.] malloc



   3.51%  ovn-controller      [.] expr_normalize_and



   3.41%  ovn-controller      [.] match_hash



   3.40%  ovn-controller      [.] flow_wildcards_hash



   3.39%  libc-2.17.so        [.] __memcpy_ssse3_back



   2.81%  libc-2.17.so        [.] malloc_consolidate



   2.64%  ovn-controller      [.] is_all_zeros



   2.49%  libc-2.17.so        [.] __strcmp_sse42



   2.30%  ovn-controller      [.] add_conjunction



   2.17%  ovn-controller      [.] bitwise_rscan



   1.76%  ovn-controller      [.] expr_destroy



   1.61%  libc-2.17.so        [.] __libc_calloc



   1.57%  ovn-controller      [.] bitwise_copy



   1.54%  ovn-controller      [.] ovsdb_idl_read



   1.46%  libc-2.17.so        [.] __memcmp_sse4_1



   1.43%  ovn-controller      [.] ovn_flow_lookup



   1.39%  ovn-controller      [.] consider_logical_flow.isra.2



   1.26%  ovn-controller      [.] ovsdb_datum_compare_3way



   1.24%  ovn-controller      [.] mf_subvalue_intersect



   1.17%  ovn-controller      [.] expr_match_new



   1.17%  libc-2.17.so        [.] free



   1.12%  ovn-controller      [.] resize



   1.02%  ovn-controller      [.] expr_matches_destroy



   1.01%  ovn-controller      [.] ovsdb_idl_index_generic_comparer



   0.91%  ovn-controller      [.] ofctrl_add_flow



   0.87%  ovn-controller      [.] expr_clone



   0.87%  ovn-controller      [.] expr_match_add



   0.84%  libc-2.17.so        [.] vfprintf
   0.80%  ovn-controller      [.] match_init_catchall



   0.72%  libc-2.17.so        [.] msort_with_tmp.part.0



   0.71%  ovn-controller      [.] hash_bytes



   0.64%  ovn-controller      [.] skiplist_forward_to_



   0.62%  ovn-controller      [.] expr_simplify



   0.54%  ovn-controller      [.] match_set_metadata



   0.52%  ovn-controller      [.] ovsdb_atom_compare_3way



   0.49%  ovn-controller      [.] parse_constant



   0.49%  ovn-controller      [.] expr_to_matches



   0.48%  ovn-controller      [.] ofctrl_put



   0.46%  ovn-controller      [.] crush_and_numeric



   0.41%  ovn-controller      [.] constrain_match



   0.40%  ovn-controller      [.] lex_token_parse



   0.35%  ovn-controller      [.] expr_is_cmp



   0.30%  libc-2.17.so        [.] __memcpy_sse2



   0.29%  ovn-controller      [.] mf_get_value



   0.29%  ovn-controller      [.] lex_parse_integer__



   0.28%  ovn-controller      [.] expr_normalize_or



   0.27%  ovn-controller      [.] xmalloc



   0.26%  ovn-controller      [.] flow_wildcards_init_catchall



   0.25%  ovn-controller      [.] expr_annotate__



   0.24%  ovn-controller      [.] mf_set



   0.23%  libc-2.17.so        [.] _IO_default_xsputn



   0.23%  ovn-controller      [.] expr_combine



   0.23%  libc-2.17.so        [.] __strspn_sse2
*******

I think we may have to optimize the expr_*() functions.
I don't have any solid idea at this point of time. Dumitru and I are
planning to
explore more on this in the coming weeks.

Any comments/suggestions/thoughts on this ?

Thanks
Numan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openvswitch.org/pipermail/ovs-discuss/attachments/20190706/f5f1b896/attachment-0001.html>


More information about the discuss mailing list