Sidekiq Jobs::PollFeed failing - is this bad?


(Lee_Ars) #1

Checked on my /sidekiq URL for the first time in about a million years, and I’ve got a job that looks like it’s failing repeatedly—Jobs:PollFeed. Is this bad? I watched it kick off automatically and it failed; tried firing it manually, and it failed then as well. Nothing relevant showing up under /logs.

Do I need to do anything to fix this, or should I not worry about it?


(Sam Saffron) #3

Are you 100% sure nothing is showing up in logs? I am certain I log these failures.


(Lee_Ars) #4

Ahhh, you’re right. My brain must have been somewhere else. Firing manually causes it to immediately fail, and it generates two apparently identical entries:

exception: undefined method `category' for nil:NilClass context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"} backtrace: /var/www/discourse/app/models/search_observer.rb:44

exception: undefined method `category' for nil:NilClass
context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"}
backtrace: /var/www/discourse/app/models/search_observer.rb:44:in `after_save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/active_model/observing.rb:352:in `update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/activerecord/observer.rb:118:in `block (2 levels) in define_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:453:in `_run__1418590778327565733__save__callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:80:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/callbacks.rb:302:in `create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/persistence.rb:103:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/validations.rb:51:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/attribute_methods/dirty.rb:32:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block (2 levels) in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:330:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:327:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:285:in `rollback_active_record_state!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:269:in `save'
/var/www/discourse/lib/post_revisor.rb:109:in `update_post'
/var/www/discourse/lib/post_revisor.rb:75:in `block in revise_and_create_new_version'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:221:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/lib/post_revisor.rb:72:in `revise_and_create_new_version'
/var/www/discourse/lib/post_revisor.rb:54:in `revise_post'
/var/www/discourse/lib/post_revisor.rb:23:in `revise!'
/var/www/discourse/app/models/topic_embed.rb:54:in `import'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:38:in `block in poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `each'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:16:in `execute'
/var/www/discourse/app/jobs/base.rb:131:in `block (2 levels) in perform'

…and:

exception: undefined method `category' for nil:NilClass context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"} backtrace: /var/www/discourse/app/models/search_observer.rb:44

exception: undefined method `category' for nil:NilClass
context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"}
backtrace: /var/www/discourse/app/models/search_observer.rb:44:in `after_save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/active_model/observing.rb:352:in `update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/activerecord/observer.rb:118:in `block (2 levels) in define_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:453:in `_run__1418590778327565733__save__callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:80:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/callbacks.rb:302:in `create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/persistence.rb:103:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/validations.rb:51:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/attribute_methods/dirty.rb:32:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block (2 levels) in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:330:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:327:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:285:in `rollback_active_record_state!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:269:in `save'
/var/www/discourse/lib/post_revisor.rb:109:in `update_post'
/var/www/discourse/lib/post_revisor.rb:75:in `block in revise_and_create_new_version'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:221:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/lib/post_revisor.rb:72:in `revise_and_create_new_version'
/var/www/discourse/lib/post_revisor.rb:54:in `revise_post'
/var/www/discourse/lib/post_revisor.rb:23:in `revise!'
/var/www/discourse/app/models/topic_embed.rb:54:in `import'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:38:in `block in poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `each'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:16:in `execute'
/var/www/discourse/app/jobs/base.rb:131:in `block (2 levels) in perform'

(Sam Saffron) #5

hmmm … you somehow have a post in your database that has no topic?

Try running

./launcher ssh instance
rails c
> Post.where("not exists (select 1 from topics where topics.id = posts.topic_id)").to_a

We may want to add a job to nuke these records with:

# careful, run backup first ... 
> Post.where("not exists (select 1 from topics where topics.id = posts.topic_id)").delete_all

(Lee_Ars) #6

The first command kicked back a huuuuuuge amount of output without any line breaks (here it is if you want to see—looks like it’s a topic that I created before I took the forum live, with posts from June-July last year a whole bunch of older topics, but nothing that appears to be of any consequence).

Running the second command produced:

=> 20

And then re-running the first command now produces => [] for the output.

After that, manually re-firing Jobs::PollFeed still appears to result in the same error:

exception: undefined method `category' for nil:NilClass context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"} backtrace: /var/www/discourse/app/models/search_observer.rb:44

exception: undefined method `category' for nil:NilClass
context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"}
backtrace: /var/www/discourse/app/models/search_observer.rb:44:in `after_save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/active_model/observing.rb:352:in `update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rails-observers-0.1.2/lib/rails/observers/activerecord/observer.rb:118:in `block (2 levels) in define_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:453:in `_run__1418590778327565733__save__callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.0.4/lib/active_support/callbacks.rb:80:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/callbacks.rb:302:in `create_or_update'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/persistence.rb:103:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/validations.rb:51:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/attribute_methods/dirty.rb:32:in `save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block (2 levels) in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:330:in `block in with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:327:in `with_transaction_returning_status'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:270:in `block in save'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:285:in `rollback_active_record_state!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:269:in `save'
/var/www/discourse/lib/post_revisor.rb:109:in `update_post'
/var/www/discourse/lib/post_revisor.rb:75:in `block in revise_and_create_new_version'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:221:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.0.4/lib/active_record/transactions.rb:209:in `transaction'
/var/www/discourse/lib/post_revisor.rb:72:in `revise_and_create_new_version'
/var/www/discourse/lib/post_revisor.rb:54:in `revise_post'
/var/www/discourse/lib/post_revisor.rb:23:in `revise!'
/var/www/discourse/app/models/topic_embed.rb:54:in `import'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:38:in `block in poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `each'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:16:in `execute'
/var/www/discourse/app/jobs/base.rb:131:in `block (2 levels) in perform'

(Sam Saffron) #7

try pulling latest and looking at logs, I added a proper error message


(Lee_Ars) #8

Roger-dodger. One moment.


(Lee_Ars) #9

Three new errors!

Orphan post skipped in search_observer, topic_id: 620 post_id: 3064 raw:...

…and it continues on with the body of a post. FWIW, it’s a post that corresponds with a blog entry, so I believe it’s one that would have been automatically added by the static embed functionality.

Then, two of these, each identical:

exception: undefined method `update_column' for nil:NilClass
context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"}
backtrace: /var/www/discourse/lib/post_revisor.rb:134:in `update_topic_excerpt'
/var/www/discourse/lib/post_revisor.rb:25:in `revise!'
/var/www/discourse/app/models/topic_embed.rb:54:in `import'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:38:in `block in poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `each'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:16:in `execute'
/var/www/discourse/app/jobs/base.rb:131:in `block (2 levels) in perform'

Edit - I can look the post up by manually entering the URL based on its post number; it is indeed an auto-created post. In fact, it was created and there were replies in its topic, and then the replies were moved to a different topic and the topic was deleted.


(Sam Saffron) #10

If that problem child post is a problem can you try nuking it?

Post.with_deleted.find(3064).destroy

And repeat with the rest of the problem posts. We really need a repro so we can fix the root cause here.

cc @eviltrout


(Lee_Ars) #11

Nuked the post, and now I’ve got yet another new pair of failure messages when triggering the job:

exception: undefined method `raw' for nil:NilClass
context: {:current_db=>"default", :current_hostname=>"discourse.bigdinosaur.org"}
backtrace: /var/www/discourse/lib/post_revisor.rb:49:in `should_revise?'
/var/www/discourse/lib/post_revisor.rb:21:in `revise!'
/var/www/discourse/app/models/topic_embed.rb:54:in `import'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:38:in `block in poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `each'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:32:in `poll_feed'
/var/www/discourse/app/jobs/scheduled/poll_feed.rb:16:in `execute'
/var/www/discourse/app/jobs/base.rb:131:in `block (2 levels) in perform'

No specific post called out this time; just a pair of the above errors.

As near as I can remember, a repro would look like this:

  1. Enable embedding and have a topic auto-created
  2. Either move posts from another topic to that new topic, or have users post some in the topic
  3. Move all posts from that topic out to another different topic
  4. Delete the auto-created topic

IIRC, that’s what I did to get us here. I believe I had to turn embedding off and on at least once to adjust one of the embedding settings, and so a bunch of duplicate topics were created (necessitating a move of posts from the old no-longer-authoritative topics to the new ones, and then a deletion of the old ones).


(Sam Saffron) #12

Recategorizing as a bug, @eviltrout can have a look tomorrow.

I think we have enough info here.


(Lee_Ars) #13

Thanks, @sam and @eviltrout. LMK if you guys want access to my prod system to assist in nailing down the specifics. Happy to provide ssh access.


(Robin Ward) #14

All fixed up now as of the latest commit in master :smile:


(Jeff Atwood) #15