sprockets icon indicating copy to clipboard operation
sprockets copied to clipboard

Sprockets with babel-transpiler is being slow

Open Zhomart opened this issue 9 years ago • 3 comments

Every time I change my "*.es6" code, next refresh on the browser takes 16-17 seconds.

Sprockets: 4.0.0.beta3 (revision a9c6525) [master] sprockets-rails: 3.2.0 Rails: 4.2.7.1 Ruby: 2.3.1p112

I've traced little bit, but I cannot understand what's going on.

I've put some "prints" in lib/sprockets/loader.rb and changed one "survey_it.es6" and refreshed browser twice.

Hope it helps tracing issue, if it's there.

  # ...

      def load_from_unloaded(unloaded)
        unless file?(unloaded.filename)
          raise FileNotFound, "could not find file: #{unloaded.filename}"
        end

        path_to_split =
          if index_alias = unloaded.params[:index_alias]
            expand_from_root index_alias
          else
            unloaded.filename
          end

        load_path, logical_path = paths_split(config[:paths], path_to_split)

        unless load_path
          target = path_to_split
          target += " (index alias of #{unloaded.filename})" if unloaded.params[:index_alias]
          raise FileOutsidePaths, "#{target} is no longer under a load path: #{self.paths.join(', ')}"
        end

        extname, file_type = match_path_extname(logical_path, mime_exts)
        logical_path = logical_path.chomp(extname)
        name = logical_path

        if pipeline = unloaded.params[:pipeline]
          logical_path += ".#{pipeline}"
        end

        if type = unloaded.params[:type]
          logical_path += config[:mime_types][type][:extensions].first
        end

        if type != file_type && !config[:transformers][file_type][type]
          raise ConversionError, "could not convert #{file_type.inspect} to #{type.inspect}"
        end

        processors = processors_for(type, file_type, pipeline)

        processors_dep_uri = build_processors_uri(type, file_type, pipeline)
        dependencies = config[:dependencies] + [processors_dep_uri]

        gid = rand(36**6).to_s(36)
        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] before Loader/call_processors name: #{name} type: #{type} thread: #{Thread.current.object_id}"

        # Read into memory and process if theres a processor pipeline
        if processors.any?
          source_uri, _ = resolve!(unloaded.filename, pipeline: :source)
          source_asset = load(source_uri)

          source_path = source_asset.digest_path

          result = call_processors(processors, {
            environment: self,
            cache: self.cache,
            uri: unloaded.uri,
            filename: unloaded.filename,
            load_path: load_path,
            source_path: source_path,
            name: name,
            content_type: type,
            metadata: {
              dependencies: dependencies,
              map: []
            }
          })
          validate_processor_result!(result)
          source = result.delete(:data)
          metadata = result
          metadata[:charset] = source.encoding.name.downcase unless metadata.key?(:charset)
          metadata[:digest]  = digest(source)
          metadata[:length]  = source.bytesize
        else
          dependencies << build_file_digest_uri(unloaded.filename)
          metadata = {
            digest: file_digest(unloaded.filename),
            length: self.stat(unloaded.filename).size,
            dependencies: dependencies
          }
        end

        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] after Loader/call_processors name: #{name} type: #{type} thread: #{Thread.current.object_id}"

        asset = {
          uri: unloaded.uri,
          load_path: load_path,
          filename: unloaded.filename,
          name: name,
          logical_path: logical_path,
          content_type: type,
          source: source,
          metadata: metadata,
          dependencies_digest: DigestUtils.digest(resolve_dependencies(metadata[:dependencies]))
        }

        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] after Loader/asset name: #{name} type: #{type} thread: #{Thread.current.object_id}"

        asset[:id]  = hexdigest(asset)
        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] after Loader/hexdigest name: #{name} type: #{type} thread: #{Thread.current.object_id}"
        asset[:uri] = build_asset_uri(unloaded.filename, unloaded.params.merge(id: asset[:id]))
        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] after Loader/build_asset_uri name: #{name} type: #{type} thread: #{Thread.current.object_id}"

        store_asset(asset, unloaded)
        puts " -- #{Time.now.strftime("%H:%M:%S %L")} - [gid=#{gid}] after Loader/store_asset name: #{name} type: #{type} thread: #{Thread.current.object_id}"
        asset
      end

And results are here:

 -- 12:36:25 757 - [gid=jqb09z] before Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 787 - [gid=9oujkm] before Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 808 - [gid=4gv58w] before Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 836 - [gid=4gv58w] after Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 837 - [gid=4gv58w] after Loader/asset name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 838 - [gid=4gv58w] after Loader/hexdigest name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 838 - [gid=4gv58w] after Loader/build_asset_uri name: application type: application/javascript thread: 70142291357580
 -- 12:36:25 848 - [gid=4gv58w] after Loader/store_asset name: application type: application/javascript thread: 70142291357580
 -- 12:36:26 241 - [gid=n9q21t] before Loader/call_processors name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:26 242 - [gid=mfb3gs] before Loader/call_processors name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:26 242 - [gid=mfb3gs] after Loader/call_processors name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:26 242 - [gid=mfb3gs] after Loader/asset name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:26 242 - [gid=mfb3gs] after Loader/hexdigest name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:26 242 - [gid=mfb3gs] after Loader/build_asset_uri name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:26 246 - [gid=mfb3gs] after Loader/store_asset name: application/tasks/survey_it type: application/ecmascript-6 thread: 70142291357580
 -- 12:36:27 901 - [gid=n9q21t] after Loader/call_processors name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:27 901 - [gid=n9q21t] after Loader/asset name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:27 902 - [gid=n9q21t] after Loader/hexdigest name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:27 902 - [gid=n9q21t] after Loader/build_asset_uri name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:27 905 - [gid=n9q21t] after Loader/store_asset name: application/tasks/survey_it type: application/javascript thread: 70142291357580
 -- 12:36:29 038 - [gid=9oujkm] after Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:29 039 - [gid=9oujkm] after Loader/asset name: application type: application/javascript thread: 70142291357580
 -- 12:36:30 439 - [gid=9oujkm] after Loader/hexdigest name: application type: application/javascript thread: 70142291357580
 -- 12:36:30 439 - [gid=9oujkm] after Loader/build_asset_uri name: application type: application/javascript thread: 70142291357580
 -- 12:36:31 674 - [gid=9oujkm] after Loader/store_asset name: application type: application/javascript thread: 70142291357580
 -- 12:36:31 700 - [gid=5rrkyp] before Loader/call_processors name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:38 369 - [gid=5rrkyp] after Loader/call_processors name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:38 370 - [gid=5rrkyp] after Loader/asset name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:38 372 - [gid=5rrkyp] after Loader/hexdigest name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:38 372 - [gid=5rrkyp] after Loader/build_asset_uri name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:38 408 - [gid=5rrkyp] after Loader/store_asset name: application type: application/js-sourcemap+json thread: 70142291357580
 -- 12:36:39 441 - [gid=jqb09z] after Loader/call_processors name: application type: application/javascript thread: 70142291357580
 -- 12:36:39 442 - [gid=jqb09z] after Loader/asset name: application type: application/javascript thread: 70142291357580
 -- 12:36:40 975 - [gid=jqb09z] after Loader/hexdigest name: application type: application/javascript thread: 70142291357580
 -- 12:36:40 976 - [gid=jqb09z] after Loader/build_asset_uri name: application type: application/javascript thread: 70142291357580
 -- 12:36:42 028 - [gid=jqb09z] after Loader/store_asset name: application type: application/javascript thread: 70142291357580

It took 42-25 = 17 seconds.

Edit: added gid Edit: it's slow with *.coffee and *.js files too.

My application.js contains around 10 javascript/coffeescript/es6 files.

Zhomart avatar Oct 13 '16 19:10 Zhomart

Same problem here.

kofronpi avatar Jul 27 '17 12:07 kofronpi

Is it still slow with beta 6?

schneems avatar Nov 17 '17 16:11 schneems

I don't know. I've moved to webpack. We can close the issue if it'x fixed.

Zhomart avatar Nov 17 '17 16:11 Zhomart