ruby-coffee-script icon indicating copy to clipboard operation
ruby-coffee-script copied to clipboard

Gem is abnormally slow at compiling source-maps

Open TylerHorth opened this issue 8 years ago • 7 comments

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

TylerHorth avatar Dec 15 '16 18:12 TylerHorth

@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.

guilleiguaran avatar Dec 16 '16 18:12 guilleiguaran

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.

TylerHorth avatar Dec 19 '16 18:12 TylerHorth

Thanks for tracking it!!

@SamSaffron you might be interested in this.

guilleiguaran avatar Dec 19 '16 19:12 guilleiguaran

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

SamSaffron avatar Dec 19 '16 21:12 SamSaffron

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)>

TylerHorth avatar Dec 19 '16 22:12 TylerHorth

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?

SamSaffron avatar Mar 09 '17 21:03 SamSaffron

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.

matthewd avatar Mar 10 '17 05:03 matthewd