Prisma1: Deadlock found when trying to get lock; try restarting transaction (Again)

[guihalt]

Current behavior
Deleting several nodes of a simple linked list concurrently results in an internal server error, and this cluster log (the first for MySql, the later for PostgreSql):

On MySQL:

{"log":"{\"key\":\"error/unhandled\",\"requestId\":\"local:api:cjlwccos307sy09055u21tc9u\",\"clientId\":\"linkedList@dev\",\"payload\":{\"exception\":\"java.sql.SQLTransactionRollbackException: (conn=79) Deadlock found when trying to get lock; try restarting transaction\",\"query\":\"mutation {\\n      deleteItem(where: {\\n        id: \\\"cjlwccora07su0905lyw9hkcu\\\"\\n      })\\n      {id}\\n    }\",\"variables\":\"{}\",\"code\":\"0\",\"stack_trace\":\"org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:165)\\\\n org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:106)\\\\n org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:235)\\\\n org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:224)\\\\n org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:159)\\\\n com.zaxxer.hikari.pool.ProxyPreparedStatement.execute(ProxyPreparedStatement.java:44)\\\\n com.zaxxer.hikari.pool.HikariProxyPreparedStatement.execute(HikariProxyPreparedStatement.java)\\\\n com.prisma.api.connector.jdbc.database.BuilderBase.$anonfun$deleteToDBIO$1(BuilderBase.scala:70)\\\\n com.prisma.api.connector.jdbc.database.BuilderBase.$anonfun$deleteToDBIO$1$adapted(BuilderBase.scala:70)\\\\n com.prisma.api.connector.jdbc.database.BuilderBase.$anonfun$jooqToDBIO$1(BuilderBase.scala:87)\\\\n slick.jdbc.SimpleJdbcAction.run(StreamingInvokerAction.scala:70)\\\\n slick.jdbc.SimpleJdbcAction.run(StreamingInvokerAction.scala:69)\\\\n slick.dbio.DBIOAction$$anon$4.$anonfun$run$3(DBIOAction.scala:239)\\\\n scala.collection.Iterator.foreach(Iterator.scala:929)\\\\n scala.collection.Iterator.foreach$(Iterator.scala:929)\\\\n scala.collection.AbstractIterator.foreach(Iterator.scala:1417)\\\\n scala.collection.IterableLike.foreach(IterableLike.scala:71)\\\\n scala.collection.IterableLike.foreach$(IterableLike.scala:70)\\\\n scala.collection.AbstractIterable.foreach(Iterable.scala:54)\\\\n slick.dbio.DBIOAction$$anon$4.run(DBIOAction.scala:239)\\\\n slick.dbio.DBIOAction$$anon$4.run(DBIOAction.scala:237)\\\\n slick.basic.BasicBackend$DatabaseDef$$anon$2.liftedTree1$1(BasicBackend.scala:275)\\\\n slick.basic.BasicBackend$DatabaseDef$$anon$2.run(BasicBackend.scala:275)\\\\n java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\\\\n java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\\\\n java.lang.Thread.run(Thread.java:748)\",\"message\":\"(conn=79) Deadlock found when trying to get lock; try restarting transaction\"}}\n","stream":"stdout","time":"2018-09-10T13:46:51.911911169Z"}

On Postgres:

{"log":"{\"key\":\"error/unhandled\",\"requestId\":\"local:api:cjlxfuz4j001o0979zisx7scb\",\"clientId\":\"linkedList$dev\",\"payload\":{\"exception\":\"org.postgresql.util.PSQLException: ERROR: deadlock detected\\n  Detail: Process 34 wai
ts for ShareLock on transaction 4329; blocked by process 33.\\nProcess 33 waits for ShareLock on transaction 4328; blocked by process 34.\\n  Hint: See server log for query details.\\n  Where: while locking tuple (0,12) in relation \\\"It
em\\\"\\nSQL statement \\\"SELECT 1 FROM ONLY \\\"linkedList$dev\\\".\\\"Item\\\" x WHERE \\\"id\\\"::pg_catalog.text OPERATOR(pg_catalog.=) $1::pg_catalog.text FOR KEY SHARE OF x\\\"\",\"query\":\"mutation {\\n      updateItem(data: {pre
vious: {connect: {id: \\\"cjlxfuz28001h09790hqjsae6\\\"} } }, where: {id: \\\"cjlxfuz2j001l09791ri8wvfb\\\"}) {id}\\n    }\",\"variables\":\"{}\",\"code\":\"0\",\"stack_trace\":\"org.postgresql.core.v3.QueryExecutorImpl.receiveErrorRespon
se(QueryExecutorImpl.java:2433)\\\\n org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2178)\\\\n org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306)\\\\n org.postgresql.jdbc.PgStateme
nt.executeInternal(PgStatement.java:441)\\\\n org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365)\\\\n org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155)\\\\n org.postgresql.jdbc.PgPreparedSta
tement.execute(PgPreparedStatement.java:144)\\\\n com.zaxxer.hikari.pool.ProxyPreparedStatement.execute(ProxyPreparedStatement.java:44)\\\\n com.zaxxer.hikari.pool.HikariProxyPreparedStatement.execute(HikariProxyPreparedStatement.java)\\\
\n com.prisma.api.connector.jdbc.database.BuilderBase.$anonfun$insertToDBIO$1(BuilderBase.scala:63)\\\\n com.prisma.api.connector.jdbc.database.BuilderBase.$anonfun$insertToDBIO$1$adapted(BuilderBase.scala:63)\\\\n com.prisma.api.connecto
r.jdbc.database.BuilderBase.$anonfun$jooqToDBIO$1(BuilderBase.scala:81)\\\\n slick.jdbc.SimpleJdbcAction.run(StreamingInvokerAction.scala:70)\\\\n slick.jdbc.SimpleJdbcAction.run(StreamingInvokerAction.scala:69)\\\\n slick.basic.BasicBack
end$DatabaseDef$$anon$2.liftedTree1$1(BasicBackend.scala:275)\\\\n slick.basic.BasicBackend$DatabaseDef$$anon$2.run(BasicBackend.scala:275)\\\\n java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\\\\n java.uti
l.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\\\\n java.lang.Thread.run(Thread.java:748)\",\"message\":\"ERROR: deadlock detected\\n  Detail: Process 34 waits for ShareLock on transaction 4329; blocked by process
 33.\\nProcess 33 waits for ShareLock on transaction 4328; blocked by process 34.\\n  Hint: See server log for query details.\\n  Where: while locking tuple (0,12) in relation \\\"Item\\\"\\nSQL statement \\\"SELECT 1 FROM ONLY \\\"linked
List$dev\\\".\\\"Item\\\" x WHERE \\\"id\\\"::pg_catalog.text OPERATOR(pg_catalog.=) $1::pg_catalog.text FOR KEY SHARE OF x\\\"\"}}\n","stream":"stdout","time":"2018-09-11T08:12:51.169442483Z"}

To Reproduce
I prepared a reproduction here: https://github.com/guihalt/LinkedList
Please read https://github.com/guihalt/LinkedList/blob/master/README.md for more information.
In brief: create a short linked list with 4 elements, then delete all elements concurrently. About one time out of 3 or 4, it results in an internal error (cf. cluster log above, deadlock).

Expected behavior
No internal error (deadlock nor constraint violation)

Versions :

• OS:
  centos-release-7-4.1708.el7.centos.x86_64
  Linux fdcd67765900 3.10.0-514.21.2.el7.x86_64 #1 SMP Tue Jun 20 12:24:47 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
• prisma CLI, Prisma Server, etc.:
  Tested with prisma/1.13.3 (linux-x64) node-v8.11.2 and prisma/1.15.3 (linux-x64) node-v8.11.2 (cf. https://github.com/guihalt/LinkedList/blob/master/results.log)
  Please refer to https://github.com/guihalt/LinkedList/blob/master/package.json for more information.

[guihalt]

@divyenduz any news on an estimate of when you could have someone looking at this bug ?

[guihalt]

@divyenduz Can you prevent the bot to mark this issue as stale to avoid closing it too early ?

[divyenduz]

Sure, this is on my list already, and since we are commenting on it, slate bot won't show up. I think our stale bot only shows up after 45 days of no activity.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 10 days if no further activity occurs. Thank you for your contributions.

[guihalt]

is there any news on this bug ?

[jhalborg]

We've run into this issue a couple of times as well - it crashes our platform temprorarily while Kubernetes restarts stuff, so it's pretty gruesome. @divyenduz . Our AWS Aurora instance also goes crazy in CPU usage at this exact moment, don't know if it helps