Saxon v9.1.0.6
Input XML size : 30K
XSLT size: 33K
When I run an XSLT as a standard Java application in eClipse I get
very different perfromance than running exactly the same piece of Java
within an App Server.
In this case I am running an XSLT2 stylesheet that validates a
message. The XSLT was generated from a schematron schema and works
successfully in both situations.
The Java code caches a Templates object for the stylesheet to improve
performance, and indeed this is evident in both sets of test results
(i.e. the first time through there is an overhead for reading the XSLT
from disk and caching a Templates object and thereafter this is very
much reduced as it is retrieved from cache).
From profiling the code, ALL of the difference comes from this line :-
transformer.transform(new DOMSource(doc), new StreamResult(baos));
and the difference is substantial. Running in eClipse the average time
taken is usually 60-80ms whereas within the app server its 700-800ms.
I'm at a loss to understand what could be causing a 10 fold increase
in the time taken for exactly the same code. Are there any JVM or
other settings that might be causing this ?
To be certain that the App Server (and eClipse) were picking up the
Saxon JARs and not some other parser I included in the output the
vendor name and version, which in both cases reported :-
<!--XSLT vendor: SAXON 9.1.0.6 from Saxonica, XSLT version: 2.0, XSLT
vendor URL: http://www.saxonica.com/-->
Some example code and outputs below ..
Regards
Fraser.
Example code perfroming the transform (including some timing output) :-
public String transformXml(String inputXml, String xslFilePath, Vector
paramsVector,) throws Exception {
long transformstart = System.currentTimeMillis();
long start = System.currentTimeMillis();
long end = 0L;
long totalTime = 0L;
ByteArrayInputStream bais = new
ByteArrayInputStream(inputXml.getBytes(stringEncoding));
InputSource in = new InputSource(bais);
DocumentBuilderFactory dfactory =
DocumentBuilderFactory.newInstance();
dfactory.setNamespaceAware(true);
Document doc = dfactory.newDocumentBuilder().parse(in);
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to parse input: " + totalTime);
start = System.currentTimeMillis();
TransformerFactory tFactory = cachingTransformerFactory;
Transformer transformer;
transformer = tFactory.newTransformer(new
StreamSource(new File(xslFilePath)));
transformer.clearParameters();
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to create transformer: " + totalTime);
start = System.currentTimeMillis();
// Create an instance of the wbimb URI Resolver
URIResolver objResolver = new MessageBrokerURIResolver();
transformer.setURIResolver(objResolver);
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to set URIResolver: " + totalTime);
start = System.currentTimeMillis();
ByteArrayOutputStream baos = new ByteArrayOutputStream();
//set parameters
for (int x = 0; x < paramsVector.size(); x++) {
Parameter param = (Parameter) paramsVector.get(x);
transformer.setParameter(param.name, param.value);
}
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to parse params: " + totalTime);
start = System.currentTimeMillis();
/******* THIS IS WHERE MOST OF THE TIME TAKEN IS ********/
transformer.transform(new DOMSource(doc), new
StreamResult(baos));
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to perform transform: " + totalTime);
start = System.currentTimeMillis();
baos.close();
byte[] data = baos.toByteArray();
String outputString = null;
try {
outputString = new String(data, stringEncoding);
} catch (Exception e) {
String message = "Got Exception converting the
output of transform to String using encoding: " + stringEncoding;
throw new Exception(message);
}
end = System.currentTimeMillis();
totalTime = end - start;
System.out.println("Time to convert the output of the
transform to a String: " + totalTime);
long transformend = System.currentTimeMillis();
long transformtotalTime = transformend - transformstart;
System.out.println("Total time to run XSLT: " +
transformtotalTime);
return outputString;
}
... and this is some typical output from running in eClipse (I'm
running 20 iterations here) :-
===================================================
TEST : validResponse_CachedStylesheet
===================================================
Time to parse input: 172
Time to create transformer: 547
Time to set URIResolver: 0
Time to parse params: 0
Time to perform transform: 187
Time to convert the output of the transform to a String: 0
Total time to run XSLT: 906
Time to parse input: 0
Time to create transformer: 0
Time to set URIResolver: 0
Time to parse params: 0
Time to perform transform: 94
Time to convert the output of the transform to a String: 0
Total time to run XSLT: 94
Time to parse input: 0
Time to create transformer: 0
Time to set URIResolver: 0
Time to parse params: 0
Time to perform transform: 78
Time to convert the output of the transform to a String: 0
Total time to run XSLT: 78
Time to parse input: 0
Time to create transformer: 0
Time to set URIResolver: 0
Time to parse params: 0
Time to perform transform: 78
Time to convert the output of the transform to a String: 0
Total time to run XSLT: 78
...
Total time to run XSLT for (20) iterations : 2500
Average time to run XSLT for (20) iterations : 125
Heres some Log4j output from running the same code in the App Server
(note the LAST entry - 735ms) :-
<PrimaryLogText>CachingTransformerFactory: Entry for file [C:\Program
Files\IBM\MQSI\6.1\bin\..\config\flows\service\exceedinboundadapter\resources\retrievepolicysummarylistbyclientref\validation\validateResponse.xslt]
FOUND in CACHE..</PrimaryLogText>
<PrimaryLogText>CachingTransformerFactory: Using CACHED stylesheet
[C:\Program
Files\IBM\MQSI\6.1\bin\..\config\flows\service\exceedinboundadapter\resources\retrievepolicysummarylistbyclientref\validation\validateResponse.xslt]..</PrimaryLogText>
<PrimaryLogText>eXSLTPerformance.EnhancedXMLTransformationNode: Time
to create transformer: 0.</PrimaryLogText>
<PrimaryLogText>eXSLTPerformance.EnhancedXMLTransformationNode: Time
to set URIResolver: 0.</PrimaryLogText>
<PrimaryLogText>eXSLTPerformance.EnhancedXMLTransformationNode: Time
to parse params: 0.</PrimaryLogText>
<PrimaryLogText>eXSLTPerformance.EnhancedXMLTransformationNode: Time
to perfrom transform: 735.</PrimaryLogText>
--~------------------------------------------------------------------
XSL-List info and archive: http://www.mulberrytech.com/xsl/xsl-list
To unsubscribe, go to: http://lists.mulberrytech.com/xsl-list/
or e-mail: <mailto:xsl-list-unsubscribe(_at_)lists(_dot_)mulberrytech(_dot_)com>
--~--