mirror of
https://git.postgresql.org/git/postgresql.git
synced 2024-08-23 08:00:40 +02:00
Fix isolationtester race condition for notices sent before blocking.
If a test sends a notice just before blocking, it's possible on
slow machines for isolationtester to detect the blocked state before
it's consumed the notice. (For this to happen, the notice would have
to arrive after isolationtester has waited for data for 10ms, so on
fast/lightly-loaded machines it's hard to reproduce the failure.)
But, if we have seen the backend as blocked, it's certainly already
sent any notices it's going to send. Therefore, one more round of
PQconsumeInput and PQisBusy should be enough to collect and process
any such notices.
This appears to explain the instability noted in commit ebd499282
, so undo
the hack therein to not print notices from insert-conflict-specconflict.
Patch by me, diagnosis by Andres Freund.
Discussion: https://postgr.es/m/14616.1564251339@sss.pgh.pa.us
This commit is contained in:
parent
ebd4992821
commit
30717637c1
@ -13,7 +13,11 @@ 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 ...>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
@ -30,10 +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
|
||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||
pg_advisory_unlock
|
||||
|
||||
t
|
||||
s2: NOTICE: called for k1
|
||||
s2: NOTICE: blocking 2
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
|
||||
@ -50,6 +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
|
||||
step s1_upsert: <... completed>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
@ -69,7 +81,11 @@ 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 ...>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
@ -86,10 +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
|
||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||
pg_advisory_unlock
|
||||
|
||||
t
|
||||
s2: NOTICE: called for k1
|
||||
s2: NOTICE: blocking 2
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
|
||||
@ -106,6 +126,10 @@ 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
|
||||
step s2_upsert: <... completed>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
@ -127,7 +151,11 @@ 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 ...>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
@ -144,10 +172,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
|
||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||
pg_advisory_unlock
|
||||
|
||||
t
|
||||
s2: NOTICE: called for k1
|
||||
s2: NOTICE: blocking 2
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
|
||||
@ -163,10 +195,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
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
|
||||
step s1_commit: COMMIT;
|
||||
s2: NOTICE: called for k1
|
||||
s2: NOTICE: blocking 2
|
||||
step s2_upsert: <... completed>
|
||||
step controller_show: SELECT * FROM upserttest;
|
||||
key data
|
||||
|
@ -752,6 +752,28 @@ try_complete_step(Step *step, int flags)
|
||||
|
||||
if (waiting) /* waiting to acquire a lock */
|
||||
{
|
||||
/*
|
||||
* Since it takes time to perform the lock-check query,
|
||||
* some data --- notably, NOTICE messages --- might have
|
||||
* arrived since we looked. We must call PQconsumeInput
|
||||
* and then PQisBusy to collect and process any such
|
||||
* messages. In the (unlikely) case that PQisBusy then
|
||||
* returns false, we might as well go examine the
|
||||
* available result.
|
||||
*/
|
||||
if (!PQconsumeInput(conn))
|
||||
{
|
||||
fprintf(stderr, "PQconsumeInput failed: %s\n",
|
||||
PQerrorMessage(conn));
|
||||
exit(1);
|
||||
}
|
||||
if (!PQisBusy(conn))
|
||||
break;
|
||||
|
||||
/*
|
||||
* conn is still busy, so conclude that the step really is
|
||||
* waiting.
|
||||
*/
|
||||
if (!(flags & STEP_RETRY))
|
||||
printf("step %s: %s <waiting ...>\n",
|
||||
step->name, step->sql);
|
||||
|
@ -51,9 +51,6 @@ session "s1"
|
||||
setup
|
||||
{
|
||||
SET default_transaction_isolation = 'read committed';
|
||||
-- on very slow machines, the notices come out in unpredictable order,
|
||||
-- so hide them
|
||||
SET client_min_messages = warning;
|
||||
SET spec.session = 1;
|
||||
}
|
||||
step "s1_begin" { BEGIN; }
|
||||
@ -64,9 +61,6 @@ session "s2"
|
||||
setup
|
||||
{
|
||||
SET default_transaction_isolation = 'read committed';
|
||||
-- on very slow machines, the notices come out in unpredictable order,
|
||||
-- so hide them
|
||||
SET client_min_messages = warning;
|
||||
SET spec.session = 2;
|
||||
}
|
||||
step "s2_begin" { BEGIN; }
|
||||
|
Loading…
Reference in New Issue
Block a user