Project

Profile

Help

Bug #5685

closed

Stream closed on categories.xml

Added by Neil Brown 3 months ago. Updated 8 days ago.

Status:
Closed
Priority:
Low
Assignee:
Category:
-
Sprint/Milestone:
-
Start date:
2022-09-13
Due date:
% Done:

0%

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

Description

I am running Saxon HE as a Groovy task as part of a Gradle build. I am frequently encountering an exception in Saxon HE which seems to involve a Stream closed exception while reading the built-in categories.xml file. Some facts:

  • It is an intermittent error; the exact same code sometimes works and sometimes doesn't.
  • I've made the code serial so I don't think it is a parallel execution issue.
  • It seems to occur more often on Windows than on Linux but I've seen it on both.
  • It happens usually on around the 3rd or 4th call to doTransform. It doesn't matter if it's on a new Transform() object or a re-used one.

I've included the stack trace below. If you look near the end it's eventually a Stream closed exception which seems to happen while processing categories.xml so I don't think it's related to my code or my files? If you think it does relate to my code then I can try to produce a minimal example that triggers it. I've seen this same exception with Saxon HE 9.9.1-8 and 11.4. Do you have any clues as to how to fix this?

08:12:14 Caused by: java.lang.ExceptionInInitializerError
08:12:14 	at net.sf.saxon.regex.RECompiler.escape(RECompiler.java:352)
08:12:14 	at net.sf.saxon.regex.RECompiler.parseAtom(RECompiler.java:789)
08:12:14 	at net.sf.saxon.regex.RECompiler.parseTerminal(RECompiler.java:990)
08:12:14 	at net.sf.saxon.regex.RECompiler.piece(RECompiler.java:1007)
08:12:14 	at net.sf.saxon.regex.RECompiler.parseBranch(RECompiler.java:1129)
08:12:14 	at net.sf.saxon.regex.RECompiler.parseExpr(RECompiler.java:1179)
08:12:14 	at net.sf.saxon.regex.RECompiler.compile(RECompiler.java:1302)
08:12:14 	at net.sf.saxon.regex.ARegularExpression.<init>(ARegularExpression.java:55)
08:12:14 	at net.sf.saxon.java.JavaPlatform.compileRegularExpression(JavaPlatform.java:482)
08:12:14 	at net.sf.saxon.Configuration.compileRegularExpression(Configuration.java:1871)
08:12:14 	at net.sf.saxon.functions.RegexFunction.tryToBindRegularExpression(RegexFunction.java:49)
08:12:14 	at net.sf.saxon.functions.RegexFunction.makeFunctionCall(RegexFunction.java:87)
08:12:14 	at net.sf.saxon.functions.Replace.makeFunctionCall(Replace.java:63)
08:12:14 	at net.sf.saxon.functions.RegexFunctionSansFlags.makeFunctionCall(RegexFunctionSansFlags.java:47)
08:12:14 	at net.sf.saxon.functions.registry.BuiltInFunctionSet.bind(BuiltInFunctionSet.java:219)
08:12:14 	at net.sf.saxon.functions.FunctionLibraryList.bind(FunctionLibraryList.java:127)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseFunctionCall(XPathParser.java:3685)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseBasicStep(XPathParser.java:2559)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseStepExpression(XPathParser.java:2434)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseRelativePath(XPathParser.java:2353)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parsePathExpression(XPathParser.java:2315)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseSimpleMappingExpression(XPathParser.java:2329)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseUnaryExpression(XPathParser.java:2181)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseExprSingle(XPathParser.java:777)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parseExpression(XPathParser.java:679)
08:12:14 	at net.sf.saxon.expr.parser.XPathParser.parse(XPathParser.java:535)
08:12:14 	at net.sf.saxon.expr.parser.ExpressionTool.make(ExpressionTool.java:89)
08:12:14 	at net.sf.saxon.style.StyleElement.makeExpression(StyleElement.java:709)
08:12:14 	at net.sf.saxon.style.XSLAnalyzeString.prepareAttributes(XSLAnalyzeString.java:77)
08:12:14 	at net.sf.saxon.style.StyleElement.processAttributes(StyleElement.java:604)
08:12:14 	at net.sf.saxon.style.StyleElement.processAllAttributes(StyleElement.java:541)
08:12:14 	at net.sf.saxon.style.StyleElement.processAllAttributes(StyleElement.java:544)
08:12:14 	at net.sf.saxon.style.XSLTemplate.processAllAttributes(XSLTemplate.java:428)
08:12:14 	at net.sf.saxon.style.PrincipalStylesheetModule.processAllAttributes(PrincipalStylesheetModule.java:587)
08:12:14 	at net.sf.saxon.style.PrincipalStylesheetModule.preprocess(PrincipalStylesheetModule.java:366)
08:12:14 	at net.sf.saxon.style.Compilation.compilePackage(Compilation.java:290)
08:12:14 	at net.sf.saxon.style.StylesheetModule.loadStylesheet(StylesheetModule.java:249)
08:12:14 	at net.sf.saxon.style.Compilation.compileSingletonPackage(Compilation.java:113)
08:12:14 	at net.sf.saxon.s9api.XsltCompiler.compile(XsltCompiler.java:936)
08:12:14 	at net.sf.saxon.Transform.doTransform(Transform.java:769)
08:12:14 	at net.sf.saxon.Transform.doTransform(Transform.java:916)
08:12:14 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
08:12:14 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
08:12:14 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
08:12:14 	at XsltTransformation.execute(XsltTransformation.groovy:41)
08:12:14 	at org.gradle.workers.internal.DefaultWorkerServer.execute(DefaultWorkerServer.java:63)
08:12:14 	at org.gradle.workers.internal.AbstractClassLoaderWorker$1.create(AbstractClassLoaderWorker.java:49)
08:12:14 	at org.gradle.workers.internal.AbstractClassLoaderWorker$1.create(AbstractClassLoaderWorker.java:43)
08:12:14 	at org.gradle.internal.classloader.ClassLoaderUtils.executeInClassloader(ClassLoaderUtils.java:97)
08:12:14 	at org.gradle.workers.internal.AbstractClassLoaderWorker.executeInClassLoader(AbstractClassLoaderWorker.java:43)
08:12:14 	at org.gradle.workers.internal.IsolatedClassloaderWorker.run(IsolatedClassloaderWorker.java:49)
08:12:14 	at org.gradle.workers.internal.IsolatedClassloaderWorker.run(IsolatedClassloaderWorker.java:30)
08:12:14 	at org.gradle.workers.internal.IsolatedClassloaderWorkerFactory$1.lambda$execute$0(IsolatedClassloaderWorkerFactory.java:57)
08:12:14 	at org.gradle.workers.internal.AbstractWorker$1.call(AbstractWorker.java:44)
08:12:14 	at org.gradle.workers.internal.AbstractWorker$1.call(AbstractWorker.java:41)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner$CallableBuildOperationWorker.execute(DefaultBuildOperationRunner.java:204)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner$CallableBuildOperationWorker.execute(DefaultBuildOperationRunner.java:199)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner$2.execute(DefaultBuildOperationRunner.java:66)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner$2.execute(DefaultBuildOperationRunner.java:59)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner.execute(DefaultBuildOperationRunner.java:157)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner.execute(DefaultBuildOperationRunner.java:59)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationRunner.call(DefaultBuildOperationRunner.java:53)
08:12:14 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.call(DefaultBuildOperationExecutor.java:73)
08:12:14 	at org.gradle.workers.internal.AbstractWorker.executeWrappedInBuildOperation(AbstractWorker.java:41)
08:12:14 	at org.gradle.workers.internal.IsolatedClassloaderWorkerFactory$1.execute(IsolatedClassloaderWorkerFactory.java:49)
08:12:14 	at org.gradle.workers.internal.DefaultWorkerExecutor.lambda$submitWork$2(DefaultWorkerExecutor.java:205)
08:12:14 	at org.gradle.internal.work.DefaultConditionalExecutionQueue$ExecutionRunner.runExecution(DefaultConditionalExecutionQueue.java:187)
08:12:14 	at org.gradle.internal.work.DefaultConditionalExecutionQueue$ExecutionRunner.access$700(DefaultConditionalExecutionQueue.java:120)
08:12:14 	at org.gradle.internal.work.DefaultConditionalExecutionQueue$ExecutionRunner$1.run(DefaultConditionalExecutionQueue.java:162)
08:12:14 	at org.gradle.internal.Factories$1.create(Factories.java:31)
08:12:14 	at org.gradle.internal.work.DefaultWorkerLeaseService.withLocks(DefaultWorkerLeaseService.java:270)
08:12:14 	at org.gradle.internal.work.DefaultWorkerLeaseService.runAsWorkerThread(DefaultWorkerLeaseService.java:119)
08:12:14 	at org.gradle.internal.work.DefaultWorkerLeaseService.runAsWorkerThread(DefaultWorkerLeaseService.java:124)
08:12:14 	at org.gradle.internal.work.DefaultConditionalExecutionQueue$ExecutionRunner.runBatch(DefaultConditionalExecutionQueue.java:157)
08:12:14 	at org.gradle.internal.work.DefaultConditionalExecutionQueue$ExecutionRunner.run(DefaultConditionalExecutionQueue.java:126)
08:12:14 	... 2 more
08:12:14 Caused by: java.lang.RuntimeException: Failed to build categories.xml
08:12:14 	at net.sf.saxon.regex.charclass.Categories.build(Categories.java:126)
08:12:14 	at net.sf.saxon.regex.charclass.Categories.getCategory(Categories.java:198)
08:12:14 	at net.sf.saxon.regex.charclass.Categories.<clinit>(Categories.java:175)
08:12:14 	... 77 more
08:12:14 Caused by: net.sf.saxon.trans.XPathException: I/O error reported by XML parser processing categories.xml
08:12:14 	at net.sf.saxon.resource.ActiveSAXSource.deliver(ActiveSAXSource.java:231)
08:12:14 	at net.sf.saxon.resource.ActiveStreamSource.deliver(ActiveStreamSource.java:65)
08:12:14 	at net.sf.saxon.event.Sender.send(Sender.java:105)
08:12:14 	at net.sf.saxon.Configuration.buildDocumentTree(Configuration.java:4134)
08:12:14 	at net.sf.saxon.regex.charclass.Categories.build(Categories.java:124)
08:12:14 	... 79 more
08:12:14 Caused by: java.io.IOException: Stream closed
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLEntityManager$RewindableInputStream.readAndBuffer(XMLEntityManager.java:3024)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLEntityManager$RewindableInputStream.read(XMLEntityManager.java:3064)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.io.UTF8Reader.read(UTF8Reader.java:303)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLEntityScanner.load(XMLEntityScanner.java:1699)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLEntityScanner.scanLiteral(XMLEntityScanner.java:1137)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLScanner.scanPseudoAttribute(XMLScanner.java:644)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLScanner.scanXMLDeclOrTextDecl(XMLScanner.java:457)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanXMLDeclOrTextDecl(XMLDocumentFragmentScannerImpl.java:982)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$XMLDeclDriver.next(XMLDocumentScannerImpl.java:752)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:605)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:112)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:465)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:888)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:824)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:141)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1216)
08:12:14 	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:635)
08:12:14 	at net.sf.saxon.resource.ActiveSAXSource.deliver(ActiveSAXSource.java:190)
08:12:14 	... 83 more
Actions #1

Updated by Michael Kay 3 months ago

How strange. This is a really common path and you're not obviously doing anything different from what thousands of other users are doing without hitting the problem.

I do suspect a multi-threading issue. We build the categories.xml file as part of static initialization, the first time you compile a regular expression that uses Unicode character categories. The build() method is called only from a static synchronized method (which isn't ideal because it's rather a lot of processing to be doing in a synchronized method, but it should be safe). The inputStream is opened within the build() method, but I note that we never close it. We probably should, but it's hard to see how that on its own would cause the symptoms you're seeing. I wonder if there's any possibility that you're loading multiple instances of the classes in the Saxon JAR file, perhaps because of some complexity in the ClassLoader set-up?

Actions #2

Updated by Neil Brown 3 months ago

Thank you for the prompt response. I think your guess is exactly correct. I added this line of code to my Groovy Gradle task:

println("SAXON Transform class: " + transform.getClass().hashCode() + " " + Transform.class.hashCode() + " loader: " + transform.getClass().getClassLoader().hashCode() + " JVM PID: " + ProcessHandle.current().pid());

I then get this output:

SAXON Transform class: 861525141 861525141 loader: 1405291009 JVM PID: 41316
SAXON Transform class: 1295286719 1295286719 loader: 110361058 JVM PID: 41316
SAXON Transform class: 128228148 128228148 loader: 1822762519 JVM PID: 41316
SAXON Transform class: 672588550 672588550 loader: 1163876409 JVM PID: 41316

Which suggests that within the same JVM the Transform class is being loaded multiple times with different class loaders, I guess due to the way that Gradle works (to prevent contamination between task runs?). From there I should be able to come up with a work-around.

Actions #3

Updated by Vladimir Nesterovsky 3 months ago

As a side note, it might be worth to create a simple xslt (running at a pre-build time) that will generate a java class that will have all the data kept in categories.xml initialized statically in an array.

Actions #4

Updated by Michael Kay 3 months ago

I think the problem is that with multiple classloaders we can't rely on data in static being a singleton: see https://stackoverflow.com/questions/39533902/java-singleton-usage-with-multiple-class-loaders

Similarly, we can't rely on static synchronized methods being synchronized across classloader instances.

Actions #5

Updated by Neil Brown 3 months ago

Personally, I'm happy with the verdict that the bug is the fault of what I was doing in the surrounding code by having multiple class loaders, I think you're right that it's a strange situation that is hard to guard against. If anyone else encounters the problem they'll hopefully find this bug report and know what to do. For posterity, in my Gradle task I had a line (in code forked from https://github.com/eerohele/saxon-gradle):

WorkQueue workQueue = workerExecutor.classLoaderIsolation() {...}

which I changed to:

WorkQueue workQueue = workerExecutor.noIsolation()
Actions #6

Updated by Norm Tovey-Walsh 3 months ago

Saxonica Developer Community writes:

For posterity, in my Gradle task I had a line (in code forked from
https://github.com/eerohele/saxon-gradle):

WorkQueue workQueue = workerExecutor.classLoaderIsolation() {...}

which I changed to:

WorkQueue workQueue = workerExecutor.noIsolation()

Thanks for that. I have a fork of eerohele/saxon-gradle and I’ll apply
that fix to it. It’s odd that I’ve used that plugin (or my version of
it) for years and I’ve never seen this problem…

Be seeing you,
norm

--
Norm Tovey-Walsh
Saxonica

Actions #7

Updated by Michael Kay 8 days ago

  • Status changed from New to Closed
  • Assignee set to Michael Kay

Closing this as we now understand the problem and we decided there is no useful action we can take.

Please register to edit this issue

Also available in: Atom PDF