Topic: tag update deadlocking

Posted under General

Getting a deadlock message when I update post #502843

Looks like this:

ActiveRecord::StatementInvalid in PostController#update

PGError: ERROR: canceling statement due to statement timeout
CONTEXT: SQL statement "UPDATE tags SET post_count = post_count - 1 WHERE tags.id = OLD.tag_id"
PL/pgSQL function trg_posts_tags__delete() line 3 at SQL statement
: DELETE FROM posts_tags WHERE post_id = 502843
RAILS_ROOT: /home/e621/e621-production/release-2014-06-08

Application Trace | Framework Trace | Full Trace
/opt/rbenv/versions/ree-1.8.7-2012.02/lib/ruby/gems/1.8/gems/activerecord-2.3.18/lib/active_record/connection_adapters/abstract_adapter.rb:227:in log' /opt/rbenv/versions/ree-1.8.7-2012.02/lib/ruby/gems/1.8/gems/activerecord-2.3.18/lib/active_record/connection_adapters/postgresql_adapter.rb:520:in execute'
/home/e621/e621-production/release-2014-06-08/lib/core_extensions.rb:8:in __send__' /home/e621/e621-production/release-2014-06-08/lib/core_extensions.rb:8:in execute_sql'
/home/e621/e621-production/release-2014-06-08/app/models/post/tag_methods.rb:171:in commit_tags' /home/e621/e621-production/release-2014-06-08/app/models/post/tag_methods.rb:81:in commit_tags'
/home/e621/e621-production/release-2014-06-08/app/controllers/post_controller.rb:283:in update' Request Parameters: {"post"=>{"hide_anon"=>false, "old_tags"=>"anal anal_penetration canine cynder_(sunitai) fox herm intersex knot male mammal nude penetration penis sheath sunitai video_games zander", "rating"=>"Explicit", "description"=>"", "is_rating_locked"=>"0", "source"=>"http://www.furaffinity.net/user/sunitai/\r\nhttp://www.furaffinity.net/view/13874240/\r\nhttp://d.facdn.net/art/sunitai/1404259360.sunitai_kupage6.png", "tags"=>"anal anal_penetration canine cynder_(sunitai) fox intersex knot male mammal nude penetration penis sheath sunitai video_games zander", "hide_google"=>false, "parent_id"=>"", "is_note_locked"=>"0"}, "id"=>"502843", "reason"=>""} Show session dump Response Headers: {"Set-Cookie"=>"blacklisted_tags=adam_wan+animated&gore&washa&jasonafex&blood; path=/\nblacklist_avatars=true; path=/\nblacklist_users=false; path=/", "Content-Type"=>"", "Cache-Control"=>"no-cache"}[/section]

Updated by spight

Halite said:
Getting a deadlock message when I update post #502843

Does not seem to be tied to any particular post IME.

It does make me wonder if deadlocks could be reduced by changing the way tag edits work, so that they are deltas ('remove X and Y tags, add Z tag') instead of replacing the entire set of taggings at once.

IMO this is quite possible on the client side of things (store a copy of the tag list when the user clicks edit, compare the new version with the stored version to arrive at lists of removed and added tags to send.), don't know about the server side.

Updated by anonymous

Char

Former Staff

Fixing all these deadlocks is near the top of the list of issues being worked on right now. We'll let you know once things get worked out.

Updated by anonymous

Char said:
Fixing all these deadlocks is near the top of the list of issues being worked on right now. We'll let you know once things get worked out.

It's always nice to hear the update status on the issue. Thanks, Char.

Out of curiosity, is the "website under heavy load/try back later" type error issue also near the top of the list? Or is that a much bigger problem that will take even longer than this one to resolve? I mean, to a certain degree it just takes as long as it takes. But it is nice to know if there's a ballpark timeframe for it. So I was curious if any was known.

Updated by anonymous

spight

Former Staff

furrypickle said:
It's always nice to hear the update status on the issue. Thanks, Char.

Out of curiosity, is the "website under heavy load/try back later" type error issue also near the top of the list? Or is that a much bigger problem that will take even longer than this one to resolve? I mean, to a certain degree it just takes as long as it takes. But it is nice to know if there's a ballpark timeframe for it. So I was curious if any was known.

I'm pretty much going to be spending my Fourth of July trying to make sure the deadlocks are... well.. dead.

As far as the website under heavy load, I've been tapping and poking things hoping they resolve the issue. As of the last change, which I made earlier this week, the load check is based on the 5 minute load instead of the 1 minute load, so it should occur more accurately. The Load Bug is definitely on our radar, but I don't believe we can outright afford to throw dev time into it since we have other more critical issues.

Updated by anonymous

spight

Former Staff

savageorange said:
...deadlocks could be reduced by changing the way tag edits work, so that they are deltas.

With that statement alone, you're already leaps and bounds ahead of the original developers of this software.

Updated by anonymous

Genjar

Former Staff

It seems to be getting worse: I've barely been able to tag anything this week. Everything either timeouts, or occasionally deadlocks.

I had some problems last week, but nothing like this.

And now everything seems to be working fine.
Even the multi-tag searches (and tag history searches), that used to time out constantly.

Updated by anonymous

spight said:
I'm pretty much going to be spending my Fourth of July trying to make sure the deadlocks are... well.. dead.

As far as the website under heavy load, I've been tapping and poking things hoping they resolve the issue. As of the last change, which I made earlier this week, the load check is based on the 5 minute load instead of the 1 minute load, so it should occur more accurately. The Load Bug is definitely on our radar, but I don't believe we can outright afford to throw dev time into it since we have other more critical issues.

*fingers crossed* but it looks like you might have fixed the tag deadlock issue. It's been working smooth, fast and effortlessly tonight so far (the last hour or so). I was holding off at first to make sure it kept behaving. But I haven't had it deadlock on me yet, so I wanted to say thanks for that! Sorry to hear about your holiday though. Hopefully you still get some time to spend over a grill or catching the fireworks, or whatever your favorite part of the holiday is.

And thanks for the update on the Load Bug. To be honest, I get a lot less frustrated by it when I know it's actually on someone's priority list, even if it's far from the top priority. I can respect that. But thanks for taking a moment to share how things are going. The site gets better every month, and I've noticed that the turnaround time on reported bugs being fixed and some suggestions getting implemented has been pretty fast these days. So I'd say you and the dev team have been doing some great work around here. I know it probably doesn't get mentioned much, but thanks. I really appreciate all the behind-the-surface effort that goes into it. =)

Updated by anonymous

spight

Former Staff

Ok, I pushed an update that should -majorly- optimize tag_implication approval and post updates in general. (The failure rate of deadlock in jobs so far is down from 1-in-3 to... well, I've had a single failure in about 11k jobs so far.

Let me know if you see a ton of deadlocks or any other issues around updating posts' tags.

Updated by anonymous

Genjar

Former Staff

spight said:
Let me know if you see a ton of deadlocks or any other issues around updating posts' tags.

Unfortunately, it seems that I'm currently unable to tag edit anything. I keep getting new kind of error:

PGError: ERROR: duplicate key value violates unique constraint "posts_tags_post_tag_idx"
DETAIL: Key (post_id, tag_id)=(492917, 12196) already exists.
: INSERT INTO "posts_tags" ("tag_id", "post_id") VALUES(12196, 492917) RETURNING "id"

Edit: Only happens if I try to add a tag that's already tagged. So I can edit if I double-check every single tag that I add, but that of course makes tagging about ten times slower. :/

Updated by anonymous

spight

Former Staff

Genjar said:
Unfortunately, it seems that I'm currently unable to tag edit anything. I keep getting new kind of error:

PGError: ERROR: duplicate key value violates unique constraint "posts_tags_post_tag_idx"
DETAIL: Key (post_id, tag_id)=(492917, 12196) already exists.
: INSERT INTO "posts_tags" ("tag_id", "post_id") VALUES(12196, 492917) RETURNING "id"

Edit: Only happens if I try to add a tag that's already tagged. So I can edit if I double-check every single tag that I add, but that of course makes tagging about ten times slower. :/

Thanks for letting me know how to replicate it. I probably just failed some uniqueness checks somewhere. (The code behind posts and tags is... rather complicated in a bad way. :()

Updated by anonymous

spight

Former Staff

Genjar said:
Unfortunately, it seems that I'm currently unable to tag edit anything. I keep getting new kind of error:

PGError: ERROR: duplicate key value violates unique constraint "posts_tags_post_tag_idx"
DETAIL: Key (post_id, tag_id)=(492917, 12196) already exists.
: INSERT INTO "posts_tags" ("tag_id", "post_id") VALUES(12196, 492917) RETURNING "id"

Edit: Only happens if I try to add a tag that's already tagged. So I can edit if I double-check every single tag that I add, but that of course makes tagging about ten times slower. :/

Actually, I'm having trouble replicating this. I see the particular issue here was the character tag "ed" on post #492917. I suspected the issue involved implications or aliases (i.e., maybe I didn't make the tags unique -after- including those aliased and implied tags), but I haven't been able to replicate on my test post (post #504888).

If you can tell me exactly what request you make, it would spur along my troubleshooting greatly.

Updated by anonymous

Genjar

Former Staff

spight said:
If you can tell me exactly what request you make, it would spur along my troubleshooting greatly.

Sorry about that.
After further testing, it seems to only happens if I try to change the tag category, without first removing the existing tag.

For instance, post #492917 is already tagged with ed_edd_and_eddy. Which is currently a general tag. If I try adding something like copyright:ed_edd_and_eddy, I get that error.

Updated by anonymous

spight

Former Staff

Genjar said:
Sorry about that.
After further testing, it seems to only happens if I try to change the tag category, without first removing the existing tag.

For instance, post #492917 is already tagged with ed_edd_and_eddy. Which is currently a general tag. If I try adding something like copyright:ed_edd_and_eddy, I get that error.

...neat.

Updated by anonymous

spight

Former Staff

I'm adding some additional, otherwise-unrelated code to the post/tag relation, and I'll cover this issue with the fix as well.

Updated by anonymous

  • 1