Gem is abnormally slow at compiling source-maps

[TylerHorth]

Compiler	Compile time	Compile time w/ Source maps
CoffeeScript CLI	18s	18s
coffee-script-source gem (Node)	18s	18s
Coffee-Script gem (irb)	18s	220s

I tested with a single CoffeeScript file of ~20,000 lines to try to rule out environment spin up times. The generated source map for this file is ~20% smaller than the generated Javascript. This seems to be a problem to do with the ExecJS interface, but I don't know where to start seeing as it is only affecting compile time with source maps enabled.

cc @rafaelfranca

[guilleiguaran]

@TylerHorth maybe you can find if this a problem with this gem or with ExecJS (or an specific ExecJS runtime)

have you tried to run CoffeeScript compiler directly using ExecJS? On the ExecJS README we have an example about how this can be done.

[TylerHorth]

Alrighty, I've run some tests and it seems to be a problem with the MiniRacer runtime. ExecJS was defaulting to this runtime in my project. Changing to the Node runtime completely resolves the issue. It's probably safe to close this issue unless you think this Gem should be opinionated as to the runtime that's used.

[guilleiguaran]

Thanks for tracking it!!

@SamSaffron you might be interested in this.

[SamSaffron]

this worries me @TylerHorth do you have a repro somewhere so I can get to the bottom of it?

[TylerHorth]

I don't have a repo, but it's fairly straight forward to reproduce.

I started off by creating a moderately sized CoffeeScript file test.coffee: (1600 lines of console.log("test") if true)

! vim test.coffee # create CoffeeScript file
! pry
[1] pry(main)> require 'coffee-script'
=> true
[2] pry(main)> require 'benchmark'
=> true
[3] pry(main)> ExecJS.runtime.name
=> "Node.js (V8)"
[4] pry(main)> Benchmark.measure do
[4] pry(main)*   10.times do
[4] pry(main)*     CoffeeScript.compile(File.read('test.coffee'))
[4] pry(main)*   end
[4] pry(main)* end
=> #<Benchmark::Tms:0x007fc05f80f850
 @cstime=0.44,
 @cutime=4.92,
 @label="",
 @real=5.116927,
 @stime=0.020000000000000004,
 @total=5.45,
 @utime=0.06999999999999998>
[5] pry(main)> Benchmark.measure do
[5] pry(main)*   10.times do
[5] pry(main)*     CoffeeScript.compile(File.read('test.coffee'), { sourceMap: true })
[5] pry(main)*   end
[5] pry(main)* end
=> #<Benchmark::Tms:0x007fc06057cfb0
 @cstime=0.46,
 @cutime=5.210000000000001,
 @label="",
 @real=5.80459,
 @stime=0.08000000000000002,
 @total=6.280000000000001,
 @utime=0.53>
[6] pry(main)> ^D
! export EXECJS_RUNTIME=MiniRacer
! pry
[1] pry(main)> require 'coffee-script'
=> true
[2] pry(main)> ExecJS.runtime.name
=> "mini_racer (V8)"
[3] pry(main)> require 'benchmark'
=> true
[4] pry(main)> Benchmark.measure do
[4] pry(main)*   10.times do
[4] pry(main)*     CoffeeScript.compile(File.read('test.coffee'))
[4] pry(main)*   end
[4] pry(main)* end
=> #<Benchmark::Tms:0x007f809081f430
 @cstime=0.0,
 @cutime=0.0,
 @label="",
 @real=3.152735,
 @stime=0.08,
 @total=3.2,
 @utime=3.12>
[5] pry(main)> Benchmark.measure do
[5] pry(main)*   10.times do
[5] pry(main)*     CoffeeScript.compile(File.read('test.coffee'), { sourceMap: true })
[5] pry(main)*   end
[5] pry(main)* end
=> #<Benchmark::Tms:0x007f80958db1a8
 @cstime=0.0,
 @cutime=0.0,
 @label="",
 @real=61.381945,
 @stime=9.75,
 @total=65.95,
 @utime=56.2>
[6] pry(main)>

[SamSaffron]

Tyler,

I know it has taken me a while to work through this, but I spent all day today sorting this out.

What was happeneing was the mini_racer used to walk v8 object graphs recursively on the boundary between v8 and ruby, something that involved creating lots of contexts and waste. In your case the source maps piece actually generates an object in ruby with 10 of thousands of nodes, this was very expensive to walk.

I redid this per

https://github.com/discourse/mini_racer/commit/42ffdd15b3477ecd2d88c7e7905fc9c8f4476ddd

With this in place MiniRacer is outperforming node (which is expected) cause our boundary is far more efficient (no need to write files and so on)

Thanks so much for the test case here, can you try MiniRacer again?

[matthewd]

https://github.com/rails/ruby-coffee-script/pull/15 should mean a sufficiently recent (read: from git) pair of sprockets + coffee-script doesn't bother sending the complex data across the boundary at all.