Repository navigation
Intermittent Stream closed exception after upgrading to 1.10.2 #1572
Copy link
Copy link
Closed
Labels
Component: valueP3Status: acceptedtype=defectBug, not working as expectedBug, not working as expected
Description
Hello!
We recently started observing an intermittent error after upgrading from 1.8.2 to 1.10.2 (GoogleCloudPlatform/DataflowTemplates#929).
I suspect it might be related to some racing/concurrency issues, as it happens sporadically and we are running Maven using multiple threads (mvn -T8 ...). It is either very hard to get when running in a single thread (I tried a bunch of times and it didn't repro), or parallelism is actually the issue.
Full stacktrace:
Error: Failed to execute goal org.apache.maven.plugins:maven-compiler-plugin:3.6.2:compile (default-compile) on project pubsub-to-redis: Fatal error compiling: autovalue.shaded.com.google.escapevelocity.EvaluationException: In expression on line 192 of autovalue.vm: java.io.IOException: Stream closed -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.apache.maven.plugins:maven-compiler-plugin:3.6.2:compile (default-compile) on project pubsub-to-redis: Fatal error compiling
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:215)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Caused by: org.apache.maven.plugin.MojoExecutionException: Fatal error compiling
at org.apache.maven.plugin.compiler.AbstractCompilerMojo.execute (AbstractCompilerMojo.java:963)
at org.apache.maven.plugin.compiler.CompilerMojo.execute (CompilerMojo.java:158)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Caused by: org.codehaus.plexus.compiler.CompilerException: autovalue.shaded.com.google.escapevelocity.EvaluationException: In expression on line 192 of autovalue.vm: java.io.IOException: Stream closed
at org.codehaus.plexus.compiler.javac.JavaxToolsCompiler.compileInProcess (JavaxToolsCompiler.java:173)
at org.codehaus.plexus.compiler.javac.JavacCompiler.performCompile (JavacCompiler.java:174)
at org.apache.maven.plugin.compiler.AbstractCompilerMojo.execute (AbstractCompilerMojo.java:952)
at org.apache.maven.plugin.compiler.CompilerMojo.execute (CompilerMojo.java:158)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Caused by: java.lang.RuntimeException: autovalue.shaded.com.google.escapevelocity.EvaluationException: In expression on line 192 of autovalue.vm: java.io.IOException: Stream closed
at com.sun.tools.javac.api.JavacTaskImpl.handleExceptions (JavacTaskImpl.java:163)
at com.sun.tools.javac.api.JavacTaskImpl.doCall (JavacTaskImpl.java:100)
at com.sun.tools.javac.api.JavacTaskImpl.call (JavacTaskImpl.java:94)
at org.codehaus.plexus.compiler.javac.JavaxToolsCompiler.compileInProcess (JavaxToolsCompiler.java:126)
at org.codehaus.plexus.compiler.javac.JavacCompiler.performCompile (JavacCompiler.java:174)
at org.apache.maven.plugin.compiler.AbstractCompilerMojo.execute (AbstractCompilerMojo.java:952)
at org.apache.maven.plugin.compiler.CompilerMojo.execute (CompilerMojo.java:158)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Caused by: autovalue.shaded.com.google.escapevelocity.EvaluationException: In expression on line 192 of autovalue.vm: java.io.IOException: Stream closed
at autovalue.shaded.com.google.escapevelocity.Node.evaluationException (Node.java:59)
at autovalue.shaded.com.google.escapevelocity.ParseNode.render (ParseNode.java:65)
at autovalue.shaded.com.google.escapevelocity.Node$Cons.render (Node.java:91)
at autovalue.shaded.com.google.escapevelocity.DirectiveNode$IfNode.render (DirectiveNode.java:103)
at autovalue.shaded.com.google.escapevelocity.Node$Cons.render (Node.java:91)
at autovalue.shaded.com.google.escapevelocity.Template.render (Template.java:189)
at autovalue.shaded.com.google.escapevelocity.Template.evaluate (Template.java:179)
at com.google.auto.value.processor.TemplateVars.toText (TemplateVars.java:99)
at com.google.auto.value.processor.AutoValueProcessor.processType (AutoValueProcessor.java:274)
at com.google.auto.value.processor.AutoValueishProcessor.process (AutoValueishProcessor.java:441)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.callProcessor (JavacProcessingEnvironment.java:985)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.discoverAndRunProcs (JavacProcessingEnvironment.java:901)
at com.sun.tools.javac.processing.JavacProcessingEnvironment$Round.run (JavacProcessingEnvironment.java:1227)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.doProcessing (JavacProcessingEnvironment.java:1340)
at com.sun.tools.javac.main.JavaCompiler.processAnnotations (JavaCompiler.java:1254)
at com.sun.tools.javac.main.JavaCompiler.compile (JavaCompiler.java:936)
at com.sun.tools.javac.api.JavacTaskImpl.lambda$doCall$0 (JavacTaskImpl.java:104)
at com.sun.tools.javac.api.JavacTaskImpl.handleExceptions (JavacTaskImpl.java:147)
at com.sun.tools.javac.api.JavacTaskImpl.doCall (JavacTaskImpl.java:100)
at com.sun.tools.javac.api.JavacTaskImpl.call (JavacTaskImpl.java:94)
at org.codehaus.plexus.compiler.javac.JavaxToolsCompiler.compileInProcess (JavaxToolsCompiler.java:126)
at org.codehaus.plexus.compiler.javac.JavacCompiler.performCompile (JavacCompiler.java:174)
at org.apache.maven.plugin.compiler.AbstractCompilerMojo.execute (AbstractCompilerMojo.java:952)
at org.apache.maven.plugin.compiler.CompilerMojo.execute (CompilerMojo.java:158)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Caused by: java.io.IOException: Stream closed
at java.util.zip.InflaterInputStream.ensureOpen (InflaterInputStream.java:68)
at java.util.zip.InflaterInputStream.read (InflaterInputStream.java:143)
at java.io.FilterInputStream.read (FilterInputStream.java:133)
at sun.nio.cs.StreamDecoder.readBytes (StreamDecoder.java:284)
at sun.nio.cs.StreamDecoder.implRead (StreamDecoder.java:326)
at sun.nio.cs.StreamDecoder.read (StreamDecoder.java:178)
at java.io.InputStreamReader.read (InputStreamReader.java:181)
at java.io.BufferedReader.fill (BufferedReader.java:161)
at java.io.BufferedReader.read (BufferedReader.java:182)
at java.io.LineNumberReader.read (LineNumberReader.java:126)
at autovalue.shaded.com.google.escapevelocity.Parser.next (Parser.java:144)
at autovalue.shaded.com.google.escapevelocity.Parser.skipSpace (Parser.java:171)
at autovalue.shaded.com.google.escapevelocity.Parser.expect (Parser.java:189)
at autovalue.shaded.com.google.escapevelocity.Parser.parseIfOrElseIf (Parser.java:418)
at autovalue.shaded.com.google.escapevelocity.Parser.parseDirective (Parser.java:370)
at autovalue.shaded.com.google.escapevelocity.Parser.parseNode (Parser.java:271)
at autovalue.shaded.com.google.escapevelocity.Parser.parseToStop (Parser.java:223)
at autovalue.shaded.com.google.escapevelocity.Parser.skipNewlineAndParseToStop (Parser.java:251)
at autovalue.shaded.com.google.escapevelocity.Parser.parseForEach (Parser.java:476)
at autovalue.shaded.com.google.escapevelocity.Parser.parseDirective (Parser.java:378)
at autovalue.shaded.com.google.escapevelocity.Parser.parseNode (Parser.java:271)
at autovalue.shaded.com.google.escapevelocity.Parser.parseToStop (Parser.java:223)
at autovalue.shaded.com.google.escapevelocity.Parser.parse (Parser.java:128)
at autovalue.shaded.com.google.escapevelocity.Template.parseFrom (Template.java:147)
at autovalue.shaded.com.google.escapevelocity.ParseNode.render (ParseNode.java:62)
at autovalue.shaded.com.google.escapevelocity.Node$Cons.render (Node.java:91)
at autovalue.shaded.com.google.escapevelocity.DirectiveNode$IfNode.render (DirectiveNode.java:103)
at autovalue.shaded.com.google.escapevelocity.Node$Cons.render (Node.java:91)
at autovalue.shaded.com.google.escapevelocity.Template.render (Template.java:189)
at autovalue.shaded.com.google.escapevelocity.Template.evaluate (Template.java:179)
at com.google.auto.value.processor.TemplateVars.toText (TemplateVars.java:99)
at com.google.auto.value.processor.AutoValueProcessor.processType (AutoValueProcessor.java:274)
at com.google.auto.value.processor.AutoValueishProcessor.process (AutoValueishProcessor.java:441)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.callProcessor (JavacProcessingEnvironment.java:985)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.discoverAndRunProcs (JavacProcessingEnvironment.java:901)
at com.sun.tools.javac.processing.JavacProcessingEnvironment$Round.run (JavacProcessingEnvironment.java:1227)
at com.sun.tools.javac.processing.JavacProcessingEnvironment.doProcessing (JavacProcessingEnvironment.java:1340)
at com.sun.tools.javac.main.JavaCompiler.processAnnotations (JavaCompiler.java:1254)
at com.sun.tools.javac.main.JavaCompiler.compile (JavaCompiler.java:936)
at com.sun.tools.javac.api.JavacTaskImpl.lambda$doCall$0 (JavacTaskImpl.java:104)
at com.sun.tools.javac.api.JavacTaskImpl.handleExceptions (JavacTaskImpl.java:147)
at com.sun.tools.javac.api.JavacTaskImpl.doCall (JavacTaskImpl.java:100)
at com.sun.tools.javac.api.JavacTaskImpl.call (JavacTaskImpl.java:94)
at org.codehaus.plexus.compiler.javac.JavaxToolsCompiler.compileInProcess (JavaxToolsCompiler.java:126)
at org.codehaus.plexus.compiler.javac.JavacCompiler.performCompile (JavacCompiler.java:174)
at org.apache.maven.plugin.compiler.AbstractCompilerMojo.execute (AbstractCompilerMojo.java:952)
at org.apache.maven.plugin.compiler.CompilerMojo.execute (CompilerMojo.java:158)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:200)
at org.apache.maven.lifecycle.internal.builder.multithreaded.MultiThreadedBuilder$1.call (MultiThreadedBuilder.java:196)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call (Executors.java:515)
at java.util.concurrent.FutureTask.run (FutureTask.java:264)
at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:628)
at java.lang.Thread.run (Thread.java:829)
Error:
Error: Re-run Maven using the -X switch to enable full debug logging.
Error:
Error: For more information about the errors and possible solutions, please read the following articles:
Error: [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
Error:
Error: After correcting the problems, you can resume the build with the command
Error: mvn <goals> -rf :pubsub-to-redis
Reactions are currently unavailable
Metadata
Metadata
Assignees
Labels
Component: valueP3Status: acceptedtype=defectBug, not working as expectedBug, not working as expected
Activity
cgdecker commentedon Aug 3, 2023
@eamonnmcmanus
I dug around in the code for a bit to see what might have changed between 1.8.2 and 1.10.2 that could be a cause for this, and what looked most likely to me is the change to parse files for
#parsenodes at template evaluation time rather than template parse time.It seems like that could be a problem here because
AutoValueTemplateVarsholds a pre-parsedstatic final Templateforautovalue.vm, which will then need to try to open and parse (and cache)equalshashcode.vm(always) andbuilder.vm(if there's a builder -- this seems to be where the exception is occurring in this case). The issue then could have to do with howTemplateVars.class.getResourceAsStreamis used to to open the streams to read those from.All that said, I'm not sure why opening that stream seemingly must be succeeding in this stack trace and the exception is then occurring while reading from from it. Maybe something is closing the original jar stream that the static reference to
TemplateVars.classwas loaded from, making the streams opened from it withgetResourceAsStreamalso closed?Revert auto-value version to 1.8.2, intermittently getting "Stream cl…
eamonnmcmanus commentedon Aug 3, 2023
Thanks @cgdecker, I think your theory is correct.
From the stack traces, it looks like this is happening on Java 8. I think the issue is JDK-6947916, which was fixed in Java 9. We already have a workaround but as Colin notes that only applies when the original
autovalue.vmis read. The#parsehappens later, outside thetry/catchwhere the workaround is active.I put a lot of effort into making this workaround, including a ridiculously complicated regression test, then unknowingly undid it all with the change Colin mentions.
While it's probably possible to come up with a new workaround, I think it would be a lot easier just to build with a more recent JDK. JDK 8 was released in 2014 and is more or less EOL now. Unless you can confirm that it is in fact a more recent JDK? (I'm assuming it's 8 because there are no module names in the stack traces.)
eamonnmcmanus commentedon Aug 3, 2023
(You can still build with
--target 8to produce Java-8-compatible.classfiles.)cgdecker commentedon Aug 3, 2023
Looking at the failed build link, it looks like Maven should be compiling with JDK 11 in this case:
Specifically with:
I wonder if changing the
distributionto something else (oracleoradoptmaybe?) would change anything.bvolpato commentedon Aug 3, 2023
Thanks for looking into this!
Right, it should be Java 11.
I got locally too with
After running
while mvn -T32 clean compile -DskipTests -e; do doneat DataflowTemplates for a couple of minutes.It's hard to bisect because it takes a bit to run, but I am pretty confident it is not happening with a single thread (or the probability is minimal), as the loop ran for hours with
-T1.Appreciate you guys looking -- but note that I understand this is a very specific use-case and this is not urgent. We reverted to 1.8.2 for the time being.
eamonnmcmanus commentedon Aug 3, 2023
I'm still puzzled at the absence of module names in those stack traces. Could you do this experiment in your environment?
It's those
java.base/that I would expect to see in a stack trace from the JDK 11 compiler. Unless the Zulu JDK doesn't do that?I'm persisting here just because it still seems like a big coincidence that (1) the stack traces look like Java 8 and (2) the symptoms correspond exactly to a bug that was fixed in Java 9.
cgdecker commentedon Aug 3, 2023
Curiously, I just ran the
jshellbinary fromzulu11.66.15-ca-jdk11.0.20-linux_x64and saw module names as expected, so I do wonder if something weird is going on.eamonnmcmanus commentedon Aug 3, 2023
For example, if the
pom.xmlwere doing something like this then the compilation could end up using JDK 8 even though Maven itself is running with JDK 11.honnix commentedon Sep 6, 2023
We also hit this problem quite often these day. Is there a plan to get this prioritized a bit? Thank you.
eamonnmcmanus commentedon Sep 6, 2023
Can you confirm whether you are using JDK 8 or a later JDK version?
honnix commentedon Sep 6, 2023
I can confirm we use Java 11 and compile with 11 as release target as well. We have Maven parallell build enabled.
eamonnmcmanus commentedon Sep 6, 2023
OK. If you have an exception stack-trace, can you show it? I'm curious if it contains module names, as I mentioned in an earlier comment. But I think it is probably possible to rework the code so that the existing workaround is applied more generally.
honnix commentedon Sep 6, 2023
Sure. There it is:
eamonnmcmanus commentedon Sep 6, 2023
Huh. That certainly does look like a Java 11 stacktrace. But JDK-6947916 is supposed to be fixed there. So perhaps there is another related issue? Anyway, I think this can be worked around and will look into that.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
Apply a workaround for a JDK bug unconditionally.
eamonnmcmanus commentedon Sep 8, 2023
I made it so that we no longer ever use
JarURLConnectionto read the resources (template files) that AutoValue needs. Instead, we always open the jar where the AutoValue code lives explicitly, and read the resources out of it. That's probably a bit more expensive, but only happens once per template and per compilation.honnix commentedon Sep 8, 2023
@eamonnmcmanus Thank you so much getting this fixed! I'm looking forward to trying in the next release.