PostrgeSQL : deadlock detecded

[zyx974_]

Hi,

I'm using Nuxeo 6.0-HF05 with a cluster of 2 nuxeo server. We are facing slow down of access in DM. When slow down appears I notice "deadlock detected" error in the Postgres log files (see logs below).

Is there a way to avoid this behavior ? Is it a bug ? I can't reproduce it but it appears regularly in production.

    2015-09-11 10:13:34 RET [5351]: [1-1] ERROR:  deadlock detected
    2015-09-11 10:13:34 RET [5351]: [2-1] DETAIL:  Process 5351 waits for ShareLock on transaction 72303514; blocked by process 9897.
    Process 9897 waits for ShareLock on transaction 72303486; blocked by process 5351.
    Process 5351: UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    Process 9897: INSERT INTO "documents_count_statistics" ("id", "childrencount", "descendantscount") VALUES ($1, $2, $3)
    2015-09-11 10:13:34 RET [5351]: [3-1] HINT:  See server log for query details.
    2015-09-11 10:13:34 RET [5351]: [4-1] STATEMENT:  UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    2015-09-11 10:13:34 RET [5351]: [5-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:34 RET [5351]: [6-1] STATEMENT:  SELECT "id", "name", "grant", "permission", "user", "group" FROM "acls" WHERE "id" IN ($1) ORDER BY "id", "pos"
    2015-09-11 10:13:34 RET [5351]: [7-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:34 RET [5351]: [8-1] STATEMENT:  INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12)
    2015-09-11 10:13:34 RET [5351]: [9-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:34 RET [5351]: [10-1] STATEMENT:  SELECT nx_update_read_acls()
    2015-09-11 10:13:35 RET [9410]: [53-1] LOG:  using stale statistics instead of current ones because stats collector is not responding
    2015-09-11 10:13:46 RET [9897]: [7-1] ERROR:  deadlock detected
    2015-09-11 10:13:46 RET [9897]: [8-1] DETAIL:  Process 9897 waits for ShareLock on transaction 72303598; blocked by process 9469.
    Process 9469 waits for ShareLock on transaction 72303514; blocked by process 9897.
    Process 9897: UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    Process 9469: INSERT INTO "documents_count_statistics" ("id", "childrencount", "descendantscount") VALUES ($1, $2, $3)
    2015-09-11 10:13:46 RET [9897]: [9-1] HINT:  See server log for query details.
    2015-09-11 10:13:46 RET [9897]: [10-1] STATEMENT:  UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    2015-09-11 10:13:47 RET [9897]: [11-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:47 RET [9897]: [12-1] STATEMENT:  SELECT "id", "name", "grant", "permission", "user", "group" FROM "acls" WHERE "id" IN ($1) ORDER BY "id", "pos"
    2015-09-11 10:13:48 RET [9897]: [13-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:48 RET [9897]: [14-1] STATEMENT:  INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12)
    2015-09-11 10:13:48 RET [9897]: [15-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:13:48 RET [9897]: [16-1] STATEMENT:  SELECT nx_update_read_acls()
    2015-09-11 10:13:55 RET [9410]: [54-1] LOG:  using stale statistics instead of current ones because stats collector is not responding
    2015-09-11 10:14:06 RET [9420]: [1-1] ERROR:  deadlock detected
    2015-09-11 10:14:06 RET [9420]: [2-1] DETAIL:  Process 9420 waits for ShareLock on transaction 72303598; blocked by process 9469.
    Process 9469 waits for ShareLock on transaction 72303684; blocked by process 9420.
    Process 9420: UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    Process 9469: INSERT INTO "documents_count_statistics" ("id", "childrencount", "descendantscount") VALUES ($1, $2, $3)
    2015-09-11 10:14:06 RET [9420]: [3-1] HINT:  See server log for query details.
    2015-09-11 10:14:06 RET [9420]: [4-1] STATEMENT:  UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    2015-09-11 10:14:06 RET [9420]: [5-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:14:06 RET [9420]: [6-1] STATEMENT:  SELECT "id", "name", "grant", "permission", "user", "group" FROM "acls" WHERE "id" IN ($1) ORDER BY "id", "pos"
    2015-09-11 10:14:06 RET [9420]: [7-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:14:06 RET [9420]: [8-1] STATEMENT:  INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12)
    2015-09-11 10:14:06 RET [9420]: [9-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:14:06 RET [9420]: [10-1] STATEMENT:  SELECT nx_update_read_acls()
    2015-09-11 10:14:07 RET [839]: [1-1] LOG:  using stale statistics instead of current ones because stats collector is not responding
    2015-09-11 10:14:13 RET [9469]: [1-1] ERROR:  deadlock detected
    2015-09-11 10:14:13 RET [9469]: [2-1] DETAIL:  Process 9469 waits for ShareLock on transaction 72304003; blocked by process 5337.
    Process 5337 waits for ShareLock on transaction 72303598; blocked by process 9469.
    Process 9469: UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    Process 5337: INSERT INTO "documents_count_statistics" ("id", "childrencount", "descendantscount") VALUES ($1, $2, $3)
    2015-09-11 10:14:13 RET [9469]: [3-1] HINT:  See server log for query details.
    2015-09-11 10:14:13 RET [9469]: [4-1] STATEMENT:  UPDATE "hierarchy" SET "mixintypes" = $1 WHERE "id" = $2
    2015-09-11 10:14:13 RET [9469]: [5-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:14:13 RET [9469]: [6-1] STATEMENT:  SELECT "id", "name", "grant", "permission", "user", "group" FROM "acls" WHERE "id" IN ($1) ORDER BY "id", "pos"
    2015-09-11 10:14:13 RET [9469]: [7-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2015-09-11 10:14:13 RET [9469]: [8-1] STATEMENT:  INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12)
    2015-09-11 10:14:13 RET [9469]: [9-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block

[Florent_Guillau]

What is logged in server.log for this?

[zyx974_]

Hello,

Sorry, this is not an answer, but I dont know how to upload a file in a comment (there is a lot of log).

server.log is attached. Thank you !

[Florent_Guillau]

The first thing I'd do is upgrade to the latest hotfix version, Nuxeo 6.0-HF05 is quite old and a number of tickets related to quota computation have been fixed, it may help.