Weird (AS::Dependencies?) bug

There is a long dating bug affecting my application for a while but I never bothered to investigate it because it only affected the first request to my application and only under development environment (where autoload is used by Rails).

This is what I get:

rails s => Booting WEBrick => Rails 3.2.11 application starting in development on http://0.0.0.0:3000 => Call with -d to detach => Ctrl-C to shutdown server [2013-02-08 11:50:42] INFO WEBrick 1.3.1 [2013-02-08 11:50:42] INFO ruby 1.9.3 (2013-01-15) [x86_64-linux] [2013-02-08 11:50:42] INFO WEBrick::HTTPServer#start: pid=1537 port=3000

Started POST "/search/store_state" for 127.0.0.1 at 2013-02-08 11:51:04 -0200

ActionController::RoutingError (uninitialized constant ActionView::Helpers::NumberHelper):    lib/parse_format_utils.rb:2:in `<top (required)>'    lib/query_builder.rb:4:in `<top (required)>'    lib/search_results.rb:3:in `<top (required)>'    app/controllers/search_controller.rb:1:in `<top (required)>'

parse_format_utils.rb:2 => require 'action_view/helpers/number_helper'

I've modified it to:

begin    require 'action_view/helpers/number_helper' rescue Exception => e    p e    puts e.backtrace.join "\n" end

Here is the output:

> rails s => Booting WEBrick => Rails 3.2.11 application starting in development on http://0.0.0.0:3000 => Call with -d to detach => Ctrl-C to shutdown server [2013-02-08 11:32:04] INFO WEBrick 1.3.1 [2013-02-08 11:32:04] INFO ruby 1.9.3 (2013-01-15) [x86_64-linux] [2013-02-08 11:32:04] INFO WEBrick::HTTPServer#start: pid=1061 port=3000 #<NameError: uninitialized constant ActionView::Helpers::NumberHelper> /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_view/helpers.rb:50:in `<module:Helpers>' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_view/helpers.rb:4:in `<module:ActionView>' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_view/helpers.rb:3:in `<top (required)>' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_view/helpers/number_helper.rb:10:in `<module:ActionView>' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_view/helpers/number_helper.rb:8:in `<top (required)>' /home/rodrigo/ecore/src/myapp/lib/parse_format_utils.rb:3:in `<top (required)>' /home/rodrigo/ecore/src/myapp/lib/query_builder.rb:4:in `<top (required)>' /home/rodrigo/ecore/src/myapp/lib/search_results.rb:3:in `<top (required)>' /home/rodrigo/ecore/src/myapp/app/controllers/search_controller.rb:1:in `<top (required)>' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/inflector/methods.rb:230:in `block in constantize' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/inflector/methods.rb:229:in `each' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/inflector/methods.rb:229:in `constantize' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/routing/route_set.rb:69:in `controller_reference' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/routing/route_set.rb:54:in `controller' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/routing/route_set.rb:32:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/journey-1.0.4/lib/journey/router.rb:56:in `each' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/routing/route_set.rb:601:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/warden-1.2.1/lib/warden/manager.rb:35:in `block in call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/warden-1.2.1/lib/warden/manager.rb:34:in `catch' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/warden-1.2.1/lib/warden/manager.rb:34:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/etag.rb:23:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/conditionalget.rb:35:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/head.rb:14:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/params_parser.rb:21:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/flash.rb:242:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:210:in `context' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:205:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/cookies.rb:341:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/callbacks.rb:405:in `_run__2728328958449052391__call__575225088242605981__callbacks' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/callbacks.rb:405:in `__run_callback' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/callbacks.rb:385:in `_run_call_callbacks' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/callbacks.rb:81:in `run_callbacks' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/callbacks.rb:27:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/reloader.rb:65:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/remote_ip.rb:31:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/rack/logger.rb:32:in `call_app' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/rack/logger.rb:16:in `block in call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/tagged_logging.rb:22:in `tagged' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/rack/logger.rb:16:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/request_id.rb:22:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/methodoverride.rb:21:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/runtime.rb:17:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/activesupport-3.2.11/lib/active_support/cache/strategy/local_cache.rb:72:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/lock.rb:15:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/actionpack-3.2.11/lib/action_dispatch/middleware/static.rb:62:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/engine.rb:479:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/application.rb:223:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/content_length.rb:14:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/railties-3.2.11/lib/rails/rack/log_tailer.rb:17:in `call' /home/rodrigo/.rvm/gems/ruby-1.9.3-p374/gems/rack-1.4.5/lib/rack/handler/webrick.rb:59:in `service' /home/rodrigo/.rvm/rubies/ruby-1.9.3-p374/lib/ruby/1.9.1/webrick/httpserver.rb:138:in `service' /home/rodrigo/.rvm/rubies/ruby-1.9.3-p374/lib/ruby/1.9.1/webrick/httpserver.rb:94:in `run' /home/rodrigo/.rvm/rubies/ruby-1.9.3-p374/lib/ruby/1.9.1/webrick/server.rb:191:in `block in start_thread'

Any ideas what is happening here? I have no clue! Why a code like this would automatically load helpers.rb?

helpers/number_helper.rb:

8: module ActionView 9: # = Action View Number Helpers 10: module Helpers #:nodoc:

Thanks in advance, Rodrigo.

Seems unrelated to dependencies.rb, most likely a missing require somewhere within Rails.

It can be the case that it does not show up in production because of eager loading.

Any ideas why helpers.rb is loaded when you write code like below?

module ActionView    module Helpers      module NumberHelper

Is this normal MRI behavior or is this caused by dependencies.rb?

Ruby on Rails itself does not use dependencies.rb to load its code. It is a regular Ruby library that uses requires and Kernel#autoload with some added sugar. AS::Dependencies only covers application constant autoloading.

The thing goes like this: When an application boots in any environment action_view.rb is loaded. When that file is executed an autoload for :Helpers is configured under ActionView. In a default setup, helpers.rb is not yet loaded. That is, if you run

    rails runner 1

helpers.rb is not loaded (at least in 3-2-stable, not that we are explaining any contract, only load order execution to follow what happens in your exception).

But if you force the evaluation of the constant as in your example above:

    module ActionView       module Helpers         ...       end     end

that autoload is triggered because the interpreter checks whether "Helpers" is a constant defined in the module object stored in ActionView. Therefore, helpers.rb is interpreted and sets in turn an autoload for NumberHelper below AV::Helpers.

So, module Helpers in that snippet *reopens* a module object defined via the autoload, rather than creating the module object. The execution follows and the same happens with the "NumberHelper" constant down below. The interpreter checks whether it belongs to the module object stored in AV::Helpers. Since it is unknown and there is an autoload for it it gets triggered, and loads... well the very number_helper.rb whose execution we were in the middle of (not sure this sentence is valid English :).

I suspect there is a circularity here that is showing up that way.

Would need to dig deeper to fully explain how this ends up in an exception, maybe I'll do it tonight, but in the meantime here's some context in case it helps.

I think I was fighting the same bug some time ago …

(the resolution for me to avoid any explicit use of

‘require’ in the application and depend fully on autoloading).

Doing what amounts to a “circular” call of ‘require’ triggers it. The

second time around, it seems to have forgotten the results of the

earlier require (IIRC, the second call to require is not really executed,

(correct, because it was already executed), but the result of the require

seems to be forgotten …) and then later on, when that module is called,

I got an

uninitialized constant

exception.

Only occurs in development (not in test or production),

actually with WEBrick.

app/models $ head -10 sparql.rb

It makes total sense. What doesn’t make sense is the source of helpers.rb to me:

https://github.com/rails/rails/blob/master/actionpack/lib/action_view/helpers.rb

First it should explicitly require (or require_dependency)

‘active_support/autoload’ and ‘active_support/concern’, right?

But then, why using autoload if you're just including all modules

next?

Some very common files are loaded at the entry point of every component, to avoid repeating their require again and again:

https://github.com/rails/rails/blob/master/activesupport/lib/active_support/rails.rb

As for the autoload + include, I don’t really know, maybe it is a fancy way to avoid writing a file path. Seems unnecessary to me at first glance. Maybe someone else from the team has a better justification?

    Some very common

files are loaded at the entry point of every component, to avoid repeating their require again and again:

https://github.com/rails/rails/blob/master/activesupport/lib/active_support/rails.rb

But shouldn't helpers.rb require 'active_support/rails' then instead

of just ‘active_support/benchmarkable’?

Otherwise it should be documented that we're not supposed to require

specific parts of some libraries included in Rails… That way I’d know (although surprised) that I’m not supposed to require ‘action_view/helpers/number_helper’ but simply ‘action_view/helpers’ (or just ‘action_view’?)

Anyway, thanks for your input. It helped documenting the bug in my own code and stop the exception on the first request for dev environment. But here is how my file looks like currently on latest released Rails:

require 'action_view/helpers' # required due to bug in Rails:

require ‘action_view/helpers/number_helper’

number_helper depends on non declared module below. This is fixed

on Rails master and 3.2-stable branch so this can be removed

once we upgrade to Rails 4 or when a new Rails 3.2 is released:

require ‘active_support/core_ext/hash/keys’ require ‘active_support/core_ext/hash/reverse_merge’ I’ve fixed the last issues recently in the 3.2-stable branch but I’d still like to be able to remove the first require. Should I send a pull request to helpers.rb to just replace autoload by regular requires (or require_relative, maybe for master)? Thanks, Rodrigo.

No, no, as/rails.rb is already required by the entry point

of every component (except AS). That is a given in the

context of a Rails application, and

gem ‘active_record’

does that if standalone.

I don’t understand what you mean. In my unit tests involving ParseFormatUtils for instance Rails is never loaded and my application doesn’t even use ActiveRecord.

But my tests weren't complaining anyway because they don't autoload

ActionView/Helpers.

Also, even if I explicitly required as/rails it wouldn't fix the

situation for my case.

This is what's happening in a simplified way:

./test.rb:
autoload :A, 'a'
require 'a/b'

./lib/a.rb:
module A
  autoload :B, 'a/b'
  include B
end

./lib/a/b.rb:
module A
  module B
  end
end

ruby -I lib test.rb

This is enough to create the circular dependency error. Maybe this

is one of the reasons why Matz wants to remove autoload from Ruby…

Sorry but I don't have any suggestions right now that would make

require ‘a/b’ work if ‘a’ is set to be autoloaded and ‘a’ requires ‘b’ which depends on ‘a’…

Unless we create some 'action_view/helpers/all.rb'  file. Would that

be acceptable?

Best,
Rodrigo.

I am only explaining why autoload and concern have no explicit requires in that file. That was a tangential question you did not directly related to the exception.

I know it is tangential. I was just explaining why I don’t agree with the current approach because non Rails code could rely only on ‘action_view/helpers’, don’t you agree? How are they supposed to know that they should first require ‘active_support/rails’ or any other entry point?

I don't think it is fine to just assume that ActionView classes only

make sense in within the Rails context. This is an unsafe assumption that I don’t agree with.

The correct way to use any one of the rails pieces is to require the framework file first.

You have to do

require 'action_view' # this file only loads what is needed to use the framework inside and outside the rails scope
require 'action_view/helpers'

See also https://github.com/rails/rails/pull/6964#issuecomment-6765540

Is this documented somewhere? Since it doesn’t follow any best practices I think this particular Rails behavior should be documented, right?

At least, now that I know that this behavior is intentional in Rails I documented myself in my own class so that other developers could also understand the reason I’m depending on full ActionView when I really depend only on NumberHelper:

require 'bigdecimal'
# In Rails, if you need action_view/helpers/number_helper you have

to require ‘action_view’, # then 'action_view/helpers and finally ‘action_view/helpers/number_helper’. Pretty stupid but we don’t control # Rails. Since ActionView will load all components, we don’t need to require the other files, just ‘action_view’: require ‘action_view’ #require ‘action_view/helpers/number_helper’

I don’t remember if this is documented somewhere but I don’t think we have a guide to “How to use Rails pieces outside Rails” to put this kind of information.

I would be grateful if you don't insult the project.

Maybe I think twice before expending so much time writing detailed replies to you again.

If I wrote a small guide on the subject would it be accepted?