In the learning process, the best eye-opener is failure. Yep, this will be a quick story about my recent failure.

The problem

My problem was/is relatively easy - compilation of my project in Scala takes ages. Ok, to be precise "only" 2 minutes, but this is still unacceptable. I have a feeling that, probably, the root cause of this problem is the implicit and macro hell that we have accidentally created:)

Before I turn the whole codebase upside down, I wanted to start with some methodology. I tried to get an answer to a simple question: which sources, packages are the slowest to compile? After some research, I realised that this is not so easy to figure out. There are no tools for such "profiling" - perfect, so let's create an open source for that.

The idea

Compilation in Scala is based on many phases (25 in scala 2.11) that transform source tree to another tree. You can write your own Scala compiler plugin, which could be launched after configured phase. The idea was quite obvious:

after each phase, get the timestamp and source name.

after the last phase, calculate the difference and you will get the time required for compiling a specific source.

Yes, probably, more experienced Scala developers already see a trap here. Unfortunately, I was too eager to do something new, so I jumped directly to the editor.

Scala compiler plugin

It is very easy to start, the only thing you need is a little boilerplate code.

Descriptor:

<plugin> <name>scala-compiler-plugin-template</name> <classname>com.softwaremill.ScalaCompilerPlugin</classname> </plugin>

And a few lines of code:

class ScalaCompilerPlugin(override val global: Global) extends Plugin { override val name: String = "scala-compiler-plugin" override val description: String = "scala compiler plugin simple example" override val components: List[PluginComponent] = List(new ScalaCompilerPluginComponent(global)) } class ScalaCompilerPluginComponent(val global: Global) extends PluginComponent { override val phaseName: String = "compiler-plugin-phase" override val runsAfter: List[String] = List("parser") override def newPhase(prev: Phase): Phase = new StdPhase(prev) { override def apply(unit: global.CompilationUnit): Unit = { global.reporter.echo("implement me ") } } }

That's it - after publishing it as a jar, you can use it in another project, by adding the following lines to build.sbt:

autoCompilerPlugins := true addCompilerPlugin("com.softwaremill" %% "scala-compiler-plugin-template" % "0.0.1-SNAPSHOT")

Or you can just download the template from here.

The failure

It turns out that each phase is launched for all sources. After finishing, the compiler moves to the next phase, etc. Because of that, it is impossible to analyse compilation time per single source (using compiler plugin). The only thing that you can measure this way is the total phase time. It is already possible to get those values. You just need to launch compilation with -verbose flag. After some grepping:

sbt clean compile | grep "in.*ms]" | grep -v "loaded"

you will get a nice report:

[info] [parser in 691ms] [info] [linter-parsed in 141ms] [info] [namer in 107ms] [info] [packageobjects in 7ms] [info] [typer in 51565ms] [info] [linter-typed in 13614ms] [info] [linter-typed-interpreter in 6940ms] [info] [wartremover-traverser in 1ms] [info] [patmat in 2662ms] [info] [superaccessors in 909ms] [info] [extmethods in 48ms] [info] [pickler in 259ms] [info] [Extracts the public API from source files. in 2707ms] [info] [Extracts dependency information in 894ms] [info] [refchecks in 1552ms] [info] [linter-refchecked in 779ms] [info] [uncurry in 4187ms] [info] [tailcalls in 334ms] [info] [specialize in 2238ms] [info] [explicitouter in 1112ms] [info] [erasure in 5926ms] [info] [posterasure in 574ms] [info] [lazyvals in 267ms] [info] [lambdalift in 1103ms] [info] [constructors in 990ms] [info] [flatten in 468ms] [info] [mixin in 2082ms] [info] [cleanup in 223ms] [info] [delambdafy in 0ms] [info] [Generate ICode from the AST in 2237ms] [info] [jvm in 8363ms] [info] [Finds concrete instances of provided superclasses, and application entry points. in 109ms] [info] [total in 113105ms]

Takeaways