Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Gem is abnormally slow at compiling source-maps #12

Open
TylerHorth opened this issue Dec 15, 2016 · 7 comments
Open

Gem is abnormally slow at compiling source-maps #12

TylerHorth opened this issue Dec 15, 2016 · 7 comments

Comments

@TylerHorth
Copy link

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
Copy link
Member

@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
Copy link
Author

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
Copy link
Member

Thanks for tracking it!!

@SamSaffron you might be interested in this.

@SamSaffron
Copy link

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

@TylerHorth
Copy link
Author

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
Copy link

SamSaffron commented Mar 9, 2017

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

rubyjs/mini_racer@42ffdd1

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
Copy link
Member

matthewd commented Mar 10, 2017

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants