1

I'm working on an application upgraded to Rails 5.1, when an Internal Server Error occurs I get the exception message, but no stacktrace. For example:

Completed 500 Internal Server Error in 25ms (ActiveRecord: 13.5ms)

NoMethodError - undefined method `performer' for #<AssignSiteToStudy::Form>
Did you mean?  performer_id:

There is no further information either in stdout or the development log file.

After some investigation it seems the that the problem occurs in the better_errors gem, specifially Rails.backtrace_cleaner.clean removes all lines of the backtrace:

# better_errors-2.5.0/lib/better_errors/middleware.rb:

def backtrace_frames
  if defined?(Rails) && defined?(Rails.backtrace_cleaner)
    Rails.backtrace_cleaner.clean @error_page.backtrace_frames.map(&:to_s)
   else
     @error_page.backtrace_frames
   end
end

Update: The actual error occurs with in an engine which is located outside the Rails root. It is referenced in Gemfile using path, e.g. gem "my_engine", path: '~/dev/my_engine.

Kris
  • 19,188
  • 9
  • 91
  • 111
  • Have you checked your log_level? https://guides.rubyonrails.org/debugging_rails_applications.html#log-levels – Sean Huber Oct 02 '18 at 16:25
  • `Rails.configuration.log_level #=> :debug`. I'm running in development environment. – Kris Oct 02 '18 at 16:57

3 Answers3

4

The real problem here is that the error is coming from an engine which is outside the Rails root. In the Gemfile it is referenced as gem 'my_engine', path: '~/dev/my_engine'.

This means the filter which removes Rails root and would usually turn /home/user/dev/project/app/... in to app/... does not do so for path outside the Rails root and thus they are excluded by the Rails silencer which removes anything that does not start with lib, app etc.

The solution is to manage the silencers ourselves, luckily we already had a ENV var, ENGINES_HOME, which points to the root directory for our engines repos. In initializers/backtrace_cleaner.rb:

Rails.backtrace_cleaner.remove_silencers!

if ENV['ENGINES_HOME']
  Rails.backtrace_cleaner.add_filter { |line| line.sub(ENV['ENGINES_HOME'], "engines") } 
end

Rails.backtrace_cleaner.add_silencer { |line| line !~ /^\/?(app|config|lib|spec|engines)/}
Kris
  • 19,188
  • 9
  • 91
  • 111
1

Removing the better_errors gem fixes this issue. Now I get:

Completed 500 Internal Server Error in 1674ms (ActiveRecord: 50.4ms)

undefined method `sites' for #<Class:0x000055a38ef961b8>

ActionView::Template::Error (undefined method `sites' for #<Class:0x000055a38ef961b8>):
1: $('#sites_panel').html('<%= escape_javascript render partial: ...
activerecord (5.1.6) lib/active_record/dynamic_matchers.rb:22:in `method_missing'
/home/user/dev/engine/app/services/update_site_assigned_to_study.rb:30:in `site'
etc.
etc.

The reason this works is that Rails.backtrace_cleaner filters out all lines. This is because the combination of filters and silencers in Rails::BacktraceCleaner end up removing lines from the engine, in which the errors occurs, because it is outside the Rails root.

Usually, as in this case, when all lines have been filtered out by the backtrace cleaner ActionDispatch::DebugExceptions#log_error will display the full backtrace as fallback to displaying nothing.

However when using better_errors the usual Rails code, in #log_error, does not appear it be called. I speculate that better_errors monkey patches Rails. Either way better_errors uses Rails.backtrace_cleaner filtering out all lines without a fallback for the case when all lines have been filtered out.

Kris
  • 19,188
  • 9
  • 91
  • 111
0

To expand on Kris' answer, if you're looking for a solution without ENV variable, another option could be:

Rails.backtrace_cleaner.add_filter { |line| line.sub(/(.*)(\/name_of_your_engin_goes_here\/)(.*)/, '\2\3') }

This will transform this: bla/bla/bla/name_of_your_engin_goes_here/bla/bla/bla.rb

into this: /name_of_your_engin_goes_here/bla/bla/bla.rb

Yann
  • 43
  • 1
  • 5