Server: Database Deadlock with Postgres

Created on 31 Jul 2018 · 12Comments · Source: nextcloud/server

Doctrine\DBAL\Exception\DriverException: An exception occurred while executing 'UPDATE "filecache" SET "mtime" = GREATEST("mtime", ?), "etag" = ? WHERE ("storage" = ?) AND ("path_hash" IN ('d41d8cd98f00b204e9800998ecf8427e', 'dcecaf22bf647820655259752bde9a89', '83da648e3544520bff107f9e7eddd629', 'a5d1d680ea9153370ed2913a3595360a'))' with params [1533059822, "5b60a2eeaaaaf", 1]: SQLSTATE[40P01]: Deadlock detected: 7 ERROR: deadlock detected DETAIL: Process 25363 waits for ExclusiveLock on tuple (111,26) of relation 16464 of database 16384; blocked by process 25373. Process 25373 waits for ShareLock on transaction 67276; blocked by process 25368. Process 25368 waits for ShareLock on transaction 67337; blocked by process 25361. Process 25361 waits for ExclusiveLock on tuple (111,26) of relation 16464 of database 16384; blocked by process 25363. HINT: See server log for query details.

I can see hundreds of those errors within the last hour.

Steps to reproduce

Install latest docker image with postgres / apache
Sync files via WebDAV

Server configuration

Operating system:
Docker image on Debian host

Web server:
Apache

Database:
Postgres

PHP version:
From official Docker image

Nextcloud version: (see Nextcloud admin page)
Latest from official Docker image

Updated from an older Nextcloud/ownCloud or fresh install:
No

Signing status:

Signing status

No errors have been found.

Are you using encryption: no

Are you using an external user-backend, if yes which one: no

0. Needs triage bug

Source

muesli

Most helpful comment

Any update on this?

gorefest on 11 Feb 2019

👍2

All 12 comments

GitMate.io thinks possibly related issues are https://github.com/nextcloud/server/issues/9961 (PostgreSQL DeadLock), https://github.com/nextcloud/server/issues/3453 (Intermittent deadlock in database access, causes client sync issues), https://github.com/nextcloud/server/issues/4110 (Question: SSL-Postgres), https://github.com/nextcloud/server/issues/8113 ([Question] - Reset Database?), and https://github.com/nextcloud/server/issues/173 (Database conversion: hangs forever).

nextcloud-bot on 31 Jul 2018

I have the same issue here with PostgreSQL. In other databases this error may keep undetected because of missing deadlock detection.

It seems, that there is a wrong order of SQL updates in transactions.

From the PostgreSQL log:

2018-09-26 17:09:02 CEST [67928]: [217-1] user=XXX,db=XXX ERROR:  deadlock detected
2018-09-26 17:09:02 CEST [67928]: [218-1] user=XXX,db=XXX DETAIL:  Process 67928 waits for ShareLock on transaction 102103330; blocked by process 67
929.
        Process 67929 waits for ShareLock on transaction 102103329; blocked by process 67928.
        Process 67928: UPDATE "oc_file_locks" SET "lock" = "lock" -1 WHERE ("key" IN ($1, $2, $3, $4, $5)) AND ("lock" > 0)
        Process 67929: UPDATE "oc_file_locks" SET "lock" = "lock" -1 WHERE ("key" IN ($1, $2, $3, $4, $5)) AND ("lock" > 0)
2018-09-26 17:09:02 CEST [67928]: [219-1] user=XXX,db=XXX TIPP:  See server log for query details.
2018-09-26 17:09:02 CEST [67928]: [220-1] user=XXX,db=XXX CONTEXT:  while updating tuple (23,71) in relation "oc_file_locks"
2018-09-26 17:09:02 CEST [67928]: [221-1] user=XXX,db=XXX STATEMENT:  UPDATE "oc_file_locks" SET "lock" = "lock" -1 WHERE ("key" IN ($1, $2, $3, $4,
 $5)) AND ("lock" > 0)

alvar-freude on 26 Sep 2018

Any update on this?

gorefest on 11 Feb 2019

👍2

I also see errors like this when syncing a lot of files at once, on Nextcloud 15.0.7 with Postgresql 10. However, despite the ugly-looking errors (22 when syncing a directory tree of size 222MB containing ~10k files), everything eventually gets synced correctly. That's OK, but not exactly good.

oreinert on 12 Apr 2019

Any updates on this?
I am facing same issue on Debian with Nextcloud 15.0.7 , postgres 11.3-1
The application gets unresponsive and results in 503, Service Unavailable

MVTec on 21 May 2019

:ping_pong: @nextcloud/server-triage

J0WI on 21 May 2019

same issue here, first time user of nextcloud. Issue occurred when I tried to upload a folder of about 1000 files from the web ui, it resulted in the above deadlock errors occuring about 10 times which I had to "X" in the web ui.

Using docker postgres:11.3 and nextcloud:16.0.1-apache
Going to switch to maria as per recommendations

abedwardsw on 14 Jun 2019

Duplicate of #11136

skjnldsv on 14 Jun 2019

I was able to get this fixed (Debian with Nextcloud 15.0.7 , postgres 11.3-1), by using Redis for Transactional File Locking. This results in reducing DB load and hence no more deadlocks.
https://docs.nextcloud.com/server/16/admin_manual/configuration_server/caching_configuration.html#id2

MVTec on 14 Jun 2019

👍1

Awesome! Thanks a lot for the feedback! :)

skjnldsv on 14 Jun 2019

This issue still happens on Nextcloud 18.

This is a bug in Nextcloud. The PostgreSQL error means that clients tried to perform queries in an order that causes a deadlock. If PostgreSQL detects a deadlock it will abort one of the transactions that cause the deadlock.

Repeating the transaction that fails could be a possible fix.

Using redis is just a workaround: If redis is used, then Nextcloud doesn't use the database and the bug is in the database file locking code.

This is is only a duplicate of #11136 if preview generation uses file locking. The SQL tables in this issue and #11136 are different, so it's unlikely to be the same issue.

APTX on 28 Jun 2020

happened to me on NC 19.0.1 with PG 12.3

020-07-26 12:55:07.371 UTC [519] STATEMENT: INSERT INTO "oc_filecache_extended" ("fileid", "upload_time") VALUES($1, $2)
2020-07-26 12:56:49.962 UTC [625] ERROR: deadlock detected
2020-07-26 12:56:49.962 UTC [625] DETAIL: Process 625 waits for ShareLock on transaction 1135285; blocked by process 633.
Process 633 waits for ShareLock on transaction 1135286; blocked by process 625.
Process 625: UPDATE "oc_file_locks" SET "lock" = "lock" - '1' WHERE ("key" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27, $28, $29, $30, $31, $32, $33, $34, $35, $36, $37, $38, $39, $40, $41, $42, $43, $44, $45, $46, $47, $48, $49, $50, $51, $52, $53, $54, $55, $56, $57, $58, $59, $60, $61, $62, $63, $64, $65, $66, $67, $68, $69, $70, $71, $72, $73, $74, $75, $76, $77, $78, $79, $80, $81, $82, $83, $84, $85, $86, $87, $88, $89, $90, $91, $92, $93, $94, $95, $96, $97, $98, $99, $100)) AND ("lock" > 0)
Process 633: UPDATE "oc_file_locks" SET "lock" = "lock" + 1, "ttl" = $1 WHERE "key" = $2 AND "lock" >= 0
2020-07-26 12:56:49.962 UTC [625] HINT: See server log for query details.
2020-07-26 12:56:49.962 UTC [625] CONTEXT: while updating tuple (102,28) in relation "oc_file_locks"
2020-07-26 12:56:49.962 UTC [625] STATEMENT: UPDATE "oc_file_locks" SET "lock" = "lock" - '1' WHERE ("key" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27, $28, $29, $30, $31, $32, $33, $34, $35, $36, $37, $38, $39, $40, $41, $42, $43, $44, $45, $46, $47, $48, $49, $50, $51, $52, $53, $54, $55, $56, $57, $58, $59, $60, $61, $62, $63, $64, $65, $66, $67, $68, $69, $70, $71, $72, $73, $74, $75, $76, $77, $78, $79, $80, $81, $82, $83, $84, $85, $86, $87, $88, $89, $90, $91, $92, $93, $94, $95, $96, $97, $98, $99, $100)) AND ("lock" > 0)
2020-07-26 13:37:49.242 UTC [2065] ERROR: deadlock detected
2020-07-26 13:37:49.242 UTC [2065] DETAIL: Process 2065 waits for ShareLock on transaction 1149158; blocked by process 2075.
Process 2075 waits for ShareLock on transaction 1149159; blocked by process 2065.
Process 2065: UPDATE "oc_file_locks" SET "lock" = "lock" - '1' WHERE ("key" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27, $28, $29, $30, $31, $32, $33, $34, $35, $36, $37, $38, $39, $40, $41, $42, $43, $44, $45, $46, $47, $48, $49, $50, $51, $52, $53, $54, $55, $56, $57, $58, $59, $60, $61, $62, $63, $64, $65, $66, $67, $68, $69, $70, $71, $72, $73, $74, $75, $76, $77, $78, $79, $80, $81, $82, $83, $84, $85, $86, $87, $88, $89, $90, $91, $92, $93, $94, $95, $96, $97, $98, $99, $100)) AND ("lock" > 0)
Process 2075: INSERT INTO "oc_file_locks" ("key", "lock", "ttl") VALUES($1, $2, $3) ON CONFLICT DO NOTHING
2020-07-26 13:37:49.242 UTC [2065] HINT: See server log for query details.
2020-07-26 13:37:49.242 UTC [2065] CONTEXT: while updating tuple (216,108) in relation "oc_file_locks"
2020-07-26 13:37:49.242 UTC [2065] STATEMENT: UPDATE "oc_file_locks" SET "lock" = "lock" - '1' WHERE ("key" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27, $28, $29, $30, $31, $32, $33, $34, $35, $36, $37, $38, $39, $40, $41, $42, $43, $44, $45, $46, $47, $48, $49, $50, $51, $52, $53, $54, $55, $56, $57, $58, $59, $60, $61, $62, $63, $64, $65, $66, $67, $68, $69, $70, $71, $72, $73, $74, $75, $76, $77, $78, $79, $80, $81, $82, $83, $84, $85, $86, $87, $88, $89, $90, $91, $92, $93, $94, $95, $96, $97, $98, $99, $100)) AND ("lock" > 0)