Project

Profile

Help

Bug #4342

closed

Sporadic spikes in XSL processing time due to internal looping

Added by Stefan Fritz about 5 years ago. Updated almost 5 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Diagnostics
Sprint/Milestone:
-
Start date:
2019-10-16
Due date:
% Done:

0%

Estimated time:
Legacy ID:
Applies to branch:
9.9, trunk
Fix Committed on Branch:
9.9, trunk
Fixed in Maintenance Release:
Platforms:

Description

Stylesheet sporadically takes many minutes vs some seconds to run. Inside the debugger this can be enforced (see steps below).

Given the XSL output warnings like "Too many nested template or function calls. The stylesheet may be looping." I assume that Saxon internally runs into a StackOverflowError. Which was also explained here: https://saxonica.plan.io/boards/3/topics/7287 The problem is that in above discussion the user got an exception and could react. Here the behavior is inconsistent and is causing a business impact if it happens.

The workaround/solution is to increase stack size e.g. -Xss4m

The reason I log this is that I think Saxon should behave consistently and not start looping internally. Such issues are hard to catch in a production environment.

Steps to reproduce (e.g run inside Eclipse):

class: com.aurea.support.SaxonXSLCmdLine

arguments: perftests\ebixml-CUBE-DC_Dev_200.xml perftests\EBI\XSLs\Relationship_EBI.xsl out.xml param1=123|param2=444

JVM arguments: -Xss1m -Dxsl.useTracing=false

Running the XSL takes e.g. 4000ms

Now run again but set a breakpoint:

net.sf.saxon.expr.insturct.Instruction /* / public static ParameterSet assembleParams(XPathContext context, WithParam[] actualParams) / / throws XPathException / / { / 207 / if ((actualParams == null) || (actualParams.length == 0)) { / 208 / return null; / / } / 210 / ParameterSet params = new ParameterSet(actualParams.length); / 211 / for (WithParam actualParam : actualParams) { / 212 / params.put(actualParam.getVariableQName(), actualParam / 213 / .getSelectValue(context), actualParam / 214 / .isTypeChecked()); / / } / 216 / return params; //<<--- BREAKPOINT / */ }

  • advance ca. 10 times in Debugger to hit it that often
  • then disable the breakpoint and let it continue.
  • It seems to loop.

Sometimes it gets in the loop also without the debugger. Processing then took 3116604 ms instead of 4000 ms.

Without optimizer it takes ca. 12 sec. but disabling this is not an option as many other XSLs would be impacted.

Attached is a video that shows the issue. The reproducible can be found in the ZIP of https://saxonica.plan.io/issues/4340 (please do not attached the customer data here)


Files

zoom_0.mp4 (8.46 MB) zoom_0.mp4 Stefan Fritz, 2019-10-16 12:25

Please register to edit this issue

Also available in: Atom PDF