Better errors page significantly slower with Puma 3.x

[DannyBen]

Hi,

I noticed the better_errors page became very slow to show the right panel. The page loads quickly, but the right panel takes several seconds to load.

I believe I have traced the problem to Puma 3.x.

Puma 2.16.0 works fast
Puma 3.0.0 and the latest 3.1.1 load the right pane slowly.

[andreykul]

Definitely significant change in load time for the right panel from Puma 2.16 to Puma 3.1.

[mikereinmiller]

Same issue here when using rails s, I did notice when I run puma directly it is no longer slow. I'm not sure the difference, but running bundle exec puma works as expected with better_errors.

[mikereinmiller]

Also as another note this appears to be related to the binding_of_caller gem, not better_errors...

[DannyBen]

@mikereinmiller - good observation. maybe one of us should open a ticket at binding_of_caller then?

[mikereinmiller]

@DannyBen Probably a good idea, I'll let you get it started since you started this thread as well. I suppose this issue on better_errors could be closed as well.

[DannyBen]

I would keep this ticket open for now, even if just for the benefit of users observing the issue and coming to report.

EDIT: Also, I am also a little concerned. Seems like binding_of_caller was last released as a gem in 2013. Are there alternatives that better_errors can use instead?

[umhan35]

When running rails s, the __better_errors/xxxxx/variables request has 2MB response body instead of ~100 KB when running puma

[cannikin]

@umhan35 is right, when running the app with bundle exec puma or bin/puma the better_errors page is as fast as expected. It's only when running the server with bin/rails s that it's super slow. Sure enough the __better_errors/xxxxx/variables page is HUGE when bin/rails s is running the server... I was seeing a 1.5MB response.

Here's the output of both (I replaced \n with actual line breaks to make it slightly more readable): https://gist.github.com/cannikin/1e62e4a9b4f6f691de358bf84232c4da (You'll have to click RAW to see the full Rails one: it's just too big.)

It appears the @request dumps in the rails version are muuuuuuuuuch longer. Like thousands of lines longer.

[cannikin]

I've got a hack if you want to keep using binding_of_caller! If you just want to use the REPL and don't care about the dumped list of rack, local and instance variables beneath the console output, see our fork here: https://github.com/workingnotworking/better_errors

local_variables, instance_variables and rack_session methods (that dump those variables) all just return an empty hash. This brings the payload back down to a couple of KB.

In the long run I don't think this is actually a problem with binding_of_caller or better_errors. I think something about Rails object structure changed between 4.2 and 5.0 which just causes MUCH more data to be dumped when inspecting those variable groups.

[tobypinder]

Worth mentioning that the chrome thread was using 50% CPU for my machine with the better_errors page open in the background (!!!)

Would really love to see @cannikin's solution applied as a configuration option to disable these features since this also prevents large ActiveRecord queries from being performed (since #inspect will realise the collection, regardless of if the collection is yet paginated/scoped properly). The stack inspecting REPL is the bread and butter and printing all the instance variables is unfortunately having a huge impact on this.

[jmuheim]

Just want to point out that the fork of @cannikin seems to break REPL for me (which is the only reason I have binding_of_caller in my Gemfile anyways). So it seems worthless to me.

By the way: the web-console gem (which is included in Rails 5 by default) offers a very fast REPL from within standard error pages (or by placing a <%= console %> statement somewhere in your code. Maybe using this could speed things up?

[vavgustov]

as a temp solution to reduce response size from __better_errors/xxxxx/variables you can add next code to application_controller.rb:

before_action :better_errors_hack, if: -> { Rails.env.development? }

def better_errors_hack
  env['puma.config'].options.user_options.delete :app
end

in this case response size using rails s will be comparable with puma command

[inopinatus]

@vavgustov that wasn't working for me, this does:

before_action :better_errors_hack, if: -> { Rails.env.development? }

def better_errors_hack
  request.env['puma.config'].options.user_options.delete :app
end

[vavgustov]

@inopinatus you probably use rails 5.1.
I'm using 5.0.2 and env worked ok but some time ago I noticed this message in server logs:

DEPRECATION WARNING: env is deprecated and will be removed from Rails 5.1.

So yes better to use request.env instead of env.

[inopinatus]

confirmed, this came up during 5.1rc1 upgrade preparation.

[cannikin]

Hmm, I'm on 5.0.2 and @vavgustov / @inopinatus hack doesn't seem to have any effect for me. better_errors takes forever to render again and the Rack session output is MASSIVE. Full dump here: https://gist.github.com/cannikin/d71e442b6ca46fba130448207ce8f2c9

[tobypinder]

I was making a PR that might fix this issue in #360, can anyone confirm?

The root cause of the problem is just because puma has a "big variable" and better_errors tries to serialize everything. The PR allows users to configure a maximum size, above which they do not attempt to serve the heftier payloads to the browser.

I haven't tested this on 5.x yet at all, but progress on getting the PR reviewed/merged seems to have stalled a little (no hate, we're all busy people 😎 )

Busy this weekend but I can take a look on Monday if there is any feedback on the PR, keen to help get this in people's hands as it's such a relatively small fix for huge Quality of Life gains!

[versality]

Any progress on this ? It feels kind of silly that Puma and Better Errors being both stock packages on Rails do not work together (unless complete request freeze for 20 seconds is considered working).

Is there anything we can help with in order to speed up the process ?

[grepsedawk]

This is NOT better_errors' fault! That being said, here's what I'm doing to help this:
In my application controller:

before_action :better_errors_hack, if: -> { Rails.env.development? }

def better_errors_hack
  request.env['puma.config'].options.user_options.delete :app
end

[DannyBen]

Although this may not be a better_errors fault, it is observed only when using better_errors, and renders the better_errors gem a little less useful (or at least less... better...). Why not enable this hack (or similar) by default in the better_errors gem, so that all its users can return to using it happily, and being eternally grateful?

Judging by the length of this thread, it is obvious that it bothers a few people, and many think (correctly or not) that it is a better_errors problem.

[tobypinder]

@pachonk I would certainly class it as a behaviour that better_errors needs to fix - handling of large objects leading to an unusable error page is a fairly significant limitation right now whether it's the puma object or just any large instance variable being resolved and #inspected.

If anyone can find problems with the PR (#360) I will happily make the changes, but I've used it in development for months (from my fork) without problem. As far as I am aware the PR is classed as "failing" due to a problem with the Continuous Integration for the project rather than any failing/missing tests, but I'm happy to be corrected and put the work in if we can get this merged and released :)

[inopinatus]

My slightly naive workaround broke things like app.get '/' in the console, so I've just revised this to be

class ApplicationController < ActionController::Base
  before_action :better_errors_hack, if: -> { Rails.env.development? }
  #...

  private
  def better_errors_hack
    request.env['puma.config'].options.user_options.delete(:app) if request.env.has_key?('puma.config')
  end
end

[vavgustov]

Seems this issue will be fixed in version 2.5. Meanwhile I added fix from above comments
(comment-1, comment-2, comment-3) to experimental debug_extras gem. Originally
this gem has been developed for other purposes which you can see in 'Features' and 'Screenshots' section. However I found that it make sense to implement this 'hack' as middleware and added it to gem to avoid junk in application_controller.rb.

[RobinDaugherty]

This should be fixed by #402, which was included in v2.4.0. Can anyone give it a try and reopen this if needed?

[tagliala]

@RobinDaugherty thanks, it seems fixed to me!

[mchlfhr]

Can confirm! I updated better_errors from 2.1.1 to 2.4 and the console loads way faster now (2.1.1: 30-60 seconds / 2.4: 1 second).

This is life changing! Thank you sooo much!