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

When not using dev server, compile is called for every single asset tag and dev and test page rendering is very slow #2814

Closed
davetron5000 opened this issue Dec 18, 2020 · 7 comments

Comments

@davetron5000
Copy link
Contributor

problem

When not using webpack-dev-server, it seems that Webpacker calls compile for every single asset tag in dev and test, making dev and test very slow.

Based on commit history, this seems intentional or at least this behavior has existed for a while. Is there a way to disable it in test at least?

background

We have a run-of-the-mill ERB-based app. We are on Webpacker 5.2.1, Rails 6.0.2.

Our header prefetches several fonts and our pages load many images. Webpacker and Webpack 100% work to compile things and make the site work as intended. Production is not affected.

The problem is when a page is loaded in dev or test, each time a webpacker-provided helper is called, compile is called:

Like so:

First, lookup! is called on the manifest:

def asset_pack_path(name, **options)
if current_webpacker_instance.config.extract_css? || !stylesheet?(name)
path_to_asset(current_webpacker_instance.manifest.lookup!(name), options)
end
end

lookup! calls lookup, which calls compile if compiling?

def lookup(name, pack_type = {})
compile if compiling?
find(full_pack_name(name, pack_type[:type]))
end
# Like lookup, except that if no asset is found, raises a Webpacker::Manifest::MissingEntryError.
def lookup!(name, pack_type = {})
lookup(name, pack_type) || handle_missing_entry(name, pack_type)
end

compiling? is true if we are set to compile (true dev and test) and the dev server is not running:

def compiling?
config.compile? && !dev_server.running?
end

The result is that our image-heavy pages show [Webpacker] Everything's up-to-date. Nothing to do many times and a page that renders in < 1s in production takes 10s locally.

What I need help with

  • Although not using the dev server may be unusual, this issue must happen for everyone running system tests. In our app, there is one test of our home page that takes 56seconds. If I set compile: false in webpacker.yml it takes 1.5 seconds.
  • Is Webpacker aware of the request/response cycle or is it only aware of a particular asset helper being called? This is question for someone who knows the code to point me in the right direction.

I think a solution might be to only call compile once per request, so if someone knows the codebase well, I can provide a patch.

See Also

@rossta
Copy link
Member

rossta commented Dec 21, 2020

this issue must happen for everyone running system tests

Yes, you are correct. This issue would affect anyone not using the dev server for development as well.

Is Webpacker aware of the request/response cycle or is it only aware of a particular asset helper being called?

The Webpacker manifest and compiler do not have knowledge of the request cycle but the Helper is a typical Rails view helper so it would— and could leverage request-specific state (but does not currently).

The webpack executable is not getting called multiple times since after the first call to compile in your tests, it will short-circuit on if stale?:

def compile
if stale?
run_webpack.tap do |success|

stale? inverts fresh? which compares the last_compilatIon_digest to the watched_files_digest:

def fresh?
watched_files_digest == last_compilation_digest
end
# Returns true if the compiled packs are out of date with the underlying asset files.
def stale?
!fresh?
end

So my guess would be the slowness comes from the watched_files_digest method which calculates the hexdigest for every watched file—I haven't profiled but would image this to get expensive for an app with a lot of files:

def last_compilation_digest
compilation_digest_path.read if compilation_digest_path.exist? && config.public_manifest_path.exist?
rescue Errno::ENOENT, Errno::ENOTDIR
end
def watched_files_digest
warn "Webpacker::Compiler.watched_paths has been deprecated. Set additional_paths in webpacker.yml instead." unless watched_paths.empty?
Dir.chdir File.expand_path(config.root_path) do
files = Dir[*default_watched_paths, *watched_paths].reject { |f| File.directory?(f) }
file_ids = files.sort.map { |f| "#{File.basename(f)}/#{Digest::SHA1.file(f).hexdigest}" }
Digest::SHA1.hexdigest(file_ids.join("/"))
end
end

A rudimentary improvement could be something like an instance variable flag set in helper.rb after the first manifest.lookup! and passed into lookup calls to short-circuit before compile if compile?.

@davetron5000
Copy link
Contributor Author

Hmm, I guess that means it has to read in every single file in every watched directory every time a helper tag is used. I have to assume that many many apps would have a lot of stuff in there and thus would have this problem. At my next convenience I will see if this is what is slow.

For anyone that has this problem, here is what i have done to make my tests at least not be slow:

  • In webpacker.yml, set compile: false for the test env

  • Inside Rspec-generated rails_helper.rb:

    $ran_webpack = false # gross global var, I know
    
    config.before(:each) do |example|
    
      system_test = example.metadata[:type] == :system
    
      if system_test
        if !$ran_webpack
          if ENV["SKIP_WEBPACK"] == "true"
            puts "[ spec/rails_helper.rb ] Skipping Webpack. System tests may fail if you changed assets relevant to a test"
            $ran_webpack = true
          else
            puts "[ spec/rails_helper.rb ] Running Webpack before system tests"
            if system((Rails.root / "bin" / "webpack").to_s)
              $ran_webpack = true
            else
              puts "[ spec/rails_helper.rb ] There was a problem running Webpack. Exiting…"
              exit 1
            end
          end
        end
      end
    end

    This ensures that Webpack is run before any system test runs, but allow syou to skip it via SKIP_WEBPACK if you haven't changed assets relevant to your test while e.g. doing a TDD cycle.

For dev…I am setting compile: false in webpacker.yml and trying to remember not to commit that :)

Other info of relevance:

  • this is all inside a Docker container
  • the Rails app is mounted via NFS, which doesn't work with webpack-dev-server nor with Webpack's polling, so bin/webpack --watch --watch-poll=10 doesn't work.
  • NFS makes everything a lot faster on Mac vs. whatever Docker does to mount macOS volumes
  • I am aware of docker-sync and my already gray hair got grayer just trying to set it up and it ultimately did not work

@davetron5000
Copy link
Contributor Author

OK, coming back to this since Slack is down lol.

I put in some puts-based timing around the watched_files_digest call. It seems to take around 100ms, but the problem is that it's being called for every single helper invocation. One of our pages has 75 of these, so that's 7ish seconds. Based on my understanding of the method, it calculates this for every single file that could possibly have been changed, and then does that every single time no matter what.

But I guess I'm still stuck on the notion that this must be a problem for everyone all the time. Our app is pretty small, so any reasonably-complex app must have this problem in spades, and should've had this problem for a very long time since the Webpacker code has been relative stable.

Perhaps 100ms per call is not normal and there's something about my setup?

@palkan
Copy link
Contributor

palkan commented Jan 25, 2021

We recently stumbled on the same problem. With ~600 files to watch and a dozen of calls per request, we had 6-7s spent in the Webpacker stale check.

Here is the solution I've ended up with:

# config/initializers/webpacker.rb

# Only add file watcher if lazy compilation is enabled
if Webpacker.config.compile?
  module Webpacker
    module FileWatcherStaleCheck
      STALE_CHECK_MUTEX = Mutex.new

      def initialize(*)
        super
        @need_stale_check = true
      end

      def compile
        STALE_CHECK_MUTEX.synchronize do
          @watcher ||= build_watcher do
            @need_stale_check = true
            super.tap do
              @need_stale_check = false
            end
          end

          if @need_stale_check
            @watcher.execute
          else
            @watcher.execute_if_updated
          end
        end
      end

      private

      def build_watcher(&block)
        reloadable_paths = Dir[*default_watched_paths, *watched_paths]

        # Only watch for the app's file (excluding vendors, etc.)
        reloadable_paths.select! { |path| path.match? %r{app/javascript} }

        # We do not watch added/removed files (directories), 'cause we have hundreds of
        # them and that's pretty slow
        Rails.application.config.file_watcher.new(reloadable_paths, [], &block)
      end
    end

    Compiler.prepend(FileWatcherStaleCheck)
  end
end

Now it's unnoticeable. Note that I'm not watching directories, thus, adding new files won't work. When I tried to add directories as well, it was much slower.

@davetron5000
Copy link
Contributor Author

This is not working for me. I thought it was that the regexp needs to be %r{app/javascript} (no "s"), but it still doesn't work. It basically does not ever run Webpack, even if files in reloadable_paths have changed.

One thing about my setup that may be different is that we have spring/listen disabled and am using the ActiveSupport::FileUpdateChecker for file_watcher. This is because we are running inside Docker using NFS mounts, which don't support evented filesystems. There must be some interaction between this and that base class, but I'm not familiar enough with Webpacker's internals to know what it might be.

@palkan
Copy link
Contributor

palkan commented Jan 25, 2021

ActiveSupport::FileUpdateChecker for file_watcher. This is because we are running inside Docker using NFS mounts

Yeah, that could be the reason.

But it still should call Webpack at least once, since we run #execute for the first call.

@jakeonfire
Copy link

jakeonfire commented Jan 20, 2022

thanks for the ideas @palkan. since we are using the dev server in development and thus only doing lazy compilation for specs in the test env (and don't care at all about source file changes during spec runs) just shortcutting the compiler after the first (successful) run does the trick:

module Webpacker
  module OneTimeCompiler
    def compile
      @compiled ||= super
    end
  end

  Compiler.prepend(OneTimeCompiler) if Webpacker.config.compile?
end

i'd love to see an option for this in the webpacker config - and default to it in the generated template's test env. probably lots of seconds could be saved for lots of developers. 🌎 🕐

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

No branches or pull requests

6 participants