Project

Profile

Help

Actions
Send by e-mail Copy link

Bug #6348

closed

net.sf.saxon.expr.XPathContextMajor.getTargetComponent throws NullPointerException - race condition

Added by Johan Gheys 9 months ago. Updated 5 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Michael Kay
Category:
Multithreading
Sprint/Milestone:
-
Start date:
2024-02-15
Due date:
% Done:

100%

Estimated time:
Legacy ID:
Applies to branch:
12, trunk
Fix Committed on Branch:
12, trunk
Fixed in Maintenance Release:
12.5
Platforms:
.NET, Java

Description

I don't know if this bug deserves much attention since (a) the problem occurs only occasionally and (b) saxon:transform() will soon be replaced by fn:transform() with an extra parameter anyway (see #6339), but herewith the error message since this might help to improve the code:

2024-02-15 08:52:15 [INFO] Launching /micro/merge-split-and-purge-versions.xslt
2024-02-15 08:52:15 [INFO] 	parameter input-folder=C:/Data/Interfac/INT/intb/micro/8.2/tmp/
2024-02-15 08:52:15 [INFO] 	parameter latest-release-folder=C:/Data/Interfac/INT/intb/micro/8.2/latest-release/
2024-02-15 08:52:15 [INFO] 	parameter output-folder=C:/Data/Interfac/INT/intb/micro/8.2/
2024-02-15 08:52:15 [INFO] 	parameter purge-date=2024-02-05
2024-02-15 08:52:15 [INFO] 	parameter split-date=2024-02-05
2024-02-15 08:52:15 [INFO] 	parameter working-date=2024-02-25
2024-02-15 08:52:15 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/catenaryCase.xml
2024-02-15 08:52:16 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/gigBySerZone.xml
2024-02-15 08:52:16 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/graphicalCatenaryCase.xml
2024-02-15 08:52:18 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/graphicalEdge.xml
2024-02-15 08:52:19 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/graphicalLevelCrossing.xml
2024-02-15 08:52:21 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/graphicalNode.xml
2024-02-15 08:52:23 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/graphicalPlatform.xml
2024-02-15 08:52:23 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/gridInterGrid.xml
2024-02-15 08:52:23 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/levelCrossing.xml
2024-02-15 08:52:24 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/location.xml
2024-02-15 08:52:24 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/milestone.xml
2024-02-15 08:52:26 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/node.xml
java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	... 17 more
java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	... 17 more
2024-02-15 08:52:29 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/nodeByCatenaryCase.xml
2024-02-15 08:52:31 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/nodeByGig.xml
2024-02-15 08:52:34 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/nodeByLocation.xml
2024-02-15 08:52:53 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/nodeByRouteEdge.xml
2024-02-15 08:53:12 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/nodeByTrackEdge.xml
2024-02-15 08:53:15 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/platform.xml
2024-02-15 08:53:15 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/platformSide.xml
2024-02-15 08:53:17 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/routeEdge.xml
2024-02-15 08:53:21 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/shape.xml
2024-02-15 08:53:21 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/style.xml
2024-02-15 08:53:21 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/subLocation.xml
2024-02-15 08:53:22 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/trackEdge.xml
2024-02-15 08:53:23 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/validityDate.xml
2024-02-15 08:53:24 [DEBUG] Exporting file:/C:/Data/Interfac/INT/intb/micro/8.2/view.xml
java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	... 11 more
Caused by: java.lang.NullPointerException
	at net.sf.saxon.expr.XPathContextMajor.getTargetComponent(XPathContextMajor.java:684)
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:376)
	... 17 more
Some child xsl:result-document threads have not finished
Error 
   java.lang.RuntimeException: Internal error evaluating template rule  in module
  jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
java.lang.RuntimeException: Internal error evaluating template rule  in module
  jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1926)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.lambda$elaborateForPush$1(Block.java:853)
	at net.sf.saxon.expr.instruct.Copy$CopyElaborator.lambda$elaborateForPush$0(Copy.java:589)
	at net.sf.saxon.expr.instruct.TemplateRule.a
Error in xsl:sequence/@select on line 33 column 45 of batch.xslt:
  FOER0000  Error signalled by application call on error()
In template xsl:initial-template on line 13 column 56 of batch.xslt:
     Focus: absent
     Local variables
        $vv:v0 {fn:current-date() lt xs:date("2000-01-01")} = false()
        $startTime = xs:dateTimeStamp("2024-02-15T08:46:43.449+01:00")
In template xsl:initial-template on line 13 column 56 of batch.xslt:
     Focus: absent
     Local variables
        $vv:v0 {fn:current-date() lt xs:date("2000-01-01")} = false()
        $startTime = xs:dateTimeStamp("2024-02-15T08:46:43.449+01:00")
Error signalled by application call on error()
2024-02-15 08:53:34 [ERROR] description: java.lang.RuntimeException: Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt(Internal error evaluating template rule  in module jar:file:int-batch-DEV-SNAPSHOT.jar!/micro/merge-split-and-purge-versions.xslt)
2024-02-15 08:53:34 [ERROR] module: jar:file:int-batch-DEV-SNAPSHOT.jar!/shared/shared-functions.xslt
2024-02-15 08:53:34 [ERROR] line-number: 1062
2024-02-15 08:53:34 [ERROR] Batch execution failed - see above output for any hints

The dataset attached is, of course, a filtered dataset to avoid unnecessarily increasing the upload volume.

Files

Download all files
saxon-transform-6348.zip (3.26 MB) saxon-transform-6348.zip Johan Gheys, 2024-02-15 11:34
shared-functions.xslt (57.5 KB) shared-functions.xslt Johan Gheys, 2024-02-15 11:48

Related issues

Has duplicate Saxon - Bug #6425: When the saxon:thread attribute is set for xsl:for-each in saxon-ee-12.4 (enterprise edition), NullPointException and ClassCastException occasionally occur in multi-thread scenarios.DuplicateMichael Kay2024-05-152024-06-30

Actions
Actions
Copy link
 #2

Updated by Johan Gheys 9 months ago

Attached is the original (not cleaned out) shared-functions.xslt.

Actions
Copy link
 #3

Updated by Michael Kay 9 months ago

After running it a dozen times or so, I got a failure, which is probably the same bug, though the symptoms are slightly different:

Error 
   java.lang.RuntimeException: Internal error evaluating template rule  in module
  file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt: Internal error evaluating template rule  in module file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt
java.lang.RuntimeException: Internal error evaluating template rule  in module file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt
	at net.sf.saxon.expr.instruct.TemplateRule.applyLeavingTail(TemplateRule.java:386)
	at net.sf.saxon.trans.Mode.handleRuleNotNull(Mode.java:587)
	at net.sf.saxon.trans.Mode.applyTemplates(Mode.java:521)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:650)
	at net.sf.saxon.expr.instruct.ResultDocument.processInstruction(ResultDocument.java:403)
	at com.saxonica.config.EnterpriseConfiguration.lambda$processResultDocument$1(EnterpriseConfiguration.java:1929)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.ClassCastException: class net.sf.saxon.expr.Component cannot be cast to class net.sf.saxon.expr.Component$M (net.sf.saxon.expr.Component and net.sf.saxon.expr.Component$M are in unnamed module of loader 'app')
	at net.sf.saxon.expr.instruct.ApplyTemplates.getTargetMode(ApplyTemplates.java:303)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:613)
	at net.sf.saxon.expr.instruct.Block$BlockElaborator.l
2024-02-22 17:49:26 [ERROR] description: java.lang.RuntimeException: Internal error evaluating template rule  in module file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt: Internal error evaluating template rule  in module file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt(Internal error evaluating template rule  in module file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt)
2024-02-22 17:49:26 [ERROR] module: file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/shared-functions.xslt
2024-02-22 17:49:26 [ERROR] line-number: 385
Actions
Copy link
 #4

Updated by Michael Kay 9 months ago

I'm not making much progress. As with all multithreading bugs, the main diagnostic process seems to be to stare at the code until you see something questionable. But let's start by writing down what I know.

Firstly, there's no evidence that saxon:transform is relevant to the problem.

What we can see, in both stack traces, is that there's an asynchronous call on xsl:result-document, which is processed in its own thread and immediately does apply-templates. The asynchronous thread should have been started with a completely clean copy of the dynamic context. But when apply-templates accesses the dynamic context to determine the current component, it finds in one case that it is null, and in the other case that it is a component of the wrong kind. This can only mean that the current component has been modified in a different thread. But of course, the code is carefully written to ensure this can't happen -- in theory.

Actions
Copy link
 #5

Updated by Michael Kay 9 months ago

I added a diagnostic to XPathContext.setCurrentComponent() to check whether the same context object is ever updated from more than one thread. It shouldn't happen, and it doesn't. (But perhaps it does on the rare runs that fail?)

Actions
Copy link
 #6

Updated by Michael Kay 9 months ago

After another half dozen successful runs, I got a failing run with a different failure:

Caused by: java.lang.UnsupportedOperationException: getLength() not available at net.sf.saxon.om.SequenceTool.getLength(SequenceTool.java:138) at net.sf.saxon.expr.sort.SortedIterator.buildArray(SortedIterator.java:202) at net.sf.saxon.expr.sort.SortedIterator.doSort(SortedIterator.java:268) at net.sf.saxon.expr.sort.SortedIterator.next(SortedIterator.java:156) at net.sf.saxon.expr.elab.PullElaborator.lambda$elaborateForPush$0(PullElaborator.java:39) at net.sf.saxon.expr.instruct.DocumentInstr$DocumentInstrElaborator.lambda$elaborateForItem$3(DocumentInstr.java:392)

This is actually reporting a ClassCastException - SortedIterator is doing

int allocated = SequenceTool.supportsGetLength(base) ? SequenceTool.getLength(base) : 100

and this can only mean that base was a LastPositionFinder when supportsGetLength() was called, and is no longer a LastPositionFinder when getLength() is called.

Well, this seems to be the result of a device used by SortedIterator to catch exceptions and defer them, and the device is misfiring, so all it tells us is that there has been an unexpected internal exception and we don't know what it is. So that's not very helpful. This code was written before we had UncheckedXPathException so I will change it to use that,

Actions
Copy link
 #7

Updated by Michael Kay 9 months ago

I've now once again hit the failure

  • ☐ java.lang.ClassCastException: class net.sf.saxon.expr.Component cannot be cast to class net.sf.saxon.expr.Component$M (net.sf.saxon.expr.Component and net.sf.saxon.expr.Component$M are in unnamed module of loader 'app')

but it also (perhaps in another thread) does

java.lang.UnsupportedOperationException: getLength() not available
	at net.sf.saxon.om.SequenceTool.getLength(SequenceTool.java:138)
	at net.sf.saxon.expr.sort.SortedIterator.buildArray(SortedIterator.java:199)
	at net.sf.saxon.expr.sort.SortedIterator.doSort(SortedIterator.java:265)
Actions
Copy link
 #8

Updated by Michael Kay 9 months ago

Alter another couple of dozen successful runs, another failure with

Caused by: java.lang.UnsupportedOperationException: getLength() not available at net.sf.saxon.om.SequenceTool.getLength(SequenceTool.java:138) at net.sf.saxon.expr.sort.SortedIterator.buildArray(SortedIterator.java:204)

despite the fact that SortedIterator,base is now final.

And the next failure is another ClassCastException, I added some diagnostics and it tells us

In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#-1
Current component is net.sf.saxon.expr.instruct.GlobalVariable@5d683ff1

The -1 should be a line number....

I think it's very likely we're in the code at line 26 of this module:

         <xsl:for-each select="$input-xml">
            <xsl:result-document href="{$output-xml}" method="xml">
               <xsl:apply-templates>
                  <xsl:with-param name="latest-release-xml" select="$latest-release-xml" tunnel="yes"/>
               </xsl:apply-templates>
            </xsl:result-document>
         </xsl:for-each>
Actions
Copy link
 #9

Updated by Michael Kay 9 months ago

I've now managed to display the name of the offending global variable:

Current component is variable day-before-working-date

In the debugger I've monitored where we set this variable to be the current component. It seems to be set twice (which is interesting), but in neither case is it overwriting any previous current component.

I found that line numbers are retained if Transform is run with the -l option.

Both evaluations of the global variable are from line 744, but they occur in different threads.

Actions
Copy link
 #10

Updated by Michael Kay 9 months ago

A different manifestation this time:

java.lang.ClassCastException: class net.sf.saxon.expr.instruct.GlobalVariable cannot be cast to class net.sf.saxon.expr.instruct.UserFunction (net.sf.saxon.expr.instruct.GlobalVariable and net.sf.saxon.expr.instruct.UserFunction are in unnamed module of loader 'app')
	at net.sf.saxon.expr.UserFunctionCall$UserFunctionCallElaborator.lambda$elaborateForPull$0(UserFunctionCall.java:743)
	at net.sf.saxon.expr.instruct.ApplyTemplates$ApplyTemplatesElaborator.lambda$elaborateForPush$1(ApplyTemplates.java:634)

But in very much the same area: the component picked up from the currentComponent binding vector is the wrong component. Perhaps it's significant that it's a GlobalVariable muscling in again?

Actions
Copy link
 #11

Updated by Michael Kay 9 months ago

In the latest incarnation the failing apply-templates is on line 672

<xsl:apply-templates mode="local:split-and-purge" select="shared:merge-versions($subLocation)"/>

and the current component is the function shared:merge-versions#1

Actions
Copy link
 #12

Updated by Michael Kay 9 months ago

The getLength() failure has come up again, now with extra diagnostics:

Caused by: java.lang.UnsupportedOperationException: getLength() not available in class com.saxonica.ee.parallel.MultithreadedFocusTrackingIterator

That's interesting. From the Javadoc:

the synchronization is designed only to

  • allow a call on {@link #getLength()} (caused by an XPath invocation of last()) to occur
  • asynchronously with the thread that advances the iterator. This happens specifically when an
  • xsl:result-document instruction is executed asynchronously, and the code within
  • the body of the xsl:result-document instruction calls last(). In this situation
  • the main thread (the one that advances the focus, and spawns new threads for xsl:result-document)
  • must be suspended while the value of last() is computed, which is done by reading the iterator
  • to completion; when the main thread resumes, there will be a new base iterator positioned over the materialized
  • sequence that was read into memory as a side-effect of calling last().

  • See bug 3927.

I've added more diagnostics for the next time it happens...

Actions
Copy link
 #13

Updated by Michael Kay 9 months ago

ClassCastException again. This time:

In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#229 Current component in net.sf.saxon.expr.XPathContextMajor@5036f29c is variable working-date

Here line 229 is

<xsl:apply-templates mode="local:split-and-purge" select="shared:merge-versions($graphicalStopSignal)"/>

which has no obvious relationship to the variable working-date

The time I've logged all calls to XPathContext.setCurrentComponent() (about 100K calls), and none of them sets the current component to this variable. There is only one entry that logs setting the current component for this context object, and that one sets it to the mode xsl:unnamed which is what we would expect (the relevant mode is the one of the calling template, not the called template). That setting happens a very long time before the crash.

NOTE: probably irrelevant, but worth investigating: we're frequently setting the current component twice consecutively to the same value:

net.sf.saxon.expr.XPathContextMajor@2003877a Set current component := function shared:extract-validities#3
net.sf.saxon.expr.XPathContextMajor@2003877a Set current component := function shared:extract-validities#3
net.sf.saxon.expr.XPathContextMajor@5e77f0f4 Set current component := function shared:open-file#2
net.sf.saxon.expr.XPathContextMajor@5e77f0f4 Set current component := function shared:open-file#2
net.sf.saxon.expr.XPathContextMajor@19b30c92 Set current component := function shared:open-file#1
net.sf.saxon.expr.XPathContextMajor@19b30c92 Set current component := function shared:open-file#1.

At best this suggests some inefficiency.

Next failure:

In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#630 Current component in net.sf.saxon.expr.XPathContextMajor@27dd88fd is function shared:merge-versions#1

The one consistent feature is that it's always xsl:apply-templates that is failing to find the current component; other constructs, like function calls, seem to have no problem.

Actions
Copy link
 #14

Updated by Michael Kay 9 months ago

I was wondering whether the problem might be related to JIT compilation of template rules, so I ran with -jit:off. On about the 15th attempt, it failed in the familiar way.

However, there's a new feature here. The diagnostic messages output for the ClassCastException now appear thrice, but interleaved.:

In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#526
In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#572
In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#557
Current component in net.sf.saxon.expr.XPathContextMajor@3c34a303 is variable working-date
Current component in net.sf.saxon.expr.XPathContextMajor@645ea33b is variable working-date
Current component in net.sf.saxon.expr.XPathContextMajor@62c2c613 is variable working-date

This can only mean that the CCE has occurred simultaneously in 3 different threads. It's noticeable that although they affect three different xsl:apply-templates instructions, the incorrect current component is the same each time.

Ummmm. It's not actually the current component that's the wrong type, it's the target component, which we find via the current component. In the messages above, we're not actually displaying the current component, we're displaying the target component, which is the value of currentComponent.getComponentBindings().get(bindingSlot) So the currentComponent might be correct, but its componentBindings are incorrect...

Actions
Copy link
 #15

Updated by Michael Kay 9 months ago

Now making this distinction in the diagnostics, I'm getting

In apply-templates at file:/Users/mike/bugs/2024/6348-Gheys/saxon-transform-6348/xslt/merge-split-and-purge-versions.xslt#713
Current component in net.sf.saxon.expr.XPathContextMajor@d65555 is mode xsl:unnamed
Target component in net.sf.saxon.expr.XPathContextMajor@d65555 (109) is variable working-date

The component xsl:unnamed contains all the template rules in the unnamed mode, and this has a large number of binding slots for its references to other components used by these template rules; hence the high slot number 109.

Perhaps something is going wrong with the allocation of component binding slots? And perhaps this is related to the use of saxon:transform?

It seems that setting -jit:off on the command line has no effect on the secondary stylesheet compiled using saxon:transform. This is still using JIT compilation of template rules. And when a template rule is first evaluated, additional binding slots are allocated to its containing mode, And if this happens in asynchronous code executed by xsl:result-document, then two template rules may be compiled concurrently and may be allocated the same slots.

That feels like the right explanation.

Actions
Copy link
 #16

Updated by Michael Kay 9 months ago

Examination of the code confirms that there is no attempt to stop two concurrent JIT template initializations adding slots to the binding vector for the containing mode simultaneously, and the symptoms are consistent with this (at any rate, the "wrong target component" exceptions - it doesn't directly explain the getLength() problem).

To avoid long locks, the best strategy seems to be for template initialization to first calculate how many slots it needs in the binding vector, then do a synchronized allocation of a block of slots, and then do a second pass to insert the slot numbers. Or it could build a list of actions to be performed in this first pass, and then execute these actions in the second.

Actions
Copy link
 #17

Updated by Michael Kay 9 months ago

Actually, I think the solution is simpler: it's enough to synchronize the three lines of code:

            int slot = bindings.size();
            ComponentBinding cb = new ComponentBinding(name, target);
            bindings.add(cb);

(and the second line could be moved up...) That's obviously a very short single-threaded section.

Actions
Copy link
 #18

Updated by Michael Kay 9 months ago

  • Category set to Multithreading
  • Status changed from New to Resolved
  • Assignee set to Michael Kay
  • Priority changed from Low to Normal
  • Applies to branch 12, trunk added
  • Fix Committed on Branch 12, trunk added
  • Platforms .NET, Java added

Fixed on the 12,x and main branches.

SUMMARY: when xsl:result-document operates asynchronously, and JIT compilation of template rules is in effect, it is possible for two template rules to be compiled in parallel; since both might be allocating slots for component references (to functions, variables, named templates etc) in the binding vector for the containing mode, the allocation needs to be synchronised to keep everything consistent.

Actions
Copy link
 #19

Updated by Johan Gheys 9 months ago

Indeed, we were not sure if this had anything to do with saxon:transform(). Whenever the phenomenon occurred with us, saxon:transform() was always involved (but maybe that just means we use saxon:transform() a lot). Anyway, thanks Michael for your persistence in reproducing and solving this bug. Thanks to your clear view, the solution is indeed surprisingly simple, but no less important.

Actions
Copy link
 #20

Updated by Michael Kay 6 months ago

  • Has duplicate Bug #6425: When the saxon:thread attribute is set for xsl:for-each in saxon-ee-12.4 (enterprise edition), NullPointException and ClassCastException occasionally occur in multi-thread scenarios. added
Actions
Copy link
 #21

Updated by O'Neil Delpratt 5 months ago

  • Status changed from Resolved to Closed
  • % Done changed from 0 to 100
  • Fixed in Maintenance Release 12.5 added

Bug fix applied in the Saxon 12.5 Maintenance release.

Please register to edit this issue

Actions
Send by e-mail Copy link

Also available in: Atom PDF