Re: Trigger and deadlock

Поиск
Список
Период
Сортировка
От Loïc Rollus
Тема Re: Trigger and deadlock
Дата
Msg-id CADUcbP-RGjvvxKwg_78hoAc2dpzj7Sc0ts-CLCZer3a7_hTvEw@mail.gmail.com
обсуждение исходный текст
Ответ на Re: Trigger and deadlock  (Loïc Rollus <loicrollus@gmail.com>)
Ответы Re: Trigger and deadlock  (Loïc Rollus <loicrollus@gmail.com>)
Список pgsql-general
 Here is pg_lock for relation Y (= 2027300)


 locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid  |       mode       | granted 
----------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+------------------+---------
 tuple    |  2026760 |  2027300 |  365 |    42 |            |               |         |       |          | 6/313              | 9274 | ShareLock        | f
 tuple    |  2026760 |  2027300 |  365 |    42 |            |               |         |       |          | 5/113              | 9273 | ExclusiveLock    | f
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 3/2532             | 9104 | AccessShareLock  | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 3/2532             | 9104 | RowShareLock     | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 3/2532             | 9104 | RowExclusiveLock | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 5/113              | 9273 | AccessShareLock  | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 5/113              | 9273 | RowShareLock     | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 5/113              | 9273 | RowExclusiveLock | t
 tuple    |  2026760 |  2027300 |  365 |    42 |            |               |         |       |          | 3/2532             | 9104 | ExclusiveLock    | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 6/313              | 9274 | AccessShareLock  | t
 relation |  2026760 |  2027300 |      |       |            |               |         |       |          | 6/313              | 9274 | RowShareLock     | t


29-07-2013 10:12:29,004 ERROR GrailsExceptionResolver - PSQLException occurred when processing request: [POST] /api/annotation.json
ERROR: deadlock detected
  Détail : Process 9273 waits for ExclusiveLock on tuple (365,42) of relation 2027300 of database 2026760; blocked by process 9104.
Process 9104 waits for ShareLock on transaction 1286966; blocked by process 9273.
  Indice : See server log for query details.
  Où : SQL statement "UPDATE y
                SET count_x = count_x + 1
                WHERE y.id = NEW.y_id"
PL/pgSQL function "incrementy" line 6 at SQL statement. Stacktrace follows:
org.postgresql.util.PSQLException: ERROR: deadlock detected

I don't understand where the "ExclusiveLock" come from. 
"EXCLUSIVE: This lock mode is not automatically acquired on tables by any PostgreSQL command."
In log, I just see that Hibernate just read the row y (365,42) (simple select). No explicit lock.

Loïc










2013/7/29 Loïc Rollus <loicrollus@gmail.com>
Hi,

Thanks for your quick reply!
I found the table. But the ctid of the row has changed. But during my test, I update only 1 row from this table, so I know the row.

I had already put log_statement to 'all'. It's strange because in the log, I only see simple "SELECT ... FROM" on this table (no UPDATE or SELECT FOR UPDATE). But I can't see request from trigger (not show by log_statement='all'?).

Here is a log sample (simplify: insert into X should update the counter on the specific row from Y)


1286781 22142 2013-07-26 13:55:22 CEST LOG:  execute <unnamed>: insert into X...
1286780 22426 2013-07-26 13:55:22 CEST LOG:  execute <unnamed>: insert into X...
====> it should be UPDATE on Y from trigger here
1286781 22142 2013-07-26 13:55:22 CEST LOG:  execute select this_.id as id54_0_,.... from ....
[...22142 follow its way, commit, and carry another request ]
1286785 22142 2013-07-26 13:55:23 CEST LOG:  execute <unnamed>: insert into X
1286785 22142 2013-07-26 13:55:25 CEST ERROR:  deadlock detected
1286785 22142 2013-07-26 13:55:25 CEST DETAIL:  Process 22142 waits for ShareLock on transaction 1286780; blocked by process 22426.
Process 22426 waits for ExclusiveLock on tuple (365,13) of relation 2027300 of database 2026760; blocked by process 22142.
1286785 22142 2013-07-26 13:55:25 CEST HINT:  See server log for query details.
1286785 22142 2013-07-26 13:55:25 CEST CONTEXT:  SQL statement "UPDATE Y
1286785 22142 2013-07-26 13:55:25 CEST STATEMENT:  insert into X
Process 22426 waits for ShareLock on transaction 1286782; blocked by process 22429.
1286785 22142 2013-07-26 13:55:25 CEST LOG:  execute S_3: ROLLBACK

I will try to query pg_locks to see more info

Thanks







2013/7/26 Albe Laurenz <laurenz.albe@wien.gv.at>
Loïc Rollus wrote:
> I've try to make some concurrency robustness test with an web server app that use Hibernate and
> Postgres.
> It seems that my trigger make deadlock when multiple thread use it.
>
> I will try to simplify examples:
> I have a table "films"(id, title,director) and a table "directors"(id,name,nbreFilms). I want to
> automaticaly count directors's films.
>
> So I have this triggers after each insert on films:
>
> CREATE OR REPLACE FUNCTION incrementDirectors() RETURNS TRIGGER AS $incDirectors$
> BEGIN
>     UPDATE directors
>     SET nbreFilm = nbreFilm + 1
>     WHERE directors.id = NEW.director;
>     RETURN NEW;
> END;
> $incDirectors$ LANGUAGE plpgsql;
> CREATE TRIGGER triggerIncrDirectors AFTER INSERT ON films FOR EACH ROW EXECUTE PROCEDURE
> incrementDirectors();
>
>
> When I do a lot of INSERT films at the same time, I have this error:
>
> ******************************************************************************************************
> ********
> 1286785 22142 2013-07-26 13:55:25 CEST ERROR:  deadlock detected
> 1286785 22142 2013-07-26 13:55:25 CEST DETAIL:  Process 22142 waits for ShareLock on transaction
> 1286780; blocked by process 22426.
> Process 22426 waits for ExclusiveLock on tuple (365,13) of relation 2027300 of database 2026760;
> blocked by process 22142.
> 1286785 22142 2013-07-26 13:55:25 CEST HINT:  See server log for query details.
> ******************************************************************************************************
> ********
>
> If I look in postgresql log for process, I see this (its a web app):
> 1.Process 22142: take a ADD request from http,
> 2.Process 22426: take a ADD request from http,
> 3.Process 22142: do INSERT of new film
> 4.Process 22146: do INSERT of new film
> 5.Process 22142: continue request (Process 22146 seems to be blocked) and do COMMIT
> 6.Process 22142: take a ADD request from http,
> 7.Process 22142: do INSERT of new film
> 8.DEADLOCK: process 22142 is waiting for 22146 and 22146 is waiting for 22142
>
> I don't understant why the commit of the process 22142 won't unlock process 22426.
>
> Have you an idea?

It would be interesting to know what relation 2027300 of database 2026760 is.

Then you could select the offending tuple with
SELECT * FROM <tablename> WHERE ctid='(365,13)';

What I would do is to set log_statement='all' and see what
exact SQL statements are issued. Maybe Hibernate does something
you do not know.

It may also be interesting to query pg_locks immediately before
commit to see what locks one transaction holds.

Yours,
Laurenz Albe


В списке pgsql-general по дате отправления:

Предыдущее
От: Loïc Rollus
Дата:
Сообщение: Re: Trigger and deadlock
Следующее
От: Amit Langote
Дата:
Сообщение: Re: SQL for multimedia retrieval