We consume lots of SOAP. Its probably a GDS thing.

Due to increased response sizes, our parsing times went up. Fun times! Here are the steps taken for optimizing XML parsing (using python>=3.4 and lxml)

Metrics, Profiling

Our parse function interface is more or less like this

def iparse(xml_string):
    """
    Parse the string xml_string. 
    Return a list of result tuples
    """

We need to profile our code to find bottlenecks. We also need big XML files for testing. Here is code that generates a (hypothetical) XML Response and dumps it to stdout

from lxml import etree as ET

def generate_test_xml(n_results=250):
    root = ET.Element("{http://www.w3.org/1999/xhtml}Body")
    response = ET.SubElement(root, "{http://www.w3.org/1999/xhtml}Response")
    for i in range(n_results):
        parent = ET.SubElement(response, "{http://www.w3.org/1999/xhtml}ResponseItem", ResponseItemID=str(i))
        for j in range(100):
            child = ET.SubElement(parent, "{http://www.w3.org/1999/xhtml}ResponseItemDatum", SubItemID=str(j), ResponseItemID=str(i))
            child2 = ET.SubElement(child, "{http://www.w3.org/1999/xhtml}ResponseItemDatumChild2", SubItemID=str(j + 1), ResponseItemID=str(i))
            child2.text = str(j * i)
            child3 = ET.SubElement(child2, "{http://www.w3.org/1999/xhtml}ResponseItemDatumChild3", SubItemID=str(j + 2), ResponseItemID=str(i))
            child3.text = str(j * i)
            child4 = ET.SubElement(child3, "{http://www.w3.org/1999/xhtml}ResponseItemDatumChild4", SubItemID=str(j + 3), ResponseItemID=str(i))
            child4.text = str(j * i)
            child5 = ET.SubElement(child3, "{http://www.w3.org/1999/xhtml}ResponseItemDatumChild5", SubItemID=str(j + 3), ResponseItemID=str(i))
            child5.text = str(j * i)

    ET.dump(root)

if __name__ == '__main__':
    generate_test_xml()
Then we can generate a simple xml file like so

    python gen_xml.py > demo.xml

Assuming there is a module named `parsers` in our `PYTHONPATH`, we can test different parser implementation
functions within that module with this small script

import argparse
import sys
import logging
from time import time
import parsers

logger = logging.getLogger("parser.test")
logger.setLevel(logging.DEBUG)

ch = logging.StreamHandler(sys.stdout)
ch.setLevel(logging.DEBUG)
formatter = logging.Formatter('[%(asctime)s] %(message)s')
ch.setFormatter(formatter)
logger.addHandler(ch)


def test_parser(parser):
    with open("demo.xml") as f:
        s = f.read()
    now = time()
    logger.info("evaluating parser `{}`".format(parser.__name__))
    results = parser(s)
    logger.info("parsing completed in {0:0.5f} sec.".format(time() - now))
    logger.info("correctly parsed {0} results.".format(len(results)))


def main():
    parser = argparse.ArgumentParser(description='Test A Parser Implementation')
    parser.add_argument('-p','--parser_function', default="parsers.parse",
                        help='Parser function to measure')

    opts = parser.parse_args()
    fn_name = opts.parser_function.split(".")[-1]
    parser = getattr(parsers, fn_name)
    test_parser(parser)
    return 0

if __name__ == '__main__':
    main()

By running it like so

PYTHONPATH=`pwd` python test.py -p parsers.parse

Diving in

Initial parse performance

The existing implementation removes XML namespaces, then parses and locates elements of interest using ElementTree standard operations (findall, find, etc).

def parse(xml):
 root = strip_namespaces(xml)
 results = []
 for subelement in root.findall(".//ResponseItemDatum"):
 i = subelement.find(".//ResponseItemDatumChild3").get("SubItemID")
 j = subelement.find(".//ResponseItemDatumChild4").get("SubItemID")
 results.append((i,j))
 return results

results:

[2014-04-29 14:30:07,288] evaluating parser `parse`
[2014-04-29 14:30:10,631] parsing completed in 3.34278 sec.
[2014-04-29 14:30:10,631] correctly parsed 25000 results.

Profiling

After profiling the code with guppy, we discovered that more than 50% of parsing time was spent stripping namespaces function. We refactored the code to use namespaces:

def parse4(xml):
    root = ET.fromstring(xml)
    results = []
    for subelement in root.iterfind(".//{http://www.w3.org/1999/xhtml}ResponseItemDatum"):
        chd = subelement.find(".//{http://www.w3.org/1999/xhtml}ResponseItemDatumChild3")
        i = chd.get("SubItemID")
        j = chd.find("{http://www.w3.org/1999/xhtml}ResponseItemDatumChild4").get("SubItemID")
        results.append((i,j))
    return results

results:

[2014-04-29 15:17:09,212] evaluating parser `parse4`
[2014-04-29 15:17:10,357] parsing completed in 1.14476 sec.

The function strip_namespaces removed namespaces by applying an XSLT transformation

def strip_namespaces(xml_with_namespaces):
    xslt = '''
    

    
        
            
        
    

    
        
            
        
    

    
        
            
        
    
    
    '''
    xslt_doc = ET.parse(io.BytesIO(xslt.encode("latin-1")))
    transform = ET.XSLT(xslt_doc)
    dom = ET.parse(io.BytesIO(xml_with_namespaces.encode("latin-1")))
    return transform(dom)

Performing XSLT transformations turned out to be a heavy operation. When processing typical SOAP responses (< 100KB), the convenience of using
simple ElementPath queries sans the namespaces outweighs the performance penalty. However, with bigger responses, we want performs way better.

Using pure XPath

The next profiler run revealed another bottleneck -- ElementPath selection operations themselves. After more lxml digging, the solution came in the form of precompiled pure-XPath expressions.

XP_NS = {"o": "http://www.w3.org/1999/xhtml"}
XP_ALL_ELEMS = "o:Response/o:ResponseItem/o:ResponseItemDatum"
XP_CHD_ELEM = "o:ResponseItemDatumChild2/o:ResponseItemDatumChild3"
XP_CHD_ELEM2 = "o:ResponseItemDatumChild4"
find_all_elems = ET.XPath(XP_ALL_ELEMS, namespaces=XP_NS)
find_child_elem = ET.XPath(XP_CHD_ELEM, namespaces=XP_NS)
find_child_elem2 = ET.XPath(XP_CHD_ELEM2, namespaces=XP_NS)

def parse5(xml):
    root = ET.fromstring(xml)
    results = []
    for subelement in find_all_elems(root):
        chd = find_child_elem(subelement)[0]
        i = chd.get("SubItemID")
        j = find_child_elem2(chd)[0].get("SubItemID")
        results.append((i,j))
    return results

results:

[2014-04-29 15:20:04,464] evaluating parser `parse5`
[2014-04-29 15:20:05,060] parsing completed in 0.59525 sec.

Using iterparse

def parse6(xml):

    XP_NS = {"o": "http://www.w3.org/1999/xhtml"}
    XP_CHD_ELEM2 = "o:ResponseItemDatumChild4"

    find_child_elem2 = ET.XPath(XP_CHD_ELEM2, namespaces=XP_NS)
    results = []
    XP_CHD_ELEM_TAG = "{http://www.w3.org/1999/xhtml}ResponseItemDatumChild3"
    l_elem = None

    for _, elem in ET.iterparse(io.BytesIO(xml.encode("latin-1")), events=("end",)):
        l_elem = elem
        tag = elem.tag
        if tag == XP_CHD_ELEM_TAG:
            i = elem.get("SubItemID")
            j = find_child_elem2(elem)[0].get("SubItemID")
            results.append((i,j))
            elem.clear()
    if l_elem is not None:
        l_elem.clear()
    return results

results:

[2014-04-29 15:21:40,416] evaluating parser `parse6`
[2014-04-29 15:21:41,020] parsing completed in 0.60345 sec.

Final results and conclusion

From 3.34 down to 0.6 seconds! We made parsing much faster.
The factors that contributed the most to achieving significant optimizations were removing XSLT transformations, exclusive use of precompiled
XPATH expressions for element finding operations. Finally, using iterparse + element clearing reduced memory usage for a negligible performance penalty. Happy servers! :)