Adding a test for speculative insert abort case

Started by Melanie Plagemanover 6 years ago31 messages
#1Melanie Plageman
melanieplageman@gmail.com

Today, while poking around the table_complete_speculative code which Ashwin
mentioned in [1]/messages/by-id/CALfoeitk7-TACwYv3hCw45FNPjkA86RfXg4iQ5kAOPhR+F1Y4w@mail.gmail.com, we were trying to understand when exactly we would
complete a
speculative insert by aborting.

We added a logging message to heapam_tuple_complete_speculative before it
calls
heap_abort_speculative and ran the regression and isolation tests to see
what
test failed so we knew how to exercise this codepath.
No tests failed, so we spent some time trying to understand when 'succeeded'
would be true coming into heap_tuple_complete_speculative.

Eventually, we figured out that if one transaction speculatively inserts a
tuple into a table with a unique index and then pauses before inserting the
value into the index, and while it is paused, another transaction
successfully
inserts a value which would conflict with that value, it would result in an
aborted speculative insertion.

t1(id,val)
unique index t1(id)

s1: insert into t1 values(1, 'someval') on conflict(id) do update set val =
'someotherval';
s1: pause in ExecInsert before calling ExecInsertIndexTuples
s2: insert into t1 values(1, 'someval');
s2: continue

We don't know of a way to add this scenario to the current isolation
framework.

Can anyone think of a good way to put this codepath under test?

- Melanie & Ashwin

[1]: /messages/by-id/CALfoeitk7-TACwYv3hCw45FNPjkA86RfXg4iQ5kAOPhR+F1Y4w@mail.gmail.com
/messages/by-id/CALfoeitk7-TACwYv3hCw45FNPjkA86RfXg4iQ5kAOPhR+F1Y4w@mail.gmail.com

#2Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#1)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-04-30 17:15:55 -0700, Melanie Plageman wrote:

Today, while poking around the table_complete_speculative code which Ashwin
mentioned in [1], we were trying to understand when exactly we would
complete a
speculative insert by aborting.

(FWIW, it's on my todo queue to look at this)

We added a logging message to heapam_tuple_complete_speculative before it
calls
heap_abort_speculative and ran the regression and isolation tests to see
what
test failed so we knew how to exercise this codepath.
No tests failed, so we spent some time trying to understand when 'succeeded'
would be true coming into heap_tuple_complete_speculative.

Eventually, we figured out that if one transaction speculatively inserts a
tuple into a table with a unique index and then pauses before inserting the
value into the index, and while it is paused, another transaction
successfully
inserts a value which would conflict with that value, it would result in an
aborted speculative insertion.

t1(id,val)
unique index t1(id)

s1: insert into t1 values(1, 'someval') on conflict(id) do update set val =
'someotherval';
s1: pause in ExecInsert before calling ExecInsertIndexTuples
s2: insert into t1 values(1, 'someval');
s2: continue

We don't know of a way to add this scenario to the current isolation
framework.

Can anyone think of a good way to put this codepath under test?

Not easily so - that's why the ON CONFLICT patch didn't add code
coverage for it :(. I wonder if you could whip something up by having
another non-unique expression index, where the expression acquires a
advisory lock? If that advisory lock where previously acquired by
another session, that should allow to write a reliable isolation test?

Alternatively, as a fallback, there's a short pgbench test, I wonder if we
could just adapt that to use ON CONFLICT UPDATE?

Greetings,

Andres Freund

#3Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#2)
Re: Adding a test for speculative insert abort case

On Tue, Apr 30, 2019 at 5:22 PM Andres Freund <andres@anarazel.de> wrote:

Not easily so - that's why the ON CONFLICT patch didn't add code
coverage for it :(. I wonder if you could whip something up by having
another non-unique expression index, where the expression acquires a
advisory lock? If that advisory lock where previously acquired by
another session, that should allow to write a reliable isolation test?

So, I took a look at one of the existing tests that does something like what
you mentioned and tried the following:
----------
create table t1(key int, val text);
create unique index t1_uniq_idx on t1(key);
create or replace function t1_lock_func(int) returns int immutable language
sql AS
'select pg_advisory_xact_lock_shared(1); select $1';
create index t1_lock_idx ON t1(t1_lock_func(key));
----------
s1:
begin isolation level read committed;
insert into t1 values(1, 'someval');
s2:
set default_transaction_isolation = 'read committed';
insert into t1 values(1, 'anyval') on conflict(key) do update set val =
'updatedval';
----------

So, the above doesn't work because s2 waits to acquire the lock in the first
phase of the speculative insert -- when it is just checking the index,
before
inserting to the table and before inserting to the index.

Then when the s1 is committed, we won't execute the speculative insert code
at
all and will go into ExecOnConflictUpdate instead.

Maybe I just need a different kind of advisory lock to allow
ExecCheckIndexConstraints to be able to check the index here. I figured it
is a
read operation, so a shared advisory lock should be okay, but it seems like
it
is not okay

Without knowing any of the context, on an initial pass of debugging, I did
notice that, in the initial check of the index by s2, XactLockTableWait is
called with reason_wait as XLTW_InsertIndex (even though we are just trying
to
check it, so maybe it knows our intentions:))

Is there something I can do in the test to allow my check to go
through but the insert to have to wait?

--
Melanie Plageman

In reply to: Melanie Plageman (#1)
Re: Adding a test for speculative insert abort case

On Tue, Apr 30, 2019 at 5:16 PM Melanie Plageman
<melanieplageman@gmail.com> wrote:

Can anyone think of a good way to put this codepath under test?

During the initial development of ON CONFLICT, speculative insertion
itself was tested using custom stress testing that you can still get
here:

https://github.com/petergeoghegan/jjanes_upsert

I'm not sure that this is something that you can adopt, but I
certainly found it very useful at the time. It tests whether or not
there is agreement among concurrent speculative inserters, and whether
or not there are "unprincipled deadlocks" (user hostile deadlocks that
cannot be fixed by reordering something in application code).

--
Peter Geoghegan

#5Andres Freund
andres@anarazel.de
In reply to: Peter Geoghegan (#4)
Re: Adding a test for speculative insert abort case

Hi,

On April 30, 2019 6:43:08 PM PDT, Peter Geoghegan <pg@bowt.ie> wrote:

On Tue, Apr 30, 2019 at 5:16 PM Melanie Plageman
<melanieplageman@gmail.com> wrote:

Can anyone think of a good way to put this codepath under test?

During the initial development of ON CONFLICT, speculative insertion
itself was tested using custom stress testing that you can still get
here:

https://github.com/petergeoghegan/jjanes_upsert

I'm not sure that this is something that you can adopt, but I
certainly found it very useful at the time. It tests whether or not
there is agreement among concurrent speculative inserters, and whether
or not there are "unprincipled deadlocks" (user hostile deadlocks that
cannot be fixed by reordering something in application code).

I think we want a deterministic case. I recall asking for that back then...

Andres
--
Sent from my Android device with K-9 Mail. Please excuse my brevity.

#6Thomas Munro
thomas.munro@gmail.com
In reply to: Melanie Plageman (#1)
Re: Adding a test for speculative insert abort case

On Wed, May 1, 2019 at 12:16 PM Melanie Plageman
<melanieplageman@gmail.com> wrote:

s1: insert into t1 values(1, 'someval') on conflict(id) do update set val = 'someotherval';
s1: pause in ExecInsert before calling ExecInsertIndexTuples
s2: insert into t1 values(1, 'someval');
s2: continue

We don't know of a way to add this scenario to the current isolation framework.

Can anyone think of a good way to put this codepath under test?

Hi Melanie,

I think it'd be nice to have a set of macros that can create wait
points in the C code that isolation tests can control, in a special
build. Perhaps there could be shm hash table of named wait points in
shared memory; if DEBUG_WAIT_POINT("foo") finds that "foo" is not
present, it continues, but if it finds an entry it waits for it to go
away. Then isolation tests could add/remove names and signal a
condition variable to release waiters.

I contemplated that while working on SKIP LOCKED, which had a bunch of
weird edge cases that I tested by inserting throw-away wait-point code
like this:

/messages/by-id/CADLWmXXss83oiYD0pn_SfQfg+yNEpPbPvgDb8w6Fh--jScSybA@mail.gmail.com

--
Thomas Munro
https://enterprisedb.com

#7Melanie Plageman
melanieplageman@gmail.com
In reply to: Thomas Munro (#6)
Re: Adding a test for speculative insert abort case

On Tue, Apr 30, 2019 at 7:14 PM Thomas Munro <thomas.munro@gmail.com> wrote:

I think it'd be nice to have a set of macros that can create wait
points in the C code that isolation tests can control, in a special
build. Perhaps there could be shm hash table of named wait points in
shared memory; if DEBUG_WAIT_POINT("foo") finds that "foo" is not
present, it continues, but if it finds an entry it waits for it to go
away. Then isolation tests could add/remove names and signal a
condition variable to release waiters.

I contemplated that while working on SKIP LOCKED, which had a bunch of
weird edge cases that I tested by inserting throw-away wait-point code
like this:

/messages/by-id/CADLWmXXss83oiYD0pn_SfQfg+yNEpPbPvgDb8w6Fh--jScSybA@mail.gmail.com

Yes, I agree it would be nice to have a framework like this.

Greenplum actually has a fault injection framework that, I believe, works
similarly to what you are describing -- i.e. sets a variable in shared
memory.
There is an extension, gp_inject_fault, which allows you to set the faults.
Andreas Scherbaum wrote a blog post about how to use it [1]http://engineering.pivotal.io/post/testing_greenplum_database_using_fault_injection/.

The Greenplum implementation is not documented particularly well in the
code,
but, it is something that folks working on Greenplum have talked about
modifying
and proposing to Postgres.

[1]: http://engineering.pivotal.io/post/testing_greenplum_database_using_fault_injection/

--
Melanie Plageman

#8Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#3)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-04-30 18:34:42 -0700, Melanie Plageman wrote:

On Tue, Apr 30, 2019 at 5:22 PM Andres Freund <andres@anarazel.de> wrote:

Not easily so - that's why the ON CONFLICT patch didn't add code
coverage for it :(. I wonder if you could whip something up by having
another non-unique expression index, where the expression acquires a
advisory lock? If that advisory lock where previously acquired by
another session, that should allow to write a reliable isolation test?

So, I took a look at one of the existing tests that does something like what
you mentioned and tried the following:
----------
create table t1(key int, val text);
create unique index t1_uniq_idx on t1(key);
create or replace function t1_lock_func(int) returns int immutable language
sql AS
'select pg_advisory_xact_lock_shared(1); select $1';
create index t1_lock_idx ON t1(t1_lock_func(key));
----------
s1:
begin isolation level read committed;
insert into t1 values(1, 'someval');
s2:
set default_transaction_isolation = 'read committed';
insert into t1 values(1, 'anyval') on conflict(key) do update set val =
'updatedval';
----------

So, the above doesn't work because s2 waits to acquire the lock in the first
phase of the speculative insert -- when it is just checking the index,
before
inserting to the table and before inserting to the index.

Couldn't that be addressed by having t1_lock_func() acquire two locks?
One for blocking during the initial index probe, and one for the
speculative insertion?

I'm imagining something like

if (pg_try_advisory_xact_lock(1))
pg_advisory_xact_lock(2);
else
pg_advisory_xact_lock(1);

in t1_lock_func. If you then make the session something roughly like

s1: pg_advisory_xact_lock(1);
s1: pg_advisory_xact_lock(2);

s2: upsert t1 <blocking for 1>
s1: pg_advisory_xact_unlock(1);
s2: <continuing>
s2: <blocking for 2>
s1: insert into t1 values(1, 'someval');
s1: pg_advisory_xact_unlock(2);
s2: <continuing>
s2: spec-conflict

Greetings,

Andres Freund

#9Andres Freund
andres@anarazel.de
In reply to: Andres Freund (#8)
1 attachment(s)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-05-01 11:41:48 -0700, Andres Freund wrote:

I'm imagining something like

if (pg_try_advisory_xact_lock(1))
pg_advisory_xact_lock(2);
else
pg_advisory_xact_lock(1);

in t1_lock_func. If you then make the session something roughly like

s1: pg_advisory_xact_lock(1);
s1: pg_advisory_xact_lock(2);

s2: upsert t1 <blocking for 1>
s1: pg_advisory_xact_unlock(1);
s2: <continuing>
s2: <blocking for 2>
s1: insert into t1 values(1, 'someval');
s1: pg_advisory_xact_unlock(2);
s2: <continuing>
s2: spec-conflict

Needed to be slightly more complicated than that, but not that much. See
the attached test. What do you think?

I think we should apply something like this (minus the WARNING, of
course). It's a bit complicated, but it seems worth covering this
special case.

Greetings,

Andres Freund

Attachments:

speculative-conflict.difftext/x-diff; charset=us-asciiDownload
diff --git a/src/backend/executor/nodeModifyTable.c b/src/backend/executor/nodeModifyTable.c
index 444c0c05746..bad50aab007 100644
--- a/src/backend/executor/nodeModifyTable.c
+++ b/src/backend/executor/nodeModifyTable.c
@@ -554,6 +554,8 @@ ExecInsert(ModifyTableState *mtstate,
 												   &specConflict,
 												   arbiterIndexes);
 
+			elog(WARNING, "speculative: %d", !!specConflict);
+
 			/* adjust the tuple's state accordingly */
 			table_complete_speculative(resultRelationDesc, slot,
 									   specToken, specConflict);
diff --git a/src/test/isolation/expected/speculative-conflict.out b/src/test/isolation/expected/speculative-conflict.out
new file mode 100644
index 00000000000..7b6ce4bb989
--- /dev/null
+++ b/src/test/isolation/expected/speculative-conflict.out
@@ -0,0 +1,185 @@
+Parsed test spec with 3 sessions
+
+starting permutation: controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_2_2 controller_show controller_unlock_1_2 controller_show
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: WARNING:  speculative: 0
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2    
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+s1: WARNING:  speculative: 1
+step s1_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
+
+starting permutation: controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show controller_unlock_2_2 controller_show
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+s1: WARNING:  speculative: 0
+step s1_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s1    
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: WARNING:  speculative: 1
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s1 with conflict update s2
+
+starting permutation: controller_locks controller_show s1_begin s2_begin s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show controller_unlock_2_2 controller_show s1_commit controller_show s2_commit controller_show
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_begin: BEGIN;
+step s2_begin: BEGIN;
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+s1: WARNING:  speculative: 0
+step s1_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: WARNING:  speculative: 1
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_commit: COMMIT;
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s1    
+step s2_commit: COMMIT;
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s1 with conflict update s2
diff --git a/src/test/isolation/specs/speculative-conflict.spec b/src/test/isolation/specs/speculative-conflict.spec
new file mode 100644
index 00000000000..49de55e289a
--- /dev/null
+++ b/src/test/isolation/specs/speculative-conflict.spec
@@ -0,0 +1,129 @@
+setup
+{
+     CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+     BEGIN
+        RAISE NOTICE 'called for %', $1;
+
+	-- depending on lock state `, wait for lock 2 or 3
+        IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
+            RAISE NOTICE 'blocking 2';
+            PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 2);
+        ELSE
+            RAISE NOTICE 'blocking 3';
+            PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 3);
+        END IF;
+    RETURN $1;
+    END;$$;
+
+    CREATE TABLE upserttest(key text, data text);
+
+    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+}
+
+teardown
+{
+    DROP TABLE upserttest;
+}
+
+session "controller"
+step "controller_locks" {SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);}
+step "controller_unlock_1_1" { SELECT pg_advisory_unlock(1, 1); }
+step "controller_unlock_2_1" { SELECT pg_advisory_unlock(2, 1); }
+step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
+step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
+step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
+step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_show" {SELECT * FROM upserttest; }
+
+session "s1"
+setup { SET spec.session = 1; }
+step "s1_begin"  { BEGIN; }
+step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
+step "s1_commit"  { COMMIT; }
+
+session "s2"
+setup { SET spec.session = 2; }
+step "s2_begin"  { BEGIN; }
+step "s2_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; }
+step "s2_commit"  { COMMIT; }
+
+# Test that speculative locks are correctly acquired and released, s2
+# inserts, s1 updates.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the second session to finish insertion
+   "controller_unlock_2_2"
+   # This should now show a successful insertion
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # This should now show a successful UPSERT
+   "controller_show"
+
+# Test that speculative locks are correctly acquired and released, s2
+# inserts, s1 updates.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # This should now show a successful insertion
+   "controller_show"
+   # Allow the second session to finish insertion
+   "controller_unlock_2_2"
+   # This should now show a successful UPSERT
+   "controller_show"
+
+# Test that speculative locks are correctly acquired and released, s2
+# inserts, s1 updates.  With the added complication that transactions
+# don't immediately commit.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_begin" "s2_begin"
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # But the change isn't visible yet, nor should the second session continue
+   "controller_show"
+   # Allow the second session to finish insertion, but it's blocked
+   "controller_unlock_2_2"
+   "controller_show"
+   # But committing should unblock
+   "s1_commit"
+   "controller_show"
+   "s2_commit"
+   "controller_show"
#10Andres Freund
andres@anarazel.de
In reply to: Andres Freund (#9)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-05-10 14:40:38 -0700, Andres Freund wrote:

On 2019-05-01 11:41:48 -0700, Andres Freund wrote:

I'm imagining something like

if (pg_try_advisory_xact_lock(1))
pg_advisory_xact_lock(2);
else
pg_advisory_xact_lock(1);

in t1_lock_func. If you then make the session something roughly like

s1: pg_advisory_xact_lock(1);
s1: pg_advisory_xact_lock(2);

s2: upsert t1 <blocking for 1>
s1: pg_advisory_xact_unlock(1);
s2: <continuing>
s2: <blocking for 2>
s1: insert into t1 values(1, 'someval');
s1: pg_advisory_xact_unlock(2);
s2: <continuing>
s2: spec-conflict

Needed to be slightly more complicated than that, but not that much. See
the attached test. What do you think?

I think we should apply something like this (minus the WARNING, of
course). It's a bit complicated, but it seems worth covering this
special case.

And pushed. Let's see what the buildfarm says.

Regards,

Andres

#11Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#10)
Re: Adding a test for speculative insert abort case

On Tue, May 14, 2019 at 12:19 PM Andres Freund <andres@anarazel.de> wrote:

Hi,

On 2019-05-10 14:40:38 -0700, Andres Freund wrote:

On 2019-05-01 11:41:48 -0700, Andres Freund wrote:

I'm imagining something like

if (pg_try_advisory_xact_lock(1))
pg_advisory_xact_lock(2);
else
pg_advisory_xact_lock(1);

in t1_lock_func. If you then make the session something roughly like

s1: pg_advisory_xact_lock(1);
s1: pg_advisory_xact_lock(2);

s2: upsert t1 <blocking for 1>
s1: pg_advisory_xact_unlock(1);
s2: <continuing>
s2: <blocking for 2>
s1: insert into t1 values(1, 'someval');
s1: pg_advisory_xact_unlock(2);
s2: <continuing>
s2: spec-conflict

Needed to be slightly more complicated than that, but not that much. See
the attached test. What do you think?

I think we should apply something like this (minus the WARNING, of
course). It's a bit complicated, but it seems worth covering this
special case.

And pushed. Let's see what the buildfarm says.

Regards,

Andres

So, I recognize this has already been merged. However, after reviewing the
test,
I believe there is a typo in the second permutation.

# Test that speculative locks are correctly acquired and released, s2
# inserts, s1 updates.

I think you meant

# Test that speculative locks are correctly acquired and released, s1
# inserts, s2 updates.

Though, I'm actually not sure how this permutation is exercising different
code than the first permutation.

Also, it would make the test easier to understand for me if, for instances
of the
word "lock" in the test description and comments, you specified locktype --
e.g.
advisory lock.
I got confused between the speculative lock, the object locks on the index
which
are required for probing or inserting into the index, and the advisory
locks.

Below is a potential re-wording of one of the permutations that is more
explicit
and more clear to me as a reader.

# Test that speculative locks are correctly acquired and released, s2
# inserts, s1 updates.
permutation
# acquire a number of advisory locks, to control execution flow - the
# blurt_and_lock function acquires advisory locks that allow us to
# continue after a) the optimistic conflict probe b) after the
# insertion of the speculative tuple.

"controller_locks"
"controller_show"
# Both sessions will be waiting on advisory locks
"s1_upsert" "s2_upsert"
"controller_show"
# Switch both sessions to wait on the other advisory lock next time
"controller_unlock_1_1" "controller_unlock_2_1"
# Allow both sessions to do the optimistic conflict probe and do the
# speculative insertion into the table
# They will then be waiting on another advisory lock when they attempt to
# update the index
"controller_unlock_1_3" "controller_unlock_2_3"
"controller_show"
# Allow the second session to finish insertion (complete speculative)
"controller_unlock_2_2"
# This should now show a successful insertion
"controller_show"
# Allow the first session to finish insertion (abort speculative)
"controller_unlock_1_2"
# This should now show a successful UPSERT
"controller_show"

I was also wondering: Is it possible that one of the "controller_unlock_*"
functions will get called before the session with the upsert has had a
chance to
move forward in its progress and be waiting on that lock?
That is, given that we don't check that the sessions are waiting on the
locks
before unlocking them, is there a race condition?

I noticed that there is not a test case which would cover the speculative
wait
codepath. This seems much more challenging, however, it does seem like a
worthwhile test to have.

--
Melanie Plageman

#12Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#11)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-05-15 18:34:15 -0700, Melanie Plageman wrote:

So, I recognize this has already been merged. However, after reviewing the
test,
I believe there is a typo in the second permutation.

# Test that speculative locks are correctly acquired and released, s2
# inserts, s1 updates.

I think you meant

# Test that speculative locks are correctly acquired and released, s1
# inserts, s2 updates.

Hm, yea.

Though, I'm actually not sure how this permutation is exercising differen.
code than the first permutation.

I was basically just trying to make sure that there's a sensible result
independent of which transaction "wins", while keeping the command-start
order the same. Probably not crucial, but seemed like a reasonable
addition.

Also, it would make the test easier to understand for me if, for instances
of the
word "lock" in the test description and comments, you specified locktype --
e.g.
advisory lock.
I got confused between the speculative lock, the object locks on the index
which
are required for probing or inserting into the index, and the advisory
locks.

Below is a potential re-wording of one of the permutations that is more
explicit
and more clear to me as a reader.

Minor gripe: For the future, it's easier to such changes as a patch as
well - otherwise others need to move it to the file and diff it to
comment on the changes.

# Test that speculative locks are correctly acquired and released, s2
# inserts, s1 updates.
permutation
# acquire a number of advisory locks, to control execution flow - the
# blurt_and_lock function acquires advisory locks that allow us to
# continue after a) the optimistic conflict probe b) after the
# insertion of the speculative tuple.

"controller_locks"
"controller_show"
# Both sessions will be waiting on advisory locks
"s1_upsert" "s2_upsert"
"controller_show"
# Switch both sessions to wait on the other advisory lock next time
"controller_unlock_1_1" "controller_unlock_2_1"
# Allow both sessions to do the optimistic conflict probe and do the
# speculative insertion into the table
# They will then be waiting on another advisory lock when they attempt to
# update the index
"controller_unlock_1_3" "controller_unlock_2_3"
"controller_show"
# Allow the second session to finish insertion (complete speculative)
"controller_unlock_2_2"
# This should now show a successful insertion
"controller_show"
# Allow the first session to finish insertion (abort speculative)
"controller_unlock_1_2"
# This should now show a successful UPSERT
"controller_show"

I was also wondering: Is it possible that one of the
"controller_unlock_*" functions will get called before the session
with the upsert has had a chance to move forward in its progress and
be waiting on that lock? That is, given that we don't check that the
sessions are waiting on the locks before unlocking them, is there a
race condition?

Isolationtester only switches between commands when either the command
finished, or once it's know to be waiting for a lock. Therefore I don't
think this race exists? That logic is in the if (flags & STEP_NONBLOCK)
block in isolationtester.c:try_complete_step().

Does that make sense? Or did I misunderstand your concern?

I noticed that there is not a test case which would cover the speculative
wait
codepath. This seems much more challenging, however, it does seem like a
worthwhile test to have.

Shouldn't be that hard to create, I think. I think acquiring another
lock in a second, non-unique, expression index, ought to do the trick?
It probably has to be created after the unique index (so it's later in
the

Greetings,

Andres Freund

#13Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#12)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Wed, May 15, 2019 at 6:50 PM Andres Freund <andres@anarazel.de> wrote:

Also, it would make the test easier to understand for me if, for

instances

of the
word "lock" in the test description and comments, you specified locktype

--

e.g.
advisory lock.
I got confused between the speculative lock, the object locks on the

index

which
are required for probing or inserting into the index, and the advisory
locks.

Below is a potential re-wording of one of the permutations that is more
explicit
and more clear to me as a reader.

Minor gripe: For the future, it's easier to such changes as a patch as
well - otherwise others need to move it to the file and diff it to
comment on the changes.

Will do--attached, though the wording is a rough suggestion.

I was also wondering: Is it possible that one of the

"controller_unlock_*" functions will get called before the session
with the upsert has had a chance to move forward in its progress and
be waiting on that lock? That is, given that we don't check that the
sessions are waiting on the locks before unlocking them, is there a
race condition?

Isolationtester only switches between commands when either the command
finished, or once it's know to be waiting for a lock. Therefore I don't
think this race exists? That logic is in the if (flags & STEP_NONBLOCK)
block in isolationtester.c:try_complete_step().

Does that make sense? Or did I misunderstand your concern?

I see. I didn't know what the blocking/waiting logic was in the isolation
framework. Nevermind, then.

I noticed that there is not a test case which would cover the speculative
wait
codepath. This seems much more challenging, however, it does seem like a
worthwhile test to have.

Shouldn't be that hard to create, I think. I think acquiring another
lock in a second, non-unique, expression index, ought to do the trick?
It probably has to be created after the unique index (so it's later in
the

I would think that the sequence would be s1 and s2 probe the index, s1 and
s2
insert into the table, s1 updates the index but does not complete the
speculative insert and clear the token (pause before
table_complete_speculative). s2 is in speculative wait when attempting to
update
the index.

Something like

permutation
"controller_locks"
"controller_show"
"s1_upsert" "s2_upsert"
"controller_show"
"controller_unlock_1_1" "controller_unlock_2_1"
"controller_unlock_1_3" "controller_unlock_2_3"
"controller_unlock_1_2"
"s1_magically_pause_before_complete_speculative"
# put s2 in speculative wait
"controller_unlock_2_2"
"s1_magically_unpause_before_complete_speculative"

So, how would another lock on another index keep s1 from clearing the
speculative token after it has updated the index?

--
Melanie Plageman

Attachments:

specconflict_permutation_comment_update.patchapplication/octet-stream; name=specconflict_permutation_comment_update.patchDownload
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..3c7f9c2239 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -70,24 +70,29 @@ step "s2_commit"  { COMMIT; }
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
+
    "controller_locks"
    "controller_show"
+   # Both sessions will be waiting on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
-   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   # Switch both sessions to wait on the other advisory lock next time
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
-   # Allow the second session to finish insertion
+   # Allow the second session to finish insertion (complete speculative)
    "controller_unlock_2_2"
    # This should now show a successful insertion
    "controller_show"
-   # Allow the first session to finish insertion
+   # Allow the first session to finish insertion (abort speculative)
    "controller_unlock_1_2"
    # This should now show a successful UPSERT
    "controller_show"
#14Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#13)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-05-15 20:35:49 -0700, Melanie Plageman wrote:

I noticed that there is not a test case which would cover the speculative
wait
codepath. This seems much more challenging, however, it does seem like a
worthwhile test to have.

Shouldn't be that hard to create, I think. I think acquiring another
lock in a second, non-unique, expression index, ought to do the trick?
It probably has to be created after the unique index (so it's later in
the

I would think that the sequence would be s1 and s2 probe the index, s1 and
s2
insert into the table, s1 updates the index but does not complete the
speculative insert and clear the token (pause before
table_complete_speculative). s2 is in speculative wait when attempting to
update
the index.

Something like

permutation
"controller_locks"
"controller_show"
"s1_upsert" "s2_upsert"
"controller_show"
"controller_unlock_1_1" "controller_unlock_2_1"
"controller_unlock_1_3" "controller_unlock_2_3"
"controller_unlock_1_2"
"s1_magically_pause_before_complete_speculative"
# put s2 in speculative wait
"controller_unlock_2_2"
"s1_magically_unpause_before_complete_speculative"

So, how would another lock on another index keep s1 from clearing the
speculative token after it has updated the index?

If there were a second index on upserttest, something like CREATE INDEX
ON upserttest((blurt_and_lock2(key))); and blurt_and_lock2 acquired a
lock on (current_setting('spec.session')::int, 4), ISTM you could cause
a block to happen after the first index (the unique one, used for ON
CONFLICT) successfully created the index entry, but before
complete_speculative is called. Shouldn't that fulfil your
s1_magically_pause_before_complete_speculative goal? The
controller_locks would only acquire the (1, 4) lock, thereby *not*
blocking s2 (or you could just release the lock in a separate step).

Greetings,

Andres Freund

#15Ashwin Agrawal
aagrawal@pivotal.io
In reply to: Melanie Plageman (#13)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Wed, May 15, 2019 at 8:36 PM Melanie Plageman <melanieplageman@gmail.com>
wrote:

On Wed, May 15, 2019 at 6:50 PM Andres Freund <andres@anarazel.de> wrote:

I noticed that there is not a test case which would cover the

speculative

wait
codepath. This seems much more challenging, however, it does seem like a
worthwhile test to have.

Shouldn't be that hard to create, I think. I think acquiring another
lock in a second, non-unique, expression index, ought to do the trick?
It probably has to be created after the unique index (so it's later in
the

I would think that the sequence would be s1 and s2 probe the index, s1

and s2
insert into the table, s1 updates the index but does not complete the
speculative insert and clear the token (pause before
table_complete_speculative). s2 is in speculative wait when attempting to
update
the index.

Something like

permutation
"controller_locks"
"controller_show"
"s1_upsert" "s2_upsert"
"controller_show"
"controller_unlock_1_1" "controller_unlock_2_1"
"controller_unlock_1_3" "controller_unlock_2_3"
"controller_unlock_1_2"
"s1_magically_pause_before_complete_speculative"
# put s2 in speculative wait
"controller_unlock_2_2"
"s1_magically_unpause_before_complete_speculative"

So, how would another lock on another index keep s1 from clearing the
speculative token after it has updated the index?

The second index would help to hold the session after inserting the tuple
in unique index but before completing the speculative insert. Hence, helps
to create the condition easily. I believe order of index insertion is
helping here that unique index is inserted and then non-unique index is
inserted too.

Attaching patch with the test using the idea Andres mentioned and it works
to excercise the speculative wait.

Attachments:

0001-Add-test-to-validate-speculative-wait-is-performed.patchtext/x-patch; charset=US-ASCII; name=0001-Add-test-to-validate-speculative-wait-is-performed.patchDownload
From 24e44f1a971e8957503205376d655e22b0e5fbdc Mon Sep 17 00:00:00 2001
From: Ashwin Agrawal <aagrawal@pivotal.io>
Date: Wed, 15 May 2019 22:21:48 -0700
Subject: [PATCH] Add test to validate speculative wait is performed.

---
 .../expected/insert-conflict-specconflict.out | 69 +++++++++++++++++++
 .../specs/insert-conflict-specconflict.spec   | 44 ++++++++++++
 2 files changed, 113 insertions(+)

diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 5726bdb8e8..ca2b65ca56 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -177,3 +177,72 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX ON upserttest((blurt_and_lock2(key)));
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step controller_print_speculative_locks: SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted;
+locktype       classid        objid          mode           granted        
+
+speculative token4              0              ShareLock      f              
+speculative token4              0              ExclusiveLock  t              
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..71e46727cf 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -23,6 +23,13 @@ setup
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock1 called for %', $1;
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
     CREATE TABLE upserttest(key text, data text);
 
     CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
@@ -45,7 +52,10 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted; }
 
 session "s1"
 setup
@@ -54,6 +64,7 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
+step "s1_create_non_unique_index" { CREATE INDEX ON upserttest((blurt_and_lock2(key))); }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
 step "s1_commit"  { COMMIT; }
 
@@ -147,3 +158,36 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if session sees a speculatively
+# inserted tuple. Speculatively inserted tuple means tuple is inserted into the
+# table and unique index but yet to *complete* the speculative insertion
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "s1_create_non_unique_index"
+   "controller_locks"
+   "controller_show"
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report waiting on speculative lock
+   "controller_print_speculative_locks"
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
-- 
2.19.1

#16Melanie Plageman
melanieplageman@gmail.com
In reply to: Ashwin Agrawal (#15)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Wed, May 15, 2019 at 10:32 PM Ashwin Agrawal <aagrawal@pivotal.io> wrote:

The second index would help to hold the session after inserting the tuple
in unique index but before completing the speculative insert. Hence, helps
to create the condition easily. I believe order of index insertion is
helping here that unique index is inserted and then non-unique index is
inserted too.

Oh, cool. I didn't know that execution order would be guaranteed for which
index
to insert into first.

Attaching patch with the test using the idea Andres mentioned and it works
to excercise the speculative wait.

It looks good.
I thought it would be helpful to mention why you have s1 create the
non-unique
index after the permutation has begun. You don't want this index to
influence
the behavior of the other permutations--this part makes sense. However, why
have
s1 do it instead of the controller?

I added a couple suggested changes to the comments in the permutation in the
version in the patch I attached. Note that I did not update the answer
files.
(These suggested changes to comments are in distinct from and would be in
addition to the suggestions I had for the wording of the comments overall
in the
above email I sent).

--
Melanie Plageman

Attachments:

0002-Add-test-to-validate-speculative-wait-is-performed.patchapplication/octet-stream; name=0002-Add-test-to-validate-speculative-wait-is-performed.patchDownload
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 71e46727cf..4ae33319ab 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -159,14 +159,20 @@ permutation
    "s2_commit"
    "controller_show"
 
-# Test that speculative wait is performed if session sees a speculatively
-# inserted tuple. Speculatively inserted tuple means tuple is inserted into the
-# table and unique index but yet to *complete* the speculative insertion
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
-   # continue after a) the optimistic conflict probe b) after the
+   # continue after a) the optimistic conflict probe and b) after the
    # insertion of the speculative tuple.
+   # blurt_and_lock2 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations. also, s1 creates it instead of the controller because ...
    "s1_create_non_unique_index"
    "controller_locks"
    "controller_show"
@@ -184,9 +190,9 @@ permutation
    "controller_unlock_2_2"
    # This should still not show a successful insertion
    "controller_show"
-   # Allow the first session, it should perform speculative wait
+   # Allow the first session to continue, it should perform speculative wait
    "controller_unlock_1_2"
-   # Should report waiting on speculative lock
+   # Should report s1 is waiting on speculative lock
    "controller_print_speculative_locks"
    "controller_unlock_2_4"
    # This should now show a successful UPSERT
#17Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#16)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-05-16 13:59:47 -0700, Melanie Plageman wrote:

On Wed, May 15, 2019 at 10:32 PM Ashwin Agrawal <aagrawal@pivotal.io> wrote:

The second index would help to hold the session after inserting the tuple
in unique index but before completing the speculative insert. Hence, helps
to create the condition easily. I believe order of index insertion is
helping here that unique index is inserted and then non-unique index is
inserted too.

Oh, cool. I didn't know that execution order would be guaranteed for which
index
to insert into first.

It's not *strictly* speaking *always* well defined. The list of indexes
is sorted by the oid of the index - so once created, it's
consistent. But when the oid assignment wraps around, it'd be the other
way around. But I think it's ok to disregard that - it'll never happen
in regression tests run against a new cluster, and you'd have to run
tests against an installed cluster for a *LONG* time for a *tiny* window
where the wraparound would happen precisely between the creation of the
two indexes.

Makes sense?

I guess we could make that case a tiny bit easier to diagnose in the
extremely unlikely case it happens by having a step that outputs
SELECT 'index_a'::regclass::int8 < 'index_b'::regclass::int8;

Greetings,

Andres Freund

#18Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#17)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Thu, May 16, 2019 at 2:03 PM Andres Freund <andres@anarazel.de> wrote:

Hi,

On 2019-05-16 13:59:47 -0700, Melanie Plageman wrote:

On Wed, May 15, 2019 at 10:32 PM Ashwin Agrawal <aagrawal@pivotal.io>

wrote:

The second index would help to hold the session after inserting the

tuple

in unique index but before completing the speculative insert. Hence,

helps

to create the condition easily. I believe order of index insertion is
helping here that unique index is inserted and then non-unique index is
inserted too.

Oh, cool. I didn't know that execution order would be guaranteed for

which

index
to insert into first.

It's not *strictly* speaking *always* well defined. The list of indexes
is sorted by the oid of the index - so once created, it's
consistent. But when the oid assignment wraps around, it'd be the other
way around. But I think it's ok to disregard that - it'll never happen
in regression tests run against a new cluster, and you'd have to run
tests against an installed cluster for a *LONG* time for a *tiny* window
where the wraparound would happen precisely between the creation of the
two indexes.

Makes sense?

Yep, thanks.

I guess we could make that case a tiny bit easier to diagnose in the
extremely unlikely case it happens by having a step that outputs
SELECT 'index_a'::regclass::int8 < 'index_b'::regclass::int8;

Good idea.
I squashed the changes I suggested in previous emails, Ashwin's patch, my
suggested updates to that patch, and the index order check all into one
updated
patch attached.

--
Melanie Plageman

Attachments:

0003-Add-test-to-validate-speculative-wait-is-performed.patchapplication/octet-stream; name=0003-Add-test-to-validate-speculative-wait-is-performed.patchDownload
diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 5726bdb8e8..1fbe7bc4d5 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -177,3 +177,76 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key)));
+step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
+?column?       
+
+t              
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step controller_print_speculative_locks: SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted;
+locktype       classid        objid          mode           granted        
+
+speculative token4              0              ShareLock      f              
+speculative token4              0              ExclusiveLock  t              
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..dd38d2642e 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -23,9 +23,16 @@ setup
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock1 called for %', $1;
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
     CREATE TABLE upserttest(key text, data text);
 
-    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+    CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock(key)));
 }
 
 teardown
@@ -45,7 +52,10 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted; }
 
 session "s1"
 setup
@@ -54,6 +64,8 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
+step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key))); }
+step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
 step "s1_commit"  { COMMIT; }
 
@@ -70,49 +82,57 @@ step "s2_commit"  { COMMIT; }
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
-   # Allow the second session to finish insertion
+   # Allow the second session to finish insertion (complete speculative)
    "controller_unlock_2_2"
    # This should now show a successful insertion
    "controller_show"
-   # Allow the first session to finish insertion
+   # Allow the first session to finish insertion (abort speculative)
    "controller_unlock_1_2"
    # This should now show a successful UPSERT
    "controller_show"
 
-# Test that speculative locks are correctly acquired and released, s2
-# inserts, s1 updates.
+# Test that speculative locks are correctly acquired and released, s1
+# inserts, s2 updates.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
-   # Allow the first session to finish insertion
+   # Allow the first session to finish insertion (complete speculative)
    "controller_unlock_1_2"
    # This should now show a successful insertion
    "controller_show"
-   # Allow the second session to finish insertion
+   # Allow the second session to finish insertion (abort speculative)
    "controller_unlock_2_2"
    # This should now show a successful UPSERT
    "controller_show"
@@ -121,18 +141,22 @@ permutation
 # inserts, s1 updates.  With the added complication that transactions
 # don't immediately commit.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_begin" "s2_begin"
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
    # Allow the first session to finish insertion
@@ -147,3 +171,50 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
+permutation
+   # acquire a number of advisory locks to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe and b) after the
+   # insertion of the speculative tuple.
+   # blurt_and_lock2 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations. also, s1 creates it instead of the controller because ...
+   "s1_create_non_unique_index"
+   # confirm that the insertion into the unique index will happen first
+   "s1_confirm_index_order"
+   "controller_locks"
+   "controller_show"
+   # Both sessions wait on advisory locks
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session to continue, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"
+   # Allow s2 to insert into the non-unique index and complete
+   # s1 will no longer wait and will proceed to update
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
#19Melanie Plageman
melanieplageman@gmail.com
In reply to: Melanie Plageman (#18)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Thu, May 16, 2019 at 8:46 PM Melanie Plageman <melanieplageman@gmail.com>
wrote:

I squashed the changes I suggested in previous emails, Ashwin's patch, my
suggested updates to that patch, and the index order check all into one
updated
patch attached.

I realized that the numbers at the front probably indicate which patch it
is in
a patch set and not the version, so, if that is the case, a renamed patch --
second version but the only patch needed if you are applying to master.
Is this right?

--
Melanie Plageman

Attachments:

0001-Add-test-to-validate-speculative-wait-is-performed-v2.patchapplication/octet-stream; name=0001-Add-test-to-validate-speculative-wait-is-performed-v2.patchDownload
diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 5726bdb8e8..1fbe7bc4d5 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -177,3 +177,76 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key)));
+step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
+?column?       
+
+t              
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step controller_print_speculative_locks: SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted;
+locktype       classid        objid          mode           granted        
+
+speculative token4              0              ShareLock      f              
+speculative token4              0              ExclusiveLock  t              
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..dd38d2642e 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -23,9 +23,16 @@ setup
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock1 called for %', $1;
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
     CREATE TABLE upserttest(key text, data text);
 
-    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+    CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock(key)));
 }
 
 teardown
@@ -45,7 +52,10 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative token' order by granted; }
 
 session "s1"
 setup
@@ -54,6 +64,8 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
+step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key))); }
+step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
 step "s1_commit"  { COMMIT; }
 
@@ -70,49 +82,57 @@ step "s2_commit"  { COMMIT; }
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
-   # Allow the second session to finish insertion
+   # Allow the second session to finish insertion (complete speculative)
    "controller_unlock_2_2"
    # This should now show a successful insertion
    "controller_show"
-   # Allow the first session to finish insertion
+   # Allow the first session to finish insertion (abort speculative)
    "controller_unlock_1_2"
    # This should now show a successful UPSERT
    "controller_show"
 
-# Test that speculative locks are correctly acquired and released, s2
-# inserts, s1 updates.
+# Test that speculative locks are correctly acquired and released, s1
+# inserts, s2 updates.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
-   # Allow the first session to finish insertion
+   # Allow the first session to finish insertion (complete speculative)
    "controller_unlock_1_2"
    # This should now show a successful insertion
    "controller_show"
-   # Allow the second session to finish insertion
+   # Allow the second session to finish insertion (abort speculative)
    "controller_unlock_2_2"
    # This should now show a successful UPSERT
    "controller_show"
@@ -121,18 +141,22 @@ permutation
 # inserts, s1 updates.  With the added complication that transactions
 # don't immediately commit.
 permutation
-   # acquire a number of locks, to control execution flow - the
+   # acquire a number of advisory locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
    "controller_show"
+   # Both sessions wait on advisory locks
    "s1_begin" "s2_begin"
    "s1_upsert" "s2_upsert"
    "controller_show"
    # Switch both sessions to wait on the other lock next time (the speculative insertion)
    "controller_unlock_1_1" "controller_unlock_2_1"
-   # Allow both sessions to continue
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
    "controller_unlock_1_3" "controller_unlock_2_3"
    "controller_show"
    # Allow the first session to finish insertion
@@ -147,3 +171,50 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
+permutation
+   # acquire a number of advisory locks to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe and b) after the
+   # insertion of the speculative tuple.
+   # blurt_and_lock2 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations. also, s1 creates it instead of the controller because ...
+   "s1_create_non_unique_index"
+   # confirm that the insertion into the unique index will happen first
+   "s1_confirm_index_order"
+   "controller_locks"
+   "controller_show"
+   # Both sessions wait on advisory locks
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session to continue, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"
+   # Allow s2 to insert into the non-unique index and complete
+   # s1 will no longer wait and will proceed to update
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
#20Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Melanie Plageman (#19)
Re: Adding a test for speculative insert abort case

On 2019-May-17, Melanie Plageman wrote:

I realized that the numbers at the front probably indicate which patch
it is in a patch set and not the version, so, if that is the case, a
renamed patch -- second version but the only patch needed if you are
applying to master. Is this right?

That's correct. I suggest that "git format-patch -vN origin/master",
where the N is the version you're currently posting, generates good
patch files to attach in email.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#21Melanie Plageman
melanieplageman@gmail.com
In reply to: Melanie Plageman (#18)
2 attachment(s)
Re: Adding a test for speculative insert abort case

On Thu, May 16, 2019 at 8:46 PM Melanie Plageman <melanieplageman@gmail.com>
wrote:

Good idea.
I squashed the changes I suggested in previous emails, Ashwin's patch, my
suggested updates to that patch, and the index order check all into one
updated
patch attached.

I've updated this patch to make it apply on master cleanly. Thanks to
Alvaro for format-patch suggestion.

The first patch in the set adds the speculative wait case discussed
above from Ashwin's patch.

The second patch in the set is another suggestion I have. I noticed
that the insert-conflict-toast test mentions that it is "not
guaranteed to lead to a failed speculative insertion" and, since it
seems to be testing the speculative abort but with TOAST tables, I
thought it might work to kill that spec file and move that test case
into insert-conflict-specconflict so the test can utilize the existing
advisory locks being used for the other tests in that file to make it
deterministic which session succeeds in inserting the tuple.

--
Melanie Plageman

Attachments:

v2-0002-Add-TOAST-case-to-spec-conflict-tests.patchtext/x-patch; charset=US-ASCII; name=v2-0002-Add-TOAST-case-to-spec-conflict-tests.patchDownload
From e8652d872c953ca9bc077027cc34b26b870e5b73 Mon Sep 17 00:00:00 2001
From: csteam <mplageman@pivotal.io>
Date: Wed, 5 Jun 2019 15:24:19 -0700
Subject: [PATCH v2 2/2] Add TOAST case to spec conflict tests

The spec insert-conflict-toast seems to be testing the speculative abort
case -- given two concurrent inserts inserting duplicate values to a
unique index, only one should succeed and, if the other has had a chance
to insert the tuple into the table, this tuple should be killed. The
comment in that test said that it was not deterministic, so, if making
it deterministic required adding additional pg_advisory_locks similar to
what is in the spec insert-conflict-specconflict, combining them made
sense.
---
 .../expected/insert-conflict-specconflict.out | 56 +++++++++++++++++++
 .../specs/insert-conflict-specconflict.spec   | 30 ++++++++++
 2 files changed, 86 insertions(+)

diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 2f003ca1bf..a21ed0b165 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -112,6 +112,62 @@ key            data
 
 k1             inserted s1 with conflict update s2
 
+starting permutation: controller_locks controller_show s1_insert_toast s2_insert_toast controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show_count controller_unlock_2_2 controller_show_count
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+step s2_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step s1_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+step s2_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+
 starting permutation: controller_locks controller_show s1_begin s2_begin s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show controller_unlock_2_2 controller_show s1_commit controller_show s2_commit controller_show
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
 pg_advisory_locksess           lock           
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 7f29fb9d02..a8b35a0c7b 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -30,6 +30,8 @@ setup
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION ctoast_large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
+
     CREATE TABLE upserttest(key text, data text);
 
     CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock(key)));
@@ -55,6 +57,7 @@ step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
 step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
 step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_show_count" {SELECT COUNT(*) FROM upserttest; }
 step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative
 token' ORDER BY granted; }
 
@@ -68,6 +71,7 @@ step "s1_begin"  { BEGIN; }
 step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key))); }
 step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
+step "s1_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s1_commit"  { COMMIT; }
 
 session "s2"
@@ -78,6 +82,7 @@ setup
 }
 step "s2_begin"  { BEGIN; }
 step "s2_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; }
+step "s2_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s2_commit"  { COMMIT; }
 
 # Test that speculative locks are correctly acquired and released, s2
@@ -130,6 +135,31 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
+# Test that speculatively inserted toast rows do not cause conflicts.
+# s1 inserts successfully, s2 does not.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_insert_toast" "s2_insert_toast"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # This should now show that 1 additional tuple was inserted successfully
+   "controller_show_count"
+   # Allow the second session to finish insertion and kill the speculatively inserted tuple
+   "controller_unlock_2_2"
+   # This should show the same number of tuples as before s2 inserted
+   "controller_show_count"
+
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.  With the added complication that transactions
 # don't immediately commit.
-- 
2.21.0

v2-0001-Test-speculative-wait-case.patchtext/x-patch; charset=US-ASCII; name=v2-0001-Test-speculative-wait-case.patchDownload
From 18958df4fd59870781fc1fe252ce78dbc64f5e0a Mon Sep 17 00:00:00 2001
From: csteam <mplageman@pivotal.io>
Date: Wed, 5 Jun 2019 14:54:33 -0700
Subject: [PATCH v2 1/2] Test speculative wait case

Add a permutation for exercising speculative wait code (from Ashwin's
patch).
Fix typo in previously added comment.
---
 .../expected/insert-conflict-specconflict.out | 72 +++++++++++++++++++
 .../specs/insert-conflict-specconflict.spec   | 68 ++++++++++++++++--
 2 files changed, 136 insertions(+), 4 deletions(-)

diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 5726bdb8e8..2f003ca1bf 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -177,3 +177,75 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key)));
+step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
+?column?       
+
+t              
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step controller_print_speculative_locks: SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative
+token' ORDER BY granted;
+locktype       classid        objid          mode           granted        
+
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..7f29fb9d02 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,7 +10,7 @@ setup
 {
      CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
      BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock() called for %', $1;
 
 	-- depending on lock state, wait for lock 2 or 3
         IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
@@ -23,9 +23,16 @@ setup
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock2() called for %', $1;
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
     CREATE TABLE upserttest(key text, data text);
 
-    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+    CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock(key)));
 }
 
 teardown
@@ -45,7 +52,11 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative
+token' ORDER BY granted; }
 
 session "s1"
 setup
@@ -54,6 +65,8 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
+step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key))); }
+step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
 step "s1_commit"  { COMMIT; }
 
@@ -92,8 +105,8 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
-# Test that speculative locks are correctly acquired and released, s2
-# inserts, s1 updates.
+# Test that speculative locks are correctly acquired and released, s1
+# inserts, s2 updates.
 permutation
    # acquire a number of locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
@@ -147,3 +160,50 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
+permutation
+   # acquire a number of advisory locks to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe and b) after the
+   # insertion of the speculative tuple.
+   # blurt_and_lock2 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations.
+   "s1_create_non_unique_index"
+   # confirm that the insertion into the unique index will happen first
+   "s1_confirm_index_order"
+   "controller_locks"
+   "controller_show"
+   # Both sessions wait on advisory locks
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session to continue, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"
+   # Allow s2 to insert into the non-unique index and complete
+   # s1 will no longer wait and will proceed to update
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
-- 
2.21.0

#22Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#21)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-06-05 15:49:47 -0700, Melanie Plageman wrote:

On Thu, May 16, 2019 at 8:46 PM Melanie Plageman <melanieplageman@gmail.com>
wrote:

Good idea.
I squashed the changes I suggested in previous emails, Ashwin's patch, my
suggested updates to that patch, and the index order check all into one
updated
patch attached.

I've updated this patch to make it apply on master cleanly. Thanks to
Alvaro for format-patch suggestion.

Planning to push this, now that v12 is branched off. But only to master, I
don't think it's worth backpatching at the moment.

The second patch in the set is another suggestion I have. I noticed
that the insert-conflict-toast test mentions that it is "not
guaranteed to lead to a failed speculative insertion" and, since it
seems to be testing the speculative abort but with TOAST tables, I
thought it might work to kill that spec file and move that test case
into insert-conflict-specconflict so the test can utilize the existing
advisory locks being used for the other tests in that file to make it
deterministic which session succeeds in inserting the tuple.

Seems like a good plan.

diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..7f29fb9d02 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,7 +10,7 @@ setup
{
CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock() called for %', $1;
-- depending on lock state, wait for lock 2 or 3
IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
@@ -23,9 +23,16 @@ setup
RETURN $1;
END;$$;
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock2() called for %', $1;
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+

Any chance for a bit more descriptive naming than *2? I can live with
it, but ...

+step "controller_print_speculative_locks" { SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative
+token' ORDER BY granted; }

I think showing the speculative locks is possibly going to be unreliable
- the release time of speculative locks is IIRC not that reliable. I
think it could e.g. happen that speculative locks are held longer
because autovacuum spawned an analyze in the background.

+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"

Hm, I might be missing something, but I don't think it currently
does. Looking at the expected file:

+step controller_print_speculative_locks: SELECT locktype,classid,objid,mode,granted FROM pg_locks WHERE locktype='speculative
+token' ORDER BY granted;
+locktype       classid        objid          mode           granted        
+

And if it showed something, it'd make the test not work, because
classid/objid aren't necessarily going to be the same from test to test.

Greetings,

Andres Freund

#23Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#22)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Wed, Jul 24, 2019 at 11:48 AM Andres Freund <andres@anarazel.de> wrote:

diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec

b/src/test/isolation/specs/insert-conflict-specconflict.spec

index 3a70484fc2..7f29fb9d02 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,7 +10,7 @@ setup
{
CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text

IMMUTABLE LANGUAGE plpgsql AS $$

BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock() called for %', $1;

-- depending on lock state, wait for lock 2 or 3
IF

pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN

@@ -23,9 +23,16 @@ setup
RETURN $1;
END;$$;

+ CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text

IMMUTABLE LANGUAGE plpgsql AS $$

+    BEGIN
+        RAISE NOTICE 'blurt_and_lock2() called for %', $1;
+        PERFORM

pg_advisory_xact_lock(current_setting('spec.session')::int, 4);

+    RETURN $1;
+    END;$$;
+

Any chance for a bit more descriptive naming than *2? I can live with
it, but ...

Taylor Vesely and I paired on updating this test, and, it became clear
that the way that the steps and functions are named makes it very
difficult to understand what the test is doing. That is, I helped
write this test and, after a month away, I could no longer understand
what it was doing at all.

We changed the text of the blurts to "acquiring advisory lock ..."
from "blocking" because we realized that this would print even when
the lock was acquired immediately successfully, which is a little
misleading for the reader.

He's taking a stab at some renaming/refactoring to make it more clear
(including renaming blurt_and_lock2())

+step "controller_print_speculative_locks" { SELECT

locktype,classid,objid,mode,granted FROM pg_locks WHERE
locktype='speculative

+token' ORDER BY granted; }

I think showing the speculative locks is possibly going to be unreliable
- the release time of speculative locks is IIRC not that reliable. I
think it could e.g. happen that speculative locks are held longer
because autovacuum spawned an analyze in the background.

I actually think having the "controller_print_speculative_locks"
wouldn't be a problem because we have not released the advisory lock
on 4 in s2 that allows it to complete its speculative insertion and so
s1 will still be in speculative wait.

The step that might be a problem if autovacuum delays release of the
speculative locks is the "controller_show" step, because, at that
point, if the lock wasn't released, then s1 would still be waiting and
wouldn't have updated.

+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"

Hm, I might be missing something, but I don't think it currently
does. Looking at the expected file:

+step controller_print_speculative_locks: SELECT

locktype,classid,objid,mode,granted FROM pg_locks WHERE
locktype='speculative
+token' ORDER BY granted;
+locktype       classid        objid          mode           granted

+

Oops! due to an errant newline, the query wasn't correct.

And if it showed something, it'd make the test not work, because
classid/objid aren't necessarily going to be the same from test to test.

Good point. In the attached patch, classid/objid columns are removed
from the SELECT list.

Melanie & Taylor

Attachments:

v3-0001-Test-additional-speculative-conflict-scenarios.patchapplication/octet-stream; name=v3-0001-Test-additional-speculative-conflict-scenarios.patchDownload
From 1bcd51c17f46d9b7389638131c6870a2baf8328a Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplageman@gmail.com>
Date: Tue, 6 Aug 2019 11:49:40 -0700
Subject: [PATCH v3] Test additional speculative conflict scenarios

Previously, the speculative insert tests did not cover the case when a
tuple t is inserted into a table with a unique index on a column but
before it can insert into the index, a concurrent transaction has
inserted a conflicting value into the index and the insertion of tuple t
must be aborted.

The basic permutation is one session successfully inserts into the table
and an associated unique index while a concurrent session successfully
inserts into the table but discovers a conflict before inserting into
the index and must abort the insertion.

Several variants on this include:
- swap which session is successful
- first session insert transaction does not commit, so second session
must wait on a transaction lock
- first session insert does not "complete", so second session must wait
on a speculative insertion lock

Also, refactor the existing TOAST table upsert test to be in the same
spec and reuse the steps.

Co-authored-by: Ashwin Agrawal <aagrawal@pivotal.io>
Co-authored-by: Taylor Vesely <tvesely@pivotal.io>
Co-authored-by: Andres Freund <andres@anarazel.de>
---
 .../expected/insert-conflict-specconflict.out | 237 +++++++++++++++---
 .../expected/insert-conflict-toast.out        |  15 --
 src/test/isolation/isolation_schedule         |   1 -
 .../specs/insert-conflict-specconflict.spec   | 102 +++++++-
 .../specs/insert-conflict-toast.spec          |  51 ----
 5 files changed, 295 insertions(+), 111 deletions(-)
 delete mode 100644 src/test/isolation/expected/insert-conflict-toast.out
 delete mode 100644 src/test/isolation/specs/insert-conflict-toast.spec

diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 20cc421b87..741d553402 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -13,11 +13,11 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -34,14 +34,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -58,10 +58,10 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step s1_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -81,11 +81,11 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -102,14 +102,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -126,16 +126,84 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
 
+starting permutation: controller_locks controller_show s1_insert_toast s2_insert_toast controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show_count controller_unlock_2_2 controller_show_count
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+s1: NOTICE:  blurt_and_lock() called for k2
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+s2: NOTICE:  blurt_and_lock() called for k2
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock() called for k2
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step s1_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+step s2_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+
 starting permutation: controller_locks controller_show s1_begin s2_begin s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show controller_unlock_2_2 controller_show s1_commit controller_show s2_commit controller_show
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
 pg_advisory_locksess           lock           
@@ -151,11 +219,11 @@ key            data
 
 step s1_begin: BEGIN;
 step s2_begin: BEGIN;
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -172,14 +240,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -195,16 +263,16 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
 step s1_commit: COMMIT;
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -215,3 +283,96 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key)));
+step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
+?column?       
+
+t              
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock2() called for k1
+s2: NOTICE:  acquiring advisory lock on 4
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock2() called for k1
+s1: NOTICE:  acquiring advisory lock on 4
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_print_speculative_locks: SELECT locktype, mode, granted FROM pg_locks WHERE locktype='speculative token' ORDER BY granted;
+locktype       mode           granted        
+
+speculative tokenShareLock      f              
+speculative tokenExclusiveLock  t              
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/expected/insert-conflict-toast.out b/src/test/isolation/expected/insert-conflict-toast.out
deleted file mode 100644
index e86b98020f..0000000000
--- a/src/test/isolation/expected/insert-conflict-toast.out
+++ /dev/null
@@ -1,15 +0,0 @@
-Parsed test spec with 3 sessions
-
-starting permutation: s2insert s3insert s1commit
-pg_advisory_xact_lock
-
-               
-step s2insert: 
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
- <waiting ...>
-step s3insert: 
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
- <waiting ...>
-step s1commit: COMMIT;
-step s2insert: <... completed>
-step s3insert: <... completed>
diff --git a/src/test/isolation/isolation_schedule b/src/test/isolation/isolation_schedule
index 69ae227953..81928a5922 100644
--- a/src/test/isolation/isolation_schedule
+++ b/src/test/isolation/isolation_schedule
@@ -37,7 +37,6 @@ test: insert-conflict-do-nothing-2
 test: insert-conflict-do-update
 test: insert-conflict-do-update-2
 test: insert-conflict-do-update-3
-test: insert-conflict-toast
 test: insert-conflict-specconflict
 test: delete-abort-savept
 test: delete-abort-savept-2
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..a404a4a5c7 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,22 +10,32 @@ setup
 {
      CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
      BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock() called for %', $1;
 
 	-- depending on lock state, wait for lock 2 or 3
         IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
-            RAISE NOTICE 'blocking 2';
+            RAISE NOTICE 'acquiring advisory lock on 2';
             PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 2);
         ELSE
-            RAISE NOTICE 'blocking 3';
+            RAISE NOTICE 'acquiring advisory lock on 3';
             PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 3);
         END IF;
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock2() called for %', $1;
+		RAISE NOTICE 'acquiring advisory lock on 4';
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
+    CREATE OR REPLACE FUNCTION ctoast_large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
+
     CREATE TABLE upserttest(key text, data text);
 
-    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+    CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock(key)));
 }
 
 teardown
@@ -45,7 +55,11 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_show_count" {SELECT COUNT(*) FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype, mode, granted FROM pg_locks WHERE locktype='speculative token' ORDER BY granted; }
 
 session "s1"
 setup
@@ -54,7 +68,10 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
+step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock2(key))); }
+step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
 step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
+step "s1_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s1_commit"  { COMMIT; }
 
 session "s2"
@@ -65,6 +82,7 @@ setup
 }
 step "s2_begin"  { BEGIN; }
 step "s2_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; }
+step "s2_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s2_commit"  { COMMIT; }
 
 # Test that speculative locks are correctly acquired and released, s2
@@ -92,8 +110,8 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
-# Test that speculative locks are correctly acquired and released, s2
-# inserts, s1 updates.
+# Test that speculative locks are correctly acquired and released, s1
+# inserts, s2 updates.
 permutation
    # acquire a number of locks, to control execution flow - the
    # blurt_and_lock function acquires advisory locks that allow us to
@@ -117,6 +135,31 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
+# Test that speculatively inserted toast rows do not cause conflicts.
+# s1 inserts successfully, s2 does not.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_insert_toast" "s2_insert_toast"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # This should now show that 1 additional tuple was inserted successfully
+   "controller_show_count"
+   # Allow the second session to finish insertion and kill the speculatively inserted tuple
+   "controller_unlock_2_2"
+   # This should show the same number of tuples as before s2 inserted
+   "controller_show_count"
+
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.  With the added complication that transactions
 # don't immediately commit.
@@ -147,3 +190,50 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
+permutation
+   # acquire a number of advisory locks to control execution flow - the
+   # blurt_and_lock function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe and b) after the
+   # insertion of the speculative tuple.
+   # blurt_and_lock2 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations.
+   "s1_create_non_unique_index"
+   # confirm that the insertion into the unique index will happen first
+   "s1_confirm_index_order"
+   "controller_locks"
+   "controller_show"
+   # Both sessions wait on advisory locks
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session to continue, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"
+   # Allow s2 to insert into the non-unique index and complete
+   # s1 will no longer wait and will proceed to update
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
diff --git a/src/test/isolation/specs/insert-conflict-toast.spec b/src/test/isolation/specs/insert-conflict-toast.spec
deleted file mode 100644
index c5e39ef9e3..0000000000
--- a/src/test/isolation/specs/insert-conflict-toast.spec
+++ /dev/null
@@ -1,51 +0,0 @@
-# INSERT...ON CONFLICT test on table with TOAST
-#
-# This test verifies that speculatively inserted toast rows do not
-# cause conflicts. It does so by using expression index over a
-# function which acquires an advisory lock, triggering two index
-# insertions to happen almost at the same time. This is not guaranteed
-# to lead to a failed speculative insertion, but makes one quite
-# likely.
-
-setup
-{
-  CREATE TABLE ctoast (key int primary key, val text);
-  CREATE OR REPLACE FUNCTION ctoast_lock_func(int) RETURNS INT IMMUTABLE LANGUAGE SQL AS 'select pg_advisory_xact_lock_shared(1); select $1;';
-  CREATE OR REPLACE FUNCTION ctoast_large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
-  CREATE UNIQUE INDEX ctoast_lock_idx ON ctoast (ctoast_lock_func(key));
-}
-
-teardown
-{
-  DROP TABLE ctoast;
-  DROP FUNCTION ctoast_lock_func(int);
-  DROP FUNCTION ctoast_large_val();
-}
-
-session "s1"
-setup
-{
-  BEGIN ISOLATION LEVEL READ COMMITTED;
-  SELECT pg_advisory_xact_lock(1);
-}
-step "s1commit" { COMMIT; }
-
-session "s2"
-setup
-{
-  SET default_transaction_isolation = 'read committed';
-}
-step "s2insert" {
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
-}
-
-session "s3"
-setup
-{
-  SET default_transaction_isolation = 'read committed';
-}
-step "s3insert" {
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
-}
-
-permutation "s2insert" "s3insert" "s1commit"
-- 
2.22.0

#24Melanie Plageman
melanieplageman@gmail.com
In reply to: Melanie Plageman (#23)
1 attachment(s)
Re: Adding a test for speculative insert abort case

On Wed, Aug 7, 2019 at 1:47 PM Melanie Plageman <melanieplageman@gmail.com>
wrote:

On Wed, Jul 24, 2019 at 11:48 AM Andres Freund <andres@anarazel.de> wrote:

diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec

b/src/test/isolation/specs/insert-conflict-specconflict.spec

index 3a70484fc2..7f29fb9d02 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,7 +10,7 @@ setup
{
CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text

IMMUTABLE LANGUAGE plpgsql AS $$

BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock() called for %', $1;

-- depending on lock state, wait for lock 2 or 3
IF

pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN

@@ -23,9 +23,16 @@ setup
RETURN $1;
END;$$;

+ CREATE OR REPLACE FUNCTION blurt_and_lock2(text) RETURNS text

IMMUTABLE LANGUAGE plpgsql AS $$

+    BEGIN
+        RAISE NOTICE 'blurt_and_lock2() called for %', $1;
+        PERFORM

pg_advisory_xact_lock(current_setting('spec.session')::int, 4);

+    RETURN $1;
+    END;$$;
+

Any chance for a bit more descriptive naming than *2? I can live with
it, but ...

Taylor Vesely and I paired on updating this test, and, it became clear
that the way that the steps and functions are named makes it very
difficult to understand what the test is doing. That is, I helped
write this test and, after a month away, I could no longer understand
what it was doing at all.

We changed the text of the blurts to "acquiring advisory lock ..."
from "blocking" because we realized that this would print even when
the lock was acquired immediately successfully, which is a little
misleading for the reader.

He's taking a stab at some renaming/refactoring to make it more clear
(including renaming blurt_and_lock2())

So, Taylor and I had hoped to rename the steps to something more specific
that
told the story of what this test is doing and made it more clear.
Unfortunately,
our attempt to do that didn't work and made step re-use very difficult.
Alas, we decided the original names were less confusing.

My idea for renaming blurt_and_lock2() was actually to rename
blurt_and_lock()
to blurt_and_lock_123() -- since it always takes a lock on 1,2, or 3.
Then, I could name the second function, which locks 4, blurt_and_lock_4().
What do you think?

I've attached a rebased patch updated with the new function names.

+step "controller_print_speculative_locks" { SELECT

locktype,classid,objid,mode,granted FROM pg_locks WHERE
locktype='speculative

+token' ORDER BY granted; }

I think showing the speculative locks is possibly going to be unreliable
- the release time of speculative locks is IIRC not that reliable. I
think it could e.g. happen that speculative locks are held longer
because autovacuum spawned an analyze in the background.

I actually think having the "controller_print_speculative_locks"
wouldn't be a problem because we have not released the advisory lock
on 4 in s2 that allows it to complete its speculative insertion and so
s1 will still be in speculative wait.

The step that might be a problem if autovacuum delays release of the
speculative locks is the "controller_show" step, because, at that
point, if the lock wasn't released, then s1 would still be waiting and
wouldn't have updated.

So, what should we do about this? Do you agree that the "controller_show"
step
would be a problem?

--
Melanie Plageman

Attachments:

v4-0001-Test-additional-speculative-conflict-scenarios.patchapplication/octet-stream; name=v4-0001-Test-additional-speculative-conflict-scenarios.patchDownload
From a3a7d256928dd8b2c0ff8407981f103ac182c014 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplageman@gmail.com>
Date: Wed, 21 Aug 2019 13:47:23 -0700
Subject: [PATCH v4] Test additional speculative conflict scenarios

Previously, the speculative insert tests did not cover the case when a
tuple t is inserted into a table with a unique index on a column but
before it can insert into the index, a concurrent transaction has
inserted a conflicting value into the index and the insertion of tuple t
must be aborted.

The basic permutation is one session successfully inserts into the table
and an associated unique index while a concurrent session successfully
inserts into the table but discovers a conflict before inserting into
the index and must abort the insertion.

Several variants on this include:
- swap which session is successful
- first session insert transaction does not commit, so second session
must wait on a transaction lock
- first session insert does not "complete", so second session must wait
on a speculative insertion lock

Also, refactor the existing TOAST table upsert test to be in the same
spec and reuse the steps.

Co-authored-by: Ashwin Agrawal <aagrawal@pivotal.io>
Co-authored-by: Andres Freund <andres@anarazel.de>
Reviewed-by: Taylor Vesely <tvesely@pivotal.io>
---
 .../expected/insert-conflict-specconflict.out | 247 ++++++++++++++----
 .../expected/insert-conflict-toast.out        |  15 --
 src/test/isolation/isolation_schedule         |   1 -
 .../specs/insert-conflict-specconflict.spec   | 114 +++++++-
 .../specs/insert-conflict-toast.spec          |  51 ----
 5 files changed, 305 insertions(+), 123 deletions(-)
 delete mode 100644 src/test/isolation/expected/insert-conflict-toast.out
 delete mode 100644 src/test/isolation/specs/insert-conflict-toast.spec

diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 20cc421b87..47f5c66539 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -13,12 +13,12 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
-step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
-step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -34,14 +34,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -58,10 +58,10 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step s1_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -81,12 +81,12 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
-step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
-step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -102,14 +102,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -126,16 +126,84 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
 
+starting permutation: controller_locks controller_show s1_insert_toast s2_insert_toast controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show_count controller_unlock_2_2 controller_show_count
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+s1: NOTICE:  blurt_and_lock_123() called for k2
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock_123() called for k2
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+step s1_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  acquiring advisory lock on 2
+step s2_insert_toast: <... completed>
+step controller_show_count: SELECT COUNT(*) FROM upserttest;
+count          
+
+1              
+
 starting permutation: controller_locks controller_show s1_begin s2_begin s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show controller_unlock_2_2 controller_show s1_commit controller_show s2_commit controller_show
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
 pg_advisory_locksess           lock           
@@ -151,12 +219,12 @@ key            data
 
 step s1_begin: BEGIN;
 step s2_begin: BEGIN;
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 3
-step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 3
-step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -172,14 +240,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  called for k1
-s1: NOTICE:  blocking 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
@@ -195,16 +263,16 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
 step s1_commit: COMMIT;
-s2: NOTICE:  called for k1
-s2: NOTICE:  blocking 2
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -215,3 +283,94 @@ step controller_show: SELECT * FROM upserttest;
 key            data           
 
 k1             inserted s1 with conflict update s2
+
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock_4(key)));
+step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
+?column?       
+
+t              
+step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess), generate_series(1,3) b(lock);
+pg_advisory_locksess           lock           
+
+               1              1              
+               1              2              
+               1              3              
+               2              1              
+               2              2              
+               2              3              
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 3
+step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 3
+step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_2_1: SELECT pg_advisory_unlock(2, 1);
+pg_advisory_unlock
+
+t              
+step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  acquiring advisory lock on 2
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_lock_2_4: SELECT pg_advisory_lock(2, 4);
+pg_advisory_lock
+
+               
+step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
+pg_advisory_unlock
+
+t              
+s2: NOTICE:  blurt_and_lock_4() called for k1
+s2: NOTICE:  acquiring advisory lock on 4
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock_4() called for k1
+s1: NOTICE:  acquiring advisory lock on 4
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step controller_print_speculative_locks: SELECT locktype, mode, granted FROM pg_locks WHERE locktype='speculative token' ORDER BY granted;
+locktype       mode           granted        
+
+speculative tokenShareLock      f              
+speculative tokenExclusiveLock  t              
+step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
+pg_advisory_unlock
+
+t              
+s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  acquiring advisory lock on 2
+step s1_upsert: <... completed>
+step s2_upsert: <... completed>
+step controller_show: SELECT * FROM upserttest;
+key            data           
+
+k1             inserted s2 with conflict update s1
diff --git a/src/test/isolation/expected/insert-conflict-toast.out b/src/test/isolation/expected/insert-conflict-toast.out
deleted file mode 100644
index e86b98020f..0000000000
--- a/src/test/isolation/expected/insert-conflict-toast.out
+++ /dev/null
@@ -1,15 +0,0 @@
-Parsed test spec with 3 sessions
-
-starting permutation: s2insert s3insert s1commit
-pg_advisory_xact_lock
-
-               
-step s2insert: 
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
- <waiting ...>
-step s3insert: 
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
- <waiting ...>
-step s1commit: COMMIT;
-step s2insert: <... completed>
-step s3insert: <... completed>
diff --git a/src/test/isolation/isolation_schedule b/src/test/isolation/isolation_schedule
index 69ae227953..81928a5922 100644
--- a/src/test/isolation/isolation_schedule
+++ b/src/test/isolation/isolation_schedule
@@ -37,7 +37,6 @@ test: insert-conflict-do-nothing-2
 test: insert-conflict-do-update
 test: insert-conflict-do-update-2
 test: insert-conflict-do-update-3
-test: insert-conflict-toast
 test: insert-conflict-specconflict
 test: delete-abort-savept
 test: delete-abort-savept-2
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.spec
index 3a70484fc2..2696c332a8 100644
--- a/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -8,24 +8,34 @@
 
 setup
 {
-     CREATE OR REPLACE FUNCTION blurt_and_lock(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+     CREATE OR REPLACE FUNCTION blurt_and_lock_123(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
      BEGIN
-        RAISE NOTICE 'called for %', $1;
+        RAISE NOTICE 'blurt_and_lock_123() called for %', $1;
 
 	-- depending on lock state, wait for lock 2 or 3
         IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
-            RAISE NOTICE 'blocking 2';
+            RAISE NOTICE 'acquiring advisory lock on 2';
             PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 2);
         ELSE
-            RAISE NOTICE 'blocking 3';
+            RAISE NOTICE 'acquiring advisory lock on 3';
             PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 3);
         END IF;
     RETURN $1;
     END;$$;
 
+    CREATE OR REPLACE FUNCTION blurt_and_lock_4(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
+    BEGIN
+        RAISE NOTICE 'blurt_and_lock_4() called for %', $1;
+		RAISE NOTICE 'acquiring advisory lock on 4';
+        PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
+    RETURN $1;
+    END;$$;
+
+    CREATE OR REPLACE FUNCTION ctoast_large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
+
     CREATE TABLE upserttest(key text, data text);
 
-    CREATE UNIQUE INDEX ON upserttest((blurt_and_lock(key)));
+    CREATE UNIQUE INDEX upserttest_key_uniq_idx ON upserttest((blurt_and_lock_123(key)));
 }
 
 teardown
@@ -45,7 +55,11 @@ step "controller_unlock_1_2" { SELECT pg_advisory_unlock(1, 2); }
 step "controller_unlock_2_2" { SELECT pg_advisory_unlock(2, 2); }
 step "controller_unlock_1_3" { SELECT pg_advisory_unlock(1, 3); }
 step "controller_unlock_2_3" { SELECT pg_advisory_unlock(2, 3); }
+step "controller_lock_2_4" { SELECT pg_advisory_lock(2, 4); }
+step "controller_unlock_2_4" { SELECT pg_advisory_unlock(2, 4); }
 step "controller_show" {SELECT * FROM upserttest; }
+step "controller_show_count" {SELECT COUNT(*) FROM upserttest; }
+step "controller_print_speculative_locks" { SELECT locktype, mode, granted FROM pg_locks WHERE locktype='speculative token' ORDER BY granted; }
 
 session "s1"
 setup
@@ -54,7 +68,10 @@ setup
   SET spec.session = 1;
 }
 step "s1_begin"  { BEGIN; }
-step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
+step "s1_create_non_unique_index" { CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock_4(key))); }
+step "s1_confirm_index_order" { SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8; }
+step "s1_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; }
+step "s1_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s1_commit"  { COMMIT; }
 
 session "s2"
@@ -64,14 +81,15 @@ setup
   SET spec.session = 2;
 }
 step "s2_begin"  { BEGIN; }
-step "s2_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; }
+step "s2_upsert" { INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; }
+step "s2_insert_toast" { INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; }
 step "s2_commit"  { COMMIT; }
 
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.
 permutation
    # acquire a number of locks, to control execution flow - the
-   # blurt_and_lock function acquires advisory locks that allow us to
+   # blurt_and_lock_123 function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
@@ -92,11 +110,11 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
-# Test that speculative locks are correctly acquired and released, s2
-# inserts, s1 updates.
+# Test that speculative locks are correctly acquired and released, s1
+# inserts, s2 updates.
 permutation
    # acquire a number of locks, to control execution flow - the
-   # blurt_and_lock function acquires advisory locks that allow us to
+   # blurt_and_lock_123 function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
@@ -117,12 +135,37 @@ permutation
    # This should now show a successful UPSERT
    "controller_show"
 
+# Test that speculatively inserted toast rows do not cause conflicts.
+# s1 inserts successfully, s2 does not.
+permutation
+   # acquire a number of locks, to control execution flow - the
+   # blurt_and_lock_123 function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe b) after the
+   # insertion of the speculative tuple.
+   "controller_locks"
+   "controller_show"
+   "s1_insert_toast" "s2_insert_toast"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to continue
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # Allow the first session to finish insertion
+   "controller_unlock_1_2"
+   # This should now show that 1 additional tuple was inserted successfully
+   "controller_show_count"
+   # Allow the second session to finish insertion and kill the speculatively inserted tuple
+   "controller_unlock_2_2"
+   # This should show the same number of tuples as before s2 inserted
+   "controller_show_count"
+
 # Test that speculative locks are correctly acquired and released, s2
 # inserts, s1 updates.  With the added complication that transactions
 # don't immediately commit.
 permutation
    # acquire a number of locks, to control execution flow - the
-   # blurt_and_lock function acquires advisory locks that allow us to
+   # blurt_and_lock_123 function acquires advisory locks that allow us to
    # continue after a) the optimistic conflict probe b) after the
    # insertion of the speculative tuple.
    "controller_locks"
@@ -147,3 +190,50 @@ permutation
    "controller_show"
    "s2_commit"
    "controller_show"
+
+# Test that speculative wait is performed if a session sees a speculatively
+# inserted tuple. A speculatively inserted tuple is one which has been inserted
+# both into the table and the unique index but has yet to *complete* the
+# speculative insertion
+permutation
+   # acquire a number of advisory locks to control execution flow - the
+   # blurt_and_lock_123 function acquires advisory locks that allow us to
+   # continue after a) the optimistic conflict probe and b) after the
+   # insertion of the speculative tuple.
+   # blurt_and_lock_4 acquires an advisory lock which allows us to pause
+   # execution c) before completing the speculative insertion
+
+   # create the second index here to avoid affecting the other
+   # permutations.
+   "s1_create_non_unique_index"
+   # confirm that the insertion into the unique index will happen first
+   "s1_confirm_index_order"
+   "controller_locks"
+   "controller_show"
+   # Both sessions wait on advisory locks
+   "s1_upsert" "s2_upsert"
+   "controller_show"
+   # Switch both sessions to wait on the other lock next time (the speculative insertion)
+   "controller_unlock_1_1" "controller_unlock_2_1"
+   # Allow both sessions to do the optimistic conflict probe and do the
+   # speculative insertion into the table
+   # They will then be waiting on another advisory lock when they attempt to
+   # update the index
+   "controller_unlock_1_3" "controller_unlock_2_3"
+   "controller_show"
+   # take lock to block second session after inserting in unique index but
+   # before completing the speculative insert
+   "controller_lock_2_4"
+   # Allow the second session to move forward
+   "controller_unlock_2_2"
+   # This should still not show a successful insertion
+   "controller_show"
+   # Allow the first session to continue, it should perform speculative wait
+   "controller_unlock_1_2"
+   # Should report s1 is waiting on speculative lock
+   "controller_print_speculative_locks"
+   # Allow s2 to insert into the non-unique index and complete
+   # s1 will no longer wait and will proceed to update
+   "controller_unlock_2_4"
+   # This should now show a successful UPSERT
+   "controller_show"
diff --git a/src/test/isolation/specs/insert-conflict-toast.spec b/src/test/isolation/specs/insert-conflict-toast.spec
deleted file mode 100644
index c5e39ef9e3..0000000000
--- a/src/test/isolation/specs/insert-conflict-toast.spec
+++ /dev/null
@@ -1,51 +0,0 @@
-# INSERT...ON CONFLICT test on table with TOAST
-#
-# This test verifies that speculatively inserted toast rows do not
-# cause conflicts. It does so by using expression index over a
-# function which acquires an advisory lock, triggering two index
-# insertions to happen almost at the same time. This is not guaranteed
-# to lead to a failed speculative insertion, but makes one quite
-# likely.
-
-setup
-{
-  CREATE TABLE ctoast (key int primary key, val text);
-  CREATE OR REPLACE FUNCTION ctoast_lock_func(int) RETURNS INT IMMUTABLE LANGUAGE SQL AS 'select pg_advisory_xact_lock_shared(1); select $1;';
-  CREATE OR REPLACE FUNCTION ctoast_large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
-  CREATE UNIQUE INDEX ctoast_lock_idx ON ctoast (ctoast_lock_func(key));
-}
-
-teardown
-{
-  DROP TABLE ctoast;
-  DROP FUNCTION ctoast_lock_func(int);
-  DROP FUNCTION ctoast_large_val();
-}
-
-session "s1"
-setup
-{
-  BEGIN ISOLATION LEVEL READ COMMITTED;
-  SELECT pg_advisory_xact_lock(1);
-}
-step "s1commit" { COMMIT; }
-
-session "s2"
-setup
-{
-  SET default_transaction_isolation = 'read committed';
-}
-step "s2insert" {
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
-}
-
-session "s3"
-setup
-{
-  SET default_transaction_isolation = 'read committed';
-}
-step "s3insert" {
-  INSERT INTO ctoast (key, val) VALUES (1, ctoast_large_val()) ON CONFLICT DO NOTHING;
-}
-
-permutation "s2insert" "s3insert" "s1commit"
-- 
2.22.0

#25Michael Paquier
michael@paquier.xyz
In reply to: Melanie Plageman (#24)
Re: Adding a test for speculative insert abort case

On Wed, Aug 21, 2019 at 01:59:00PM -0700, Melanie Plageman wrote:

So, what should we do about this? Do you agree that the "controller_show"
step would be a problem?

Andres, it seems to me that this is waiting some input from you.
--
Michael

#26Andres Freund
andres@anarazel.de
In reply to: Melanie Plageman (#24)
Re: Adding a test for speculative insert abort case

Hi,

On 2019-08-21 13:59:00 -0700, Melanie Plageman wrote:

+step "controller_print_speculative_locks" { SELECT

locktype,classid,objid,mode,granted FROM pg_locks WHERE
locktype='speculative

+token' ORDER BY granted; }

I think showing the speculative locks is possibly going to be unreliable
- the release time of speculative locks is IIRC not that reliable. I
think it could e.g. happen that speculative locks are held longer
because autovacuum spawned an analyze in the background.

I actually think having the "controller_print_speculative_locks"
wouldn't be a problem because we have not released the advisory lock
on 4 in s2 that allows it to complete its speculative insertion and so
s1 will still be in speculative wait.

Hm. At the very least it'd have to be restricted to only match locks in
the same database - e.g. for parallel installcheck it is common for
there to be other concurrent tests. I'll add that when committing, no
need for a new version.

I'm also a bit concerned that adding the pg_locks query would mean we can't
run the test in parallel with others, if we ever finally get around to
adding a parallel isolationtester schedule (which is really needed, it's
too slow as is).
/messages/by-id/20180124231006.z7spaz5gkzbdvob5@alvherre.pgsql
But I guess we we'll just deal with not running this test in parallel.

The step that might be a problem if autovacuum delays release of the
speculative locks is the "controller_show" step, because, at that
point, if the lock wasn't released, then s1 would still be waiting and
wouldn't have updated.

So, what should we do about this? Do you agree that the "controller_show"
step would be a problem?

It hasn't caused failures so far, I think. Or are you saying you think
it's more likely to cause failures in the added tests?

Had planned to commit now, but I'm not able to think through the state
transitions at this hour, apparently :(. I'll try to do it tomorrow
morning.

Greetings,

Andres Freund

#27Andres Freund
andres@anarazel.de
In reply to: Andres Freund (#26)
1 attachment(s)
Re: Adding a test for speculative insert abort case

Hi,

I'm currently fighting with a race I'm observing in about 1/4 of the
runs. I get:
@@ -361,16 +361,18 @@
locktype mode granted

speculative tokenShareLock f
speculative tokenExclusiveLock t
step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
pg_advisory_unlock

 t
 s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
+s1: NOTICE:  acquiring advisory lock on 2
 step s1_upsert: <... completed>
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data

k1 inserted s2 with conflict update s1
(this is the last permutation)

The issue is basically that s1 goes through the
check_exclusion_or_unique_constraint() conflict check twice.

I added a bit of debugging information (using fprintf, with elog it was
much harder to hit):

Success:
2020-02-07 16:14:56.501 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167003: acquiring xact lock
2020-02-07 16:14:56.512 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.522 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167002: releasing xact lock 2 3
1167004: acquired xact lock
1167004: xid 8466 acquiring 5
2020-02-07 16:14:56.523 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC70F0: - Heap/INSERT: off 2 flags 0x0C
2020-02-07 16:14:56.523 PST [1167004][6/1014:8466] NOTICE: blurt_and_lock_123() called for k1 in session 2
2020-02-07 16:14:56.523 PST [1167004][6/1014:8466] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:14:56.523 PST [1167004][6/1014:8466] NOTICE: acquiring advisory lock on 2
2020-02-07 16:14:56.523 PST [1167004][6/1014:8466] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167004: acquiring xact lock
2020-02-07 16:14:56.533 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.544 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.555 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.565 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.576 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.587 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167002: releasing xact lock 2 2
1167004: acquired xact lock
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC7150: - Btree/NEWROOT: lev 0
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC7190: - Btree/INSERT_LEAF: off 1
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] NOTICE: blurt_and_lock_4() called for k1 in session 2
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 3 at RAISE
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] NOTICE: acquiring advisory lock on 4
2020-02-07 16:14:56.588 PST [1167004][6/1014:8466] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 4 at RAISE
1167004: acquiring xact lock
2020-02-07 16:14:56.598 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.609 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.620 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.630 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167002: releasing xact lock 1 2
1167003: acquired xact lock
2020-02-07 16:14:56.631 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC71D0: - Btree/INSERT_LEAF: off 1
2020-02-07 16:14:56.631 PST [1167003][5/1254:8465] NOTICE: blurt_and_lock_4() called for k1 in session 1
2020-02-07 16:14:56.631 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 3 at RAISE
2020-02-07 16:14:56.631 PST [1167003][5/1254:8465] NOTICE: acquiring advisory lock on 4
2020-02-07 16:14:56.631 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 4 at RAISE
1167003: acquiring xact lock
1167003: acquired xact lock
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC7230: - Btree/NEWROOT: lev 0
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC7270: - Btree/INSERT_LEAF: off 1
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC72A8: - Heap/DELETE: off 1 flags 0x08
1167003: xid 8465 releasing lock 5
1167003: retry due to conflict
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] NOTICE: acquiring advisory lock on 2
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167003: acquiring xact lock
1167003: acquired xact lock
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] NOTICE: acquiring advisory lock on 2
2020-02-07 16:14:56.632 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167003: acquiring xact lock
1167003: acquired xact lock
1167003: xid 8465 waiting xwait 8466 (xmin 8466 xmax 0) spec 5
2020-02-07 16:14:56.642 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.653 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.667 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:14:56.677 PST [1167001][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167002: releasing xact lock 2 4
1167004: acquired xact lock
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC72E8: - Btree/INSERT_LEAF: off 2
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC7318: - Heap/HEAP_CONFIRM: off 2
1167004: xid 8466 releasing lock 5
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC7348: - Transaction/COMMIT: 2020-02-07 16:14:56.678602-08
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] LOG: xlog flush request 0/9CC7348; write 0/9CBDF58; flush 0/9CBDF58
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] STATEMENT: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2';
2020-02-07 16:14:56.678 PST [1167003][5/1254:8465] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:14:56.678 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:14:56.678 PST [1167003][5/1254:8465] NOTICE: acquiring advisory lock on 2
2020-02-07 16:14:56.678 PST [1167003][5/1254:8465] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167003: acquiring xact lock
1167003: acquired xact lock
2020-02-07 16:14:56.678 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC7380: - Heap/LOCK: off 2: xid 8465: flags 0x00 LOCK_ONLY EXCL_LOCK
2020-02-07 16:14:56.679 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC73F0: - Heap/HOT_UPDATE: off 2 xmax 8465 flags 0x10 ; new off 3 xmax 8465
2020-02-07 16:14:56.679 PST [1167003][5/1254:8465] LOG: INSERT @ 0/9CC7420: - Transaction/COMMIT: 2020-02-07 16:14:56.679085-08
2020-02-07 16:14:56.679 PST [1167003][5/1254:8465] LOG: xlog flush request 0/9CC7420; write 0/9CC7060; flush 0/9CC7060
2020-02-07 16:14:56.679 PST [1167003][5/1254:8465] STATEMENT: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1';

fail:
1167056: releasing xact lock 2 3
1167058: acquired xact lock
1167058: xid 8490 acquiring 5
2020-02-07 16:16:43.990 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D1D8: - Heap/INSERT: off 2 flags 0x0C
2020-02-07 16:16:43.990 PST [1167058][6/11:8490] NOTICE: blurt_and_lock_123() called for k1 in session 2
2020-02-07 16:16:43.990 PST [1167058][6/11:8490] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:16:43.990 PST [1167058][6/11:8490] NOTICE: acquiring advisory lock on 2
2020-02-07 16:16:43.990 PST [1167058][6/11:8490] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167058: acquiring xact lock
2020-02-07 16:16:44.000 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.011 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.022 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.033 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.044 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.054 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167056: releasing xact lock 2 2
1167058: acquired xact lock
2020-02-07 16:16:44.055 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D238: - Btree/NEWROOT: lev 0
2020-02-07 16:16:44.055 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D278: - Btree/INSERT_LEAF: off 1
2020-02-07 16:16:44.056 PST [1167058][6/11:8490] NOTICE: blurt_and_lock_4() called for k1 in session 2
2020-02-07 16:16:44.056 PST [1167058][6/11:8490] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 3 at RAISE
2020-02-07 16:16:44.056 PST [1167058][6/11:8490] NOTICE: acquiring advisory lock on 4
2020-02-07 16:16:44.056 PST [1167058][6/11:8490] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 4 at RAISE
1167058: acquiring xact lock
2020-02-07 16:16:44.066 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.076 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.087 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.098 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167056: releasing xact lock 1 2
1167057: acquired xact lock
2020-02-07 16:16:44.099 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D2B8: - Btree/INSERT_LEAF: off 1
2020-02-07 16:16:44.099 PST [1167057][5/13:8489] NOTICE: blurt_and_lock_4() called for k1 in session 1
2020-02-07 16:16:44.099 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 3 at RAISE
2020-02-07 16:16:44.099 PST [1167057][5/13:8489] NOTICE: acquiring advisory lock on 4
2020-02-07 16:16:44.099 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_4(text) line 4 at RAISE
1167057: acquiring xact lock
1167057: acquired xact lock
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D318: - Btree/NEWROOT: lev 0
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D358: - Btree/INSERT_LEAF: off 1
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D390: - Heap/DELETE: off 1 flags 0x08
1167057: xid 8489 releasing lock 5
1167057: retry due to conflict
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] NOTICE: acquiring advisory lock on 2
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167057: acquiring xact lock
1167057: acquired xact lock
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] NOTICE: acquiring advisory lock on 2
2020-02-07 16:16:44.100 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167057: acquiring xact lock
1167057: acquired xact lock
1167057: xid 8489 waiting xwait 8490 (xmin 8490 xmax 0) spec 5
2020-02-07 16:16:44.110 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.121 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.135 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
2020-02-07 16:16:44.145 PST [1167055][3/0:0] DEBUG: bind <unnamed> to isolationtester_waiting
1167056: releasing xact lock 2 4
1167058: acquired xact lock
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D3D0: - Btree/INSERT_LEAF: off 2
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D400: - Heap/HEAP_CONFIRM: off 2
1167058: xid 8490 releasing lock 5
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D430: - Transaction/COMMIT: 2020-02-07 16:16:44.146767-08
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] LOG: xlog flush request 0/9D2D430; write 0/9D24058; flush 0/9D24058
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] STATEMENT: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2';
2020-02-07 16:16:44.146 PST [1167057][5/13:8489] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:16:44.146 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:16:44.146 PST [1167057][5/13:8489] NOTICE: acquiring advisory lock on 2
2020-02-07 16:16:44.146 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167057: acquiring xact lock
1167057: acquired xact lock
1167057: xid 8489 waiting xwait 8490 (xmin 8490 xmax 0) spec 0
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] NOTICE: blurt_and_lock_123() called for k1 in session 1
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 3 at RAISE
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] NOTICE: acquiring advisory lock on 2
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] CONTEXT: PL/pgSQL function blurt_and_lock_123(text) line 7 at RAISE
1167057: acquiring xact lock
1167057: acquired xact lock
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D468: - Heap/LOCK: off 2: xid 8489: flags 0x00 LOCK_ONLY EXCL_LOCK
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D4D8: - Heap/HOT_UPDATE: off 2 xmax 8489 flags 0x10 ; new off 3 xmax 8489
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] LOG: INSERT @ 0/9D2D508: - Transaction/COMMIT: 2020-02-07 16:16:44.147348-08
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] LOG: xlog flush request 0/9D2D508; write 0/9D2D148; flush 0/9D2D148
2020-02-07 16:16:44.147 PST [1167057][5/13:8489] STATEMENT: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1';

The important bit is here the different "xid .* waiting xwait .* spec*"
lines. In the success case we see:

1167003: xid 8465 waiting xwait 8466 (xmin 8466 xmax 0) spec 5
1167002: releasing xact lock 2 4
1167004: acquired xact lock
1167004: xid 8466 releasing lock 5
2020-02-07 16:14:56.678 PST [1167004][6/1014:8466] LOG: INSERT @ 0/9CC7348: - Transaction/COMMIT: 2020-02-07 16:14:56.678602-08
1167003: acquired xact lock

In the failing case we see:
1167057: xid 8489 waiting xwait 8490 (xmin 8490 xmax 0) spec 5
1167056: releasing xact lock 2 4
1167058: acquired xact lock
1167058: xid 8490 releasing lock 5
2020-02-07 16:16:44.146 PST [1167058][6/11:8490] LOG: INSERT @ 0/9D2D430: - Transaction/COMMIT: 2020-02-07 16:16:44.146767-08
1167057: xid 8489 waiting xwait 8490 (xmin 8490 xmax 0) spec 0
1167057: acquired xact lock

I think the issue here is that determines whether s1 can finish its
check_exclusion_or_unique_constraint() check with one retry is whether
it reaches it does the tuple visibility test before s2's transaction has
actually marked itself as visible (note that ProcArrayEndTransaction is
after RecordTransactionCommit logging the COMMIT above).

I think the fix is quite easy: Ensure that there *always* will be the
second wait iteration on the transaction (in addition to the already
always existing wait on the speculative token). Which is just adding
s2_begin s2_commit steps. Simple, but took me a few hours to
understand :/.

I've attached that portion of my changes. Will interrupt scheduled
programming for a bit of exercise now.

Greetings,

Andres Freund

Attachments:

fix.difftext/x-diff; charset=us-asciiDownload
diff --git i/src/test/isolation/expected/insert-conflict-specconflict.out w/src/test/isolation/expected/insert-conflict-specconflict.out
index 47f5c665396..762a5869383 100644
--- i/src/test/isolation/expected/insert-conflict-specconflict.out
+++ w/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -13,10 +13,10 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
@@ -34,13 +34,13 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -58,9 +58,9 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step s1_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
@@ -81,10 +81,10 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
@@ -102,13 +102,13 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -126,9 +126,9 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
@@ -149,10 +149,10 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  blurt_and_lock_123() called for k2
+s1: NOTICE:  blurt_and_lock_123() called for k2 in session 1
 s1: NOTICE:  acquiring advisory lock on 3
 step s1_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
-s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  blurt_and_lock_123() called for k2 in session 2
 s2: NOTICE:  acquiring advisory lock on 3
 step s2_insert_toast: INSERT INTO upserttest VALUES('k2', ctoast_large_val()) ON CONFLICT DO NOTHING; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
@@ -170,13 +170,13 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k2
+s1: NOTICE:  blurt_and_lock_123() called for k2 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  blurt_and_lock_123() called for k2 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -194,9 +194,9 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  blurt_and_lock_123() called for k2 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
-s2: NOTICE:  blurt_and_lock_123() called for k2
+s2: NOTICE:  blurt_and_lock_123() called for k2 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step s2_insert_toast: <... completed>
 step controller_show_count: SELECT COUNT(*) FROM upserttest;
@@ -219,10 +219,10 @@ key            data
 
 step s1_begin: BEGIN;
 step s2_begin: BEGIN;
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
@@ -240,13 +240,13 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -263,15 +263,15 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
 step s1_commit: COMMIT;
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
@@ -284,7 +284,7 @@ key            data
 
 k1             inserted s1 with conflict update s2
 
-starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 controller_show
+starting permutation: s1_create_non_unique_index s1_confirm_index_order controller_locks controller_show s2_begin s1_upsert s2_upsert controller_show controller_unlock_1_1 controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show controller_lock_2_4 controller_unlock_2_2 controller_show controller_unlock_1_2 controller_print_speculative_locks controller_unlock_2_4 s2_commit controller_show
 step s1_create_non_unique_index: CREATE INDEX upserttest_key_idx ON upserttest((blurt_and_lock_4(key)));
 step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 < 'upserttest_key_idx'::regclass::int8;
 ?column?       
@@ -302,10 +302,11 @@ pg_advisory_locksess           lock
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
-s1: NOTICE:  blurt_and_lock_123() called for k1
+step s2_begin: BEGIN;
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 3
 step s1_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s1') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s1'; <waiting ...>
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 3
 step s2_upsert: INSERT INTO upserttest(key, data) VALUES('k1', 'inserted s2') ON CONFLICT (blurt_and_lock_123(key)) DO UPDATE SET data = upserttest.data || ' with conflict update s2'; <waiting ...>
 step controller_show: SELECT * FROM upserttest;
@@ -323,13 +324,13 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_123() called for k1
+s2: NOTICE:  blurt_and_lock_123() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 2
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -342,7 +343,7 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
 pg_advisory_unlock
 
 t              
-s2: NOTICE:  blurt_and_lock_4() called for k1
+s2: NOTICE:  blurt_and_lock_4() called for k1 in session 2
 s2: NOTICE:  acquiring advisory lock on 4
 step controller_show: SELECT * FROM upserttest;
 key            data           
@@ -351,11 +352,11 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_4() called for k1
+s1: NOTICE:  blurt_and_lock_4() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 4
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step controller_print_speculative_locks: SELECT locktype, mode, granted FROM pg_locks WHERE locktype='speculative token' ORDER BY granted;
 locktype       mode           granted        
@@ -366,10 +367,13 @@ step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
 pg_advisory_unlock
 
 t              
-s1: NOTICE:  blurt_and_lock_123() called for k1
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
+s1: NOTICE:  acquiring advisory lock on 2
+step s2_upsert: <... completed>
+step s2_commit: COMMIT;
+s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
 step s1_upsert: <... completed>
-step s2_upsert: <... completed>
 step controller_show: SELECT * FROM upserttest;
 key            data           
 
diff --git i/src/test/isolation/specs/insert-conflict-specconflict.spec w/src/test/isolation/specs/insert-conflict-specconflict.spec
index 2696c332a89..c029b94a9c2 100644
--- i/src/test/isolation/specs/insert-conflict-specconflict.spec
+++ w/src/test/isolation/specs/insert-conflict-specconflict.spec
@@ -10,7 +10,7 @@ setup
 {
      CREATE OR REPLACE FUNCTION blurt_and_lock_123(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
      BEGIN
-        RAISE NOTICE 'blurt_and_lock_123() called for %', $1;
+        RAISE NOTICE 'blurt_and_lock_123() called for % in session %', $1, current_setting('spec.session')::int;
 
 	-- depending on lock state, wait for lock 2 or 3
         IF pg_try_advisory_xact_lock(current_setting('spec.session')::int, 1) THEN
@@ -25,8 +25,8 @@ setup
 
     CREATE OR REPLACE FUNCTION blurt_and_lock_4(text) RETURNS text IMMUTABLE LANGUAGE plpgsql AS $$
     BEGIN
-        RAISE NOTICE 'blurt_and_lock_4() called for %', $1;
-		RAISE NOTICE 'acquiring advisory lock on 4';
+        RAISE NOTICE 'blurt_and_lock_4() called for % in session %', $1, current_setting('spec.session')::int;
+        RAISE NOTICE 'acquiring advisory lock on 4';
         PERFORM pg_advisory_xact_lock(current_setting('spec.session')::int, 4);
     RETURN $1;
     END;$$;
@@ -210,6 +210,7 @@ permutation
    "s1_confirm_index_order"
    "controller_locks"
    "controller_show"
+   "s2_begin"
    # Both sessions wait on advisory locks
    "s1_upsert" "s2_upsert"
    "controller_show"
@@ -235,5 +236,6 @@ permutation
    # Allow s2 to insert into the non-unique index and complete
    # s1 will no longer wait and will proceed to update
    "controller_unlock_2_4"
+   "s2_commit"
    # This should now show a successful UPSERT
    "controller_show"
#28Andres Freund
andres@anarazel.de
In reply to: Andres Freund (#27)
Re: Adding a test for speculative insert abort case

Hi,

On 2020-02-07 16:40:46 -0800, Andres Freund wrote:

I'm currently fighting with a race I'm observing in about 1/4 of the
runs. [...]
I think the issue here is that determines whether s1 can finish its
check_exclusion_or_unique_constraint() check with one retry is whether
it reaches it does the tuple visibility test before s2's transaction has
actually marked itself as visible (note that ProcArrayEndTransaction is
after RecordTransactionCommit logging the COMMIT above).

I think the fix is quite easy: Ensure that there *always* will be the
second wait iteration on the transaction (in addition to the already
always existing wait on the speculative token). Which is just adding
s2_begin s2_commit steps. Simple, but took me a few hours to
understand :/.

I've attached that portion of my changes. Will interrupt scheduled
programming for a bit of exercise now.

I've pushed this now. Thanks for the patch, and the review!

I additionally restricted the controller_print_speculative_locks step to
the current database and made a bunch of debug output more
precise. Survived ~150 runs locally.

Lets see what the buildfarm says...

Regards,

Andres

#29Melanie Plageman
melanieplageman@gmail.com
In reply to: Andres Freund (#28)
Re: Adding a test for speculative insert abort case

On Tue, Feb 11, 2020 at 4:45 PM Andres Freund <andres@anarazel.de> wrote:

I additionally restricted the controller_print_speculative_locks step to
the current database and made a bunch of debug output more
precise. Survived ~150 runs locally.

Lets see what the buildfarm says...

Thanks so much for finishing the patch and checking for race
conditions!

--
Melanie Plageman

#30Amit Kapila
amit.kapila16@gmail.com
In reply to: Melanie Plageman (#29)
Re: Adding a test for speculative insert abort case

On Wed, Feb 12, 2020 at 6:50 AM Melanie Plageman
<melanieplageman@gmail.com> wrote:

On Tue, Feb 11, 2020 at 4:45 PM Andres Freund <andres@anarazel.de> wrote:

I additionally restricted the controller_print_speculative_locks step to
the current database and made a bunch of debug output more
precise. Survived ~150 runs locally.

Lets see what the buildfarm says...

Thanks so much for finishing the patch and checking for race
conditions!

Can we change the status of CF entry for this patch [1]https://commitfest.postgresql.org/27/2200/ -- With Regards, Amit Kapila. EnterpriseDB: http://www.enterprisedb.com to committed
or is there any work pending?

[1]: https://commitfest.postgresql.org/27/2200/ -- With Regards, Amit Kapila. EnterpriseDB: http://www.enterprisedb.com
--
With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

#31Andres Freund
andres@anarazel.de
In reply to: Amit Kapila (#30)
Re: Adding a test for speculative insert abort case

On 2020-03-24 18:03:57 +0530, Amit Kapila wrote:

Can we change the status of CF entry for this patch [1] to committed
or is there any work pending?

Done!