url helpers aren't thread safe

[ahorek]

.sass

background-image: asset-url("flags.png");

Expected behavior

works like if I disable concurrent compilation

Actual behavior

if concurrent complation is enabled #469 it fails to compile assets sometimes

System configuration

lastest sprockets 4 e25e0f5
ruby 2.5.0p0 (2017-12-25 revision 61468) [x86_64-linux]

[michaelglass]

I had a little trouble figuring out how to disable concurrency, so dropping this here for posterity.

When using sprockets-rails:

Rails.application.config.assets.configure do |env|
  env.export_concurrent = false
end

Maybe export_concurrent should default to false while there are a bunch of concurrency issues

Disabling concurrency fixed these bugs for me as well:

sass/sassc-ruby#116
sass/sassc-rails#121

[ahorek]

still valid on 4.0.0.beta9

I found a method that is definitely not thread-safe, see

sprockets/lib/sprockets/utils.rb

Line 126 in 0cb3314

def module_include(base, mod)

and there's a second issue, options are corrupted for some reason

sprockets/lib/sprockets/sass_processor.rb

Line 299 in 7743c1e

options[:sprockets][:context]

here's the backtrace

[SassC::FunctionsHandler] undefined method `[]' for nil:NilClass
/gems/sprockets/lib/sprockets/sass_processor.rb:302:in `sprockets_context'
/gems/sassc-rails-2.1.1/lib/sassc/rails/template.rb:91:in `asset_path'
/gems/sassc-rails-2.1.1/lib/sassc/rails/template.rb:99:in `asset_url'
/gems/sprockets/lib/sprockets/sass_processor.rb:176:in `image_url'
/gems/sassc-2.0.1/lib/sassc/functions_handler.rb:22:in `block (2 levels) in setup'
/gems/sassc-2.0.1/lib/sassc/engine.rb:42:in `compile_data_context'
/gems/sassc-2.0.1/lib/sassc/engine.rb:42:in `render'
/gems/sassc-rails-2.1.1/lib/sassc/rails/template.rb:41:in `block in call'
/gems/sprockets/lib/sprockets/utils.rb:142:in `block in module_include'
/gems/sprockets/lib/sprockets/utils.rb:129:in `synchronize'
/gems/sprockets/lib/sprockets/utils.rb:129:in `module_include'
/gems/sassc-rails-2.1.1/lib/sassc/rails/template.rb:40:in `call'
/gems/sprockets/lib/sprockets/processor_utils.rb:84:in `call_processor'
/gems/sprockets/lib/sprockets/processor_utils.rb:66:in `block in call_processors'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `reverse_each'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `call_processors'
/gems/sprockets/lib/sprockets/processor_utils.rb:22:in `block in '
/gems/sprockets/lib/sprockets/processor_utils.rb:33:in `call'
/gems/sprockets/lib/sprockets/processor_utils.rb:84:in `call_processor'
/gems/sprockets/lib/sprockets/processor_utils.rb:66:in `block in call_processors'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `reverse_each'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `call_processors'
/gems/sprockets/lib/sprockets/loader.rb:181:in `load_from_unloaded'
/gems/sprockets/lib/sprockets/loader.rb:59:in `block in load'
/gems/sprockets/lib/sprockets/loader.rb:334:in `fetch_asset_from_dependency_cache'
/gems/sprockets/lib/sprockets/loader.rb:43:in `load'
/gems/sprockets/lib/sprockets/cached_environment.rb:44:in `load'
/gems/sprockets/lib/sprockets/bundle.rb:41:in `block in call'
/gems/sprockets/lib/sprockets/utils.rb:173:in `dfs'
/gems/sprockets/lib/sprockets/bundle.rb:42:in `call'
/gems/sprockets/lib/sprockets/processor_utils.rb:84:in `call_processor'
/gems/sprockets/lib/sprockets/processor_utils.rb:66:in `block in call_processors'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `reverse_each'
/gems/sprockets/lib/sprockets/processor_utils.rb:65:in `call_processors'
/gems/sprockets/lib/sprockets/loader.rb:181:in `load_from_unloaded'
/gems/sprockets/lib/sprockets/loader.rb:59:in `block in load'
/gems/sprockets/lib/sprockets/loader.rb:334:in `fetch_asset_from_dependency_cache'
/gems/sprockets/lib/sprockets/loader.rb:43:in `load'
/gems/sprockets/lib/sprockets/cached_environment.rb:44:in `load'
/gems/sprockets/lib/sprockets/base.rb:81:in `find_asset'
/gems/sprockets/lib/sprockets/base.rb:88:in `find_all_linked_assets'
/gems/sprockets/lib/sprockets/manifest.rb:125:in `block (2 levels) in find'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
/gems/concurrent-ruby-1.1.5/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `block in synchronize'
/gems/concurrent-ruby-1.1.5/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/gems/concurrent-ruby-1.1.5/lib/concurrent/synchronization/mutex_lockable_object.rb:41:in `synchronize'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/safe_task_executor.rb:19:in `execute'
/gems/concurrent-ruby-1.1.5/lib/concurrent/promise.rb:563:in `block in realize'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/gems/concurrent-ruby-1.1.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'

@schneems any idea how to fix? disabling concurrency works, but it doesn't really fix the problem.

[maxwell]

I had a little trouble figuring out how to disable concurrency, so dropping this here for posterity.

When using sprockets-rails:

Rails.application.config.assets.configure do |env|
  env.export_concurrent = false
end

Maybe export_concurrent should default to false while there are a bunch of concurrency issues

Disabling concurrency fixed these bugs for me as well:

sass/sassc-ruby#116
sass/sassc-rails#121

Where do we need to put this exactly? I keep getting "export_concurrent" MethodNotFound error when I put it in an initializer or production.rb

thanks!

[ahorek]

@maxwell what is your version of sprockets? export_concurrent option is 4.x only

I investigated a little and the actual problem is if multiple assets have the same dependency.

sprockets/lib/sprockets/loader.rb

Line 182 in 4d6805e

result = call_processors(processors, {

asset1 -> asset2
asset3 -> asset2

unfortunatelly I wasn't able to find a solution how to avoid this problem or at least warn that something is wrong. The current behaviour is very unpredictable and error prone.

[schneems]

@ahorek do you have an example app that fails consistently? If I can get a repo then maybe we can do something clever to make sure every asset's exporters only get run once.

[ahorek]

hi @schneems I can't reproduce the second problem now (it's quite random), but I wrote a test case for the original problem #620

it fails on travis:

SassC::SyntaxError: Error: error in C function video-url: undefined method `[]' for nil:NilClass
        on line 4 of test/fixtures/sass/urls.scss, in function `video-url`
        from line 4 of test/fixtures/sass/urls.scss
>>    url: video-url("foo.mov");
   --------^
    /home/travis/build/rails/sprockets/test/fixtures/sass/urls.scss:4

[ahorek]

the error with url helpers should be fixed by
sass/sassc-ruby#138
however this is definitelly a piece of code that deservers a better api. All path helpers are redefined over and over again on each call...

the second problem is actually a silent segfault caused by this
sass/sassc-ruby#133
it happens much more often with concurrent compilation.

and a minor issue on Windows
#623

cc @schneems

[schneems]

I think for now we should default that concurrent exporter value to false and add some docs that show how to turn it on. Can someone send me a PR?

[ahorek]

sprockets 4 is significantely slower than the old version :-(

sprockets 4.0.0.beta10 + concurrent (8C) 88.703000  61.593000 150.296000 (106.922231)
sprockets 4.0.0.beta10                   69.093000  40.078000 109.171000 (317.931694)
sprockets 3.7.2                          39.234000  34.031000  73.265000 (222.999873)

[schneems]

Odd that the "real" time in beta10 is half that of sprockets 3.7.2 even though the "user" time is much higher.

[ahorek]

here's a ruby-prof report
https://github.com/ahorek/sprockets/blob/benchmark/benchmark/sprockets3.txt
https://github.com/ahorek/sprockets/blob/benchmark/benchmark/sprockets4.txt

[jrochkind]

Odd that the "real" time in beta10 is half that of sprockets 3.7.2 even though the "user" time is much higher.

You're talking about real time in "beta10 + concurrent" right? Which I think it explains it, if it can use more cores, it can do more CPU time in less real/wall time. The "beta10" without concurrent is quite a bit slower in real/wall time too.

However, this very ticket suggests the concurrent mode may not be safe.

[ahorek]

FYI #630 fixes the problem with concurrency to me, but it also requires a new release of sassc gem

You're talking about real time in "beta10 + concurrent" right? Which I think it explains it, if it can use more cores, it can do more CPU time in less real/wall time.

you're right

I think the reason why is sprockets 4 slower is because of the source-maps feature. I tried to optimize the hottest loop a little #628 #629 but it still has a significant overhead.