RT 4.4.1 and transaction isolation level on Postgres

Vaclav_Ovsik · January 2, 2017, 4:12pm

Hi,
to reproduce the deadlock problem with RT 4.4.1 on Postgres I tried to install
RT 4.4.1 as clean new instalation:
1. On Debian 8.6 stable + Postgres 9.4
2. On Debian sid (unstable) + Postgres 9.6 (there was a need to
change one sql command, option NOCREATEUSER → NOCREATEROLE)

To my surprise I created ticket in queue General (default) and the bug
appeared immediately when I tried to change owner of a ticket and record
comment together.

Can anybody confirm on different system?

Steps:

Create Postgres cluster (server instance):

pg_createcluster 9.6 main --locale cs_CZ.UTF-8
Change access to rt4 database, so I don’t need to set password for rt_user
in /etc/postgresql/9.6/main/pg_hba.conf

diff --git a/postgresql/9.6/main/pg_hba.conf b/postgresql/9.6/main/pg_hba.conf
index b708a885…85857f64 100644
— a/postgresql/9.6/main/pg_hba.conf
+++ b/postgresql/9.6/main/pg_hba.conf
@@ -86,6 +86,8 @@ local all postgres peer

TYPE DATABASE USER ADDRESS METHOD

+local rt4 rt_user trust

“local” is for Unix domain socket connections only

local all all peer

IPv4 local connections:
Start Postgres & check

pg_ctlcluster 9.6 main start
pg_lsclusters
Install RT 4.4.1 from RT sources…

cd rt-4.4.1-sources
./configure --prefix=/opt/rt --with-db-type=Pg
sudo make install

Change db host, so the connection will go through unix domain socket

cd /opt/rt
cat <<‘EOT’ >etc/RT_SiteConfig.pm
Set($WebPort, 8888);
Set($DatabaseHost, undef);
Set($DatabaseRTHost, undef);
1;
EOT

Postgres user needs to read schame etc

chmod a+r etc/{acl,initialdata,schema}*

Postgres 9.6 no longer support NOCREATEUSER, but NOTCREATEROLE
(PostgreSQL: Documentation: 9.6: Release 9.6)

sed -i -e ‘s/NOCREATEUSER/NOCREATEROLE/;’ etc/acl.Pg

Initialize database (if something went wrong, remove not finished database
using ‘sudo -u postgres dropdb rt4’ and try better again)

sudo -u postgres /usr/bin/perl -I/opt/rt/local/lib -I/opt/rt/lib sbin/rt-setup-database --action init
Start RT built int HTTP server by hand:

sudo -u www-data /opt/rt/sbin/rt-server --port 8888
Go to browser and type location localhost:8888
- login as root / password
- click on “New ticket in” General, enter something into subject and message
  and click “Create”
  (Owner is nobody, requestor is root)
- Go Actions / Comment, type something into message and change owner
  to root. Click “Update ticket”
- If owner was changed, try repeat previous step switching owner
  between nobody & root, until error.

My session:

bobek:/opt/rt# sudo -u www-data /opt/rt/sbin/rt-server --port 8888
[21132] [Mon Jan 2 15:58:50 2017] [info]: Successful login for root from 127.0.0.1 (/opt/rt/sbin/…/lib/RT/Interface/Web.pm:831)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372820-1051.1-7-0@example.com #1/31 - Scrip 7 On Create Autoreply To Requestors (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372820-1051.1-7-0@example.com sent To: root@localhost (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:316)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1765.1-8-0@example.com #1/31 - Scrip 8 On Create Notify Owner and AdminCcs (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1765.1-8-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1271.1-9-0@example.com #1/31 - Scrip 9 On Create Notify Ccs (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1271.1-9-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1685.1-10-0@example.com #1/31 - Scrip 10 On Create Notify Other Recipients (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:00:21 2017] [info]: rt-4.4.1-21133-1483372821-1685.1-10-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:00:21 2017] [info]: Ticket 1 created in queue ‘General’ by root (/opt/rt/sbin/…/lib/RT/Ticket.pm:567)
[21132] [Mon Jan 2 16:02:37 2017] [info]: rt-4.4.1-21132-1483372957-1152.1-11-0@example.com not sending to root@localhost, creator of the transaction, due to NotifyActor setting (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:901)
[21133] [Mon Jan 2 16:02:48 2017] [info]: rt-4.4.1-21133-1483372968-1533.1-11-0@example.com not sending to root@localhost, creator of the transaction, due to NotifyActor setting (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:901)
[21133] [Mon Jan 2 16:02:48 2017] [info]: rt-4.4.1-21133-1483372968-1533.1-11-0@example.com #1/39 - Scrip 11 On Owner Change Notify Owner (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:02:48 2017] [info]: rt-4.4.1-21133-1483372968-1533.1-11-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1299.1-1-0@example.com #1/45 - Scrip 1 On Comment Notify AdminCcs as Comment (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1299.1-1-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1044.1-2-0@example.com #1/45 - Scrip 2 On Comment Notify Other Recipients as Comment (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1044.1-2-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1062.1-11-0@example.com #1/46 - Scrip 11 On Owner Change Notify Owner (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21133] [Mon Jan 2 16:03:19 2017] [info]: rt-4.4.1-21133-1483372999-1062.1-11-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21132] [Mon Jan 2 16:03:34 2017] [info]: rt-4.4.1-21132-1483373014-750.1-11-0@example.com not sending to root@localhost, creator of the transaction, due to NotifyActor setting (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:901)
[21140] [Mon Jan 2 16:03:37 2017] [info]: rt-4.4.1-21140-1483373017-415.1-1-0@example.com #1/53 - Scrip 1 On Comment Notify AdminCcs as Comment (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21140] [Mon Jan 2 16:03:37 2017] [info]: rt-4.4.1-21140-1483373017-415.1-1-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21140] [Mon Jan 2 16:03:37 2017] [info]: rt-4.4.1-21140-1483373017-851.1-2-0@example.com #1/53 - Scrip 2 On Comment Notify Other Recipients as Comment (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:285)
[21140] [Mon Jan 2 16:03:37 2017] [info]: rt-4.4.1-21140-1483373017-851.1-2-0@example.com No recipients found. Not sending. (/opt/rt/sbin/…/lib/RT/Interface/Email.pm:806)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: DBD::Pg::st execute failed: ERROR: deadlock detected
DETAIL: Process 21479 waits for ShareLock on transaction 1134; blocked by process 21157.
Process 21157 waits for ShareLock on transaction 1135; blocked by process 21479.
HINT: See server log for query details.
CONTEXT: while updating tuple (0,21) in relation “tickets” at /usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 586. (/usr/share/perl5/DBIx/SearchBuilder/Handle.pm:586)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: RT::Handle=HASH(0x55fc4d97fd18) couldn’t execute the query 'UPDATE Tickets SET Owner=? WHERE id=? ’ at /usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 599.
DBIx::SearchBuilder::Handle::SimpleQuery(RT::Handle=HASH(0x55fc4d97fd18), "UPDATE Tickets SET Owner=? WHERE id=? ", 14, 1) called at /usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 453
DBIx::SearchBuilder::Handle::UpdateRecordValue(RT::Handle=HASH(0x55fc4d97fd18), “Column”, “Owner”, “Table”, “Tickets”, “PrimaryKeys”, HASH(0x55fc4de23ab8), “Value”, …) called at /usr/share/perl5/DBIx/SearchBuilder/Record.pm line 871
DBIx::SearchBuilder::Record::__Set(RT::Ticket=HASH(0x55fc4dce9210), “Field”, “Owner”, “Value”, 14, “IsSQL”, undef) called at /usr/share/perl5/DBIx/SearchBuilder/Record/Cachable.pm line 140
DBIx::SearchBuilder::Record::Cachable::__Set(RT::Ticket=HASH(0x55fc4dce9210), “Field”, “Owner”, “Value”, 14, “IsSQL”, undef) called at /usr/share/perl5/DBIx/SearchBuilder/Record.pm line 744
DBIx::SearchBuilder::Record::_Set(RT::Ticket=HASH(0x55fc4dce9210), “Field”, “Owner”, “Value”, 14, “IsSQL”, undef) called at /opt/rt/sbin/…/lib/RT/Record.pm line 462
RT::Record::_Set(RT::Ticket=HASH(0x55fc4dce9210), “Field”, “Owner”, “Value”, 14) called at /opt/rt/sbin/…/lib/RT/Ticket.pm line 2634
RT::_Set(RT::Ticket=HASH(0x55fc4dce9210), “Field”, “Owner”, “Value”, 14, “CheckACL”, 0, “RecordTransaction”, …) called at /opt/rt/sbin/…/lib/RT/Group.pm line 993
RT::Group::_AddMember(RT::Group=HASH(0x55fc4db25448), “PrincipalId”, 14, “InsideTransaction”, 1, “Object”, RT::Ticket=HASH(0x55fc4dce9210)) called at /opt/rt/sbin/…/lib/RT/Ticket.pm line 1968
RT::SetOwner(RT::Ticket=HASH(0x55fc4dce9210), 14, “Set”) called at /opt/rt/sbin/…/lib/RT/Interface/Web.pm line 2975
HTML::Mason::Commands::ProcessTicketBasics(“ARGSRef”, HASH(0x55fc4dc9a470), “TicketObj”, RT::Ticket=HASH(0x55fc4dce9210)) called at /opt/rt/share/html/Ticket/Display.html line 190
HTML::Mason::Commands::ANON(“TicketObj”, RT::Ticket=HASH(0x55fc4dce9210), “SubmitTicket”, “Update Ticket”, “TxnRecipients”, “”, “QuoteTransaction”, “”, …) called at /usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dc8e118), “TicketObj”, RT::Ticket=HASH(0x55fc4dce9210), “SubmitTicket”, “Update Ticket”, “TxnRecipients”, “”, “QuoteTransaction”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, “TicketObj”, RT::Ticket=HASH(0x55fc4dce9210), “SubmitTicket”, “Update Ticket”, “TxnRecipients”, “”, …) called at /opt/rt/share/html/Ticket/Update.html line 347
HTML::Mason::Commands::ANON(“UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, “new”, “UpdateBcc”, “”, …) called at /usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dbdba78), “UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, “new”, “UpdateBcc”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, “UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 955
HTML::Mason::Request::call_next(RT::Interface::Web::Request=HASH(0x55fc4d5afea0)) called at /opt/rt/share/html/Ticket/autohandler line 66
HTML::Mason::Commands::ANON(“UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, “new”, “UpdateBcc”, “”, …) called at /usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4dbf6580), “UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, “new”, “UpdateBcc”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 1302
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, “UpdateTimeWorked”, “”, “Action”, “Comment”, “DefaultStatus”, …) called at /opt/rt/sbin/…/lib/RT/Interface/Web.pm line 696
RT::Interface::Web::ShowRequestedPage(HASH(0x55fc4da121e8)) called at /opt/rt/sbin/…/lib/RT/Interface/Web.pm line 375
RT::Interface::Web::HandleRequest(HASH(0x55fc4da121e8)) called at /opt/rt/share/html/autohandler line 53
HTML::Mason::Commands::ANON(“QuoteTransaction”, “”, “TxnRecipients”, “”, “SubmitTicket”, “Update Ticket”, “UpdateTimeWorked-TimeUnits”, “minutes”, …) called at /usr/share/perl5/HTML/Mason/Component.pm line 135
HTML::Mason::Component::run(HTML::Mason::Component::FileBased=HASH(0x55fc4d9d0930), “QuoteTransaction”, “”, “TxnRecipients”, “”, “SubmitTicket”, “Update Ticket”, “UpdateTimeWorked-TimeUnits”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 1300
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 1292
HTML::Mason::Request::comp(undef, undef, undef, “QuoteTransaction”, “”, “TxnRecipients”, “”, “SubmitTicket”, …) called at /usr/share/perl5/HTML/Mason/Request.pm line 481
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 481
eval {…} called at /usr/share/perl5/HTML/Mason/Request.pm line 433
HTML::Mason::Request::exec(RT::Interface::Web::Request=HASH(0x55fc4d5afea0)) called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 96
eval {…} called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 96
HTML::Mason::Request::PSGI::exec(RT::Interface::Web::Request=HASH(0x55fc4d5afea0)) called at /usr/share/perl5/HTML/Mason/Interp.pm line 342
HTML::Mason::Interp::exec(undef, undef, “QuoteTransaction”, “”, “TxnRecipients”, “”, “SubmitTicket”, “Update Ticket”, …) called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 59
eval {…} called at /usr/share/perl5/HTML/Mason/PSGIHandler.pm line 59
HTML::Mason::PSGIHandler::invoke_mason(HTML::Mason::PSGIHandler::Streamy=HASH(0x55fc4d5ae0a8), HASH(0x55fc4d9c9e38), HASH(0x55fc4d9b4de8)) called at /usr/share/perl5/HTML/Mason/PSGIHandler/Streamy.pm line 52
HTML::Mason::PSGIHandler::Streamy::ANON(CODE(0x55fc4d9b4ba8)) called at /usr/share/perl5/Plack/Util.pm line 339
Plack::Util::ANON(CODE(0x55fc4dcc5180)) called at /usr/share/perl5/Starlet/Server.pm line 377
Starlet::Server::handle_connection(Plack::Handler::Starlet=HASH(0x55fc4d79b858), HASH(0x55fc4da86f38), IO::Socket::INET=GLOB(0x55fc4d9c9b80), CODE(0x55fc4d353d00), “”, “”, “”) called at /usr/share/perl5/Starlet/Server.pm line 190
Starlet::Server::accept_loop(Plack::Handler::Starlet=HASH(0x55fc4d79b858), CODE(0x55fc4d353d00), 100) called at /usr/share/perl5/Plack/Handler/Starlet.pm line 80
Plack::Handler::Starlet::run(Plack::Handler::Starlet=HASH(0x55fc4d79b858), CODE(0x55fc4d353d00)) called at /usr/share/perl5/Plack/Loader.pm line 84
Plack::Loader::run(Plack::Loader=HASH(0x55fc4d45ee08), Plack::Handler::Starlet=HASH(0x55fc4d79b858)) called at /usr/share/perl5/Plack/Runner.pm line 277
Plack::run(RT::PlackRunner=HASH(0x55fc46c5af10)) called at /opt/rt/sbin/…/lib/RT/PlackRunner.pm line 141
eval {…} called at /opt/rt/sbin/…/lib/RT/PlackRunner.pm line 141
RT::PlackRunner::run(RT::PlackRunner=HASH(0x55fc46c5af10)) called at /opt/rt/sbin/rt-server line 162 (/usr/share/perl/5.24/Carp.pm:170)
[21140] [Mon Jan 2 16:03:38 2017] [warning]: Rollback and commit are mixed while escaping nested transaction at /usr/share/perl5/DBIx/SearchBuilder/Handle.pm line 845. (/usr/share/perl5/DBIx/SearchBuilder/Handle.pm:845)
[21131] [Mon Jan 2 16:03:38 2017] [info]: rt-4.4.1-21131-1483373018-15.1-11-0@example.com not sending to root@localhost, creator of the transaction, due to NotifyActor setting (/opt/rt/sbin/…/lib/RT/Action/SendEmail.pm:901)

PS: I reported this problem already on Login
#32381: RT 4.4 database deadlock during comment/correspondence + owner change together

Zito

chmrr · January 3, 2017, 4:10am

Can anybody confirm on different system?

Thanks for the detailed replication instructions. I can replicate, and
have tracked down a minimal replication case. I’ll drop my findings
and suggestion on your ticket.

The short form is that this is due to 4.4’s new PreviewScrips
functionality, which simulates (then rolls back) all of the changes,
which is racing with the actual change. The bad news is that it’s the
real change, not the dry run, which gets killed in the deadlock
detector, meaning that the owner does go unchanged. At least this is
bubbled up to the user in the ticket display page, but this is still
quite unfortunate.

Amusingly, there are some strong parallels to the canonical Therac-25
case[1] – the race here requires that one trigger a PreviewScrips very
quickly before submitting, which is rare except with users quite
accustomed to the UI. In the Therac-25 case, only skilled users
could navigate to the bottom of the form within 8 seconds and thus
deliver lethal doses of radiation to their patients.

…RT is designed to be robust, but there’s a reason it doesn’t rate
itself as meant to be used for safety- or life-critical applications.

Alex

[1] Therac-25 - Wikipedia

Vaclav_Ovsik · January 3, 2017, 4:06pm

Can anybody confirm on different system?

Thanks for the detailed replication instructions. I can replicate, and
have tracked down a minimal replication case. I’ll drop my findings
and suggestion on your ticket.
…

Great, thank you very much for your time and effort!

How about the Mysql don’t have this problem - is this caused by
the different default transaction isolation level or not?

I can change isolation level in postgresql.conf to ‘repeatable read’
and things are different.

Should I change the default isolation level on Postgres for RT to
‘repeatable read’?

Zito

chmrr · January 4, 2017, 12:50pm

How about the Mysql don’t have this problem - is this caused by
the different default transaction isolation level or not?

MySQL suffers from the exact same problem – but, as it happens,
both more silently and more catastrophically. See

github.com/bestpractical/rt

Add a test showing transaction deadlocks with concurrent ticket updates

committed 08:53AM - 04 Jan 17 UTC

alexmv

+75 -1

Ticket updates can deadlock due to their haphazard use of transactions; this tes…t attempts to trigger such deadlocks. The real-world scenario is that PreviewScrips opens a transaction and (via ->_NewTransaction to record correspondence) calls ->LockForUpdate to lock the ticket object. Meanwhile, the real update has been submitted, and calls ->SetOwner outside of a transaction. On PostgreSQL, the deadlock aborts and rolls back the SetOwner transaction; database integrity is preserved, but only one SetOwner succeeds: DBD::Pg::st execute failed: ERROR: deadlock detected DETAIL: Process 27554 waits for ShareLock on transaction 862271; blocked by process 27555. Process 27555 waits for ShareLock on transaction 862270; blocked by process 27554. HINT: See server log for query details. CONTEXT: while deleting tuple (0,104) in relation "cachedgroupmembers" RT::Handle=HASH(0x6409108) couldn't execute the query 'DELETE FROM CachedGroupMembers WHERE id=? ' [stacktrace omitted] DBD::Pg::st execute failed: ERROR: current transaction is aborted, commands ignored until end of transaction block RT::Handle=HASH(0x6409108) couldn't execute the query 'DELETE FROM GroupMembers WHERE id=? ' [stacktrace omitted] Couldn't delete cached group submember 22 Use of uninitialized value $_[1] in join or string at (eval 272) line 2. Rollback and commit are mixed while escaping nested transaction/warn not ok 5 - 27552 returned 1 # Failed test '27552 returned 1' # at t/ticket/race.t line 106. # got: '1' # expected: '0' ok 6 - 27553 returned 0 not ok 7 - Found two new SetWatcher transactions # Failed test 'Found two new SetWatcher transactions' # at t/ticket/race.t line 117. # got: '1' # expected: '2' ok 8 - Not the base owner ok 9 - GroupMembers agrees ok 10 - CachedGroupMembers agrees On mysql, the outcome is worse -- deadlock does not abort the transaction, it merely causes that statement to fail, with a gentle suggestion to restart the transaction. Because of bugs propagating this error up, this becomes a mostly-silent corruption of database consistency, with the denormalized 'Owner' column disagreeing with GroupMembers and CachedGroupMembers for the group: DBD::mysql::st execute failed: Deadlock found when trying to get lock; try restarting transaction RT::Handle=HASH(0x5f63cc8) couldn't execute the query 'DELETE FROM CachedGroupMembers WHERE id=? ' [stacktrace omitted] ok 5 - 805 returned 0 ok 6 - 806 returned 0 ok 7 - Found two new SetWatcher transactions ok 8 - Not the base owner not ok 9 - GroupMembers agrees # Failed test 'GroupMembers agrees' # at t/ticket/race.t line 121. not ok 10 - CachedGroupMembers agrees # Failed test 'CachedGroupMembers agrees' # at t/ticket/race.t line 122. The following commits address these issues.

I can change isolation level in postgresql.conf to ‘repeatable read’
and things are different.

I advise against doing that. Upon inspection, RT is not prepared to
deal with the “could not serialize access due to concurrent update”
errors that arise from updates to rows in multiple transactions in
Postgres’ repeatable-read isolation.

Repeatable-read is only possible in MySQL because it has a fascinating
definition of “repeatable”:

----------------------------- Process 1 ------------------------
mysql> set transaction isolation level repeatable read;
Query OK, 0 rows affected (0.00 sec)

mysql> start transaction with consistent snapshot;
Query OK, 0 rows affected (0.00 sec)

mysql> select id, Subject from Tickets where id = 1;
| id | Subject |
| 1 | foo |
1 row in set (0.00 sec)

----------------------------- Process 2 ------------------------

mysql> set transaction isolation level repeatable read;
Query OK, 0 rows affected (0.00 sec)

mysql> start transaction with consistent snapshot;
Query OK, 0 rows affected (0.00 sec)

mysql> update Tickets set Subject = ‘bar’ where id = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0

mysql> commit;
Query OK, 0 rows affected (0.00 sec)

----------------------------- Process 1 ------------------------

mysql> select id, Subject from Tickets where id = 1;
| id | Subject |
| 1 | foo |
1 row in set (0.00 sec)

mysql> select id, Subject from Tickets where id = 1 FOR UPDATE;
| id | Subject |
| 1 | bar |
1 row in set (0.00 sec)

Contrast this with PostgreSQL, whose definition of repeatable read
acknowledges that fully consistent updates are not possible in all
cases:

----------------------------- Process 1 ------------------------
rt4=# start transaction;
START TRANSACTION
rt4=# set transaction isolation level repeatable read;
SET
rt4=# select id, Subject from Tickets where id = 1;
id | subject
1 | foo
(1 row)

----------------------------- Process 2 ------------------------
rt4=# start transaction;
START TRANSACTION
rt4=# set transaction isolation level repeatable read;
SET
rt4=# update Tickets set Subject = ‘bar’ where id = 1;
UPDATE 1
rt4=# commit;
COMMIT

----------------------------- Process 1 ------------------------
rt4=# select id, Subject from Tickets where id = 1;
id | subject
1 | foo
(1 row)

rt4=# select id, Subject from Tickets where id = 1 FOR UPDATE;
ERROR: could not serialize access due to concurrent update

( Yes, MySQL requires SET TRANSACTION ISOLATION outside the
transaction, and PostgreSQL requires it to be inside. See
https://dev.mysql.com/doc/refman/5.7/en/set-transaction.html
PostgreSQL: Documentation: 9.1: SET TRANSACTION )

Should I change the default isolation level on Postgres for RT to
‘repeatable read’?

No. You should try the 4.4/previewscrips-race branch, which I’ve just
pushed:

https://github.com/bestpractical/rt/compare/4.4-trunk...4.4/previewscrips-race

The gory details are contained in the commits therein.

Alex

Vaclav_Ovsik · January 4, 2017, 5:48pm

…
MySQL suffers from the exact same problem – but, as it happens,
both more silently and more catastrophically. See
Add a test showing transaction deadlocks with concurrent ticket updates · bestpractical/rt@e36364c · GitHub

Eh. I’m glad I did transition from Mysql to Postgres years ago :).

I can change isolation level in postgresql.conf to ‘repeatable read’
and things are different.

I advise against doing that. Upon inspection, RT is not prepared to
deal with the “could not serialize access due to concurrent update”
errors that arise from updates to rows in multiple transactions in
Postgres’ repeatable-read isolation.

OK, thanks!

Repeatable-read is only possible in MySQL because it has a fascinating
definition of “repeatable”:
…

Should I change the default isolation level on Postgres for RT to
‘repeatable read’?

No. You should try the 4.4/previewscrips-race branch, which I’ve just
pushed:

https://github.com/bestpractical/rt/compare/4.4-trunk...4.4/previewscrips-race

The gory details are contained in the commits therein.

You have my respect! Wonderful job. I tried your changes on my test
instance first. The problem is solved I think.
I installed changes to production instance too.
Thanks for your time and effort!
Zito

RT 4.4.1 and transaction isolation level on Postgres

TYPE DATABASE USER ADDRESS METHOD

“local” is for Unix domain socket connections only

IPv4 local connections: