Scala3doc spin loop

reid-spencer · May 23, 2023, 6:33pm

I’ve been blocked for a month by a hang when generating documentation from Scala 3 sources. I’ve tried Scala 3.2.2 and 3.3.0-RC6. Both versions exhibit a 100% CPU spin loop with no output. I have waited > 1 hour so this isn’t some kind of slowdown but a bug. This is invoked from the SBT “doc” command. I know precious little about the internals of scala3doc, so I’m asking for some help with:

has anyone else experienced this hang in scala3doc?
how can I get scala3doc to output some tracing or debug info that would be useful to the implementors?
this only happens in one of my 8 modules (the largest one, a language compiler); are there known issues with particular comment input? (I’m using -comment-syntax:wiki
can anyone suggest an approach to debugging this?

acruise · May 23, 2023, 9:12pm

Hi Reid!

Maybe try grabbing a few thread dumps with kill -QUIT <jvm pid> (or jstack <jvm pid>) and see if they’re it’s always hung up in the same place?

reid-spencer · May 23, 2023, 9:14pm

Sure, I can try that. Thanks!

reid-spencer · May 23, 2023, 9:46pm

@acruise

That was productive. There seems to be one thread, consuming most of the CPU, that is stuck in hashing. I used kill -QUIT four times and got these results:

#1

"pool-13-thread-7" #202 prio=5 os_prio=31 cpu=39685.99ms elapsed=42.63s tid=0x000000014a216800 nid=0xbb0f runnable  [0x00000002b9432000]
   java.lang.Thread.State: RUNNABLE
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:65)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.Some.hashCode(Option.scala:618)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:76)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.runtime.ScalaRunTime$._hashCode(ScalaRunTime.scala:158)
	at dotty.tools.scaladoc.Type.hashCode(api.scala:130)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.listHash(MurmurHash3.scala:285)
	at scala.util.hashing.MurmurHash3$.seqHash(MurmurHash3.scala:355)

(a total of 9 recursions through MurmurHash3.productHash starting from scala.collection.SeqOps.distinct(Seq.scala:206) )

#2

"pool-13-thread-7" #202 prio=5 os_prio=31 cpu=211434.48ms elapsed=215.28s tid=0x000000014a216800 nid=0xbb0f runnable  [0x00000002b9432000]
  java.lang.Thread.State: RUNNABLE
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:65)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.runtime.ScalaRunTime$._hashCode(ScalaRunTime.scala:158)
	at dotty.tools.scaladoc.Keyword.hashCode(api.scala:131)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.listHash(MurmurHash3.scala:285)
	at scala.util.hashing.MurmurHash3$.seqHash(MurmurHash3.scala:355)
	at scala.collection.Seq.hashCode(Seq.scala:41)
	at scala.collection.Seq.hashCode$(Seq.scala:41)
	at scala.collection.AbstractSeq.hashCode(Seq.scala:1188)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:76)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)

( a total of 7 recursions through MurmurHash3.productHash scala.collection.SeqOps.distinct(Seq.scala:206) )

#3

"pool-13-thread-7" #202 prio=5 os_prio=31 cpu=258258.81ms elapsed=262.14s tid=0x000000014a216800 nid=0xbb0f runnable  [0x00000002b9432000]
   java.lang.Thread.State: RUNNABLE
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.runtime.ScalaRunTime$._hashCode(ScalaRunTime.scala:158)
	at dotty.tools.scaladoc.DRI.hashCode(DRI.scala:11)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at dotty.tools.scaladoc.Parameter.hashCode(api.scala:105)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.listHash(MurmurHash3.scala:285)
	at scala.util.hashing.MurmurHash3$.seqHash(MurmurHash3.scala:355)
	at scala.collection.Seq.hashCode(Seq.scala:41)
	at scala.collection.Seq.hashCode$(Seq.scala:41)
	at scala.collection.AbstractSeq.hashCode(Seq.scala:1188)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:76)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)

( a total of 7 recursions through MurmurHash3.productHash scala.collection.SeqOps.distinct(Seq.scala:206) )

#4

"pool-13-thread-7" #202 prio=5 os_prio=31 cpu=303508.19ms elapsed=307.44s tid=0x000000014a216800 nid=0xbb0f runnable  [0x00000002b9432000]
   java.lang.Thread.State: RUNNABLE
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:76)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.runtime.ScalaRunTime$._hashCode(ScalaRunTime.scala:158)
	at dotty.tools.scaladoc.DRI.hashCode(DRI.scala:11)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.productHash(MurmurHash3.scala:76)
	at scala.util.hashing.MurmurHash3$.productHash(MurmurHash3.scala:343)
	at scala.runtime.ScalaRunTime$._hashCode(ScalaRunTime.scala:158)
	at dotty.tools.scaladoc.Name.hashCode(api.scala:129)
	at scala.runtime.Statics.anyHash(Statics.java:127)
	at scala.util.hashing.MurmurHash3.listHash(MurmurHash3.scala:285)
	at scala.util.hashing.MurmurHash3$.seqHash(MurmurHash3.scala:355)

( a total of 5 recursions through MurmurHash3.productHash scala.collection.SeqOps.distinct(Seq.scala:206) )

I left it running while I captured this and took a screenshot of the activity Monitor on MacOS:

It shows > 22 minutes of CPU time, 85 threads, and 100.0% CPU usage (although I’ve seen it near 150%, so other threads are active too).

While I don’t think the MurmurHash3 is at fault, something higher up in the call stack is certainly heavily using it via SeqOps.distinct. Perhaps the full stack trace would be useful to you? I would attach them, but that option doesn’t seem available here.

Thanks,
Reid

smarter · May 23, 2023, 10:42pm

Instead of kill use jstack to get stack traces for all threads.
Also as a workaround you can turn off scaladoc generation in your project:

Compile / doc / sources := Seq()

WojciechMazur · May 24, 2023, 6:03am

Have you thought about reporting that to the compiler team? There is a dedicated issue tracker in Issues · lampepfl/dotty · GitHub. If reported month ago I believe it could have been already fixed and shipped in 3.3.0. In the standard release cycle 3.3.1 could be expected in around 6 weeks

reid-spencer · May 24, 2023, 5:10pm

Yes, I thought about it, but I have very little to report besides the user-level symptom: hang. I also don’t have the time availability to find a minimal test case over many thousands of lines of comments, which is likely to be their first request.

reid-spencer · May 24, 2023, 5:33pm

I took your advice and filed it as scaladoc hangs · Issue #17577 · lampepfl/dotty · GitHub