[rt-users] Postgresql default isolation level (was Re: mysql DB engine ndbdcluster)

Václav Ovsík vaclav.ovsik at i.cz
Thu Dec 22 08:03:35 EST 2016 

On Wed, Dec 21, 2016 at 06:38:08PM +0100, Václav Ovsík wrote:
>... 
>  ================================================================
>  * default_transaction_isolation = 'serializable'
>    - I tried the action many times, but Pg is silent - nothing appears
>      in its log file and everything seems normal.

Sorry, this is not true. I did more thorough testing today. I did experiments
on one test ticket and as the history of ticket grows, the probability of the
bug increases. Now it is almost certain the problem will occurs.
Isolation level 'serializable' behaves like 'repeatable read'. So the summary is:

===========================================================
'commited read': -> deadlock, application outputs error:

    Comments added
    Could not change owner: Could not update column Owner: Owner could not be set to 102.

Postgres log:

 2016-12-22 13:18:18 CET [26070-1] rt_rt at rt ERROR:  deadlock detected
 2016-12-22 13:18:18 CET [26070-2] rt_rt at rt DETAIL:  Process 26070 waits for ShareLock on transaction 32889; blocked by process 26097.
         Process 26097 waits for ShareLock on transaction 32890; blocked by process 26070.
         Process 26070: UPDATE Tickets SET Owner=$1 WHERE id=$2 
         Process 26097: INSERT INTO GroupMembers (LastUpdatedBy, Creator, Created, GroupId, MemberId, LastUpdated) VALUES ($1, $2, $3, $4, $5, $6)
 2016-12-22 13:18:18 CET [26070-3] rt_rt at rt HINT:  See server log for query details.
 2016-12-22 13:18:18 CET [26070-4] rt_rt at rt CONTEXT:  while updating tuple (4509,284) in relation "tickets"
 2016-12-22 13:18:18 CET [26070-5] rt_rt at rt STATEMENT:  UPDATE Tickets SET Owner=$1 WHERE id=$2 



===========================================================
'repeatable read'
'serializable':		-> application output normal status:

    Comments added
    Owner changed from eva to zito

Postgres log:
 2016-12-22 13:26:36 CET [31696-1] rt_rt at rt ERROR:  could not serialize access due to concurrent update
 2016-12-22 13:26:36 CET [31696-2] rt_rt at rt STATEMENT:  SELECT * FROM Tickets WHERE id = $1 FOR UPDATE
 2016-12-22 13:26:36 CET [31696-3] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-4] rt_rt at rt STATEMENT:  INSERT INTO Transactions (Type, Creator, ObjectId, NewValue, Field, Data, ObjectType, NewReference, ReferenceType, Created, OldReference, OldValue) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12)
 2016-12-22 13:26:36 CET [31696-5] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-6] rt_rt at rt STATEMENT:  SELECT  * FROM Transactions WHERE id = $1
 2016-12-22 13:26:36 CET [31696-7] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-8] rt_rt at rt STATEMENT:  SELECT  * FROM Tickets WHERE id = $1
 2016-12-22 13:26:36 CET [31696-9] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-10] rt_rt at rt STATEMENT:  SELECT  * FROM Transactions WHERE id = $1
 2016-12-22 13:26:36 CET [31696-11] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-12] rt_rt at rt STATEMENT:  SELECT main.* FROM Scrips main JOIN ObjectScrips ObjectScrips_1  ON ( ObjectScrips_1.Scrip = main.id ) JOIN ScripConditions ScripConditions_2  ON ( ScripConditions_2.id = main.ScripCondition )  WHERE (ObjectScrips_1.ObjectId = '0') AND (ObjectScrips_1.Stage = 'TransactionCreate') AND (ScripConditions_2.ApplicableTransTypes LIKE '%Comment%' OR ScripConditions_2.ApplicableTransTypes LIKE '%Any%') AND (main.Disabled = '0')   GROUP BY main.id   ORDER BY MIN(ObjectScrips_1.SortOrder) ASC 
 2016-12-22 13:26:36 CET [31696-13] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-14] rt_rt at rt STATEMENT:  SELECT COUNT(DISTINCT main.id) FROM Scrips main JOIN ObjectScrips ObjectScrips_1  ON ( ObjectScrips_1.Scrip = main.id ) JOIN ScripConditions ScripConditions_2  ON ( ScripConditions_2.id = main.ScripCondition )  WHERE (ObjectScrips_1.ObjectId = '0') AND (ObjectScrips_1.Stage = 'TransactionCreate') AND (ScripConditions_2.ApplicableTransTypes LIKE '%Comment%' OR ScripConditions_2.ApplicableTransTypes LIKE '%Any%') AND (main.Disabled = '0') 
 2016-12-22 13:26:36 CET [31696-15] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-16] rt_rt at rt STATEMENT:  SELECT main.* FROM Scrips main JOIN ObjectScrips ObjectScrips_1  ON ( ObjectScrips_1.Scrip = main.id ) JOIN ScripConditions ScripConditions_2  ON ( ScripConditions_2.id = main.ScripCondition )  WHERE (ObjectScrips_1.ObjectId = '0') AND (ObjectScrips_1.Stage = 'TransactionCreate') AND (ScripConditions_2.ApplicableTransTypes LIKE '%Comment%' OR ScripConditions_2.ApplicableTransTypes LIKE '%Any%') AND (main.Disabled = '0')   GROUP BY main.id   ORDER BY MIN(ObjectScrips_1.SortOrder) ASC 
 2016-12-22 13:26:36 CET [31696-17] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-18] rt_rt at rt STATEMENT:  SELECT  * FROM Tickets WHERE id = $1
 2016-12-22 13:26:36 CET [31696-19] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-20] rt_rt at rt STATEMENT:  SELECT  * FROM Transactions WHERE id = $1
 2016-12-22 13:26:36 CET [31696-21] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-22] rt_rt at rt STATEMENT:  SELECT  * FROM Tickets WHERE id = $1
 2016-12-22 13:26:36 CET [31696-23] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-24] rt_rt at rt STATEMENT:  UPDATE Tickets SET LastUpdated=$1 WHERE id=$2 
 2016-12-22 13:26:36 CET [31696-25] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-26] rt_rt at rt STATEMENT:  UPDATE Tickets SET LastUpdated=$1 WHERE id=$2 
 2016-12-22 13:26:36 CET [31696-27] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-28] rt_rt at rt STATEMENT:  UPDATE Tickets SET LastUpdated=$1 WHERE id=$2 
 2016-12-22 13:26:36 CET [31696-29] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-30] rt_rt at rt STATEMENT:  SELECT  * FROM Tickets WHERE id = $1
 2016-12-22 13:26:36 CET [31696-31] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-32] rt_rt at rt STATEMENT:  SELECT  * FROM Users WHERE id = $1
 2016-12-22 13:26:36 CET [31696-33] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-34] rt_rt at rt STATEMENT:  SELECT  * FROM Users WHERE id = $1
 2016-12-22 13:26:36 CET [31696-35] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-36] rt_rt at rt STATEMENT:  SELECT  * FROM Principals WHERE id = $1
 2016-12-22 13:26:36 CET [31696-37] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-38] rt_rt at rt STATEMENT:  SELECT main.* FROM Attributes main  WHERE (main.ObjectId = 1900) AND (main.ObjectType = 'RT::User')  ORDER BY main.id ASC 
 2016-12-22 13:26:36 CET [31696-39] rt_rt at rt ERROR:  current transaction is aborted, commands ignored until end of transaction block
 2016-12-22 13:26:36 CET [31696-40] rt_rt at rt STATEMENT:  SELECT main.* FROM Attributes main  WHERE (main.ObjectId = 1900) AND (main.ObjectType = 'RT::User')  ORDER BY main.id ASC 


It seems to me, that a transaction - comment and owner change is processed
by one RT server process and concurrently runs another web server
process gathering data for ticket history. I have a rather long ticket
history now. I added many comments already. The probability of
transaction collision is very high, so the problem occurs every time.

Are there any changes in RT between 4.2 and 4.4 toward loading web page
asynchronously? Is it possible data are loading from browser while
a modify transaction is in progress yet.

-- 
Zito

More information about the rt-users mailing list