|
Sort Order:
I've been getting them as well, about every 4th artist split edit I've tried to enter in the past day or so. My only guess as to what is happening here is:
Now, if Edit X takes a while to make its changes, Edit Y could rush ahead and credit the editor. Now, when edit X comes to credit the editor, there is already a lock on this row (implicit, from the UPDATE on the editor table), and this happens. I don't know how to fix this problem though. Presumably we need to lock something, but I don't know what that something is. We could lock the editor row at the start of an edit, so only that only one edit can be applied at once, and force the other edit to wait until this one has applied? I get tons of deadlocks when I have multiple release editor sessions open (>10) and I cycle through the tabs to submit them all at once (which is a common workflow when I have to edit the same thing on many releases at once). A bunch of the requests always end in deadlock for me, so it's very easy to reproduce using this method. As this issue has been delayed, I am moving it back to be rescheduled. I think pessimistically locking the editor table at the start of the edit transaction is the correct thing to do here, if ocharles' assessment is correct as to the cause. Internal Server Error
Oops, something went wrong!
Error:
Caught exception in MusicBrainz::Server::Controller::URL->edit "The edit could not be created.
POST: $VAR1 = {
'edit-url.as_auto_editor' => '1',
'edit-url.description' => '',
'edit-url.url' => 'http://itunes.apple.com/album/id506043907',
'edit-url.edit_note' => ''
};
Exception:$VAR1 = 'DBD::Pg::st execute failed: ERROR: deadlock detected
DETAIL: Process 29659 waits for ShareLock on tuple (10540,33) of relation 1514451 of database 1416385; blocked by process 29645.
Process 29645 waits for ShareLock on transaction 444400218; blocked by process 29217.
Process 29217 waits for ExclusiveLock on tuple (10540,33) of relation 1514451 of database 1416385; blocked by process 29659.
HINT: See server log for query details.
CONTEXT: SQL statement "SELECT 1 FROM ONLY "musicbrainz"."editor" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x" at lib/Sql.pm line 409.
at lib/Sql.pm line 423
Sql::__ANON__(\'DBD::Pg::st execute failed: ERROR: deadlock detected\\x{a}DETAIL:...\') called at local/lib/perl5/Try/Tiny.pm line 100
Try::Tiny::try(\'CODE(0xed8d330)\', \'Try::Tiny::Catch=REF(0xed79a90)\') called at lib/Sql.pm line 424
Sql::_select_list(\'Sql=HASH(0xb7016e8)\', \'INSERT INTO edit (status,data,close_time,open_time,editor,typ...\', \'ARRAY(0x4d26fa0)\', \'arrayref\', \'CODE(0x4d27018)\') called at lib/Sql.pm line 443
Sql::select_list_of_lists(\'Sql=HASH(0xb7016e8)\', \'INSERT INTO edit (status,data,close_time,open_time,editor,typ...\', 1, \'{"entity":{"name":"http://itunes.apple.com/album/they-found-y...\', undef, \'DateTime=HASH(0xed7a2a0)\', 53705, 101, \'DateTime=HASH(0xed7a660)\', ...) called at lib/Sql.pm line 377
Sql::select_single_column_array(\'Sql=HASH(0xb7016e8)\', \'INSERT INTO edit (status,data,close_time,open_time,editor,typ...\', 1, \'{"entity":{"name":"http://itunes.apple.com/album/they-found-y...\', undef, \'DateTime=HASH(0xed7a2a0)\', 53705, 101, \'DateTime=HASH(0xed7a660)\', ...) called at lib/Sql.pm line 392
Sql::select_single_value(\'Sql=HASH(0xb7016e8)\', \'INSERT INTO edit (status,data,close_time,open_time,editor,typ...\', 1, \'{"entity":{"name":"http://itunes.apple.com/album/they-found-y...\', undef, \'DateTime=HASH(0xed7a2a0)\', 53705, 101, \'DateTime=HASH(0xed7a660)\', ...) called at lib/Sql.pm line 146
Sql::insert_row(\'Sql=HASH(0xb7016e8)\', \'edit\', \'HASH(0xed83de8)\', \'id\') called at lib/MusicBrainz/Server/Data/Edit.pm line 404
MusicBrainz::Server::Data::Edit::create(\'MusicBrainz::Server::Data::Edit=HASH(0xa025e10)\', \'editor_id\', 53705, \'privileges\', 185, \'url\', \'http://itunes.apple.com/album/id506043907\', \'edit_type\', 101, ...) called at lib/MusicBrainz/Server/Controller.pm line 85
MusicBrainz::Server::Controller::__ANON__() called at local/lib/perl5/Try/Tiny.pm line 76
eval {...} called at local/lib/perl5/Try/Tiny.pm line 67
Try::Tiny::try(\'CODE(0xc7657b0)\', \'Try::Tiny::Catch=REF(0xc7656d8)\') called at lib/MusicBrainz/Server/Controller.pm line 101
MusicBrainz::Server::Controller::_insert_edit(\'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Form::URL=HASH(0x747f3e0)\', \'edit_type\', 101, \'url\', \'http://itunes.apple.com/album/id506043907\', \'description\', undef, ...) called at lib/MusicBrainz/Server/Controller.pm line 136
MusicBrainz::Server::Controller::__ANON__() called at lib/Sql.pm line 277
Sql::__ANON__() called at local/lib/perl5/Try/Tiny.pm line 76
eval {...} called at local/lib/perl5/Try/Tiny.pm line 67
Try::Tiny::try(\'CODE(0xc765438)\', \'Try::Tiny::Catch=REF(0xc680530)\') called at lib/Sql.pm line 290
Sql::_auto_transaction(\'CODE(0xc7652d0)\', \'Sql=HASH(0xb7016e8)\') called at lib/Sql.pm line 295
Sql::_run_in_transaction_one(\'CODE(0xc7652d0)\', \'Sql=HASH(0xb7016e8)\') called at lib/Sql.pm line 309
Sql::run_in_transaction(\'CODE(0xc7652d0)\', \'Sql=HASH(0xb7016e8)\') called at lib/MusicBrainz/Server/Model/MB.pm line 17
MusicBrainz::Server::Model::MB::with_transaction(\'MusicBrainz::Server::Model::MB=HASH(0x99c1be0)\', \'CODE(0xc7652d0)\') called at lib/MusicBrainz/Server/Controller.pm line 144
MusicBrainz::Server::Controller::edit_action(\'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'form\', \'URL\', \'type\', 101, \'item\', \'MusicBrainz::Server::Entity::URL=HASH(0xc3331d0)\', \'edit_args\', ...) called at lib/MusicBrainz/Server/Controller/Role/Edit.pm line 37
Moose::Meta::Role::__ANON__::SERIAL::33::edit(\'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Action.pm line 65
Catalyst::Action::execute(\'Catalyst::Action=HASH(0xb31c048)\', \'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst.pm line 1667
eval {...} called at local/lib/perl5/Catalyst.pm line 1667
Catalyst::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31c048)\') called at local/lib/perl5/Catalyst/Plugin/StackTrace.pm line 94
Catalyst::Plugin::StackTrace::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31c048)\') called at lib/MusicBrainz/Server.pm line 306
MusicBrainz::Server::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31c048)\') called at local/lib/perl5/Catalyst/Action.pm line 60
Catalyst::Action::dispatch(\'Catalyst::Action=HASH(0xb31c048)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/ActionChain.pm line 38
Catalyst::ActionChain::dispatch(\'Catalyst::ActionChain=HASH(0xbec37f8)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Controller.pm line 125
Catalyst::Controller::_ACTION(\'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Action.pm line 65
Catalyst::Action::execute(\'Catalyst::Action=HASH(0xb31a670)\', \'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst.pm line 1667
eval {...} called at local/lib/perl5/Catalyst.pm line 1667
Catalyst::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31a670)\') called at local/lib/perl5/Catalyst/Plugin/StackTrace.pm line 94
Catalyst::Plugin::StackTrace::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31a670)\') called at lib/MusicBrainz/Server.pm line 306
MusicBrainz::Server::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb31a670)\') called at local/lib/perl5/Catalyst/Action.pm line 60
Catalyst::Action::dispatch(\'Catalyst::Action=HASH(0xb31a670)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Dispatcher.pm line 257
Catalyst::Dispatcher::_do_forward(\'Catalyst::Dispatcher=HASH(0x3643780)\', \'forward\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'_ACTION\') called at local/lib/perl5/Catalyst/Dispatcher.pm line 237
Catalyst::Dispatcher::forward(\'Catalyst::Dispatcher=HASH(0x3643780)\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'_ACTION\') called at local/lib/perl5/Catalyst.pm line 342
Catalyst::forward(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'_ACTION\') called at local/lib/perl5/Catalyst/Controller.pm line 99
Catalyst::Controller::_DISPATCH(\'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Action.pm line 65
Catalyst::Action::execute(\'Catalyst::Action=HASH(0xb316fe8)\', \'MusicBrainz::Server::Controller::URL=HASH(0xb0bca68)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst.pm line 1667
eval {...} called at local/lib/perl5/Catalyst.pm line 1667
Catalyst::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb316fe8)\') called at local/lib/perl5/Catalyst/Plugin/StackTrace.pm line 94
Catalyst::Plugin::StackTrace::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb316fe8)\') called at lib/MusicBrainz/Server.pm line 306
MusicBrainz::Server::execute(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'MusicBrainz::Server::Controller::URL\', \'Catalyst::Action=HASH(0xb316fe8)\') called at local/lib/perl5/Catalyst/Action.pm line 60
Catalyst::Action::dispatch(\'Catalyst::Action=HASH(0xb316fe8)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst/Dispatcher.pm line 257
Catalyst::Dispatcher::_do_forward(\'Catalyst::Dispatcher=HASH(0x3643780)\', \'forward\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'/url/_DISPATCH\') called at local/lib/perl5/Catalyst/Dispatcher.pm line 237
Catalyst::Dispatcher::forward(\'Catalyst::Dispatcher=HASH(0x3643780)\', \'MusicBrainz::Server=HASH(0xb6f3428)\', \'/url/_DISPATCH\') called at local/lib/perl5/Catalyst.pm line 342
Catalyst::forward(\'MusicBrainz::Server=HASH(0xb6f3428)\', \'/url/_DISPATCH\') called at local/lib/perl5/Catalyst/Dispatcher.pm line 105
Catalyst::Dispatcher::dispatch(\'Catalyst::Dispatcher=HASH(0x3643780)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst.pm line 1613
Catalyst::dispatch(\'MusicBrainz::Server=HASH(0xb6f3428)\') called at lib/MusicBrainz/Server.pm line 270
Class::MOP::Class:::around(\'CODE(0x2e9f498)\', \'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/x86_64-linux-gnu-thread-multi/Class/MOP/Method/Wrapped.pm line 162
Class::MOP::Method::Wrapped::__ANON__(\'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/x86_64-linux-gnu-thread-multi/Class/MOP/Method/Wrapped.pm line 91
MusicBrainz::Server::dispatch(\'MusicBrainz::Server=HASH(0xb6f3428)\') called at local/lib/perl5/Catalyst.pm line 1963
Catalyst::__ANON__() called at local/lib/perl5/Try/Tiny.pm line 76
eval {...} called at local/lib/perl5/Try/Tiny.pm line 67
Try::Tiny::try(\'CODE(0xbc1b8a8)\', \'Try::Tiny::Catch=REF(0xbe9ad50)\') called at local/lib/perl5/Catalyst.pm line 1969
Catalyst::handle_request(\'MusicBrainz::Server\', \'env\', \'HASH(0xb6d7888)\') called at local/lib/perl5/Catalyst/Plugin/AutoRestart.pm line 114
Catalyst::Plugin::AutoRestart::handle_request(\'MusicBrainz::Server\', \'env\', \'HASH(0xb6d7888)\') called at local/lib/perl5/Catalyst/Engine.pm line 856
Catalyst::Engine::__ANON__(\'CODE(0xb6ece08)\') called at local/lib/perl5/Plack/Handler/FCGI.pm line 134
Plack::Handler::FCGI::run(\'Plack::Handler::FCGI=HASH(0x133da30)\', \'CODE(0xb656008)\') called at local/lib/perl5/Plack/Loader.pm line 88
Plack::Loader::run(\'Plack::Loader=HASH(0x1306e00)\', \'Plack::Handler::FCGI=HASH(0x133da30)\') called at local/lib/perl5/Plack/Runner.pm line 263
Plack::Runner::run(\'Plack::Runner=HASH(0x1109808)\') called at local/bin/plackup line 10
';
at lib/MusicBrainz/Server/Controller.pm line 101
at lib/Sql.pm line 290"
Stack trace:
line 17 MusicBrainz::Server::Model::MB
line 144 MusicBrainz::Server::Controller
line 37 MusicBrainz::Server::Controller::Role::Edit
line 306 MusicBrainz::Server
line 306 MusicBrainz::Server
line 306 MusicBrainz::Server
line 270 MusicBrainz::Server
Request data:
$VAR1 = {
'query_parameters' => {},
'body_parameters' => {
'edit-url.as_auto_editor' => '1',
'edit-url.description' => '',
'edit-url.url' => 'http://itunes.apple.com/album/id506043907',
'edit-url.edit_note' => ''
}
};
URL: http://musicbrainz.org/url/70d79d44-db58-4185-92c7-a2c14f08ea1e/edit
This appears to be the "other end" of this deadlock. Hm, maybe not, since that one's showing a three-way deadlock rather than the two-link one above. Okay, researching further, and getting another stacktrace from nikki to match the one two comments up: one of these deadlocks is happening in Data::Edit::create when it's entering the edit, and the other is happening later when it credits the editor. Fix will be slightly different than what I'd pushed before, but it'll be: if the edit's an autoedit, lock the editor row before inserting the edit, so the transaction doesn't try to do a lock escalation (from Share, needed for inserting the edit, to Exclusive, needed for updating the editor row), which is what's causing the deadlock. Caught exception in MusicBrainz::Server::Controller::Recording->edit "The edit could not be created. URL: http://musicbrainz.org/recording/356e64c5-82eb-4ece-a843-4619c81dbb3f/edit Had a thought on this: the issue definitely only comes up for autoedits, so: might it be valuable to enter autoedits using two transactions (one for making the edit, a second for accepting it), so they're more like normal edits? This would presumably also result in killing off the lock-escalation problems we have, since the first transaction really would only need the Share locks and the second would request Exclusive right away. The only problem I see is if the first succeeds but the second doesn't – but if we're setting expire_time correctly, that should just mean the edit gets re-tried when modbot comes along. Thoughts? My thoughts are still exactly the same as before, instead of hypothesizing where the problem might be, get someone to give us steps to reproduce, log all queries it does, and analyze these for triggers and locks that are created. Then we can manually determine what's actually deadlocking, and work out appropriate steps to go forward. Option B: The more you do, the higher the probability of triggering at least one deadlock. ocharles: let's be real clear here – that path is only available to people with production database access, such as you, and none of you are actually doing it. Which is why I started looking at this using other methods. I can definitely say that we're escalating our locks on some tables, for autoedits, which is exactly what the postgresql manual says to avoid in order to avoid deadlocks – should I put in a different bug for that, then? I'd figured it was probably okay to reuse this bug, given the rather high likelihood that they're related and that, once again: I cannot do that diagnosis you seem to insist on. Why is that path only available to the production DB? The production DB runs the exact same code as all other machines such as sandboxes. I'm not insisting on some formal proofs, but you're adding more locks and I want to be absolutely 100% positive that we are doing the correct thing. That is all. Throwing more locks at things could make things worse if we get it wrong. Until we don't have a reproducible case that doesn't happen when we apply certain changes, how can I apply this patch? If I start applying things on trust I'm not doing my job, am I? |
||||||||||||||||||||||||||||||||||||||||||||||||||
Bug
Closed
Normal
Internal Server Error (deadlock detected)
I've been getting deadlocks in several places (edit release group, edit release and edit url are the places I've seen it so far), but I seem to be getting huge amounts while trying to edit Amazon URLs. I'm already up to 48 in just two hours.
As I mentioned on IRC a while back, I didn't see a single deadlock between the launch of NGS and when I reported this ticket.
Rob thought vacuuming the database might help, but it doesn't seem to have.