Unknown error saving post, try again. Error: 500 Internal Server Error


(Marcus Baw) #1

Continuing the discussion from After upgrade to 0.9.9.18: Unknown error saving post, try again. Error: 500 Internal Server Error:

I have started having sporadic errors when posting:

“Unknown error saving post, try again. Error: 500 Internal Server Error”

I am on latest updates as of today. (260b94e) Stock Docker install with New Relic and poll plugins only.

Error logs:

ActiveRecord::RecordNotUnique (PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_topic_users_on_topic_id_and_user_id"
DETAIL:  Key (topic_id, user_id)=(697, 3) already exists.
:       INSERT INTO topic_users(user_id, topic_id, notification_level, notifications_reason_id)
       SELECT user_id, 697, 3, 6
         FROM category_users
        WHERE notification_level = 3
          AND category_id = 5
          AND NOT EXISTS(SELECT 1 FROM topic_users WHERE topic_id = 697 AND user_id = category_users.user_id)
)

I’m a bit worried that this is self-inflicted ie related to some hacking I did in the Rails console to amend CategoryUser entries in order to make all my users Watch a category by default. But I did this weeks ago and I haven’t had any problems until now. So I’m open to the idea of this being my ill-advised meddling OR a bug.

Incidentally, trying to see if there really is a duplicate entry:

pry(main)> Topic.where(id: 697)
=> []

pry(main)> TopicUser.where(topic_id:697)
=> []

Is there any other information that I can supply to help solve this? The backtrace was about 4 screens so haven’t dumped it here but it’s in this pastebin [Ruby] /var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-mini-profiler-0.9.3/lib/pa - Pastebin.com

Marcus


(Marcus Baw) #2

Can anyone help on this?


(Jeff Atwood) #3

I would disable the New Relic plugin and any other plugin we don’t officially ship.

Also check /logs in your browser as admin to see if that has a stacktrace


(Marcus Baw) #4

OK disabled NR plugin & rebuilt app, same problem.
Stacktrace is in this pastebin (it’s very large so didn’t want to dump it all here) [Ruby] /var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-mini-profiler-0.9.3/lib/pa - Pastebin.com
Googling the error implies this is a problem with Postgres primary key sequence, the threads on this problem suggest checking the primary keys in the PG console: viHistory - How to fix PostgreSQL error "duplicate key violates unique constraint"
When I checked this, they seemed OK, as in:

 discourse=# SELECT MAX(id) FROM topic_users;
 max 
 -----
 11205
 (1 row)

and

discourse=# SELECT nextval('topic_users_id_seq');
nextval
---------
11206
(1 row)

the nextval is well in advance of the MAX. I’m afraid this is at the absolute limit of my (in)competence so I defer to finer minds on whether this suggest normality or aberration

In a dev/testing box of the same deployment, I tried Rails’ ActiveRecord::Base.connection.reset_pk_sequence!('topic_users') method but this didn’t change anything. This was suggested in this SO thread ruby on rails 3 - After importing data in PostgreSQL, duplicate key value violates unique constraint - Stack Overflow

The 500 error appears to only affect one of the categories, the others are unaffected.


(Jens Maier) #5

Did you try REINDEX TABLE topic_users ?


(Marcus Baw) #6

Not yet. Thanks for the suggestion. Would I need to ./launcher rebuild app after doing a reindex?


(Jens Maier) #7

No, rebuilding does not affect the database (unless it installs a new version which runs schema migrations) and PostgreSQL can reindex a table live. I believe it will lock writes for a while, but you do not have to take the database offline.


(Marcus Baw) #8

Thanks @elberet. I rechecked my psql code and actually I had used SELECT MAX(**topic**_id) FROM topic_users; when I should have used SELECT MAX(id) FROM topic_users;. I have changed this in the initial post now.

Using the correct psql code I found that all the tables being mentioned in or around the error were indexed correctly anyway and did not require reindexing.

This made me wonder if it was a problem in the Rails code. I updated to the very latest commit as of today (eec1921ba9a99198d64ede4c7ddfed85505cb45b) and as far as I can see the problem is fixed.

M


(Marcus Baw) #9

Or not.
I am still getting regular 500 errors when creating new posts, for a number of users.
The error’s in the validation of topic_users:

ActiveRecord::RecordNotUnique (PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "index_topic_users_on_topic_id_and_user_id"
DETAIL:  Key (topic_id, user_id)=(748, 3) already exists.
:       INSERT INTO topic_users(user_id, topic_id, notification_level, notifications_reason_id)
           SELECT user_id, 748, 3, 6
             FROM category_users
            WHERE notification_level = 3
              AND category_id = 5
              AND NOT EXISTS(SELECT 1 FROM topic_users WHERE topic_id = 748 AND user_id = category_users.user_id)
)

I have tried reindexing the relevant tables but this made no difference.

Looks to me like the problem is related to the CategoryUser model discourse/category_user.rb at master · discourse/discourse · GitHub and in particular the apply_default_to_topic(topic, level, reason) and auto_track_new_topic(topic) methods.

I did some rails console hacking a few weeks ago which changed the Watching levels for various users using the set_notification_level_for_category(user, level, category_id) method - so am wondering if this could be the cause of the problem, but I can’t yet understand what ‘uniqueness’ validation I am violating and whether it is Rails or PG that is throwing the error.

Any thoughts or advice on how to get the information I need to debug this? I am happy in the Rails console and can do a bit of psql console too.

M


(Marcus Baw) #10

When I check this error Key (topic_id, user_id)=(748, 3) already exists in the Rails console I get

pry(main)> TopicUser.where(topic_id: 752, user_id: 3).exists?
=> false

Suggesting it does not exist and there is some kind of validation error.

But presumably indexing on topic_id AND user_id requires a join table inside PG so could here be an indexing problem with that table?


(Jens Maier) #11

If it doesn’t exist at the time when you’re checking the database, and we eliminate database corruption as the cause, then this would suggest that it does exist at the time the code runs but gets deleted when the transaction rolls back — in other words, the Ruby code tries to create the record twice.

If you can relyably reproduce the error, pull your database into a development environment and rescue the error wherever it pops up, then require 'pry'; binding.pry and reraise. That’d let you explore the state of the app before the transaction gets rolled back.


(Marcus Baw) #12

I’m afraid I took the chicken’s way out and manually transferred all the topics from my problem Category (only one category was affected) into a new Category, using the normal Discourse admin interface. I then renamed the new category and styled it to look exactly like the one it replaced.

So far, no problems.


(Akash Soni) #13

I’m also getting similar error:
Processing by PostsController#create as JSON

Parameters: {"api_key"=>"[FILTERED]", "api_username"=>"akash.soni", "title"=>" Getting Started with the File System", "raw"=>"In this tutorial, you’ll learn how to manage directory paths, work with URLs, use common file and folder dialogs, display file and folder information, and much more!", "category"=>"7", "tags"=>["law", "random"]}

Can't verify CSRF token authenticity.

Completed 500 Internal Server Error in 223ms (ActiveRecord: 34.3ms)

NoMethodError (undefined method `>' for nil:NilClass)

/var/www/discourse/lib/discourse_tagging.rb:58:in `tag_topic_by_names'

this issue is only for specific category That I have created for a group of some people.


(Jeff Atwood) #14

If you are getting this from an API call, you are calling incorrectly.