First time Couldn't find User with id and then succeed when create user in 4-1-stable

Created by: yin8086

When I create a new user, the first sidekiq task that send will failed because of Couldn't find User with id=9, the error class is ActiveRecord::RecordNotFound. Then after a while, sidekiq retries, this time it succeed. The result is every I create a user it leads to a failure, and then succeed. The sidekiq logs:

2013-01-22T02:17:11Z 21764 TID-1lg2u0 Sidekiq::Extensions::DelayedMailer JID-d4903f1d1d772d54c62852ed INFO: start
2013-01-22T02:17:11Z 21764 TID-1lg2u0 Sidekiq::Extensions::DelayedMailer JID-d4903f1d1d772d54c62852ed INFO: fail: 0.004 sec
2013-01-22T02:17:11Z 21764 TID-1lg2u0 WARN: {"retry"=>true, "queue"=>"default", "timeout"=>30, "class"=>"Sidekiq::Extensions::DelayedMailer", "args"=>["---\n- !ruby/class 'Notify'\n- :new_user_email\n- - 9\n - x7EWgSpH\n"], "jid"=>"d4903f1d1d772d54c62852ed", "error_message"=>"Couldn't find User with id=9", "error_class"=>"ActiveRecord::RecordNotFound", "failed_at"=>2013-01-22 02:17:11 UTC, "retry_count"=>0}
2013-01-22T02:17:11Z 21764 TID-1lg2u0 WARN: Couldn't find User with id=9
2013-01-22T02:17:11Z 21764 TID-1lg2u0 WARN: /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:341:in `find_one'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:312:in `find_with_ids'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:107:in `find'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/querying.rb:5:in `find'
/home/gitlab/gitlab/app/mailers/notify.rb:119:in `new_user_email'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/base.rb:167:in `process_action'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/base.rb:121:in `process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/rendering.rb:45:in `process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:458:in `process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:452:in `initialize'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:439:in `new'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:439:in `method_missing'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/extensions/action_mailer.rb:20:in `perform'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:45:in `block (3 levels) in process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:109:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:109:in `block in invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/timeout.rb:11:in `block in call'
/usr/local/lib/ruby/1.9.1/timeout.rb:68:in `timeout'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/timeout.rb:10:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:in `block in invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:in `block in invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/retry_jobs.rb:49:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:in `block in invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/logging.rb:22:in `with_context'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/logging.rb:7:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:in `block in invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:114:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:114:in `invoke'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:44:in `block (2 levels) in process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:80:in `stats'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:43:in `block in process'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:in `public_send'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:in `dispatch'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/future.rb:18:in `block in initialize'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/internal_pool.rb:48:in `call'
/home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/internal_pool.rb:48:in `block in create'
2013-01-22T02:18:00Z 21764 TID-1jiqco Sidekiq::Extensions::DelayedMailer JID-d4903f1d1d772d54c62852ed INFO: start
2013-01-22T02:18:00Z 21764 TID-1jiqco Sidekiq::Extensions::DelayedMailer JID-d4903f1d1d772d54c62852ed INFO: done: 0.125 sec

Created by: joaofraga

Same issue here

By Administrator on 2013-01-25T14:04:00 (imported from GitLab)

Created by: joeletizia

I'm getting the same issue except I never succeed.

2013-02-05T21:15:15Z 3599 TID-1gmscq Sidekiq::Extensions::DelayedMailer JID-1566035c237ea1163fd8cec5 INFO: start 2013-02-05T21:15:15Z 3599 TID-1gmscq Sidekiq::Extensions::DelayedMailer JID-1566035c237ea1163fd8cec5 INFO: fail: 0.013 sec 2013-02-05T21:15:15Z 3599 TID-1gmscq WARN: {"retry"=>true, "queue"=>"default", "timeout"=>30, "class"=>"Sidekiq::Extensions::DelayedMailer", "args"=>["---\n- !ruby/class 'Notify'\n- :new_user_email\n- - 7\n - Dqk1aqV1\n"], "jid"=>"1566035c237ea1163fd8cec5", "error_message"=>"Couldn't find User with id=7", "error_class"=>"ActiveRecord::RecordNotFound", "failed_at"=>2013-02-05 21:15:15 UTC, "retry_count"=>0} 2013-02-05T21:15:15Z 3599 TID-1gmscq WARN: Couldn't find User with id=7 2013-02-05T21:15:15Z 3599 TID-1gmscq WARN: /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:341:in find_one' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:312:infind_with_ids' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/relation/finder_methods.rb:107:in find' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/activerecord-3.2.11/lib/active_record/querying.rb:5:infind' /home/gitlab/gitlab/app/mailers/notify.rb:119:in new_user_email' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/base.rb:167:inprocess_action' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/base.rb:121:in process' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionpack-3.2.11/lib/abstract_controller/rendering.rb:45:inprocess' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:458:in process' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:452:ininitialize' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:439:in new' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/actionmailer-3.2.11/lib/action_mailer/base.rb:439:inmethod_missing' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/extensions/action_mailer.rb:20:in perform' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:45:inblock (3 levels) in process' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:109:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:109:inblock in invoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/timeout.rb:11:in block in call' /usr/local/lib/ruby/1.9.1/timeout.rb:68:intimeout' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/timeout.rb:10:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:inblock in invoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/active_record.rb:6:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:inblock in invoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/retry_jobs.rb:49:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:inblock in invoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/logging.rb:11:in block in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/logging.rb:22:inwith_context' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/server/logging.rb:7:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:111:inblock in invoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:114:in call' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/middleware/chain.rb:114:ininvoke' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:44:in block (2 levels) in process' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:80:instats' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/sidekiq-2.6.4/lib/sidekiq/processor.rb:43:in block in process' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:incall' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:in public_send' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/calls.rb:23:indispatch' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/future.rb:18:in block in initialize' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/internal_pool.rb:48:incall' /home/gitlab/gitlab/vendor/bundle/ruby/1.9.1/gems/celluloid-0.12.4/lib/celluloid/internal_pool.rb:48:in `block in create' 2013-02-05T21:15:42Z 3599 TID-1g26j6 Sidekiq::Extensions::DelayedMailer JID-1566035c237ea1163fd8cec5 INFO: start sendmail: fatal: open /etc/postfix/main.cf: No such file or directory 2013-02-05T21:15:42Z 3599 TID-1g26j6 Sidekiq::Extensions::DelayedMailer JID-1566035c237ea1163fd8cec5 INFO: done: 0.061 sec

By Administrator on 2013-02-05T21:22:52 (imported from GitLab)

Created by: treydock

I saw this same error during a large operation of adding a User to numerous groups with large numbers of projects in each group. Ref #2747 (closed) issuecomment-13257431

By Administrator on 2013-02-07T20:25:24 (imported from GitLab)

Created by: dzaporozhets

Cannot reproduce. Closing

By Administrator on 2013-04-15T17:12:55 (imported from GitLab)

Created by: kgodwin

@randx Would a copy of VM that I can reproduce the issue on be sufficient?

It occurs when something like this happens (before the notification is sent): deploy-bot left project at Namespace / Project deploy-bot joined project at Namespace / Project

So it keeps trying to send it under the old user_projects id (which no longer exists since the person left the project). Its not a critical bug but it is reliably reproducible at least for me.

By Administrator on 2013-05-15T18:22:22 (imported from GitLab)

Created by: mockdeep

Happens for me as well. I get a ton of stack traces in the log saying WARN: Couldn't find PdfImage with id=303. It seems to keep trying until eventually it succeeds.

By Administrator on 2013-06-28T19:16:21 (imported from GitLab)