Update statement does not always block when a different transaction has an exclusive lock for a row

[beikov]

Describe the problem

Update statement does not always block when a different transaction has an exclusive lock for a row.

To Reproduce

1. On connection 1, start TX1
2. TX1: Run select * from tbl1 t where t.id = 1 for update of t to lock a single row
3. On connection 2, start TX2
4. TX2: Run SET statement_timeout TO 100
5. TX2: Run select * from tbl1 t where t.id = 1
6. TX2: Run update tbl1 t set t.value = 'changed' where t.id = 1

Expected behavior

TX2 should block at step 6. since TX1 has a lock on the row, and TX2 should run into a timeout. It seems though, that "sometimes" the statement at step 6. succeeds.

As it is with timeout based stuff, this hard to reproduce reliably, but I wanted to report this anyway, as I believe there might be a concurrency issue lurking in CockroachDB that you might be able to find by looking at the code with this given example. The issue happened after a lot of other Hibernate testcases were executed i.e. after a lot of statements like create table, insert, select, update, delete, drop table.

Environment:

• CockroachDB version: 21.2.15
• Server OS: Linux Docker
• Client app: JDBC/Hibernate

Here are SQL log excerpts from the run:

    drop table if exists T_LOCK_A cascade
    create table T_LOCK_A (
       id bigint not null,
        a_value varchar(255),
        primary key (id)
    )

... lots of insert, select for update, update, delete statements

    insert 
    into
        T_LOCK_A
        (a_value, id) 
    values
        (?, ?)
[subsystem] TRACE g.hibernate.orm.jdbc.bind JdbcBindingLogging:28 - binding parameter [1] as [VARCHAR] - [it]
[subsystem] TRACE g.hibernate.orm.jdbc.bind JdbcBindingLogging:28 - binding parameter [2] as [BIGINT] - [6]

TX1 starts:

16:30:14,930 DEBUG SQL:128 - 
    select
        a1_0.id,
        a1_0.a_value 
    from
        T_LOCK_A a1_0 for update of a1_0
[subsystem] TRACE ibernate.orm.jdbc.extract JdbcExtractingLogging:28 - extracted value ([1] : [BIGINT]) - [6]
[subsystem] TRACE ibernate.orm.jdbc.extract JdbcExtractingLogging:28 - extracted value ([2] : [VARCHAR]) - [it]

TX2 starts: 

16:30:14,932 DEBUG SQL:128 - 
    select
        a1_0.id,
        a1_0.a_value 
    from
        T_LOCK_A a1_0 
    where
        a1_0.id=?
[subsystem] TRACE g.hibernate.orm.jdbc.bind JdbcBindingLogging:28 - binding parameter [1] as [BIGINT] - [6]
[subsystem] TRACE ibernate.orm.jdbc.extract JdbcExtractingLogging:28 - extracted value ([1] : [BIGINT]) - [6]
[subsystem] TRACE ibernate.orm.jdbc.extract JdbcExtractingLogging:28 - extracted value ([2] : [VARCHAR]) - [it]
16:30:14,936 DEBUG SQL:128 - 
    UPDATE
        T_LOCK_A 
    SET
        a_value = ? 
    where
        id = ?
[subsystem] TRACE g.hibernate.orm.jdbc.bind JdbcBindingLogging:28 - binding parameter [1] as [VARCHAR] - [changed]
[subsystem] TRACE g.hibernate.orm.jdbc.bind JdbcBindingLogging:28 - binding parameter [2] as [BIGINT] - [6]

Jira issue: CRDB-20070

[blathers-crl]

Hello, I am Blathers. I am here to help you get the issue triaged.

Hoot - a bug! Though bugs are the bane of my existence, rest assured the wretched thing will get the best of care here.

I have CC'd a few people who may be able to assist you:

• @cockroachdb/sql-schema (found keywords: drop table)
• @cockroachdb/sql-experience (found keywords: orm,Hibernate)

If we have not gotten back to your issue within a few business days, you can try the following:

• Join our community slack channel and ask on #cockroachdb.
• Try find someone from here if you know they worked closely on the area and CC them.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is otan.}

[beikov]

By the way, I'm running Cockroach like this, if that helps:

docker run -d --name=cockroach -p 26257:26257 -p 8080:8080 docker.io/cockroachdb/cockroach:v21.2.15 start-single-node \
    --insecure --store=type=mem,size=0.25 --advertise-addr=localhost
  OUTPUT=
  while [[ $OUTPUT != *"CockroachDB node starting"* ]]; do
        echo "Waiting for CockroachDB to start..."
        sleep 10
        # Note we need to redirect stderr to stdout to capture the logs
        OUTPUT=$(docker logs cockroach 2>&1)
  done
  echo "Enabling experimental box2d operators and some ptimized settings for running the tests"
  #settings documented in https://www.cockroachlabs.com/docs/v21.2/local-testing.html#use-a-local-single-node-cluster-with-in-memory-storage
  docker exec -it cockroach bash -c "cat <<EOF | ./cockroach sql --insecure
SET CLUSTER SETTING sql.spatial.experimental_box2d_comparison_operators.enabled = on;
SET CLUSTER SETTING kv.raft_log.disable_synchronization_unsafe = true;
SET CLUSTER SETTING kv.range_merge.queue_interval = '50ms';
SET CLUSTER SETTING jobs.registry.interval.gc = '30s';
SET CLUSTER SETTING jobs.registry.interval.cancel = '180s';
SET CLUSTER SETTING jobs.retention_time = '15s';
SET CLUSTER SETTING schemachanger.backfiller.buffer_increment = '128 KiB';
SET CLUSTER SETTING sql.stats.automatic_collection.enabled = false;
SET CLUSTER SETTING kv.range_split.by_load_merge_delay = '5s';
ALTER RANGE default CONFIGURE ZONE USING \"gc.ttlseconds\" = 5;
ALTER DATABASE system CONFIGURE ZONE USING \"gc.ttlseconds\" = 5;
quit
EOF
"

[beikov]

Also note that in most of my test runs, the transaction already fails at step 5. because it seems that a transaction TX2 blocks when reading a row, if TX1 has an exclusive lock on it.

[ajwerner]

Cockroach's select for update locks are best-effort. They are an optimization but not a proof. The reason is that the implementation uses non-replicated, in-memory locks. If a lease transfer for the underlying data occurs, the lock will be lost. There is nothing fundamentally incorrect about not locking for SELECT FOR UPDATE because other mechanisms will enforce serializability. When the locks fail, it just means that retries may be more common.

#75456 tracks the issue to make the locks survive lease transfers.

[beikov]

Let me ask a yes/no question to make it clear what this means. If I change the scenario to

1. On connection 1, start TX1
2. TX1: Run select * from tbl1 t where t.id = 1 for update of t to lock a single row
3. On connection 2, start TX2
4. TX2: Run SET statement_timeout TO 100
5. TX2: Run select * from tbl1 t where t.id = 1
6. TX2: Run update tbl1 t set t.value = 'changed' where t.id = 1
7. TX2: Commit

Will CockroachDB always fail at step 7. with a non-serializable transaction error? i.e. will TX2 always fail?

[ajwerner]

In this case, it is possible for both of these transaction to succeed. If, however, TX1 went and performed some write which causally impacted TX2, one of these would have to fail. As it stands, it is possible for the system to order TX1 before TX2 and retain serializability.

If TX1 were actually an UPDATE statement which performed a write, then one of the two transactions would have to fail.

[beikov]

That's good to know. So this means, the for update clause can't be trusted and I probably have to disable all tests that rely on it within Hibernate?

Just out of curiosity, is this still ACID compliant? Consider the following pseudo-program:

tx0 {
    insert("insert into tbl1(id, value) values (1, 'original')")
}
tx1 {
    var value = select("select t.value from tbl1 t where t.id = 1 for update")
    if (value == "original")
        insert("insert into tbl2(id) values (1)")
}
tx2 {
    update("update tbl1 t set t.value = 'changed' where t.id = 1")
}

In every other database that respects locks, the possible end states are

1. tbl1 = {(1, 'original')}, tbl2 = {(1)} if tx2 runs after tx1 acquired the lock
2. tbl1 = {(1, 'changed')}, tbl2 = {} if tx2 runs before tx1 acquired the lock

Now you are telling me that CockroachDB also allows the following end state?

3. tbl1 = {(1, 'changed')}, tbl2 = {(1)}

Doesn't this violate consistency/isolation somehow?

[ajwerner]

I'm confused as to how your outcome 1 happens. It implies that tx2 does not run at all, right?

Let's assume tx0 occurs before tx1 or tx2. Now, given serializability, either tx1 happens before tx2 or tx2 happens before tx1.

If tx2 happens first, then you'll get outcome 2. If tx1 happens first, then you'll move to tbl1 = {(1, 'original')}, tbl2 = {(1)} and then tx2 will run and you'll get tbl1 = {(1, 'changed')}, tbl2 = {(1)} after tx1 commits and unblocks tx2.

[beikov]

Yeah sorry for that confusing example. During the construction of the example I kind of messed up. My expectation is that TX2 runs while TX1 is running. Something like this:

tx0 {
    insert("insert into tbl1(id, value) values (1, 'original')")
}
tx1 {
    parallel(
        var value = select("select t.value from tbl1 t where t.id = 1 for update")
        tx2 {
            update("update tbl1 t set t.value = 'changed' where t.id = 1")
        }
    )
    if (value == "original")
        insert("insert into tbl2(id) values (1)")
}

[beikov]

Not sure if I can come up with a good example here, but it's confusing that this last pseudo-program can "finish" with TX2 succeeding in CockroachDB but not in other DBs.