From: Tom Lane <tgl@sss.pgh.pa.us>
To: Andres Freund <andres@anarazel.de>
Cc: pgsql-hackers@lists.postgresql.org, Peter Geoghegan <pg@bowt.ie>
Subject: Re: Testing LISTEN/NOTIFY more effectively
Date: Sat, 27 Jul 2019 18:48:30 -0400
Message-ID: <6358.1564267710@sss.pgh.pa.us> (raw)
In-Reply-To: <20190727201936.f2oa7h5tkshmeyiq@alap3.anarazel.de>
References: <31304.1564246011@sss.pgh.pa.us>
<20190727174202.jiwr4jgp3x7gvp22@alap3.anarazel.de>
<5720.1564249986@sss.pgh.pa.us>
<14616.1564251339@sss.pgh.pa.us>
<20190727185502.bciewsyxz642hyq6@alap3.anarazel.de>
<13344.1564256384@sss.pgh.pa.us>
<20190727201936.f2oa7h5tkshmeyiq@alap3.anarazel.de>
Andres Freund <andres@anarazel.de> writes:
> On 2019-07-27 15:39:44 -0400, Tom Lane wrote:
>> Unfortunately, I just found out that on a slow enough machine
>> (prairiedog's host) there *is* some variation in when that test's
>> notices come out. I am unsure whether that's to be expected or
>> whether there's something wrong there
> Hm. Any chance you could show the diff? I don't immediately see why.
Sure. If I remove the client_min_messages hack from HEAD, then on
my dev workstation I get the attached test diff; that reproduces
quite reliably on a couple of machines. However, running that
diff on prairiedog's host gets the failure attached second more
often than not. (Sometimes it will pass.)
regards, tom lane
Attachments:download all (2 files, .tar.gz)show-the-intended-notices.patch (text/x-diff, 5.5K) downloaddiff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.outindex 5726bdb..20cc421 100644--- a/src/test/isolation/expected/insert-conflict-specconflict.out+++ b/src/test/isolation/expected/insert-conflict-specconflict.out@@ -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
diff --git a/src/test/isolation/specs/insert-conflict-specconflict.spec b/src/test/isolation/specs/insert-conflict-specconflict.specindex 2d16fae..3a70484 100644--- a/src/test/isolation/specs/insert-conflict-specconflict.spec+++ b/src/test/isolation/specs/insert-conflict-specconflict.spec@@ -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; }
regression.diffs (text/x-diff, 1.3K) download
diff -U3 /Users/tgl/pgsql/src/test/isolation/expected/insert-conflict-specconflict.out /Users/tgl/pgsql/src/test/isolation/output_iso/results/insert-conflict-specconflict.out
--- /Users/tgl/pgsql/src/test/isolation/expected/insert-conflict-specconflict.out 2019-07-27 18:28:49.000000000 -0400+++ /Users/tgl/pgsql/src/test/isolation/output_iso/results/insert-conflict-specconflict.out 2019-07-27 18:41:51.000000000 -0400@@ -13,15 +13,15 @@
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: called for k1+s1: NOTICE: blocking 3
step controller_show: SELECT * FROM upserttest;
key data
+s2: NOTICE: called for k1+s2: NOTICE: blocking 3
step controller_unlock_1_1: SELECT pg_advisory_unlock(1, 1);
pg_advisory_unlock
=
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: tgl@sss.pgh.pa.us, andres@anarazel.de, pg@bowt.ie
Subject: Re: Testing LISTEN/NOTIFY more effectively
In-Reply-To: <6358.1564267710@sss.pgh.pa.us>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox