This project is archived and is in readonly mode.

#5231 ✓resolved
Jakub Suder

print stack traces with deprecation warnings

Reported by Jakub Suder | July 28th, 2010 @ 04:48 PM | in 3.0.2

Right now, the deprecation warnings from ActiveSupport look like this:

DEPRECATION WARNING: Calling a method in Rails::Application is deprecated, please call it directly in your application constant Foo::Application. (called from method_missing at .../railties-3.0.0.rc/lib/rails/application.rb:77)

This tells me nothing about where exactly is the code that causes the warning, if it's in one of the gems, in Rails, or somewhere in my code... Some kind of partial stack trace would be helpful here.

Comments and changes to this ticket

  • Neeraj Singh

    Neeraj Singh July 28th, 2010 @ 06:21 PM

    • Assigned user set to “Santiago Pastorino”
    • State changed from “new” to “open”
    • Milestone set to 3.x
    • Importance changed from “” to “Low”

    +1

    I think caller should be invoked and the output of that should be printed. Let's see what Santiago has to say.

  • Neeraj Singh

    Neeraj Singh July 28th, 2010 @ 06:22 PM

    my bad. In this case it is saying that it was called from method_missing.

    So what's the issue?

  • Jakub Suder

    Jakub Suder July 28th, 2010 @ 06:32 PM

    The issue is that I'm not interested in Rails internal code that actually outputs the deprecation warning (which is the last few lines of the backtrace), I'm interested in the code that caused the warning in the first place. In this case, the culprit was a line in my Rakefile (Rails::Application.load_tasks instead of Foo::Application.load_tasks), but the warning didn't tell me that, I had to manually add some temporary code to ActiveSupport that printed the whole backtrace (the line in Rakefile was about 10 lines deeper into the backtrace).

  • Neeraj Singh

    Neeraj Singh July 28th, 2010 @ 06:41 PM

    Point taken. However having the full backtrace all the time might be annoying.

    Personally I would like to have an option like

    config.print_full_stacktrace_from_deprecation_warnings = true
    

    In this way when I am in the mood to resolve all the warnings, I would turn that option ON and will get full stacktrace. Otherwise one line deprecation warning will be printed.

  • Jakub Suder

    Jakub Suder July 28th, 2010 @ 06:42 PM

    Sounds good. You're right that if you're not trying to solve the problem at this specific moment, it would get annoying very fast.

  • Jakub Suder

    Jakub Suder August 20th, 2010 @ 07:25 PM

    I'm uploading a patch that fixes this issue. Instead of adding an option to show full stack traces, I've changed the code to always show the first line in the stack that's outside Rails gem directory (which should almost always be the culprit that caused the warning).

    Examples - lines returned in the warning message:

    1) If I use an old form of Rails::Application.routes.draw with |map|:

    Before the patch:

    initialize at /Users/psionides/Downloads/rails/actionpack/lib/action_dispatch/routing/deprecated_mapper.rb:34
    

    Which just tells me I'm using a deprecated method related to routing, but doesn't tell me which one and where. After the patch:

    <top (required)> at /Users/psionides/Downloads/railstest/railstest/config/routes.rb:1
    

    Which tells me exactly where the error is.

    2) If I call Rails::Application.load_tasks in the Rakefile:

    Before the patch:

    method_missing at /Users/psionides/Downloads/rails/railties/lib/rails/application.rb:77
    

    After the patch:

    <top (required)> at /Users/psionides/Downloads/railstest/railstest/Rakefile:7
    

    Please review and apply the patch when you find some time.

  • Neeraj Singh

    Neeraj Singh August 20th, 2010 @ 07:52 PM

    Nice work. And indeed very useful.

  • Jakub Suder

    Jakub Suder August 23rd, 2010 @ 11:10 AM

    Is there any chance someone can apply this patch before 3.0 final? I guess it's going to be most useful once 3.0 is released, because there's going to be lots of deprecations from 2.x, and the number of things deprecated in 3.1/3.2 will probably be smaller...

  • José Valim

    José Valim August 24th, 2010 @ 09:11 PM

    • Milestone cleared.
    • Assigned user changed from “Santiago Pastorino” to “José Valim”
    • Importance changed from “Low” to “High”

    Mate, I would love to pull it in! Just one thing, couldn't you try to use Rails.backtrace_cleaner instead?

  • Jakub Suder

    Jakub Suder August 24th, 2010 @ 09:36 PM

    Hmm... it looks like I could just replace:

    rails_gem_root = File.expand_path("../../../../..", __FILE__) + "/"
    first_external = callstack.find { |line| !line.start_with?(rails_gem_root) }
    

    with:

    first_external = Rails.backtrace_cleaner.clean(callstack).first
    

    However, I'm not sure if I can assume that Rails and Rails.backtrace_cleaner are available - after all, you can use ActiveSupport without using Rails, right?

  • José Valim

    José Valim August 24th, 2010 @ 09:40 PM

    Right! Here is an example of using backtrace cleaner, checking properly if it is defined or not:

    http://github.com/rails/rails/blob/master/actionpack/lib/action_dis...

  • Jakub Suder

    Jakub Suder August 24th, 2010 @ 10:01 PM

    Honestly, I don't think this makes much sense in this case... The code in ActionDispatch uses the cleaner (if available) to remove some useless lines from the trace to make it more readable, and if it's not available, leaves it as it is, so it makes a difference for the user. Here we only want that one specific line, so adding the cleaner would just mean less code, but adding a cleaner with an if/else would actually mean more code and no advantages (other than removing Rails.root from the string, but it's just one line anyway).

    Besides, if the cause of the deprecation is inside a gem that you're using (this happened to me at least once), the cleaner would return a wrong line, because (by default) it treats everything outside your app as noise.

  • Neeraj Singh

    Neeraj Singh August 24th, 2010 @ 10:06 PM

    At this point of time I am seeing a lot of deprecation messages from third party gems. If the offending line is not there then the deprecation message might be confusing.

    Personally I would like to have an option like this

    config.print_full_stacktrace_from_deprecation_warnings = true
    

    If the option is on then dump the full trace otherwise just one line is enough.

    When a project is being migrated from 2.x to 3.x at that time I want deprecation messages to be one line because I am ignoring them. After a week when my project is passing all tests I would like to have full dump so that I could remove deprecation message.

    In some cases it might not be possible to get rid of all deprecation messages. I get some message from shoulda and I need to wait until shoulda guys fix the gem.

  • Jakub Suder

    Jakub Suder August 24th, 2010 @ 10:22 PM

    At this point of time I am seeing a lot of deprecation messages from third party gems. If the offending line is not there then the deprecation message might be confusing.

    Yeah, that's what the patch is intended to fix (the original version, without Rails cleaner). Example from my current app:

    Before the patch:

    DEPRECATION WARNING: Calling a method in Rails::Application is deprecated, please call it directly in your application constant Qwerly::Application. (called from method_missing at /Users/psionides/.rvm/gems/ruby-1.9.2-preview3@foo/gems/railties-3.0.0.rc/lib/rails/application.rb:77)
    DEPRECATION WARNING: You are using the old router DSL which will be removed in Rails 3.1. Please check how to update your routes file at: http://www.engineyard.com/blog/2010/the-lowdown-on-routes-in-rails-3/. (called from initialize at /Users/psionides/.rvm/gems/ruby-1.9.2-preview3@foo/gems/actionpack-3.0.0.rc/lib/action_dispatch/routing/deprecated_mapper.rb:33)
    

    (No clue what's going on.)

    After the patch:

    DEPRECATION WARNING: Calling a method in Rails::Application is deprecated, please call it directly in your application constant Qwerly::Application. (called from <top (required)> at /Users/psionides/.rvm/gems/ruby-1.9.2-preview3@foo/gems/jammit-0.5.1/rails/routes.rb:3)
    DEPRECATION WARNING: You are using the old router DSL which will be removed in Rails 3.1. Please check how to update your routes file at: http://www.engineyard.com/blog/2010/the-lowdown-on-routes-in-rails-3/. (called from <top (required)> at /Users/psionides/.rvm/gems/ruby-1.9.2-preview3@foo/gems/jammit-0.5.1/rails/routes.rb:3)
    

    (Aha, it's Jammit! I should probably tell them.)

  • Jakub Suder

    Jakub Suder August 24th, 2010 @ 10:25 PM

    I think an option is not necessary here, you don't really need the whole stack trace, as I thought initially - all it would tell you in the example above is how Jammit is loaded in the app - probably somehow with Bundler, but that's irrelevant; what's relevant is who calls one of the Rails methods incorrectly, and unless it's Rails itself, it will always be the first non-Rails line in the stack trace, in this case some method in Jammit. That's all I need to either fix the error myself or tell someone (gem owner) to fix it.

  • Neeraj Singh

    Neeraj Singh August 24th, 2010 @ 10:25 PM

    I see. For some reason I thought you were removing everything no belonging to my code including gems. My bad.

  • Jakub Suder

    Jakub Suder August 24th, 2010 @ 10:37 PM

    That's what the Rails cleaner would do, because it's configured by default to filter out everything that doesn't match APP_DIRS_PATTERN = /^\/?(app|config|lib|test)/.

  • José Valim

    José Valim August 25th, 2010 @ 01:12 AM

    Yes, you are right Jakub. Just one last change then: your patch should return callstack.first if no external is found (useful when we deprecate something but we are still calling inside rails tests, for example)

  • Jakub Suder
  • Repository

    Repository August 25th, 2010 @ 11:24 AM

    • State changed from “open” to “resolved”

    (from [4f945e97e55b861ab014d71efa983ab183441031]) better callstack reporting in deprecation messages

    now the reported line is the first line in the stack
    that's outside Rails, which is the one that actually
    caused the problem in the first place

    [#5231 state:resolved]

    Signed-off-by: José Valim jose.valim@gmail.com
    http://github.com/rails/rails/commit/4f945e97e55b861ab014d71efa983a...

  • Repository

    Repository August 25th, 2010 @ 11:25 AM

    (from [aec084955df4761dfc60920048209314ee466463]) better callstack reporting in deprecation messages

    now the reported line is the first line in the stack
    that's outside Rails, which is the one that actually
    caused the problem in the first place

    [#5231 state:resolved]

    Signed-off-by: José Valim jose.valim@gmail.com
    http://github.com/rails/rails/commit/aec084955df4761dfc609200482093...

  • Jeremy Kemper

    Jeremy Kemper October 15th, 2010 @ 11:01 PM

    • Milestone set to 3.0.2

Create your profile

Help contribute to this project by taking a few moments to create your personal profile. Create your profile »

<h2 style="font-size: 14px">Tickets have moved to Github</h2>

The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>

Referenced by

Pages