RE: timing steps execution

Geert,

There is a trick that I use, but I cannot guarantee that it would work on all XProc processors.
When using Calabash I use p:add-attribute to add a 'start' attribute, to an input source document, with a value of current-time(). Then, as a last step in the pipeline I add a 'duration' attribute to the result of the previous step with a value that is the current-time() minus the value of the 'start' attribute taken from the result of the step that added the start attribute at the beginning.

Example:

<p:add-attribute name="start-time" match="/*" attribute-name="start">
  <p:with-option name="attribute-value" select="current-time()"/>
</p:add-attribute>

...

<p:add-attribute match="/*" attribute-name="duration">
  <p:with-option name="attribute-value" select="xs:time(current-time()) - xs:time(/*/@start)">
    <p:pipe port="result" step="start-time"/>
  </p:with-option>
</p:add-attribute>


The evaluation context for the select expression in the second add-attribute is the document on the result port of the step named 'start-time'.

You can also add 'split-time' attributes within for-each loops too.


As pointed-out to me by Norm Walsh, this behaviour is implementation dependant.


Regards

Philip Fennell


-----Original Message-----
From: xproc-dev-request@w3.org [mailto:xproc-dev-request@w3.org] On Behalf Of Geert Bormans
Sent: 24 February 2010 17:16
To: xproc-dev@w3.org
Subject: timing steps execution

Hi all,

I have come to a point where I should start profiling steps in my pipelines.
What would be the best approach for logging start time and end time 
of individual steps in my pipeline.

Thanks

Geert

Received on Thursday, 25 February 2010 08:53:53 UTC