2.10: with -target:jvm-1.5-asm, java.util.NoSuchElementException in GenASM.popScope

[scabug]

I'm testing -target:jvm-1.5-asm with M4 and my large mixed Scala/Java codebase and I'm getting the following compiler crash.

[error]      while compiling: /Users/tisue/nl.210/src/main/org/nlogo/util/Utils.scala
[error]         during phase: jvm
[error]      library version: version 2.10.0-M4
[error]     compiler version: version 2.10.0-M4
[error]   reconstructed args: -deprecation -target:jvm-1.5-asm -feature -bootclasspath /Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/jsfd.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/classes.jar:/System/Library/Frameworks/JavaVM.framework/Frameworks/JavaRuntimeSupport.framework/Resources/Java/JavaRuntimeSupport.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/ui.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/laf.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/sunrsasign.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/jsse.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/jce.jar:/Library/Java/JavaVirtualMachines/1.6.0_33-b03-424.jdk/Contents/Classes/charsets.jar:/Users/tisue/.sbt/boot/scala-2.10.0-M4/lib/scala-library.jar -classpath /Users/tisue/nl.210/target/scala-2.10/classes:/Users/tisue/nl.210/lib_managed/jars/com.typesafe/config/config-0.4.0.jar:/Users/tisue/nl.210/lib_managed/jars/asm/asm-all/asm-all-3.3.1.jar:/Users/tisue/nl.210/lib_managed/jars/org.picocontainer/picocontainer/picocontainer-2.13.6.jar:/Users/tisue/nl.210/lib_managed/bundles/log4j/log4j/log4j-1.2.16.jar:/Users/tisue/nl.210/lib_managed/jars/javax.media/jmf/jmf-2.1.1e.jar:/Users/tisue/nl.210/lib_managed/jars/org.pegdown/pegdown/pegdown-1.1.0.jar:/Users/tisue/nl.210/lib_managed/jars/org.parboiled/parboiled-core/parboiled-core-1.0.2.jar:/Users/tisue/nl.210/lib_managed/jars/org.parboiled/parboiled-java/parboiled-java-1.0.2.jar:/Users/tisue/nl.210/lib_managed/jars/asm/asm/asm-3.3.1.jar:/Users/tisue/nl.210/lib_managed/jars/asm/asm-util/asm-util-3.3.1.jar:/Users/tisue/nl.210/lib_managed/jars/asm/asm-tree/asm-tree-3.3.1.jar:/Users/tisue/nl.210/lib_managed/jars/asm/asm-analysis/asm-analysis-3.3.1.jar:/Users/tisue/nl.210/lib_managed/jars/steveroy/mrjadapter/mrjadapter-1.2.jar:/Users/tisue/nl.210/lib_managed/jars/org.jhotdraw/jhotdraw/jhotdraw-6.0b1.jar:/Users/tisue/nl.210/lib_managed/jars/ch.randelshofer/quaqua/quaqua-7.3.4.jar:/Users/tisue/nl.210/lib_managed/jars/ch.randelshofer/swing-layout/swing-layout-7.3.4.jar:/Users/tisue/nl.210/lib_managed/jars/org.jogl/jogl/jogl-1.1.1.jar:/Users/tisue/nl.210/lib_managed/jars/org.gluegen-rt/gluegen-rt/gluegen-rt-1.1.1.jar -Xcheckinit -encoding us-ascii -d /Users/tisue/nl.210/target/scala-2.10/classes -unchecked
[error] 
[error]   last tree to typer: TypeTree(class Unit)
[error]               symbol: class Unit in package scala (flags: final abstract)
[error]    symbol definition: final abstract class Unit extends 
[error]                  tpe: Unit
[error]        symbol owners: class Unit -> package scala
[error]       context owners: method remove -> trait AgentSet$Iterator -> package agent
[error] 
[error] == Enclosing template or block ==
[error] 
[error] DefDef( // def remove(): Unit in trait AgentSet$Iterator
[error]   <deferred> <method> <java>
[error]   "remove"
[error]   []
[error]   List(Nil)
[error]   <tpt> // tree.tpe=Unit
[error]   <empty>
[error] )
[error] 
[error] == Expanded type of tree ==
[error] 
[error] TypeRef(TypeSymbol(final abstract class Unit extends ))
[error] 
[error] uncaught exception during compilation: java.util.NoSuchElementException
java.util.NoSuchElementException: key not found: value job
	at scala.collection.MapLike$class.default(MapLike.scala:228)
	at scala.collection.AbstractMap.default(Map.scala:57)
	at scala.collection.mutable.HashMap.apply(HashMap.scala:63)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder$scoping$2$.popScope(GenASM.scala:2184)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder$$anonfun$genBlock$1$1.apply(GenASM.scala:2609)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder$$anonfun$genBlock$1$1.apply(GenASM.scala:2355)
	at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:34)
	at scala.collection.mutable.ArrayOps.foreach(ArrayOps.scala:39)
	at scala.tools.nsc.backend.icode.BasicBlocks$BasicBlock.foreach(BasicBlocks.scala:185)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder.genBlock$1(GenASM.scala:2355)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder.genBlocks$1(GenASM.scala:2285)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder.genCode(GenASM.scala:2814)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder.genMethod(GenASM.scala:1615)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder$$anonfun$genClass$4.apply(GenASM.scala:1444)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder$$anonfun$genClass$4.apply(GenASM.scala:1444)
	at scala.collection.LinearSeqOptimized$class.foreach(LinearSeqOptimized.scala:59)
	at scala.collection.immutable.List.foreach(List.scala:77)
	at scala.tools.nsc.backend.jvm.GenASM$JPlainBuilder.genClass(GenASM.scala:1444)
	at scala.tools.nsc.backend.jvm.GenASM$AsmPhase.run(GenASM.scala:180)
	at scala.tools.nsc.Global$Run.compileUnitsInternal(Global.scala:1574)
	at scala.tools.nsc.Global$Run.compileUnits(Global.scala:1548)
	at scala.tools.nsc.Global$Run.compileSources(Global.scala:1544)
	at scala.tools.nsc.Global$Run.compile(Global.scala:1654)
	at xsbt.CachedCompiler0.run(CompilerInterface.scala:90)
	at xsbt.CachedCompiler0.run(CompilerInterface.scala:72)
	at xsbt.CompilerInterface.run(CompilerInterface.scala:26)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at sbt.compiler.AnalyzingCompiler.call(AnalyzingCompiler.scala:73)
	at sbt.compiler.AnalyzingCompiler.compile(AnalyzingCompiler.scala:35)
	at sbt.compiler.AnalyzingCompiler.compile(AnalyzingCompiler.scala:29)
	at sbt.compiler.AggressiveCompile$$anonfun$4$$anonfun$compileScala$1$1.apply$mcV$sp(AggressiveCompile.scala:71)
	at sbt.compiler.AggressiveCompile$$anonfun$4$$anonfun$compileScala$1$1.apply(AggressiveCompile.scala:71)
	at sbt.compiler.AggressiveCompile$$anonfun$4$$anonfun$compileScala$1$1.apply(AggressiveCompile.scala:71)
	at sbt.compiler.AggressiveCompile.sbt$compiler$AggressiveCompile$$timed(AggressiveCompile.scala:101)
	at sbt.compiler.AggressiveCompile$$anonfun$4.compileScala$1(AggressiveCompile.scala:70)
	at sbt.compiler.AggressiveCompile$$anonfun$4.apply(AggressiveCompile.scala:88)
	at sbt.compiler.AggressiveCompile$$anonfun$4.apply(AggressiveCompile.scala:60)
	at sbt.inc.IncrementalCompile$$anonfun$doCompile$1.apply(Compile.scala:24)
	at sbt.inc.IncrementalCompile$$anonfun$doCompile$1.apply(Compile.scala:22)
	at sbt.inc.Incremental$.cycle(Incremental.scala:39)
	at sbt.inc.Incremental$.compile(Incremental.scala:26)
	at sbt.inc.IncrementalCompile$.apply(Compile.scala:20)
	at sbt.compiler.AggressiveCompile.compile2(AggressiveCompile.scala:96)
	at sbt.compiler.AggressiveCompile.compile1(AggressiveCompile.scala:44)
	at sbt.compiler.AggressiveCompile.apply(AggressiveCompile.scala:31)
	at sbt.Compiler$.apply(Compiler.scala:79)
	at sbt.Defaults$$anonfun$compileTask$1.apply(Defaults.scala:571)
	at sbt.Defaults$$anonfun$compileTask$1.apply(Defaults.scala:571)
	at sbt.Scoped$$anonfun$hf2$1.apply(Structure.scala:578)
	at sbt.Scoped$$anonfun$hf2$1.apply(Structure.scala:578)
	at scala.Function1$$anonfun$compose$1.apply(Function1.scala:49)
	at sbt.Scoped$Reduced$$anonfun$combine$1$$anonfun$apply$12.apply(Structure.scala:311)
	at sbt.Scoped$Reduced$$anonfun$combine$1$$anonfun$apply$12.apply(Structure.scala:311)
	at sbt.$tilde$greater$$anonfun$$u2219$1.apply(TypeFunctions.scala:40)
	at sbt.std.Transform$$anon$5.work(System.scala:71)
	at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:232)
	at sbt.Execute$$anonfun$submit$1$$anonfun$apply$1.apply(Execute.scala:232)
	at sbt.ErrorHandling$.wideConvert(ErrorHandling.scala:18)
	at sbt.Execute.work(Execute.scala:238)
	at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:232)
	at sbt.Execute$$anonfun$submit$1.apply(Execute.scala:232)
	at sbt.ConcurrentRestrictions$$anon$4$$anonfun$1.apply(ConcurrentRestrictions.scala:159)
	at sbt.CompletionService$$anon$2.call(CompletionService.scala:30)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:680)
[error] (compile:compile) java.util.NoSuchElementException: key not found: value job

[scabug]

Imported From: https://issues.scala-lang.org/browse/SI-6049?orig=1
Reporter: @SethTisue
Assignee: @magarciaEPFL
Affected Versions: 2.10.0-M4
Other Milestones: 2.10.0-M6
See #6191

[scabug]

@SethTisue said:
I don't yet have isolated code that produces this error.

I was able to cut my codebase down from over 100K lines to about 20K lines, and the crash still happens, but cutting it any further than that is going to be difficult. (the crash goes away if I remove the two topmost classes from the source tree, but these two classes depend on a ton of other stuff.)

so my question is: are there enough clues already in the stack trace and debugging output? or should I work further on minimizing this?

[scabug]

@magarciaEPFL said (edited on Jul 10, 2012 5:17:48 PM UTC):
A temporary bandaid in
scala/scala#858
avoids the exception and emits a warning instead (including source code position).

Please give it a try, the information thus gained will help in

• minimizing the example, and
• finding the root cause of the problem (ie where GenICode emits unbalanced debug scopes for local variables).

[scabug]

@magarciaEPFL said:
Some observations about Context 's enterScope() and exitScope() in GenICode:

• enterScope() doesn't insert SCOPE_ENTER s, they result only from ValDef s found during genLoad()
• on the other hand, the only place where SCOPE_EXIT s are added is exitScope() :

      def exitScope() {
        if (bb.nonEmpty) {
          scope.locals foreach { lv => bb.emit(SCOPE_EXIT(lv)) }
        }
        scope = scope.outer
      }

• enterScope() is called upon visiting a Block or a DefDef. In the latter case, via enterMethod().
• exitScope() is called upon leaving a Block.

Proposed fix: Looks like exitScope() should also be called upon leaving a DefDef, unless it was already called for the outermost Block of that DefDef. Otherwise we would end up adding duplicate SCOPE_EXIT s.

Comments from @dragos are welcome:

• about the proposed fix
• exitScope() will add no SCOPE_EXIT s for an empty basic block (irrespective of how many locals have been queued). Why?

[scabug]

@SethTisue said:
using that branch, I found the poison pill:

~ % cat O.scala
object O {
  var i = 0
  while(true) {
    var j = 0
    if (j != 0)
      try j
      catch { case t: Throwable => }
    i
  }
}
~ % ~/scala.miguel/dists/latest/bin/scalac -version
Scala compiler version 2.10.0-20120710-143117-178752a5f5 -- Copyright 2002-2011, LAMP/EPFL
~ % ~/scala.miguel/dists/latest/bin/scalac O.scala 
O.scala:8: warning: Visited SCOPE_EXIT before visiting corresponding SCOPE_ENTER. SI-6049.
    i
    ^
one warning found

I'm not absolutely certain this is minimal, but it must be close.

[scabug]

@magarciaEPFL said (edited on Jul 11, 2012 9:22:23 AM UTC):
Slightly shorter:

object O {

  while(true) {
    var j = 0
    try j
    catch { case t: Throwable => }
  }

}

The linearization of basic blocks (shown below) results in one block (2 loop header) after another (3 successor to try body)
where the former contains the SCOPE_EXIT that corresponds to the SCOPE_ENTER in the latter block.

  def <init>(): ... {
  locals: variable j, value t
  startBlock: 1
  blocks: [1,2,3,4,5]
  
  1: 
    4	THIS(O)
    4	CALL_METHOD java.lang.Object.<init> (super())
    6	JUMP 2
    
  4[catch handler]:
    8	LOAD_EXCEPTION(class Throwable)
    9	STORE_LOCAL(value t)
    9	LOAD_FIELD scala.runtime.BoxedUnit.UNIT
    9	JUMP 3
    
  3[successor to try body]:
    8	DROP REF(class Object)
    8	SCOPE_EXIT variable j   <-------- SCOPE_EXIT before corresponding SCOPE_ENTER
    8	JUMP 2
    
  2[loop header]: 
    7	CONSTANT(0)
    7	STORE_LOCAL(variable j)
    7	SCOPE_ENTER variable j
    7	JUMP 5
    
  5[try body]:
    8	LOAD_LOCAL(variable j)
    8	BOX INT
    8	JUMP 3
    
  }
  Exception handlers: 
    catch (Throwable) in ArrayBuffer(5) starting at: 4
      consisting of blocks: List(4)
      with finalizer: null

[scabug]

@SethTisue said:
may I suggest this be marked as "critical" for 2.10?

[scabug]

@magarciaEPFL said:
This bug is critical, and the fix at scala/scala#858 has already been merged. I've left it open as a self-reminder about the interplay of CFG linearization and SCOPE_ENTER, SCOPE_EXIT. I want to take look at that in more detail as it might be relevant for other bugs.

[scabug]

@SethTisue said:
great, thanks.

for now, I was able to get my real codebase compiling on M5 by hoisting a few try/catch blocks into helper methods.

[scabug]

@SethTisue said:
M6 still gives the same SCOPE_EXIT warnings on the same code. I'm not getting the compiler crash, so this bug is fixed in that sense, but spurious warnings are bugs, too. Should I open a new ticket just on that...?

[scabug]

@magarciaEPFL said:
I guess there's still a problem (the warning about SCOPE_EXIT, but also whether the debugger shows the variable in question).

A ticket could be opened for that, yes.

[scabug]

@SethTisue said:
I see. #6191 opened, then.

[scabug]

@adriaanm said:
Just saw this warning while testing scala/scala#2347:

     [echo]        build time: 2 April 2013, 09:02:53
     [echo]      java version: Java HotSpot(TM) 64-Bit Server VM 1.6.0_43 (1.6)
     [echo]         java args: -Xmx3g -Xms3g -XX:+TieredCompilation -XX:ReservedCodeCacheSize=256m -XX:MaxPermSize=384m -XX:+UseNUMA -XX:+UseParallelGC 
     [echo]        javac args: 
     [echo]       scalac args:   -optimise
     [echo] scalac quick args:   -optimise
     [echo]          git date: 20130402-090234
     [echo]          git hash: c7a0057213
     [echo]     maven version: 2.11.0-SNAPSHOT
     [echo]      OSGi version: 2.11.0.v20130402-090234-c7a0057213
     [echo] canonical version: 2.11.0-20130402-090234-c7a0057213

asm.done:
    [mkdir] Created dir: /Users/adriaan/git/scala/build/asm/classes
    [javac] Compiling 77 source files to /Users/adriaan/git/scala/build/asm/classes
    [javac] Note: Some input files use unchecked or unsafe operations.
    [javac] Note: Recompile with -Xlint:unchecked for details.
[stopwatch] [asm.timer: 1.021 sec]
    [mkdir] Created dir: /Users/adriaan/git/scala/build/libs

forkjoin.done:
    [mkdir] Created dir: /Users/adriaan/git/scala/build/libs/classes/forkjoin
    [javac] Compiling 10 source files to /Users/adriaan/git/scala/build/libs/classes/forkjoin
    [javac] Creating empty /Users/adriaan/git/scala/build/libs/classes/forkjoin/scala/concurrent/forkjoin/package-info.class
      [jar] Building jar: /Users/adriaan/git/scala/build/libs/forkjoin.jar
[stopwatch] [forkjoin.timer: 0.252 sec]

locker.start:

locker.lib:
    [mkdir] Created dir: /Users/adriaan/git/scala/build/locker/classes/library
    [javac] Compiling 32 source files to /Users/adriaan/git/scala/build/locker/classes/library
    [javac] Note: /Users/adriaan/git/scala/src/library/scala/collection/concurrent/MainNode.java uses unchecked or unsafe operations.
    [javac] Note: Recompile with -Xlint:unchecked for details.
[locker.library] Compiling 704 files to /Users/adriaan/git/scala/build/locker/classes/library
[locker.library] /Users/adriaan/git/scala/src/library/scala/SerialVersionUID.scala:15: warning: Implementation restriction: subclassing Classfile does not
[locker.library] make your annotation visible at runtime.  If that is what
[locker.library] you want, you must write the annotation class in Java.
[locker.library] class SerialVersionUID(value: Long) extends scala.annotation.ClassfileAnnotation
[locker.library]       ^
[locker.library] warning: there were 128 deprecation warnings; re-run with -deprecation for details
[locker.library] warning: there were 5 feature warnings; re-run with -feature for details
[locker.library] warning: there were 348 inliner warnings; re-run with -Yinline-warnings for details
[locker.library] four warnings found
[propertyfile] Creating new property file: /Users/adriaan/git/scala/build/locker/classes/library/library.properties
[stopwatch] [locker.library.timer: 1:31.011 sec]

locker.reflect:
    [mkdir] Created dir: /Users/adriaan/git/scala/build/locker/classes/reflect
[locker.reflect] Compiling 137 files to /Users/adriaan/git/scala/build/locker/classes/reflect
[locker.reflect] warning: there were 27 deprecation warnings; re-run with -deprecation for details
[locker.reflect] warning: there were 1 unchecked warnings; re-run with -unchecked for details
[locker.reflect] warning: there were 6 feature warnings; re-run with -feature for details
[locker.reflect] warning: there were 61 inliner warnings; re-run with -Yinline-warnings for details
[locker.reflect] four warnings found
[propertyfile] Creating new property file: /Users/adriaan/git/scala/build/locker/classes/reflect/reflect.properties
[stopwatch] [locker.reflect.timer: 55.369 sec]

locker.comp:
    [mkdir] Created dir: /Users/adriaan/git/scala/build/locker/classes/compiler
[locker.compiler] Compiling 276 files to /Users/adriaan/git/scala/build/locker/classes/compiler
[locker.compiler] /Users/adriaan/git/scala/src/compiler/scala/tools/nsc/backend/jvm/GenASM.scala:133: warning: Visited SCOPE_EXIT before visiting corresponding SCOPE_ENTER. SI-6049
[locker.compiler]         classes -= c.symbol // GC opportunity
[locker.compiler]                 ^

[scabug]

@retronym said:
It will be silenced (but not forgotten, see #6191) after the next STARR.