Skip to content
Permalink
Browse files

Added support for profiling, the ability to get a report of the amoun…

…t of time spent processing each step
  • Loading branch information
ndw committed Feb 12, 2013
1 parent 6c2893b commit 806d5cd16434cf5e2c707167bac7518b14ee928a
@@ -0,0 +1,35 @@
<?xml version="1.0" encoding="utf-8"?>
<xsl:stylesheet xmlns:xsl="http://www.w3.org/1999/XSL/Transform"
xmlns:prof="http://xmlcalabash.com/ns/profile"
xmlns:xs="http://www.w3.org/2001/XMLSchema"
exclude-result-prefixes="prof xs"
version="2.0">

<xsl:output method="xml" encoding="utf-8" indent="yes"
omit-xml-declaration="yes"/>

<xsl:strip-space elements="*"/>

<xsl:template match="prof:profile">
<xsl:copy>
<xsl:apply-templates select="@*"/>
<xsl:choose>
<xsl:when test="*/prof:time">
<xsl:attribute name="total-time" select="prof:time"/>
<xsl:attribute name="step-time" select="prof:time - sum(*/prof:time)"/>
</xsl:when>
<xsl:otherwise>
<xsl:attribute name="step-time" select="prof:time"/>
</xsl:otherwise>
</xsl:choose>
<xsl:apply-templates select="node()"/>
</xsl:copy>
</xsl:template>

<xsl:template match="prof:time"/>

<xsl:template match="attribute()|text()|comment()|processing-instruction()">
<xsl:copy/>
</xsl:template>

</xsl:stylesheet>
@@ -66,6 +66,7 @@
public String saxonConfigFile = null;
public Hashtable<String,String> nsBindings = new Hashtable<String,String> ();
public boolean debug = false;
public String profileFile = null;
public Hashtable<String,Vector<ReadablePipe>> inputs = new Hashtable<String,Vector<ReadablePipe>> ();
public ReadablePipe pipeline = null;
public Hashtable<String,String> outputs = new Hashtable<String,String> ();
@@ -259,6 +260,7 @@ private void loadConfiguration() {

schemaAware = "true".equals(System.getProperty("com.xmlcalabash.schema-aware", ""+schemaAware));
debug = "true".equals(System.getProperty("com.xmlcalabash.debug", ""+debug));
profileFile = System.getProperty("com.xmlcalabash.profile", profileFile);
extensionValues = "true".equals(System.getProperty("com.xmlcalabash.general-values", ""+extensionValues));
xpointerOnText = "true".equals(System.getProperty("com.xmlcalabash.xpointer-on-text", ""+xpointerOnText));
transparentJSON = "true".equals(System.getProperty("com.xmlcalabash.transparent-json", ""+transparentJSON));
@@ -349,6 +351,8 @@ public void parse(XdmNode doc) {
parseNamespaceBinding(node);
} else if ("debug".equals(localName)) {
parseDebug(node);
} else if ("profile".equals(localName)) {
parseProfile(node);
} else if ("entity-resolver".equals(localName)) {
parseEntityResolver(node);
} else if ("input".equals(localName)) {
@@ -472,6 +476,10 @@ private void parseDebug(XdmNode node) {
}
}

private void parseProfile(XdmNode node) {
profileFile = node.getStringValue().trim();
}

private void parseEntityResolver(XdmNode node) {
String value = node.getAttributeValue(_class_name);
entityResolver = value;
@@ -41,12 +41,16 @@
import com.xmlcalabash.util.DefaultXProcConfigurer;
import com.xmlcalabash.util.DefaultXProcMessageListener;
import com.xmlcalabash.util.JSONtoXML;
import com.xmlcalabash.util.S9apiUtils;
import com.xmlcalabash.util.StepErrorListener;
import com.xmlcalabash.util.TreeWriter;
import net.sf.saxon.Configuration;
import net.sf.saxon.lib.ExtensionFunctionDefinition;
import net.sf.saxon.s9api.ExtensionFunction;
import net.sf.saxon.s9api.Processor;
import net.sf.saxon.s9api.QName;
import net.sf.saxon.s9api.Serializer;
import net.sf.saxon.s9api.XdmDestination;
import net.sf.saxon.s9api.XdmNode;
import net.sf.saxon.s9api.SaxonApiException;
import com.xmlcalabash.model.Parser;
@@ -55,7 +59,13 @@
import com.xmlcalabash.util.XProcURIResolver;
import com.xmlcalabash.util.URIUtils;

import java.io.File;
import java.io.FileOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.lang.reflect.Constructor;
import java.util.Calendar;
import java.util.logging.Logger;
import java.util.Hashtable;
import java.util.Vector;
@@ -68,7 +78,11 @@
import java.security.NoSuchAlgorithmException;

import javax.xml.transform.URIResolver;
import javax.xml.transform.sax.SAXSource;

import net.sf.saxon.s9api.XsltCompiler;
import net.sf.saxon.s9api.XsltExecutable;
import net.sf.saxon.s9api.XsltTransformer;
import org.apache.commons.httpclient.Cookie;
import org.xml.sax.EntityResolver;
import org.xml.sax.InputSource;
@@ -109,6 +123,14 @@
private String htmlParser = null;
private Vector<XProcExtensionFunctionDefinition> exFuncs = new Vector<XProcExtensionFunctionDefinition>();

private String profileFile = null;
private Hashtable<XStep,Calendar> profileHash = null;
private TreeWriter profileWriter = null;
private QName profileProfile = new QName("http://xmlcalabash.com/ns/profile", "profile");
private QName profileType = new QName("", "type");
private QName profileName = new QName("", "name");
private QName profileTime = new QName("http://xmlcalabash.com/ns/profile", "time");

public XProcRuntime(XProcConfiguration config) {
this.config = config;
processor = config.getProcessor();
@@ -177,6 +199,17 @@ public XProcRuntime(XProcConfiguration config) {
jsonFlavor = config.jsonFlavor;
useXslt10 = config.useXslt10;

if (config.profileFile != null) {
profileFile = config.profileFile;
profileHash = new Hashtable<XStep, Calendar> ();
profileWriter = new TreeWriter(this);
try {
profileWriter.startDocument(new URI("http://xmlcalabash.com/output/profile.xml"));
} catch (URISyntaxException use) {
// nop;
}
}

for (String className : config.extensionFunctions) {
try {
Object def = Class.forName(className).newInstance();
@@ -215,6 +248,7 @@ public XProcRuntime(XProcRuntime runtime) {
allowXPointerOnText = runtime.allowXPointerOnText;
transparentJSON = runtime.transparentJSON;
jsonFlavor = runtime.jsonFlavor;
profileFile = runtime.profileFile;
reset();
}

@@ -240,6 +274,13 @@ public boolean getDebug() {
return config.debug;
}

public String getProfileFile() {
return profileFile;
}
public void setProfileFile(String fn) {
profileFile = fn;
}

public URI getStaticBaseURI() {
return staticBaseURI;
}
@@ -432,6 +473,16 @@ private void reset() {
} catch (SaxonApiException ex) {
throw new XProcException(XProcConstants.dynamicError(9), ex);
}

if (profileFile != null) {
profileHash = new Hashtable<XStep, Calendar>();
profileWriter = new TreeWriter(this);
try {
profileWriter.startDocument(new URI("http://xmlcalabash.com/output/profile.xml"));
} catch (URISyntaxException use) {
// nop;
}
}
}

// FIXME: This design sucks
@@ -736,9 +787,69 @@ public void reportStep(XStep step) {
reported.add(step);
}

public void start(XPipeline pipe) {
public void start(XStep step) {
if (profileFile == null) {
return;
}

Calendar start = GregorianCalendar.getInstance();
profileHash.put(step, start);
profileWriter.addStartElement(profileProfile);

String name = step.getType().getClarkName();
profileWriter.addAttribute(profileType, name);
profileWriter.addAttribute(profileName, step.getStep().getName());
profileWriter.startContent();
}

public void finish(XPipeline pipe) {
public void finish(XStep step) {
if (profileFile == null) {
return;
}

Calendar start = profileHash.get(step);
long time = GregorianCalendar.getInstance().getTimeInMillis() - start.getTimeInMillis();
profileHash.remove(step);

profileWriter.addStartElement(profileTime);
profileWriter.startContent();
profileWriter.addText("" + time);
profileWriter.addEndElement();
profileWriter.addEndElement();

if (profileHash.isEmpty()) {
profileWriter.endDocument();
XdmNode profile = profileWriter.getResult();

InputStream xsl = getClass().getResourceAsStream("/etc/patch-profile.xsl");
if (xsl == null) {
throw new UnsupportedOperationException("Failed to load profile_patch.xsl from JAR file.");
}

try {
XsltCompiler compiler = getProcessor().newXsltCompiler();
compiler.setSchemaAware(false);
XsltExecutable exec = compiler.compile(new SAXSource(new InputSource(xsl)));
XsltTransformer transformer = exec.load();
transformer.setInitialContextNode(profile);
XdmDestination result = new XdmDestination();
transformer.setDestination(result);
transformer.transform();

Serializer serializer = new Serializer();
serializer.setOutputProperty(Serializer.Property.INDENT, "yes");

OutputStream outstr = new FileOutputStream(new File(profileFile));
serializer.setOutputStream(outstr);
S9apiUtils.serialize(this, result.getXdmNode(), serializer);
outstr.close();
} catch (SaxonApiException sae) {
throw new XProcException(sae);
} catch (FileNotFoundException fnfe) {
throw new XProcException(fnfe);
} catch (IOException ioe) {
throw new XProcException(ioe);
}
}
}
}
@@ -157,6 +157,10 @@ public void run(String[] args) throws SaxonApiException, IOException, URISyntaxE
config.debug = cmd.debug;
}

if (cmd.profileFile != null) {
config.profileFile = cmd.profileFile;
}

config.extensionValues |= cmd.extensionValues;
config.xpointerOnText |= cmd.allowXPointerOnText;
config.transparentJSON |= cmd.transparentJSON;
@@ -12,7 +12,6 @@
import com.xmlcalabash.io.WritablePipe;
import com.xmlcalabash.io.ReadableInline;
import com.xmlcalabash.io.ReadableDocument;
import com.xmlcalabash.io.ReadableData;
import com.xmlcalabash.io.Pipe;
import com.xmlcalabash.model.RuntimeValue;
import com.xmlcalabash.model.Step;
@@ -47,6 +46,8 @@
import net.sf.saxon.s9api.XdmDestination;
import net.sf.saxon.s9api.SaxonApiUncheckedException;

import java.util.Calendar;
import java.util.GregorianCalendar;
import java.util.Vector;
import java.util.Hashtable;
import java.util.Iterator;
@@ -376,7 +377,9 @@ public void run() throws SaxonApiException {
XProcData data = runtime.getXProcData();
data.openFrame(this);

runtime.start(this);
xstep.run();
runtime.finish(this);

// FIXME: Is it sufficient to only do this for atomic steps?
String cache = getInheritedExtensionAttribute(XProcConstants.cx_cache);
@@ -97,6 +97,8 @@ public void run() throws SaxonApiException {
inScopeOptions.put(var.getName(), value);
}

runtime.start(this);

XCompoundStep xstep = null;
for (XStep step : subpipeline) {
if (step instanceof XWhen) {
@@ -130,6 +132,8 @@ public void run() throws SaxonApiException {

xstep.run();

runtime.finish(this);

data.closeFrame();
}
}
@@ -11,6 +11,8 @@
import net.sf.saxon.s9api.QName;
import net.sf.saxon.s9api.SaxonApiException;

import java.util.Calendar;
import java.util.GregorianCalendar;
import java.util.Hashtable;
import java.util.Vector;

@@ -251,9 +253,11 @@ public void run() throws SaxonApiException {
inScopeOptions.put(var.getName(), value);
}

runtime.start(this);
for (XStep step : subpipeline) {
step.run();
}
runtime.finish(this);

for (String port : inputs.keySet()) {
if (port.startsWith("|")) {
@@ -84,6 +84,8 @@ public void run() throws SaxonApiException {

runtime.getXProcData().setIterationSize(sequenceLength);

runtime.start(this);

for (XdmNode is_doc : nodes) {
// Setup the current port before we compute variables!
current.resetWriter();
@@ -146,6 +148,8 @@ public void run() throws SaxonApiException {
}
}

runtime.finish(this);

for (String port : inputs.keySet()) {
if (port.startsWith("|")) {
String wport = port.substring(1);
@@ -89,6 +89,7 @@ public void run() throws SaxonApiException {
}
}

runtime.start(this);
for (ReadablePipe is_reader : inputs.get(iport)) {
XdmNode os_doc = null;

@@ -164,6 +165,7 @@ public void run() throws SaxonApiException {
pipe.write(os_doc);
}
}
runtime.finish(this);

for (String port : inputs.keySet()) {
if (port.startsWith("|")) {
@@ -84,7 +84,9 @@ public void run() throws SaxonApiException {

runtime.getXProcData().setIterationSize(sequenceLength);

runtime.start(this);
matcher.match(doc, match);
runtime.finish(this);

for (String port : inputs.keySet()) {
if (port.startsWith("|")) {

2 comments on commit 806d5cd

@fgeorges

This comment has been minimized.

Copy link

@fgeorges fgeorges replied Feb 12, 2013

Might be only me, but it looks like the new --profile option is not documented (in --help).

Also, via the API it is possible to set the profile file as a String. Probably passing a File object is more robust (the user has to worry about relative paths, etc., currently how are they resolved...?)

@fgeorges

This comment has been minimized.

Copy link

@fgeorges fgeorges replied Feb 12, 2013

And by the way, thank you very much for this new feature! I've just integrated it in Servlex and had a quick test, runs perfect!

Please sign in to comment.
You can’t perform that action at this time.