Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NullPointerException in compile after upgrade to sbt 1.0.2 #3623

Closed
sjoerdmulder opened this issue Oct 9, 2017 · 28 comments
Closed

NullPointerException in compile after upgrade to sbt 1.0.2 #3623

sjoerdmulder opened this issue Oct 9, 2017 · 28 comments
Assignees
Labels
area/logging Bug Merged Upstream Will be fixed in the next version of sbt
Milestone

Comments

@sjoerdmulder
Copy link

(See the guidelines for contributing, linked above)

steps

  1. Running sbt compile on our project sometimes (hard to reproduce) gives a NPE failing the build

problem

[error] java.lang.RuntimeException: java.lang.NullPointerException
[error] 	at com.sun.tools.javac.main.Main.compile(Main.java:559)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.doCall(JavacTaskImpl.java:129)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.call(JavacTaskImpl.java:138)
[error] 	at sbt.internal.inc.javac.LocalJavaCompiler.run(LocalJava.scala:152)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.$anonfun$compile$11(AnalyzingJavaCompiler.scala:130)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.timed(AnalyzingJavaCompiler.scala:196)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.compile(AnalyzingJavaCompiler.scala:120)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:104)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:132)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compileJava$1(MixedAnalyzingCompiler.scala:89)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:115)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.Incremental$.doCompile(Incremental.scala:101)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$4(Incremental.scala:82)
[error] 	at sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:117)
[error] 	at sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:64)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] 	at sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] 	at sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] 	at sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:70)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] 	at sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1403)
[error] 	at sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1385)
[error] 	at scala.Function1.$anonfun$compose$1(Function1.scala:44)
[error] 	at sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:42)
[error] 	at sbt.std.Transform$$anon$4.work(System.scala:64)
[error] 	at sbt.Execute.$anonfun$submit$2(Execute.scala:257)
[error] 	at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
[error] 	at sbt.Execute.work(Execute.scala:266)
[error] 	at sbt.Execute.$anonfun$submit$1(Execute.scala:257)
[error] 	at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:167)
[error] 	at sbt.CompletionService$$anon$2.call(CompletionService.scala:32)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error] 	at java.lang.Thread.run(Thread.java:748)
[error] Caused by: java.lang.NullPointerException
[error] 	at com.sun.tools.javac.util.DiagnosticSource.findLine(DiagnosticSource.java:163)
[error] 	at com.sun.tools.javac.util.DiagnosticSource.getLineNumber(DiagnosticSource.java:77)
[error] 	at com.sun.tools.javac.util.JCDiagnostic$SourcePosition.<init>(JCDiagnostic.java:379)
[error] 	at com.sun.tools.javac.util.JCDiagnostic.getLineNumber(JCDiagnostic.java:519)
[error] 	at com.sun.tools.javac.api.ClientCodeWrapper$DiagnosticSourceUnwrapper.getLineNumber(ClientCodeWrapper.java:637)
[error] 	at sbt.internal.inc.javac.DiagnosticsReporter$PositionImpl.<init>(DiagnosticsReporter.scala:85)
[error] 	at sbt.internal.inc.javac.DiagnosticsReporter.report(DiagnosticsReporter.scala:67)
[error] 	at com.sun.tools.javac.api.ClientCodeWrapper$WrappedDiagnosticListener.report(ClientCodeWrapper.java:593)
[error] 	at com.sun.tools.javac.util.Log.writeDiagnostic(Log.java:616)
[error] 	at com.sun.tools.javac.util.Log$DefaultDiagnosticHandler.report(Log.java:591)
[error] 	at com.sun.tools.javac.util.Log.report(Log.java:562)
[error] 	at com.sun.tools.javac.util.AbstractLog.mandatoryWarning(AbstractLog.java:199)
[error] 	at com.sun.tools.javac.util.MandatoryWarningHandler.logMandatoryWarning(MandatoryWarningHandler.java:255)
[error] 	at com.sun.tools.javac.util.MandatoryWarningHandler.report(MandatoryWarningHandler.java:133)
[error] 	at com.sun.tools.javac.comp.Check.warnDeprecated(Check.java:236)
[error] 	at com.sun.tools.javac.comp.Check$7.report(Check.java:3169)
[error] 	at com.sun.tools.javac.code.DeferredLintHandler.flush(DeferredLintHandler.java:96)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4254)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4201)
[error] 	at com.sun.tools.javac.comp.Attr.attrib(Attr.java:4176)
[error] 	at com.sun.tools.javac.main.JavaCompiler.attribute(JavaCompiler.java:1248)
[error] 	at com.sun.tools.javac.main.JavaCompiler.compile2(JavaCompiler.java:901)
[error] 	at com.sun.tools.javac.main.JavaCompiler.compile(JavaCompiler.java:860)
[error] 	at com.sun.tools.javac.main.Main.compile(Main.java:523)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.doCall(JavacTaskImpl.java:129)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.call(JavacTaskImpl.java:138)
[error] 	at sbt.internal.inc.javac.LocalJavaCompiler.run(LocalJava.scala:152)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.$anonfun$compile$11(AnalyzingJavaCompiler.scala:130)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.timed(AnalyzingJavaCompiler.scala:196)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.compile(AnalyzingJavaCompiler.scala:120)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:104)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:132)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compileJava$1(MixedAnalyzingCompiler.scala:89)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:115)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.Incremental$.doCompile(Incremental.scala:101)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$4(Incremental.scala:82)
[error] 	at sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:117)
[error] 	at sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:64)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] 	at sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] 	at sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] 	at sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:70)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] 	at sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1403)
[error] 	at sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1385)
[error] 	at scala.Function1.$anonfun$compose$1(Function1.scala:44)
[error] 	at sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:42)
[error] 	at sbt.std.Transform$$anon$4.work(System.scala:64)
[error] 	at sbt.Execute.$anonfun$submit$2(Execute.scala:257)
[error] 	at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
[error] 	at sbt.Execute.work(Execute.scala:266)
[error] 	at sbt.Execute.$anonfun$submit$1(Execute.scala:257)
[error] 	at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:167)
[error] 	at sbt.CompletionService$$anon$2.call(CompletionService.scala:32)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[error] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[error] 	at java.lang.Thread.run(Thread.java:748)

expectation

This happens only in 30% of the builds, so it's really hard to reproduce but with sbt 0.13.x it never happened

notes

sbt version: 1.0.2

@dxuhuang
Copy link

I have been upgrading a service from sbt 0.13.15 to sbt 1.0.2, and have also been seeing this error about a fraction of the times.

@benblack86
Copy link

benblack86 commented Oct 24, 2017

[error] ## Exception when compiling 44 sources to /var/services-pr/target/scala-2.12/classes
[error] java.lang.NullPointerException
[error] com.sun.tools.javac.main.Main.compile(Main.java:559)
[error] com.sun.tools.javac.api.JavacTaskImpl.doCall(JavacTaskImpl.java:129)
[error] com.sun.tools.javac.api.JavacTaskImpl.call(JavacTaskImpl.java:138)
[error] sbt.internal.inc.javac.LocalJavaCompiler.run(LocalJava.scala:152)
[error] sbt.internal.inc.javac.AnalyzingJavaCompiler.$anonfun$compile$11(AnalyzingJavaCompiler.scala:130)
[error] scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] sbt.internal.inc.javac.AnalyzingJavaCompiler.timed(AnalyzingJavaCompiler.scala:196)
[error] sbt.internal.inc.javac.AnalyzingJavaCompiler.compile(AnalyzingJavaCompiler.scala:120)
[error] sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:104)
[error] scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:132)
[error] sbt.internal.inc.MixedAnalyzingCompiler.compileJava$1(MixedAnalyzingCompiler.scala:89)
[error] sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:113)
[error] sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:305)
[error] sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:305)
[error] sbt.internal.inc.Incremental$.doCompile(Incremental.scala:101)
[error] sbt.internal.inc.Incremental$.$anonfun$compile$4(Incremental.scala:82)
[error] sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:117)
[error] sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:64)
[error] sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:70)
[error] sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1403)
[error] sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1385)
[error] scala.Function1.$anonfun$compose$1(Function1.scala:44)
[error] sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:42)
[error] sbt.std.Transform$$anon$4.work(System.scala:64)
[error] sbt.Execute.$anonfun$submit$2(Execute.scala:257)
[error] sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
[error] sbt.Execute.work(Execute.scala:266)
[error] sbt.Execute.$anonfun$submit$1(Execute.scala:257)
[error] sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:167)
[error] sbt.CompletionService$$anon$2.call(CompletionService.scala:32)
[error] java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[error] java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[error] java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[error] java.lang.Thread.run(Thread.java:745)
[error]            
[error] java.lang.RuntimeException: java.lang.NullPointerException
[error] 	at com.sun.tools.javac.main.Main.compile(Main.java:559)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.doCall(JavacTaskImpl.java:129)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.call(JavacTaskImpl.java:138)
[error] 	at sbt.internal.inc.javac.LocalJavaCompiler.run(LocalJava.scala:152)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.$anonfun$compile$11(AnalyzingJavaCompiler.scala:130)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.timed(AnalyzingJavaCompiler.scala:196)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.compile(AnalyzingJavaCompiler.scala:120)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:104)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:132)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compileJava$1(MixedAnalyzingCompiler.scala:89)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:113)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.Incremental$.doCompile(Incremental.scala:101)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$4(Incremental.scala:82)
[error] 	at sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:117)
[error] 	at sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:64)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] 	at sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] 	at sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] 	at sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:70)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] 	at sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1403)
[error] 	at sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1385)
[error] 	at scala.Function1.$anonfun$compose$1(Function1.scala:44)
[error] 	at sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:42)
[error] 	at sbt.std.Transform$$anon$4.work(System.scala:64)
[error] 	at sbt.Execute.$anonfun$submit$2(Execute.scala:257)
[error] 	at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
[error] 	at sbt.Execute.work(Execute.scala:266)
[error] 	at sbt.Execute.$anonfun$submit$1(Execute.scala:257)
[error] 	at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:167)
[error] 	at sbt.CompletionService$$anon$2.call(CompletionService.scala:32)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[error] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[error] 	at java.lang.Thread.run(Thread.java:745)
[error] Caused by: java.lang.NullPointerException
[error] 	at com.sun.tools.javac.util.DiagnosticSource.findLine(DiagnosticSource.java:163)
[error] 	at com.sun.tools.javac.util.DiagnosticSource.getLineNumber(DiagnosticSource.java:77)
[error] 	at com.sun.tools.javac.util.JCDiagnostic$SourcePosition.<init>(JCDiagnostic.java:379)
[error] 	at com.sun.tools.javac.util.JCDiagnostic.getLineNumber(JCDiagnostic.java:519)
[error] 	at com.sun.tools.javac.api.ClientCodeWrapper$DiagnosticSourceUnwrapper.getLineNumber(ClientCodeWrapper.java:637)
[error] 	at sbt.internal.inc.javac.DiagnosticsReporter$PositionImpl.<init>(DiagnosticsReporter.scala:85)
[error] 	at sbt.internal.inc.javac.DiagnosticsReporter.report(DiagnosticsReporter.scala:67)
[error] 	at com.sun.tools.javac.api.ClientCodeWrapper$WrappedDiagnosticListener.report(ClientCodeWrapper.java:593)
[error] 	at com.sun.tools.javac.util.Log.writeDiagnostic(Log.java:616)
[error] 	at com.sun.tools.javac.util.Log$DefaultDiagnosticHandler.report(Log.java:591)
[error] 	at com.sun.tools.javac.util.Log.report(Log.java:562)
[error] 	at com.sun.tools.javac.util.AbstractLog.warning(AbstractLog.java:170)
[error] 	at com.sun.tools.javac.comp.Check$3.report(Check.java:588)
[error] 	at com.sun.tools.javac.code.DeferredLintHandler.report(DeferredLintHandler.java:80)
[error] 	at com.sun.tools.javac.comp.Check.checkRedundantCast(Check.java:584)
[error] 	at com.sun.tools.javac.comp.Attr.visitTypeCast(Attr.java:3127)
[error] 	at com.sun.tools.javac.tree.JCTree$JCTypeCast.accept(JCTree.java:1814)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.visitReturn(Attr.java:1686)
[error] 	at com.sun.tools.javac.tree.JCTree$JCReturn.accept(JCTree.java:1384)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.attribStat(Attr.java:645)
[error] 	at com.sun.tools.javac.comp.Attr.attribStats(Attr.java:661)
[error] 	at com.sun.tools.javac.comp.Attr.visitBlock(Attr.java:1124)
[error] 	at com.sun.tools.javac.tree.JCTree$JCBlock.accept(JCTree.java:909)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.attribStat(Attr.java:645)
[error] 	at com.sun.tools.javac.comp.Attr.visitMethodDef(Attr.java:1013)
[error] 	at com.sun.tools.javac.tree.JCTree$JCMethodDecl.accept(JCTree.java:778)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.attribStat(Attr.java:645)
[error] 	at com.sun.tools.javac.comp.Attr.attribClassBody(Attr.java:4364)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4272)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4201)
[error] 	at com.sun.tools.javac.comp.Attr.visitClassDef(Attr.java:870)
[error] 	at com.sun.tools.javac.tree.JCTree$JCClassDecl.accept(JCTree.java:693)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.attribStat(Attr.java:645)
[error] 	at com.sun.tools.javac.comp.Attr.attribClassBody(Attr.java:4364)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4272)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4201)
[error] 	at com.sun.tools.javac.comp.Attr.visitClassDef(Attr.java:870)
[error] 	at com.sun.tools.javac.tree.JCTree$JCClassDecl.accept(JCTree.java:693)
[error] 	at com.sun.tools.javac.comp.Attr.attribTree(Attr.java:576)
[error] 	at com.sun.tools.javac.comp.Attr.attribStat(Attr.java:645)
[error] 	at com.sun.tools.javac.comp.Attr.attribClassBody(Attr.java:4364)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4272)
[error] 	at com.sun.tools.javac.comp.Attr.attribClass(Attr.java:4201)
[error] 	at com.sun.tools.javac.comp.Attr.attrib(Attr.java:4176)
[error] 	at com.sun.tools.javac.main.JavaCompiler.attribute(JavaCompiler.java:1248)
[error] 	at com.sun.tools.javac.main.JavaCompiler.compile2(JavaCompiler.java:901)
[error] 	at com.sun.tools.javac.main.JavaCompiler.compile(JavaCompiler.java:860)
[error] 	at com.sun.tools.javac.main.Main.compile(Main.java:523)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.doCall(JavacTaskImpl.java:129)
[error] 	at com.sun.tools.javac.api.JavacTaskImpl.call(JavacTaskImpl.java:138)
[error] 	at sbt.internal.inc.javac.LocalJavaCompiler.run(LocalJava.scala:152)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.$anonfun$compile$11(AnalyzingJavaCompiler.scala:130)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.timed(AnalyzingJavaCompiler.scala:196)
[error] 	at sbt.internal.inc.javac.AnalyzingJavaCompiler.compile(AnalyzingJavaCompiler.scala:120)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.$anonfun$compile$4(MixedAnalyzingCompiler.scala:104)
[error] 	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:12)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.timed(MixedAnalyzingCompiler.scala:132)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compileJava$1(MixedAnalyzingCompiler.scala:89)
[error] 	at sbt.internal.inc.MixedAnalyzingCompiler.compile(MixedAnalyzingCompiler.scala:113)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileInternal$1$adapted(IncrementalCompilerImpl.scala:305)
[error] 	at sbt.internal.inc.Incremental$.doCompile(Incremental.scala:101)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$4(Incremental.scala:82)
[error] 	at sbt.internal.inc.IncrementalCommon.recompileClasses(IncrementalCommon.scala:117)
[error] 	at sbt.internal.inc.IncrementalCommon.cycle(IncrementalCommon.scala:64)
[error] 	at sbt.internal.inc.Incremental$.$anonfun$compile$3(Incremental.scala:84)
[error] 	at sbt.internal.inc.Incremental$.manageClassfiles(Incremental.scala:129)
[error] 	at sbt.internal.inc.Incremental$.compile(Incremental.scala:75)
[error] 	at sbt.internal.inc.IncrementalCompile$.apply(Compile.scala:70)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileInternal(IncrementalCompilerImpl.scala:309)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.$anonfun$compileIncrementally$1(IncrementalCompilerImpl.scala:267)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.handleCompilationError(IncrementalCompilerImpl.scala:158)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compileIncrementally(IncrementalCompilerImpl.scala:237)
[error] 	at sbt.internal.inc.IncrementalCompilerImpl.compile(IncrementalCompilerImpl.scala:68)
[error] 	at sbt.Defaults$.compileIncrementalTaskImpl(Defaults.scala:1403)
[error] 	at sbt.Defaults$.$anonfun$compileIncrementalTask$1(Defaults.scala:1385)
[error] 	at scala.Function1.$anonfun$compose$1(Function1.scala:44)
[error] 	at sbt.internal.util.$tilde$greater.$anonfun$$u2219$1(TypeFunctions.scala:42)
[error] 	at sbt.std.Transform$$anon$4.work(System.scala:64)
[error] 	at sbt.Execute.$anonfun$submit$2(Execute.scala:257)
[error] 	at sbt.internal.util.ErrorHandling$.wideConvert(ErrorHandling.scala:16)
[error] 	at sbt.Execute.work(Execute.scala:266)
[error] 	at sbt.Execute.$anonfun$submit$1(Execute.scala:257)
[error] 	at sbt.ConcurrentRestrictions$$anon$4.$anonfun$submitValid$1(ConcurrentRestrictions.scala:167)
[error] 	at sbt.CompletionService$$anon$2.call(CompletionService.scala:32)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[error] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[error] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[error] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[error] 	at java.lang.Thread.run(Thread.java:745)
[error] (compile:compileIncremental) java.lang.NullPointerException
[error] Total time: 24 s, completed Oct 24, 2017 9:27:51 PM

@ktoso
Copy link
Member

ktoso commented Oct 30, 2017

We also noticed this, on our build servers, when we upgraded to sbt 1.0.2 recently. Locally it seems to work fine, and was not able to reproduce the issue locally so far.

Here's an example failed build https://jenkins.akka.io:8498/job/pr-validator-per-commit-jenkins/10520/console

@dxuhuang
Copy link

dxuhuang commented Nov 2, 2017

@ktoso Just noticed in your Jenkins console output that your code uses Protobuf. Our service does too. In fact another service of ours that uses Protobuf also has this error, and they are ONLY ones. Maybe this is due to sbt and Protobuf somehow not playing nicely?
@sjoerdmulder Does your project by any chance include Protobuf? 😅

@ktoso
Copy link
Member

ktoso commented Nov 2, 2017

Could be, I wonder.
Yes, we have protobuf generated classes

@benblack86
Copy link

I've managed to recreate with this example https://github.com/benblack86/sbt-protobuf-test

It is still random, but if you run sbt clean compile a few times you should hopefully see the issue.

@dxuhuang
Copy link

dxuhuang commented Nov 3, 2017

@dwijnand

@gosubpl
Copy link

gosubpl commented Nov 3, 2017

@ktoso FYI, it also fails in local builds (sometimes). Example - akka-distributed-data project.

@2m
Copy link
Member

2m commented Nov 7, 2017

I was not able to reproduce it using https://github.com/benblack86/sbt-protobuf-test neither on my machine, where I have never seen this error before, neither on our CI server where this error was spontaneously happening while building Akka.

I was also using sbt-repeat and doing repeat 100 ;clean ;compile, maybe that was the difference that prevented reproducing the error...

@sjoerdmulder
Copy link
Author

sjoerdmulder commented Nov 7, 2017 via email

@benblack86
Copy link

@2m yes, I don't think sbt-repeat will help recreate since it seems to be something random linked to when sbt starts up.

@2m
Copy link
Member

2m commented Nov 8, 2017

I also tried repeat 100 sbt clean compile using repeat shell command. And on my machine it was again fine. Was not able to try on CI machine yet because of the too old shell.

@2m
Copy link
Member

2m commented Nov 8, 2017

Another report on NPE with the same line number: facebook/buck#403

@jrudolph
Copy link
Member

jrudolph commented Nov 8, 2017

@2m the buck stack trace seems to be different. It's only the entry point com.sun.tools.javac.main.Main.compile which is the same not the actual failure line here com.sun.tools.javac.util.DiagnosticSource.findLine(DiagnosticSource.java:163).

@benblack86
Copy link

@2m did you try just doing sbt clean compile manually 5 times?

@2m
Copy link
Member

2m commented Nov 9, 2017

Yup. Quite a few times with no NPE. :\

@nmarasoiu
Copy link

Happening to me as well when compiling akka incrementally with sbt 1.0.2

@jrudolph
Copy link
Member

jrudolph commented Nov 13, 2017

This still happens regularly during Akka's CI builds. I had a look to find the (JDK) sources that fail. I didn't find any version of OpenJDK where all the line numbers would match the openjdk sources (but maybe I just missed something).

From looking at the sources it's unclear where the null dereference would happen at all. The most likely place (that's where the line number points to in most revisions) would be the array access at buf[...]. It's hard to imagine how buf could be null at that place, though. One explanation could be thread-unsafe concurrent access leading to a race condition where after a buf != null branch was taken, a subsequent invocation would null out buf because the SoftReference would have been cleared. But where would the concurrent access come from in the first place? It seems the same source file would have to be compiled at the same time and somehow the compiler internals would have to be shared?

@SethTisue
Copy link
Member

This still happens regularly during Akka's CI builds

when building Akka as part of the Scala community build, too, e.g. at https://scala-ci.typesafe.com/view/scala-2.13.x/job/scala-2.13.x-integrate-community-build/791/

@dxuhuang
Copy link

@jrudolph what's buf?

@patriknw
Copy link

Perhaps this is a stupid and obvious question, but anyway. What is changed in sbt 1.0.2 with regards to concurrency? The stack trace hints at sbt.ConcurrentRestrictions.

@jrudolph
Copy link
Member

I instrumented tools.jar and found out that indeed several threads access the problematic method. The interesting one is this: Log4j2-TF-1-AsyncLogger[AsyncContext@6500df86]-1. So, the issue here is that xsbti.Problem instances are passed to logging. They are backed by javax.tools.Diagnostic instances which are not thread-safe and which are then accessed concurrently by the Log4j2 async logging infrastructure.

There are several things at play here:

  • it's somewhat surprising that javax.tools.Diagnostic is not thread-safe (but it's also not marked as such, so it cannot be assumed)
  • the whole idea of ObjectEvents (https://github.com/sbt/util/blob/1.x/internal/util-logging/src/main/scala/sbt/internal/util/ObjectEvent.scala) for logging is very dangerous. With asynchronous loggers, it's so easy to transitively sneak some thread-unsafe objects in there. Keep logging simple to avoid errors like this. Filter as early as possible and then pass only a small set of known-to-be-thread-safe objects to the appender (strings).

@jrudolph
Copy link
Member

A first workaround could be to make sure that PositionImpl is thread-safe (by initializing fields eagerly and not holding to javax.tools.Diagnostic) but ultimately the goal should be not to pass objects to logging...

@jrudolph
Copy link
Member

For reference here is the stack trace of the concurrent access:

	at java.lang.Thread.dumpStack(Thread.java:1336)
	at com.sun.tools.javac.util.DiagnosticSource.findLine(DiagnosticSource.java:178)
	at com.sun.tools.javac.util.DiagnosticSource.getLine(DiagnosticSource.java:116)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at sbt.internal.inc.javac.DiagnosticsReporter$PositionImpl.getDiagnosticLine$1(DiagnosticsReporter.scala:107)
	at sbt.internal.inc.javac.DiagnosticsReporter$PositionImpl.lineContent(DiagnosticsReporter.scala:127)
	at sbt.internal.inc.ProblemStringFormats$$anon$1.showLines(ProblemStringFormats.scala:32)
	at sbt.internal.inc.ProblemStringFormats$$anon$1.showLines(ProblemStringFormats.scala:21)
	at sbt.internal.util.ConsoleAppender.appendEvent$1(ConsoleAppender.scala:439)
	at sbt.internal.util.ConsoleAppender.appendMessageContent(ConsoleAppender.scala:446)
	at sbt.internal.util.ConsoleAppender.appendMessage(ConsoleAppender.scala:411)
	at sbt.internal.util.ConsoleAppender.append(ConsoleAppender.scala:307)
	at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:448)
	at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:433)
	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:417)
	at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:79)
	at org.apache.logging.log4j.core.async.AsyncLogger.actualAsyncLog(AsyncLogger.java:337)
	at org.apache.logging.log4j.core.async.RingBufferLogEvent.execute(RingBufferLogEvent.java:161)
	at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:45)
	at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:29)
	at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:129)
	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)

@jrudolph
Copy link
Member

fwiw, a note about async logging. I understand, that it is compelling to do as much work as possible asynchronously when you already have an async logger. However, the ultimate reason to do async logging is to avoid I/O in the main worker threads. Shaving off a bit of CPU time from the main process by doing the string processing in the logger thread will only work on under-saturated machines anyway. In many other cases, it's probably even faster to do the inevitable string processing as soon as possible on the worker threads (better parallelism) and execute only the actual recording of the log events asynchronously.

@dwijnand
Copy link
Member

Thanks for the investigation @jrudolph!

@dwijnand dwijnand added this to the 1.2.0 milestone Nov 15, 2017
eed3si9n added a commit to eed3si9n/zinc that referenced this issue Dec 6, 2017
Fixes sbt#464 sbt/sbt#3623

Currently compiling a lot of Java code in CI environment causes NullPointerException, which is
suspected of race condition around `javax.tools.Diagnostics[S]`, which is held by `PositionImpl` and then later accessed by async logging.

This change makes the `PositionImpl` strict and immutable, and extracts it from a Java Diagnostics object. No other observable changes are introduced besides, hopefully the lack of NPE. Credit on the detective work goes to Lightbend Akka team ktoso, 2m, and jrudolph.
eed3si9n added a commit to eed3si9n/zinc that referenced this issue Dec 6, 2017
Fixes sbt#464 sbt/sbt#3623

Currently compiling a lot of Java code in CI environment causes NullPointerException, which is
suspected of race condition around `javax.tools.Diagnostics[S]`, which is held by `PositionImpl` and then later accessed by async logging.

This change makes the `PositionImpl` strict and immutable, and extracts it from a Java Diagnostics object. No other observable changes are introduced besides, hopefully the lack of NPE. Credit on the detective work goes to Lightbend Akka team ktoso, 2m, and jrudolph.
eed3si9n added a commit to eed3si9n/zinc that referenced this issue Dec 6, 2017
Fixes sbt#464 sbt/sbt#3623

Currently compiling a lot of Java code in CI environment causes NullPointerException, which is
suspected of race condition around `javax.tools.Diagnostics[S]`, which is held by `PositionImpl` and then later accessed by async logging.

This change makes the `PositionImpl` strict and immutable, and extracts it from a Java Diagnostics object. No other observable changes are introduced besides, hopefully the lack of NPE. Credit on the detective work goes to Lightbend Akka team ktoso, 2m, and jrudolph.
eed3si9n added a commit to eed3si9n/zinc that referenced this issue Dec 8, 2017
Fixes sbt#464 sbt/sbt#3623

Currently compiling a lot of Java code in CI environment causes NullPointerException, which is
suspected of race condition around `javax.tools.Diagnostics[S]`, which is held by `PositionImpl` and then later accessed by async logging.

This change makes the `PositionImpl` strict and immutable, and extracts it from a Java Diagnostics object. No other observable changes are introduced besides, hopefully the lack of NPE. Credit on the detective work goes to Lightbend Akka team ktoso, 2m, and jrudolph.
@dwijnand dwijnand modified the milestones: 1.2.0, 1.1.0 Dec 9, 2017
@dwijnand dwijnand added the Merged Upstream Will be fixed in the next version of sbt label Dec 9, 2017
@eed3si9n
Copy link
Member

New Zinc was merged in #3816 with the fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/logging Bug Merged Upstream Will be fixed in the next version of sbt
Projects
None yet
Development

No branches or pull requests