[ovirt-devel] [VDSM] Profiling results - 144 cores, 144 vms

[emarcian]

Thanks Nir for this analysis.
we currently focusing on bug verification for 3.6, afterwards, we can 
prioritiez this effort.

master branch includes some changes related to these topics?

i think it will be better to open a bug for each of the bullets, i'll 
take care of it.


Adding Gil, to mail thread

-Eldad

On 02/18/2016 01:38 AM, Nir Soffer wrote:
> Hi all,
>
> I noticed that Eldad posted profiling result from 144 cores / 144 vms run:
> See https://bugzilla.redhat.com/attachment.cgi?id=1128028
>
> Looking at the profile bellow:
>
> 1. Why _rtnl_link_alloc_cache is so expensive?
>      called only 389 times, but the most expensive call
>
> 2. Creating DomainDescriptor seems expensive - is this xml.minidom?
>
> 3. guestagent.py:84(filt) is very expensive - we probbaly want to backport
>      7091bde guestagent: Speed up xml character filtering, can shave about
>      17% of cpu time in this run.
>
> 4. pthread.py function will disapper from the profile if we replace
>      pthreading with cthreading:
>      https://github.com/nirs/cthreading
>
> 5. Why do we see xmlrpc at the top of the profile? Is this the cost
>      of mom calls?
>
> Eldad, can you repeat the same test with current master?
>
> Nir
>
> ----
>
> Thu Feb 18 00:50:24 2016    vdsm_144vms_1800sec_2.prof
>
>           29858105 function calls (34034631 primitive calls) in 1049.574 seconds
>
>     Ordered by: internal time
>     List reduced from 2420 to 20 due to restriction <20>
>
>        ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>           389   64.937    0.167   64.941    0.167
> link.py:133(_rtnl_link_alloc_cache)
>     598438   64.176    0.000   87.888    0.000
> domain_descriptor.py:23(DomainDescriptor)
>   1535528   38.922    0.001  176.177    0.000 guestagent.py:84(filt)
>       57106   31.545    0.001   31.560    0.001
> decoder.py:371(JSONDecoder.raw_decode)
>     168463   25.961    0.234  119.004    0.001
> xmlrpclib.py:721(Marshaller.dump_struct)
>   4312452   25.095    0.000   77.012    0.000 utf_8.py:15(decode)
>   7341795   21.934    0.000   41.507    0.000 string.py:511(replace)
>       28881   18.092    0.001   19.921    0.001 pthread.py:133(Cond.timedwait)
>     386282   17.509    0.000   17.509    0.000 pthread.py:95(Lock.lock)
>       46277   16.798    0.000   45.280    0.001
> guestagent.py:254(GuestAgent._handleMessage)
>       48090   16.298    0.000   37.809    0.001
> expatbuilder.py:743(ExpatBuilderNS.start_element_handler)
>   2447266   14.128    0.000   55.635    0.000 httplib.py:331(HTTPResponse)
>     339514   13.689    0.014   20.629    0.000 password.py:69(_walk)
>       78549   12.450    0.000   12.635    0.000 minidom.py:344(Attr.__init__)
>       20117   12.381    0.001   20.961    0.001 vm.py:181(SetLinkAndNetworkError)
>       14470   12.224    0.001   12.802    0.001 xmlbuilder.py:1(<module>)
>       21404   11.527    0.001   36.225    0.002 vmstats.py:240(disks)
>       87612   11.441    0.000   35.701    0.000
> sampling.py:59(InterfaceSample.readIfaceStat)
>       39924   11.323    0.000   23.047    0.001
> __init__.py:242(LogRecord.__init__)
>       14509   10.816    0.001   96.236    0.007 xmlbuilder.py:12(Options)