Failed to process hijacked response correctly : Couldn't find Topic with 'id'=569

Hi,

we are automatically suspending profiles that were not used for at least one year with the plugin discourse-auto-suspend.

Later on we are then deleting the profiles with all their posts and topics.
(we do have delete user max post age = 3700 and delete all posts max = 999)

So far I have deleted already in the last couple of months more then 1500 users with several thousand posts and probably more then one thousand topics.

But now I do have a users where the system did start to delete the posts but now the user remains at 68 posts and 63 topics no matter how often I click on the button to delete the posts and threads.

Looking at /logs it does show the following warning:

Failed to process hijacked response correctly : Couldn't find Topic with 'id'=569

When I do look with the data explorer plugin into the table topics then is there no topic with this id 569.
568 does exist from 2017-05-22 14:01:35.419842 and then 570 from 2017-05-22 14:20:27.610993

But when I look in the table posts then I do there see a topic_id 569 with 9 posts.

Looks like there is a database inconsistency. In May 2017 I was not yet the admin, so I do not know if there had eventually been some system problems at that time.

Is there any way I can solve the problem to that the delete button does continue to delete the entries?

here the backtrace of this warning:

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/finder_methods.rb:346:in `raise_record_not_found_exception!'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/finder_methods.rb:454:in `find_one'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/finder_methods.rb:433:in `find_with_ids'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/finder_methods.rb:69:in `find'
/var/www/discourse/app/serializers/post_serializer.rb:397:in `topic'
/var/www/discourse/app/serializers/post_serializer.rb:87:in `topic_slug'
(eval):22:in `_fast_attributes'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:468:in `rescue in attributes'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:455:in `attributes'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:480:in `_serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:359:in `serializable_hash'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:347:in `as_json'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/json/encoding.rb:35:in `encode'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/json/encoding.rb:22:in `encode'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.0/lib/active_support/core_ext/object/json.rb:41:in `to_json'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/active_model_serializers-0.8.4/lib/active_model/serializer.rb:331:in `to_json'
/var/www/discourse/app/models/web_hook.rb:95:in `generate_payload'
/var/www/discourse/lib/post_destroyer.rb:48:in `destroy'
/var/www/discourse/app/models/user.rb:789:in `block in delete_all_posts!'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/app/models/user.rb:788:in `delete_all_posts!'
/var/www/discourse/app/controllers/admin/users_controller.rb:51:in `block in delete_all_posts'
/var/www/discourse/lib/hijack.rb:56:in `instance_eval'
/var/www/discourse/lib/hijack.rb:56:in `block in hijack'
/var/www/discourse/lib/scheduler/defer.rb:94:in `block in do_work'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rails_multisite-2.0.4/lib/rails_multisite/connection_management.rb:63:in `with_connection'
/var/www/discourse/lib/scheduler/defer.rb:89:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:79:in `block (2 levels) in start_thread'
4 Likes

This was a regression. It’s fixed in latest.

5 Likes

thanks works fine with the latest release :wink:

just one other thing.

Is it a wanted behavior that I do have to press over and over again the delete button for every topic?
I noticed this also already with the older version but forgot to mention.
(not the button in the popup, that will close after pressing the button, but the other button below which will then open again a new popup)

Pressing the delete button does show a popup to confirm the x topics with y posts.

But it does always only delete one topic, if I press the button 10 times then 10 topics are deleted.
So if a user had several dozens of topic it is quite annoying to press the button over and over again. :wink:

1 Like

and now I do have for the above user and another user another error message when trying to delete the user after all posts and topics were deleted.

Failed to process hijacked response correctly : PG::ForeignKeyViolation: ERROR:  update or delete on table "users" violates foreign key constraint "fk_rails_b64de9b025" on table "poll_votes"
DETAIL:  Key (id)=(150) is still referenced from table "poll_votes".
: DELETE FROM "users" WHERE "users"."id" = 150

Failed to process hijacked response correctly : PG::ForeignKeyViolation: ERROR:  update or delete on table "users" violates foreign key constraint "fk_rails_b64de9b025" on table "poll_votes"
DETAIL:  Key (id)=(1030) is still referenced from table "poll_votes".
: DELETE FROM "users" WHERE "users"."id" = 1030

Therefore I am unable to delete these two users.

1 Like

Hi all,

Not 100% sure if this is related but I just did a ./launcher rebuild app a few times because I got hit with the exact same bug as @GuidoD and now my rebuilds fail:

Pups::ExecError: cd /var/www/discourse && su discourse -c 'bundle exec rake db:migrate' failed with return #<Process::Status: pid 456 exit 1>

Location of failure: /pups/lib/pups/exec_command.rb:112:in `spawn'

exec failed with the params {"cd"=>"$home", "hook"=>"bundle_exec", "cmd"=>["su discourse -c 'bundle install --deployment --verbose --without test --without development --retry 3 --jobs 4'", "su discourse -c 'bundle exec rake db:migrate'", "su discourse -c 'bundle exec rake assets:precompile'"]}

a9d224caaee5abb62d9eee07477cceb1915ccee96110253a40ee165de27f824a

** FAILED TO BOOTSTRAP ** please scroll up and look for earlier error messages, there may be more than one

The last command to run was this one:

-- execute("INSERT INTO poll_votes (poll_id, poll_option_id, user_id, created_at, updated_at)\nVALUES (29600, 118033, 1235, '2018-11-08 18:15:36 UTC' 

(And then of course many more values to be inserted).

Is this related? If so desired I can of course do some more testing.

1 Like

@zogstrip might have an idea about the poll related errors. I can take another look at the deleting.

5 Likes

Thanks for the report, it was indeed a bug.

3 Likes

Can you show us the whole log of the rebuild?

I can’t reproduce this. It always deletes all posts in one go in my tests and I can’t see anything in the code that would indicate the behavior you described.

2 Likes

Hi @zogstrip, I just managed to capture the log with this:

./launcher rebuild app 2>&1 |tee /root/rebuild.log

Unfortunately, the log is now 89 MB in size, so I’m not sure if you indeed want it all. Most of it seems to be te ‘insert into’ statements, but not sure if these are relevant or not.

Anything in particular you’re looking for?

Also: I don’t mind sharing it with you but I rather not share it with anyone just like that :wink: Would you mind a privmsg with a link?

Update: I just discovered this (sorry for not catching this sooner - easily overlooked in 89MB of textfile):

rake aborted!

StandardError: An error has occurred, this and all later migrations canceled:

undefined method `keys' for #&lt;Array:0x000055a227804890&gt;

/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:61:in `block in up'

/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:60:in `each'

/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:60:in `up'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:817:in `exec_migration'

/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:7:in `block in exec_migration'

/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:6:in `exec_migration'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:798:in `block (2 levels) in migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:797:in `block in migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:414:in `with_connection'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:796:in `migrate'

/var/www/discourse/lib/migration/safe_migrate.rb:27:in `migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:977:in `migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1292:in `block in execute_migration_in_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1343:in `block in ddl_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `block in transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/transaction.rb:230:in `block in within_new_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/transaction.rb:227:in `within_new_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/transactions.rb:212:in `transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1343:in `ddl_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1291:in `execute_migration_in_transaction'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1263:in `block in migrate_without_lock'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1262:in `each'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1262:in `migrate_without_lock'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1210:in `block in migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1363:in `with_advisory_lock'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1210:in `migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1036:in `up'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1011:in `migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/tasks/database_tasks.rb:172:in `migrate'

/var/www/discourse/lib/migration/safe_migrate.rb:50:in `migrate'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/railties/databases.rake:60:in `block (2 levels) in &lt;top (required)&gt;'

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rake-12.3.1/exe/rake:27:in `&lt;top (required)&gt;'

/usr/local/bin/bundle:23:in `load'

/usr/local/bin/bundle:23:in `&lt;main&gt;'
Caused by:

NoMethodError: undefined method `keys' for #<Array:0x000055a227804890>
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:61:in `block in up'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:60:in `each'
/var/www/discourse/plugins/poll/db/post_migrate/20180820080623_migrate_polls_data.rb:60:in `up'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:817:in `exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:7:in `block in exec_migration'
/var/www/discourse/lib/freedom_patches/schema_migration_details.rb:6:in `exec_migration'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:798:in `block (2 levels) in migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:797:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:414:in `with_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:796:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:27:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:977:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1292:in `block in execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1343:in `block in ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `block in transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/transaction.rb:230:in `block in within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/transaction.rb:227:in `within_new_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/database_statements.rb:254:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/transactions.rb:212:in `transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1343:in `ddl_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1291:in `execute_migration_in_transaction'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1263:in `block in migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1262:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1262:in `migrate_without_lock'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1210:in `block in migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1363:in `with_advisory_lock'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1210:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1036:in `up'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1011:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/tasks/database_tasks.rb:172:in `migrate'
/var/www/discourse/lib/migration/safe_migrate.rb:50:in `migrate'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/railties/databases.rake:60:in `block (2 levels) in <top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
/usr/local/bin/bundle:23:in `load'
/usr/local/bin/bundle:23:in `<main>'
Tasks: TOP => db:migrate
(See full trace by running task with --trace)
1 Like

Looks like you have some really bad polls data. Any chance you can either give me a backup or ssh access to your server?

well @gerhard this behavior is for almost every user I do delete, only for the users that did not create a topic all posts will be deleted by pressing the button.
If the user has had one or more topics pressing the delete button does in almost every case only delete one topic (the posts were in the cases often already deleted by pressing the delete button for the first time). But for example the last user had 67 topics and I had to press delete button 67 times, even though the popup asks if I want to delete all posts and topics (see image below, there I was already down from 67 to the remaining 36 topics with 36 posts (so the other posts were already deleted, because this user had originally 67 topics and several hundred posts.

I will now installed the latest version again and will check if this behavior does still exist.

Well the problem is still there:
I just tried to delete this user with one topic and 13 post

After clicking on the button the screen goes back to the previous screen:

OK now I did a forced reload of the /admin/users/2035/<user> and it does now show 0 and the delete button did of course disappear.
image

Now I checked it with another user that had more topics and posts.
image
After three minutes I did a forced reload of the page /admin/users/1502/<user>```` since the logs/admin/logs/staff_action_logs```did not show any delete anymore:

and now the reload shows, that only 12 posts were deleted and no topics

pressing again the delete button and then looking two minutes later in the logs it looks like now only 4 posts have been deleted:

and a force reload of the page does also show that this time only 4 posts had been deleted

so the problem is still existing.

And I do see another error message in the log after pressing the delete button which might be the reason that not everything is deleted in one step:
Failed to process hijacked response correctly : undefined method `first_post' for nil:NilClass

/var/www/discourse/plugins/discourse-calendar/plugin.rb:80:in `block (2 levels) in activate!'
/var/www/discourse/lib/plugin/instance.rb:291:in `block in on'
/var/www/discourse/lib/discourse_event.rb:12:in `block in trigger'
/usr/local/lib/ruby/2.5.0/set.rb:338:in `each_key'
/usr/local/lib/ruby/2.5.0/set.rb:338:in `each'
/var/www/discourse/lib/discourse_event.rb:11:in `trigger'
/var/www/discourse/lib/post_destroyer.rb:63:in `destroy'
/var/www/discourse/app/models/user.rb:789:in `block in delete_all_posts!'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/app/models/user.rb:788:in `delete_all_posts!'
/var/www/discourse/app/controllers/admin/users_controller.rb:51:in `block in delete_all_posts'
/var/www/discourse/lib/hijack.rb:56:in `instance_eval'
/var/www/discourse/lib/hijack.rb:56:in `block in hijack'
/var/www/discourse/lib/scheduler/defer.rb:94:in `block in do_work'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rails_multisite-2.0.4/lib/rails_multisite/connection_management.rb:63:in `with_connection'
/var/www/discourse/lib/scheduler/defer.rb:89:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:79:in `block (2 levels) in start_thread'

And from a former delete of probably another user:
Failed to process hijacked response correctly : undefined method `calendar_details' for nil:NilClass

/var/www/discourse/plugins/discourse-calendar/plugin.rb:81:in `block (2 levels) in activate!'
/var/www/discourse/lib/plugin/instance.rb:291:in `block in on'
/var/www/discourse/lib/discourse_event.rb:12:in `block in trigger'
/usr/local/lib/ruby/2.5.0/set.rb:338:in `each_key'
/usr/local/lib/ruby/2.5.0/set.rb:338:in `each'
/var/www/discourse/lib/discourse_event.rb:11:in `trigger'
/var/www/discourse/lib/post_destroyer.rb:63:in `destroy'
/var/www/discourse/app/models/user.rb:789:in `block in delete_all_posts!'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:41:in `each'
/var/www/discourse/app/models/user.rb:788:in `delete_all_posts!'
/var/www/discourse/app/controllers/admin/users_controller.rb:51:in `block in delete_all_posts'
/var/www/discourse/lib/hijack.rb:56:in `instance_eval'
/var/www/discourse/lib/hijack.rb:56:in `block in hijack'
/var/www/discourse/lib/scheduler/defer.rb:94:in `block in do_work'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rails_multisite-2.0.4/lib/rails_multisite/connection_management.rb:63:in `with_connection'
/var/www/discourse/lib/scheduler/defer.rb:89:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:79:in `block (2 levels) in start_thread'
3 Likes

works fine now, thanks for the quick fix.

3 Likes

Can you update the discourse-calendar plugin and try again?
The plugin will now ignore deleted posts, when the topic doesn’t exist anymore.

3 Likes

perfect, works great now, everything got deleted and then I could also delete the user.
Thanks a lot for the fix.

2 Likes

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.