[ovirt-devel] [VDSM][JSON] jsonrpc coding/encoding performance on RHEL/Centos 6

Mon Nov 10 08:40:22 UTC 2014

Great work,

+1 to merge it to all branches.

Can you post results of the same test for xmlrpc?

I wonder what is the slowdown/speedup between protocols.

On Mon, Nov 10, 2014 at 9:02 AM, Francesco Romani <fromani at redhat.com> wrote:
> Hi everyone,
>
> I was doing JSON-RPC investigation recently, running VDSM on RHEL6.{5,6},
> and while some initial profile work, I discovered a (little) performance degradation
> about pure JSONRPC coding/encoding, *only* on the above platforms. Here's why:
>
> - the JSON codec module in the python stdlib is based on simplejson
> - (thus) simplejson API is identical to stdlib's json module API
> - python 2.6 JSON codec is (based on) simplejson 1.9
> - python 2.7 JSON codec is (based on) simplejson 2.0.9, with significant speedups. See
>   https://docs.python.org/2/whatsnew/2.7.html#new-and-improved-modules and
>   https://bugs.python.org/issue4136
> - RHEL6.x/Centos 6.x includes python 2.6, so here (and only here) JSON codec
>   is unnecessarily slower.
> - RHEL6.x (surely) and CentOS 6.x (need to check, don't see why not) includes
>   anyway simplejson 2.0.9 as external package
>
> So, it seems to me that we can get python 2.7 speed even on stable platform with
> a five line patch:
>
> === cut here ===
> diff --git a/lib/yajsonrpc/__init__.py b/lib/yajsonrpc/__init__.py
> index b3fd590..6682fc3 100644
> --- a/lib/yajsonrpc/__init__.py
> +++ b/lib/yajsonrpc/__init__.py
> @@ -12,7 +12,10 @@
>  # You should have received a copy of the GNU General Public
>  # License along with this program; if not, write to the Free Software
>  # Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
> -import json
> +try:
> +    import simplejson as json
> +except ImportError
> +    import json
>  import logging
>  from functools import partial
>  from Queue import Queue
> === cut here ===
>
> Here's an excerpt of the effects of this patch, using an initial still rough bencmark
> - once again 100 VMs boot, is the beginning of every testing routine from mine,
> so nothing new here.
>
> Let's consider two initial profiles. Please note that
> 1) the amount of calls is not the same (error from mine in profiling, need more precise bench)
>    but still
> 2) using 2.0.9 module JSON just vanishes from the profile alltogether
>
> Vanilla VDSM, stdlib json, top 20 expensive calls
>
>    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
>    19/100  127.216    6.696    9.974    0.100 /usr/lib/python2.6/site-packages/mom/GuestMonitor.py:51(GuestMonitor.run)
> 1555/1635   41.180    0.026   58.566    0.036 /usr/lib64/python2.6/threading.py:481(Thread.run)
> 11708/1553160   11.967    0.001   37.921    0.000 /usr/lib64/python2.6/copy.py:144(deepcopy)
>   1268613    6.154    0.000    9.209    0.000 /usr/lib64/python2.6/copy.py:261(_keep_alive)
> 4890/130093    6.149    0.001   37.596    0.000 /usr/lib64/python2.6/copy.py:251(_deepcopy_dict)
> 497858/2070078    5.224    0.000   11.102    0.000 /usr/lib64/python2.6/json/encoder.py:284(JSONEncoder._iterencode)
> 498440/1333474    4.187    0.000   10.368    0.000 /usr/lib64/python2.6/json/encoder.py:213(JSONEncoder._iterencode_dict)
>    12/100    4.115    0.343    4.130    0.041 /usr/share/vdsm/virt/sampling.py:424(VmStatsThread.run)
>     43826    3.692    0.000    6.516    0.000 /usr/lib64/python2.6/xml/dom/expatbuilder.py:743(ExpatBuilderNS.start_element_handler)
>      7345    3.657    0.000   11.047    0.002 /usr/share/vdsm/virt/vm.py:2264(Vm._getRunningVmStats)
> 9666/320508    3.568    0.000    3.572    0.000 /usr/lib64/python2.6/xml/dom/minidom.py:305(_get_elements_by_tagName_helper)
> 274994/275000    3.339    0.000    5.593    0.000 /usr/lib64/python2.6/StringIO.py:208(StringIO.write)
>     90217    1.823    0.000    1.870    0.000 /usr/lib64/python2.6/xml/dom/minidom.py:349(Attr.__init__)
> 44025/44036    1.666    0.000    2.470    0.000 /usr/share/vdsm/storage/lvm.py:217(makeLV)
> 144212/144226    1.287    0.000    1.292    0.000 /usr/lib/python2.6/site-packages/vdsm/utils.py:285(convertToStr)
>       201    1.285    0.006    7.278    0.036 /usr/share/vdsm/storage/lvm.py:411(LVMCache._reloadlvs)
>    109880    1.235    0.000    1.283    0.000 /usr/lib64/python2.6/xml/dom/minidom.py:281(Document._append_child)
>     57874    1.163    0.000    1.799    0.000 /usr/lib64/python2.6/xml/dom/expatbuilder.py:274(ExpatBuilderNS.character_data_handler_cdata)
>   1130859    1.160    0.000    1.160    0.000 /usr/lib64/python2.6/copy.py:197(_deepcopy_atomic)
> 3021/3022    1.121    0.000    2.554    0.001 /usr/lib64/python2.6/inspect.py:247(getmembers)
>
>
> patch applied, top 20 expensive calls
>
>    24/100  117.222    4.884   13.372    0.134 /usr/lib/python2.6/site-packages/mom/GuestMonitor.py:51(GuestMonitor.run)
> 1209/1302   60.812    0.050   64.963    0.050 /usr/lib64/python2.6/threading.py:481(Thread.run)
> 9243/1235834   10.259    0.001   33.047    0.000 /usr/lib64/python2.6/copy.py:144(deepcopy)
>    13/100    7.007    0.539    7.281    0.073 /usr/share/vdsm/virt/sampling.py:424(VmStatsThread.run)
> 4116/103669    5.536    0.001   32.779    0.000 /usr/lib64/python2.6/copy.py:251(_deepcopy_dict)
> 9670/320560    4.437    0.000    4.443    0.000 /usr/lib64/python2.6/xml/dom/minidom.py:305(_get_elements_by_tagName_helper)
>      5653    3.232    0.001    9.443    0.002 /usr/share/vdsm/virt/vm.py:2264(Vm._getRunningVmStats)
>     43836    3.117    0.000    7.304    0.000 /usr/lib64/python2.6/xml/dom/expatbuilder.py:743(ExpatBuilderNS.start_element_handler)
> 274967/275000    2.955    0.000    6.833    0.000 /usr/lib64/python2.6/StringIO.py:208(StringIO.write)
> 1100/28500    2.376    0.002   12.881    0.000 /usr/share/vdsm/virt/vmxml.py:489(Element.__hacked_writexml)
> 43745/44036    1.729    0.000    2.736    0.000 /usr/share/vdsm/storage/lvm.py:217(makeLV)
> 90217/90221    1.695    0.000    1.953    0.000 /usr/lib64/python2.6/xml/dom/minidom.py:349(Attr.__init__)
>       201    1.549    0.008    7.725    0.038 /usr/share/vdsm/storage/lvm.py:411(LVMCache._reloadlvs)
>     57888    1.441    0.000    2.216    0.000 /usr/lib64/python2.6/xml/dom/expatbuilder.py:274(ExpatBuilderNS.character_data_handler_cdata)
> 2351/2354    1.262    0.001    2.750    0.001 /usr/lib64/python2.6/inspect.py:247(getmembers)
>    992794    1.232    0.000    8.027    0.000 /usr/lib64/python2.6/copy.py:261(_keep_alive)
>      4827    1.150    0.000    1.368    0.000 /usr/lib/python2.6/site-packages/mom/Policy/spark.py:211(Parser.buildState)
>    108040    1.119    0.000    1.119    0.000 /usr/lib/python2.6/site-packages/vdsm/utils.py:285(convertToStr)
> 336771/422122    1.106    0.000    2.575    0.000 /usr/share/vdsm/protocoldetector.py:108(MultiProtocolAcceptor._process_events)
>    883021    0.987    0.000    0.987    0.000 /usr/lib64/python2.6/copy.py:197(_deepcopy_atomic)
>
>
> Indeed this is a microbenchmark, but my point is we *recover* some speed at nearly
> zero cost and risk.
>
> Now, the question is:
> Do we want this patch? Do we want it on master? On 3.5 branch? Only on RHEL/Centos 6 platforms?
>
> --
> Francesco Romani
> RedHat Engineering Virtualization R & D
> Phone: 8261328
> IRC: fromani
> _______________________________________________
> Devel mailing list
> Devel at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel