Trying to speed up compilation; seeing lots of "Captured This(..." in typer phase

[Ionuț G. Stan]

Hi all,

My current project takes a lot of time to compile and I tried to find
out which step of the whole compilation process takes the most.

After running scalac with -Ydebug and -Ylog:typer, I'm seeing a lot of
log entries that look like this:

[log typer] Captured This(slick.jdbc.JdbcBackend) seen from
jdbc.this.JdbcBackend: type _1.type <: jdbc.this.JdbcBackend with
scala.this.Singleton{}
[log typer] Widened lone occurrence of _1.type inside existential to
upper bound: jdbc.this.JdbcBackend

The only difference between them being the generated number name, i.e.,
the `_1.type` part.

The Slick part is not incidental, most occurrences appear for that path
— slick.jdbc.JdbcBackend — and just a few for a single other path.

Another peculiar fact is that most of the compilation process is spent
somewhere where only 1 CPU core is used. The rest of the time, more
cores are used, mostly 3 or 4.

Can anyone that's familiar with the compiler give me a hint as to when
this might happen? What kind of code patterns can lead to this?

I understand this is a pretty vague question, so if anyone is willing to
help I can provide some further details on demand, because right now I'm
not sure what else I should be looking for.

Thanks!

--
Ionuț G. Stan | http://igstan.ro | http://bucharestfp.ro

[Adriaan Moors]

Not sure this is what's slowing down compilation but type inference is definitely not for free :-). One way to hone it could be using -uniqid -Xprint:typer. That way each symbol gets a unique number that you can grep for in the AST printed after type checking.

The difference between usage in cores comes entirely from JIT compilation and GC. The compiler is single threaded.

--
You received this message because you are subscribed to the Google Groups "scala-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to scala-user+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Ionuț G. Stan]

Thanks Adriaan, I'll give it a try. I'll come back with feedback if I
find something new.

> <mailto:scala-user%2Bunsu...@googlegroups.com>.

> For more options, visit https://groups.google.com/d/optout.
>

[Ionuț G. Stan]

I think I've found a small bug when combining -Ylog:typer with
-Ytyper-debug. Code that would otherwise compile, fails with this flag
combination. Here's a minimal reproducible test case:

https://gist.github.com/igstan/6ee14408e3df19490dabc2a826d7a4c7

[Lukas Rytz]

On Thursday, June 30, 2016 at 8:03:09 PM UTC+2, Ionuț G. Stan wrote:

Hi all,

My current project takes a lot of time to compile and I tried to find
out which step of the whole compilation process takes the most.

After running scalac with -Ydebug and -Ylog:typer, I'm seeing a lot of
log entries that look like this:

[log typer] Captured This(slick.jdbc.JdbcBackend) seen from
jdbc.this.JdbcBackend: type _1.type <: jdbc.this.JdbcBackend with
scala.this.Singleton{}
[log typer] Widened lone occurrence of _1.type inside existential to
upper bound: jdbc.this.JdbcBackend

The only difference between them being the generated number name, i.e.,
the `_1.type` part.

The Slick part is not incidental, most occurrences appear for that path
— slick.jdbc.JdbcBackend — and just a few for a single other path.

Another peculiar fact is that most of the compilation process is spent
somewhere where only 1 CPU core is used. The rest of the time, more
cores are used, mostly 3 or 4.

Higher CPU utilization unfortunately does not mean that scalac is performing

work in parallel, the implementation is single-threaded. Everything that goes

beyond 1 CPU is jit-compiling and garbage collection.

[Lukas Rytz]

This is a very annoying but known issue. In the compiler implementation,

symbols of definitions without an explicit return type (val x = 1) get a "lazy"

type. When someone needs the type of x's symbol, the righthand-side (1)

is type-checked on demand. Cycles are detected by throwing an exception

when type-checking the rhs of some definition needs its own type

(val x = y; val y = x).

the log / debug options / implementation trigger additional completion (otherwise

you'd see a lot of missing / non-completed lazy types), but they are not careful

enough and trigger cycles.

i'm not saying this shouldn't be fixed :) but priorities..

[Ionuț G. Stan]

On 05/07/2016 08:06, Lukas Rytz wrote:
>
>
> On Thursday, June 30, 2016 at 8:03:09 PM UTC+2, Ionuț G. Stan wrote:
>
> Hi all,
>
> My current project takes a lot of time to compile and I tried to find
> out which step of the whole compilation process takes the most.
>
> After running scalac with -Ydebug and -Ylog:typer, I'm seeing a lot of
> log entries that look like this:
>
> [log typer] Captured This(slick.jdbc.JdbcBackend) seen from
> jdbc.this.JdbcBackend: type _1.type <: jdbc.this.JdbcBackend with
> scala.this.Singleton{}
> [log typer] Widened lone occurrence of _1.type inside existential to
> upper bound: jdbc.this.JdbcBackend
>
> The only difference between them being the generated number name, i.e.,
> the `_1.type` part.
>
> The Slick part is not incidental, most occurrences appear for that path
> — slick.jdbc.JdbcBackend — and just a few for a single other path.
>
> Another peculiar fact is that most of the compilation process is spent
> somewhere where only 1 CPU core is used. The rest of the time, more
> cores are used, mostly 3 or 4.
>
>
> Higher CPU utilization unfortunately does not mean that scalac is performing
> work in parallel, the implementation is single-threaded. Everything that
> goes
> beyond 1 CPU is jit-compiling and garbage collection.

Oh... I just thought it was an area that didn't get to be parallelized
yet. Too bad. Thanks for pointing it out though.

>
>
> Can anyone that's familiar with the compiler give me a hint as to when
> this might happen? What kind of code patterns can lead to this?
>
> I understand this is a pretty vague question, so if anyone is
> willing to
> help I can provide some further details on demand, because right now
> I'm
> not sure what else I should be looking for.
>
> Thanks!
>
> --
> Ionuț G. Stan | http://igstan.ro | http://bucharestfp.ro
>

> --
> You received this message because you are subscribed to the Google
> Groups "scala-user" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to scala-user+...@googlegroups.com

> <mailto:scala-user+...@googlegroups.com>.

> For more options, visit https://groups.google.com/d/optout.

[Ionuț G. Stan]

On 05/07/2016 08:18, Jason Zaugg wrote:

> On Mon, 4 Jul 2016 at 17:17 Ionuț G. Stan <ionut....@gmail.com
> <mailto:ionut....@gmail.com>> wrote:
>
> I think I've found a small bug when combining -Ylog:typer with
> -Ytyper-debug. Code that would otherwise compile, fails with this flag
> combination. Here's a minimal reproducible test case:
>
> https://gist.github.com/igstan/6ee14408e3df19490dabc2a826d7a4c7
>
>

> Good catch. I think this patch is needed to fix that:
>
> |diff --git a/src/reflect/scala/reflect/internal/TypeDebugging.scala
> b/src/reflect/scala/reflect/internal/TypeDebugging.scala index
> 63f897c..e9050b4 100644 ---
> a/src/reflect/scala/reflect/internal/TypeDebugging.scala +++
> b/src/reflect/scala/reflect/internal/TypeDebugging.scala @@ -110,7
> +110,7 @@ trait TypeDebugging { val hi_s = if (noPrint(hi)) "" else " <:
> " + ptTree(hi) lo_s + hi_s case _ if (t.symbol eq null) || (t.symbol eq
> NoSymbol) => to_s(t) - case _ => "" + t.symbol.tpe + case _ => "" +
> t.symbol.rawInfo.safeToString } def ptTypeParam(td: TypeDef): String = {
> val TypeDef(_, name, tparams, rhs) = td |

Thanks Jason. I'll give it a try with a locally compiled scalac, which
is something that I haven't learned how to do yet.