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

From: "Francesco Romani" <fromani(a)redhat.com&gt; To: devel(a)ovirt.org Sent: Monday, November 10, 2014 10:02:44 AM Subject: [ovirt-devel] [VDSM][JSON] jsonrpc coding/encoding performance on RHEL/Centos 6 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?