OutOfMemoryError in dotty.tools.dotc.core.Types

[marcus-nl]

While trying out M3, aka the Developer's Preview (using SBT 1.4.4 and sbt-dotty 0.5.1), on our Scala 2.13 codebase, dotty crashes with an OutOfMemory error.

First I get these warnings (increasing available memory or using G1GC doesn't help):

[warn] In the last 10 seconds, 5.051 (51.4%) were spent in GC. [Heap: 0.04GB free of 1.00GB, max 1.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 9 seconds, 8.492 (98.9%) were spent in GC. [Heap: 0.01GB free of 1.00GB, max 1.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
...etc...

And then eventually:

Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "classloader-cache-cleanup-0"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-9-thread-7"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-9-thread-3"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-9-thread-5"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "sbt-progress-report-scheduler"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-9-thread-8"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "pool-9-thread-9"
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "sbt-task-progress-report-thread"

I've pasted an extract of the stacktrace below, creating using control-\ while it was still running.

Minimized code

n/a since I don't know where it went wrong. Is there any way I can pinpoint this?

Output (click arrow to expand)

	at dotty.tools.dotc.core.Types$LazyRef$.apply$$anonfun$1(Types.scala:2735)
	at dotty.tools.dotc.core.Types$LazyRef$$$Lambda$5806/0x0000000841e70840.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef.ref(Types.scala:2748)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver$$anonfun$1(Types.scala:5166)
	at dotty.tools.dotc.core.Types$TypeMap$$Lambda$5812/0x0000000841e75040.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef$.apply$$anonfun$1(Types.scala:2735)
        // ...hundreds more of these lines...
	at dotty.tools.dotc.core.Types$LazyRef$$$Lambda$5806/0x0000000841e70840.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef.ref(Types.scala:2748)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver$$anonfun$1(Types.scala:5166)
	at dotty.tools.dotc.core.Types$TypeMap$$Lambda$5812/0x0000000841e75040.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef$.apply$$anonfun$1(Types.scala:2735)
	at dotty.tools.dotc.core.Types$LazyRef$$$Lambda$5806/0x0000000841e70840.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef.ref(Types.scala:2748)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver$$anonfun$1(Types.scala:5166)

[OlivierBlanvillain]

This bug report is not actionable without a reproduction. Furthermore, it would really help if you could minimize it to a single file!

Is there any way I can pinpoint this?

Depending on the size of your code base you can shrink your project iteratively by first replace the body of all your methods with ??? one by one, then deleting all your methods one by one. If your code base compiles with some version of dotty version and crashes with M3 it would also be possible to do a git bisect between those two compiler version.

[marcus-nl]

If your code base compiles with some version of dotty version and crashes with M3 it would also be possible to do a git bisect between those two compiler version.

I did try it with M2 about a week ago, with the same outcome.

Depending on the size of your code base you can shrink your project iteratively by first replace the body of all your methods with ??? one by one, then deleting all your methods one by one.

Hmm, I'm afraid the code base is quite a bit too large for that.

Is there a way to log what compilation unit the compiler is currently working on? Based on the stack trace it seems like dotty is stuck in an infinite loop trying to resolve a type reference, so it would help to know what type it's stuck on, or at least in which module the reference is located.

[odersky]

What was the largest memory you tried it with? What were the warning messages then?

[marcus-nl]

What was the largest memory you tried it with? What were the warning messages then?

@odersky
I just tried it with 12G (export SBT_OPTS="-Xmx12G -XX:+UseG1GC", don't think my system can handle more than that :)) with basically the same outcome (just larger numbers and it took a lot longer):

GC Warnings

[warn] In the last 108 seconds, 27.802 (25.8%) were spent in GC. [Heap: 0.83GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 31 seconds, 28.615 (93.5%) were spent in GC. [Heap: 0.40GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 28.905 (96.7%) were spent in GC. [Heap: 0.18GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.247 (98.1%) were spent in GC. [Heap: 0.09GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.266 (99.3%) were spent in GC. [Heap: 0.04GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.546 (99.7%) were spent in GC. [Heap: 0.02GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 25 seconds, 24.71 (99.8%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.472 (99.9%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.261 (99.9%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.629 (100.0%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 28 seconds, 27.239 (100.0%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 19 seconds, 18.574 (99.7%) were spent in GC. [Heap: 0.01GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.
[warn] In the last 30 seconds, 29.494 (100.0%) were spent in GC. [Heap: 0.00GB free of 12.00GB, max 12.00GB] Consider increasing the JVM heap using `-Xmx` or try a different collector, e.g. `-XX:+UseG1GC`, for better performance.

Memory usage summary

Heap
 garbage-first heap   total 12582912K, used 12573565K [0x0000000500000000, 0x0000000800000000)
  region size 2048K, 1 young (2048K), 0 survivors (0K)
 Metaspace       used 146135K, capacity 167733K, committed 168504K, reserved 1179648K
  class space    used 23730K, capacity 38285K, committed 38656K, reserved 1048576K

Stacktrace (relevant thread only)

"pool-9-thread-3" #109 prio=5 os_prio=0 cpu=70024,33ms elapsed=397,65s tid=0x00007f57e0e47800 nid=0xd47 runnable  [0x00007f56bac25000]
   java.lang.Thread.State: RUNNABLE
	at dotty.tools.dotc.core.Substituters$.subst(Substituters.scala:23)
	at dotty.tools.dotc.core.Substituters$.mapArgs$1(Substituters.scala:20)
	at dotty.tools.dotc.core.Substituters$.mapArgs$1(Substituters.scala:20)
	at dotty.tools.dotc.core.Substituters$.mapArgs$1(Substituters.scala:20)
	at dotty.tools.dotc.core.Substituters$.subst(Substituters.scala:20)
	at dotty.tools.dotc.core.Substituters$SubstBindingMap.apply(Substituters.scala:165)
	at dotty.tools.dotc.core.Types$TypeMap.mapOverLambda(Types.scala:5098)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver(Types.scala:5123)
	at dotty.tools.dotc.core.Substituters$.subst(Substituters.scala:23)
	at dotty.tools.dotc.core.Substituters$SubstBindingMap.apply(Substituters.scala:165)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver$$anonfun$1(Types.scala:5167)
	at dotty.tools.dotc.core.Types$TypeMap$$Lambda$5964/0x0000000841e99840.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef$.apply$$anonfun$1(Types.scala:2735)
	at dotty.tools.dotc.core.Types$LazyRef$$$Lambda$5958/0x0000000841e9e040.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef.ref(Types.scala:2748)
	at dotty.tools.dotc.core.Types$TypeMap.mapOver$$anonfun$1(Types.scala:5166)
	(skipping ~1000 lines, even more than before)
	at dotty.tools.dotc.core.Types$TypeMap$$Lambda$5964/0x0000000841e99840.apply(Unknown Source)
	at dotty.tools.dotc.core.Types$LazyRef$.apply$$anonfun$1(Types.scala:2735)
	at dotty.tools.dotc.core.Types$LazyRef$$$Lambda$5958/0x0000000841e9e040.apply(Unknown Source)

[odersky]

Is there a way to log what compilation unit the compiler is currently working on? Based on the stack trace it seems like dotty is stuck in an infinite loop trying to resolve a type reference, so it would help to know what type it's stuck on, or at least in which module the reference is located.

You can get detailed info if you re-build the compiler.

In file compiler/src/dotty/tools/dotc/config/Config.scala change the line

  inline val tracingEnabled = false

to

  inline val tracingEnabled = true

Then, in file compiler/src/dotty/tools/dotc/config/Printers.scala change the line

val typr = noPrinter

to

val typr = new Printer

Then compile your application again with the setting -Ylog:typer. That will give a you very detailed trace of all the steps the compiler is taking.

[marcus-nl]

Thanks @odersky.

This reproduces the problem:

object CollectionEnhancements {
  import scala.collection.IterableOps
  implicit class RichCollection[CC[A] <: IterableOps[A, CC, CC[A]], A](val collection: CC[A]) {
    def awm(update: CC[A] => CC[A]): CC[A] = {
      val newCollection = update(collection)
      if (newCollection == collection) collection else newCollection.awm(update)
    }
    /* // or:
    def awm(update: CC[A] => CC[A]): CC[A] = update(collection) match {
      case `collection` => collection
      case updated      => updated.awm(update)
    }
    */
  }
}

Should I create a pull requests with this case added to tests/pos/i10900, or is this sufficient?

[OlivierBlanvillain]

@marcus-nl This is sufficient, thanks!

[liufengyun]

This is further minimized to the following:

import scala.collection.IterableOps
def foo[CC[A] <: IterableOps[A, CC, CC[A]], A](collection: CC[A]) =
  collection == collection

Now the compiler reports a very big type error (the same for the minimized snippet above).

[liufengyun]

The code fails in checkCanEqual, where we have ltp = CC[A], rtp = CC[A]. There is error somewhere in dealing with F-bounds.