Java deadlock in test with multiple simultaneous transactions

[archiecobbs]

As part of a separate project, I'm running unit tests that check database behavior when conflicting and non-conflicting transactions are run at the same time.

In the case of CockroachDB, one of these tests deadlocks and hangs forever. Instead, some sort of retry exception should be thrown.

Interestingly, it is a non-conflicting transaction test that is hanging (the conflicting transaction test is correctly throwing a retry exception).

The version I'm testing:

build:     beta-20160616 @ 2016/06/30 13:57:29 (go1.6.2)
admin:     http://localhost:9696
sql:       postgresql://root@localhost:26257?sslmode=disable
logs:      /usr/local/var/cockroach/logs
store[0]:  path=/usr/local/var/cockroach

Test setup:

CREATE TABLE IF NOT EXISTS "KV" (
  "kv_key" BYTES PRIMARY KEY NOT NULL,
  "kv_value" BYTES NOT NULL
);
DELETE FROM "KV";

Unit test that hangs: testNonconflictingTransactions():

What this test does:

Open 10 transactions T1, T2, ..., T10

T1: SELECT "kv_key", "kv_value" FROM "KV" WHERE "kv_key" >= ?1 ORDER BY "kv_key" ASC LIMIT 1 [?1 = 00]
T1: UPSERT INTO "KV" ("kv_key", "kv_value") VALUES (?1, ?2) [?1 = 80, ?2 = 02]
T2: SELECT "kv_key", "kv_value" FROM "KV" WHERE "kv_key" >= ?1 ORDER BY "kv_key" ASC LIMIT 1 [?1 = 01]
T2: UPSERT INTO "KV" ("kv_key", "kv_value") VALUES (?1, ?2) [?1 = 81, ?2 = 02]
T3: SELECT "kv_key", "kv_value" FROM "KV" WHERE "kv_key" >= ?1 ORDER BY "kv_key" ASC LIMIT 1 [?1 = 02]

The test hangs at this point. The stuck thread is here:

"pool-1-thread-10" prio=5 tid=0x00007fbb7e037000 nid=0x6703 runnable [0x000000012259d000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:70)
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:283)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1799)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:200)
    - locked <0x00000007adec7888> (a org.postgresql.core.v3.QueryExecutorImpl)
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:424)
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:161)
    at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.postgresql.ds.PGPooledConnection$StatementHandler.invoke(PGPooledConnection.java:426)
    at com.sun.proxy.$Proxy13.executeQuery(Unknown Source)
    at org.jsimpledb.kv.sql.SQLKVTransaction.query(SQLKVTransaction.java:279)
    at org.jsimpledb.kv.sql.SQLKVTransaction.queryKVPair(SQLKVTransaction.java:250)
    at org.jsimpledb.kv.sql.SQLKVTransaction.getAtLeast(SQLKVTransaction.java:100)
    - locked <0x00000007aded3008> (a org.jsimpledb.kv.cockroach.CockroachKVTransaction)
    at org.jsimpledb.kv.test.KVDatabaseTest$Reader.call(KVDatabaseTest.java:862)
    at org.jsimpledb.kv.test.KVDatabaseTest$Reader.call(KVDatabaseTest.java:842)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)

To run these tests yourself:

1. git clone git@github.com:archiecobbs/jsimpledb
2. cd jsimpledb
3. git checkout 89937aa672efd9ab833e28809259d2836bb3e8cb
4. mvn install -Dmaven.javadoc.skip=true -Dmaven.test.skip=true
5. Edit pom.xml, and uncomment the <cockroachURL> line (edit to suit)
6. cd jsimpledb-kv-cockroach
7. cockroach sql -e 'create database if not exists jsimpledb'
8. mvn test
9. When test hangs, hit CTRL-\ to see Java stack trace

[tbg]

Thanks @archiecobbs. You shouldn't experience deadlocks with optimistic concurrency, so either things are unacceptably slow or there is a bug. We'll look into this.

[RaduBerinde]

I will see if I can come up with a sql partest that reproduces this.

[RaduBerinde]

@archiecobbs - quick question, in #5924 (comment) you are saying that the other "conflicting" test sometimes hangs too, but here you said it doesn't? Is that one not hanging anymore in the latest beta?

[archiecobbs]

Correct, with the latest beta (beta-20160616) that test appears to be passing every time, unlike previously.

[RaduBerinde]

Great, thanks, I will focus on the non-conflict one.

[RaduBerinde]

I can reproduce fairly easily with this test:
RaduBerinde@27785ec

But now that I exactly understand the "workload", I am wondering what is your expectation here? Does this work with other SQL databases (in serializable isolation mode)? In a database that uses locking, the SELECT statement will be blocked on an earlier transaction so it would be stuck until the earlier transaction committed.

There are only two choices - either we wait for the earlier transaction to complete, or we kill the earlier transaction. I believe we may do either depending on (random) priorities; at some point we will choose to wait and we will be stuck waiting for the commit that never comes.

[RaduBerinde]

Note that this workload should work with ISOLATION LEVEL SNAPSHOT (the txns don't need to wait for each other in that mode). (I confirmed that my little test works).

You mention your tests don't hang with MySQL - are you running them in SERIALIZABLE mode in MySQL? (note that the default for MySQL is "REPEATABLE READ", which is even lower than our SNAPSHOT)

[archiecobbs]

Thanks for looking into it. We have looped around a bit since the original bug was opened and my apologies for having forgotten how this all started.

In all of the other databases, this test results in either a retry exception or a timeout exception, when the blocked thread gives up waiting for the blocking transaction to finish.

CockroachDB just hangs indefinitely, because there's no way to configure a transaction for such a timeout. This is what the original bug #5924 was about.

In the course of testing for #5924, I realized there was actually another test failing, which indicated a separate issue, and so this bug was filed for that problem. But by the time I got around to filing this bug, that second bug had already been fixed.

So back to this bug...

The behavior makes sense, in that the blocked thread must wait for the blocking transaction. But the larger issue is that CockroachDB, unlike all of the other databases tested with this test, actually makes it impossible to avoid the possibility of an indefinite hang in your program if some other really slow transaction happens to block you.

That's why a transaction timeout is needed - or, make it impossible to hang indefinitely in some other way, by throwing a retry exception after some built-in internal timeout or whatever. There's no easy way in Java to configure such a timeout on the client side.

Hope this makes sense.

[tbg]

There are only two choices - either we wait for the earlier transaction to complete, or we kill the earlier transaction. I believe we may do either depending on (random) priorities; at some point we will choose to wait and we will be stuck waiting for the commit that never comes.

Yes, in my mind the SELECT would get stronger as it retries, but I think the current implementation simply retries at the store level, without increasing the priorities. That has come up once or twice as unexpected behavior. I tend to agree with that, but the concurrency behavior is still fairly unoptimized, so we haven't tackled it yet. This fruit is getting ripe for a picking, though.

[RaduBerinde]

@archiecobbs - Makes sense. I understand the need for having a timeout - but that is already tracked by #5924. Given that there is no expectation for this test to pass without timeouts, there is no additional problem here as far as I can tell.