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

NoMethodError: undefined method on initial jobs #331

Closed
TheCorp opened this issue Aug 3, 2012 · 29 comments
Closed

NoMethodError: undefined method on initial jobs #331

TheCorp opened this issue Aug 3, 2012 · 29 comments

Comments

@TheCorp
Copy link

TheCorp commented Aug 3, 2012

So, not entirely sure about this issue but maybe you can help us track down the cause. I went through the existing open and closed issues and haven't found anything yet that seems related to this.

Basically right when we start Sidekiq workers up (on Heroku) the first few jobs always seem to error out with "NoMethodError" or "uninitialized constant" errors. For example:

NoMethodError: undefined method `initial_count_for' for #ActiveRecord::Associations::AliasTracker:0x000000064d68a8
NameError: uninitialized constant OneOfOurModels::HttpHelper
etc

initial_count_for is definitely a method in ActiveRecord and HttpHelper is a ruby library that should always be available. There are other instances of this if you want more examples. Basically it seems like the full Rails/Ruby environment hasn't been loaded into memory for the thread processing this Job?

After a minute (or less) all the jobs seem to process just fine so it seems like once things are warmed up and everything is in memory all of the jobs seem to have access to all of the functions that get mixed in. Here's our setup:

Ruby 1.9.2p290
Rails 3.2
Heroku Cedar

Let me know if this makes any sense or if you need more details about our config.

@mperham
Copy link
Collaborator

mperham commented Aug 4, 2012

Does putting require 'http_helper' at the top of the OneOfOurModels solve the problem? Is http_helper.rb in lib/?

@TheCorp
Copy link
Author

TheCorp commented Aug 4, 2012

Ill have to check that but I dont see a similar resolution to the first one I listed

NoMethodError: undefined method `initial_count_for' for #ActiveRecord::Associations::AliasTracker:0x000000064d68a8

I assume we don't have to be requiring Rails ActiveRecord libraries manually right?

@TheCorp
Copy link
Author

TheCorp commented Aug 4, 2012

So yes, the HttpHelper class is in our lib dir and that removed that issue. Although I would like to add that it was inconsistent, it didn't happen every time we started our jobs. We'll see when it runs tonight.

Unfortunately the ActiveRecord undefined method issues still happen and Im not sure how to explicitly require that where we need it. What do you think?

Also why does requiring our HttpHelper class resolve the first issue? Does that explicit require help Sidekiq to ensure its included? Just curious.

@mperham
Copy link
Collaborator

mperham commented Aug 4, 2012

Add lib to Rails eager load directory set. Everyone does this but it's not enabled by default.

@mperham mperham closed this as completed Aug 4, 2012
@mperham
Copy link
Collaborator

mperham commented Aug 4, 2012

config.autoload_paths += ["#{config.root}/lib"]

@TheCorp
Copy link
Author

TheCorp commented Aug 4, 2012

Awesome thank you, ill let you know if the other issue still shows up after we add this.

@TheCorp
Copy link
Author

TheCorp commented Aug 6, 2012

So I may have spoken too soon, this still seems to be happening. We are mainly seeing issues related to ActiveRecord at this point though. Stuff like this:

  • NoMethodError: undefined method `aliased_name_for' for #ActiveRecord::Associations::AliasTracker
  • NoMethodError: undefined method `scope' for #ActiveRecord::Associations::AssociationScope

These errors showed up on a find by id and count SQL query respectively. The errors happen at a rate of 100s out of 1 million jobs so it is very rare but something we would like to get to the bottom of. Just to be clear, these million jobs are all exactly the same and the lines of code run fine for all of the other jobs. Also the errored jobs are not for the same objects each night, just randomly interspersed although it seems to happen mainly at the beginning of our nightly runs.

Any ideas why the internals of ActiveRecord would not be loaded into memory when Sidekiq is processing a job? I won't reopen the issue, ill let you do that if you think something might be wrong with the Sidekiq internals.

@mperham
Copy link
Collaborator

mperham commented Aug 6, 2012

@tarcieri He's seeing mysterious undefined method errors in various core ActiveRecord components that are autoloaded. Could this be an autoloading race condition at fault on 1.9.2 or does that only happen on JRuby with parallel threading?

@tarcieri
Copy link

tarcieri commented Aug 6, 2012

autoload is not thread safe on 1.9.3. There are autoload bugs on 1.9.3/YARV that have only been fixed in Ruby 2.0/YARV. All code you need for your program should be loaded prior to spawning additional threads.

@mperham
Copy link
Collaborator

mperham commented Aug 6, 2012

This is a Rails 3.2 bug which does not eager load some of the ActiveRecord core API. The fix is in master and I've asked for a backport: rails/rails@8cf300c

@josevalim
Copy link

Yes, @tarcieri is correct. And please do not add lib to your eager_load directory. You should require whatever is in lib and that you want to use, as you would do with any other library.

@rafaelfranca
Copy link

Done @ rails/rails@29fb31f

@mperham
Copy link
Collaborator

mperham commented Aug 6, 2012

@TheCorp you can upgrade to Rails 3.2.8 when it ships to get the fix. I believe they've already done a release candidate or two so it should be quite soon.

@rafaelfranca
Copy link

This will not released with 3.2.8, the release branch was created before this commit. We will release at 3.2.9

@Gurpartap
Copy link

Is there a workaround until 3.2.9 is available? I'm getting similar errors with methods like scope being unavailable in random activerecord classes.

@mperham
Copy link
Collaborator

mperham commented Aug 23, 2012

@Gurpartap Write an initializer that exercises ActiveRecord, loads models from the database, walks associations, etc so as much of AR as possible is loaded. It's a hack but it should work. The rails initializers are run single-threaded before Sidekiq starts all of its threads.

@TheCorp
Copy link
Author

TheCorp commented Aug 27, 2012

Just did this and it worked perfectly. We also were seeing this issue with a few other gems like CarrierWave so the same fix worked as well to ensure it gets preloaded. Thanks.

@Gurpartap
Copy link

I'm using Rails 3.2.9 with Sidekiq 2.5.3 on Heroku. Still getting a missing method for first few job performs.

Here's the log:

app[node_worker.1]: 2012-11-25T18:05:55Z 2 TID-srfrs NodeWorker::Setup JID-084z41d6e2a6a6c8e226685f INFO: start
app[node_worker.1]: 2012-11-25T18:05:56Z 2 TID-srfrs NodeWorker::Setup JID-084z41d6e2a6a6c8e226685f INFO: fail: 0.051 sec
app[node_worker.1]: 2012-11-25T18:05:56Z 2 TID-srfrs WARN: {"retry"=>false, "queue"=>"node", "class"=>"NodeWorker::Setup", "args"=>[64], "jid"=>"084z41d6e2a6a6c8e226685f"}
app[node_worker.1]: 2012-11-25T18:05:56Z 2 TID-srfrs WARN: undefined method `default_scoped=' for #<ActiveRecord::Relation:0x00000006402580>
app[node_worker.1]: 2012-11-25T18:05:56Z 2 TID-srfrs WARN: /app/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.6/lib/active_record/scoping/named.rb:38:in `scoped'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.6/lib/active_record/querying.rb:7:in `rescue in find'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.6/lib/active_record/querying.rb:5:in `find'
app[node_worker.1]: /app/app/workers/node_worker.rb:13:in `perform'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/processor.rb:43:in `block (3 levels) in process'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:79:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:79:in `block in invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/server/timeout.rb:14:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:81:in `block in invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:81:in `block in invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/server/retry_jobs.rb:49:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:81:in `block in invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/logging.rb:22:in `with_context'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/server/logging.rb:7:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:81:in `block in invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:84:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/middleware/chain.rb:84:in `invoke'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/processor.rb:42:in `block (2 levels) in process'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/processor.rb:77:in `stats'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.5.3/lib/sidekiq/processor.rb:41:in `block in process'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.3/lib/celluloid/future.rb:18:in `block in initialize'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.3/lib/celluloid/internal_pool.rb:48:in `call'
app[node_worker.1]: /app/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.3/lib/celluloid/internal_pool.rb:48:in `block in create'

Would this be related to this issue as it happens only during the quick first run?

@TheCorp
Copy link
Author

TheCorp commented Nov 26, 2012

Yup its the same issue, just create an initializer that loads some models with ActiveRecord and you should be good to go. Its not finding the default_scope method so maybe try to make sure you are loading one of your models that has a default scope.

@JeanMertz
Copy link

Am I correct in thinking that the following happens because of the exact same problem?

2012-12-19T13:03:12Z 38167 TID-owjp1qo90 WARN: undefined method `id' for #<Hash:0x007fcc0b2c14e0>

It seems as if the ActiveRecord style method chaining simply isn't working. I use spot.project.id and I suspect .id isn't working because of the above.

@TheCorp, do you have an example on how to solve this with an initializer.

@TheCorp
Copy link
Author

TheCorp commented Dec 19, 2012

I don't know if that's the same error as the ones everyone else is having above. I don't think there should ever be a method "id" on a Hash object? Is "spot" one of your models? What is "project"? Is that a relation? If so that should be an array or at least another model, it should never resolve to a Hash class I don't think.

Most likely the project attribute is a serialized field since that's what would be Hash and then there is definitely no method "id" for that object. I can show you an example of the initializer but I doubt it would resolve your issue here.

@JeanMertz
Copy link

@TheCorp I solved the issue, a co-worker mentioned it was generally a bad idea to sent objects to Sidekiq, and instead to send ID's and get the object from the ID. This solved my issue.

Still, if you have an example at the ready, it might help other people finding this topic.

@TheCorp
Copy link
Author

TheCorp commented Dec 19, 2012

Ya Sidekiq can't be sent objects like DelayedJob can so that's definitely the case.

As for how to resolve the issue, all you have to do is put a single line in your sidekiq initializer for each issue you are having with methods being missing, something like this:

# If you are only having ActiveRecord missing method issues then all you need is this
Model.first.some_active_relation

# If you are having unicode decoding issues
ActiveSupport::Multibyte::Unicode.u_unpack('óç')

#Carrier Wave
test_file = File.new("#{Rails.root}/tmp/test.txt",'wb')
CarrierWave::SanitifiezeFile.new(test_file)
test_file.close

Anything simple like that will ensure the classes get loaded before Sidekiq uses them.

@biznickman
Copy link

I've been running into the same issue with Sidekiq, however I'm not sending objects around as @JeanMertz mentioned. Instead I'm passing by ID as is recommended, however when I go to call the ActiveRecord method update_attributes it fails with:

undefined method `aliased_name_for' for #<ActiveRecord::Associations::AliasTracker:0x00000005051428>

This is the only thread where I've seen other people with the same issue. I'm on Rails 3.2.11

@TheCorp
Copy link
Author

TheCorp commented Jan 30, 2013

See the referenced issues for how to fix that. It's here: #331

@biznickman
Copy link

@TheCorp , you just linked back to this issue :) It sounds like the main solution is an initializer with some arbitrary ActiveRecord request ... is that correct?

@TheCorp
Copy link
Author

TheCorp commented Jan 30, 2013

Oh my bad sorry! Ya definitely, use the initializer method which does any arbitrary ActiveRecord call and that should make sure everything is in memory before any Sidekiq workers get to it.

@akhilesharora
Copy link

{"class":"PostmanWorker","args":["lmd"],"retry":true,"queue":"critical","jid":"04a7ac2fa0b59a792c6d72e4","created_at":1456753992.873091,"enqueued_at":1456754044.180575,"error_message":"undefined method `perform' for #<PostmanWorker:0x007fd28ce293a0 @jid="04a7ac2fa0b59a792c6d72e4">","error_class":"NoMethodError","failed_at":1456754009.4919481,"retry_count":1,"retried_at":1456754044.182247}

Im also facing NoMethodError

@chickensmitten
Copy link

@biznickman did the arbitrary ActiveRecord call solve your problem? I am facing a problem similar to yours. Unfortunately, the ActiveRecord call in sidekiq initializer did not work for me.

In config/initializers/sidekiq.rb, I added:
User.first.blank?

Rails 4.2.1

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

No branches or pull requests

10 participants