Skip to content

Commit 2e6f972

Browse files
tglsfdctglsfdc
committed
Sync isolationtester's handling of notice/warning messages with HEAD.
Back-patch relevant parts of these commits: 3071763 Fix isolationtester race condition for notices sent before blocking ebd4992 Don't drop NOTICE messages in isolation tests a28e10e Indicate session name in isolationtester notices This ensures that older versions of the isolationtester will handle NOTICE/WARNING messages the same way as HEAD and v12 do. While this isn't fixing any critical problem right now, it seems like a prudent change to prevent surprises (like we had yesterday...) with back-patches of future isolation test changes. Back-patch as far as 9.6. Due to the significant changes we made in isolationtester in 9.6, back-patching isolation tests further than that is going to be risky anyway; besides, this patch doesn't apply cleanly before that. Discussion: https://postgr.es/m/E1i7IqC-0000Uc-5H@gemulon.postgresql.org
1 parent 801b261 commit 2e6f972

File tree

2 files changed

+88
-9
lines changed

2 files changed

+88
-9
lines changed

‎src/test/isolation/expected/insert-conflict-specconflict.out

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,7 +13,11 @@ pg_advisory_locksess lock
1313
step controller_show: SELECT * FROM upserttest;
1414
key data
1515

16+
s1: NOTICE: called for k1
17+
s1: NOTICE: blocking 3
1618
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 ...>
19+
s2: NOTICE: called for k1
20+
s2: NOTICE: blocking 3
1721
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 ...>
1822
step controller_show: SELECT * FROM upserttest;
1923
key data
@@ -30,10 +34,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
3034
pg_advisory_unlock
3135

3236
t
37+
s1: NOTICE: called for k1
38+
s1: NOTICE: blocking 2
3339
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
3440
pg_advisory_unlock
3541

3642
t
43+
s2: NOTICE: called for k1
44+
s2: NOTICE: blocking 2
3745
step controller_show: SELECT * FROM upserttest;
3846
key data
3947

@@ -50,6 +58,10 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
5058
pg_advisory_unlock
5159

5260
t
61+
s1: NOTICE: called for k1
62+
s1: NOTICE: blocking 2
63+
s1: NOTICE: called for k1
64+
s1: NOTICE: blocking 2
5365
step s1_upsert: <... completed>
5466
step controller_show: SELECT * FROM upserttest;
5567
key data
@@ -69,7 +81,11 @@ pg_advisory_locksess lock
6981
step controller_show: SELECT * FROM upserttest;
7082
key data
7183

84+
s1: NOTICE: called for k1
85+
s1: NOTICE: blocking 3
7286
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 ...>
87+
s2: NOTICE: called for k1
88+
s2: NOTICE: blocking 3
7389
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 ...>
7490
step controller_show: SELECT * FROM upserttest;
7591
key data
@@ -86,10 +102,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
86102
pg_advisory_unlock
87103

88104
t
105+
s1: NOTICE: called for k1
106+
s1: NOTICE: blocking 2
89107
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
90108
pg_advisory_unlock
91109

92110
t
111+
s2: NOTICE: called for k1
112+
s2: NOTICE: blocking 2
93113
step controller_show: SELECT * FROM upserttest;
94114
key data
95115

@@ -106,6 +126,10 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
106126
pg_advisory_unlock
107127

108128
t
129+
s2: NOTICE: called for k1
130+
s2: NOTICE: blocking 2
131+
s2: NOTICE: called for k1
132+
s2: NOTICE: blocking 2
109133
step s2_upsert: <... completed>
110134
step controller_show: SELECT * FROM upserttest;
111135
key data
@@ -127,7 +151,11 @@ key data
127151

128152
step s1_begin: BEGIN;
129153
step s2_begin: BEGIN;
154+
s1: NOTICE: called for k1
155+
s1: NOTICE: blocking 3
130156
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 ...>
157+
s2: NOTICE: called for k1
158+
s2: NOTICE: blocking 3
131159
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 ...>
132160
step controller_show: SELECT * FROM upserttest;
133161
key data
@@ -144,10 +172,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
144172
pg_advisory_unlock
145173

146174
t
175+
s1: NOTICE: called for k1
176+
s1: NOTICE: blocking 2
147177
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
148178
pg_advisory_unlock
149179

150180
t
181+
s2: NOTICE: called for k1
182+
s2: NOTICE: blocking 2
151183
step controller_show: SELECT * FROM upserttest;
152184
key data
153185

@@ -163,10 +195,16 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
163195
pg_advisory_unlock
164196

165197
t
198+
s2: NOTICE: called for k1
199+
s2: NOTICE: blocking 2
200+
s2: NOTICE: called for k1
201+
s2: NOTICE: blocking 2
166202
step controller_show: SELECT * FROM upserttest;
167203
key data
168204

169205
step s1_commit: COMMIT;
206+
s2: NOTICE: called for k1
207+
s2: NOTICE: blocking 2
170208
step s2_upsert: <... completed>
171209
step controller_show: SELECT * FROM upserttest;
172210
key data

‎src/test/isolation/isolationtester.c

Lines changed: 50 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,8 @@ static int step_qsort_cmp(const void *a, const void *b);
4747
static int step_bsearch_cmp(const void *a, const void *b);
4848

4949
static void printResultSet(PGresult *res);
50+
static void isotesterNoticeProcessor(void *arg, const char *message);
51+
static void blackholeNoticeProcessor(void *arg, const char *message);
5052

5153
/* close all connections and exit */
5254
static void
@@ -171,16 +173,19 @@ main(int argc, char **argv)
171173
}
172174

173175
/*
174-
* Suppress NOTIFY messages, which otherwise pop into results at odd
175-
* places.
176+
* Set up notice processors for the user-defined connections, so that
177+
* messages can get printed prefixed with the session names. The
178+
* control connection gets a "blackhole" processor instead (hides all
179+
* messages).
176180
*/
177-
res = PQexec(conns[i], "SET client_min_messages = warning;");
178-
if (PQresultStatus(res) != PGRES_COMMAND_OK)
179-
{
180-
fprintf(stderr, "message level setup failed: %s", PQerrorMessage(conns[i]));
181-
exit_nicely();
182-
}
183-
PQclear(res);
181+
if (i != 0)
182+
PQsetNoticeProcessor(conns[i],
183+
isotesterNoticeProcessor,
184+
(void *) (testspec->sessions[i - 1]->name));
185+
else
186+
PQsetNoticeProcessor(conns[i],
187+
blackholeNoticeProcessor,
188+
NULL);
184189

185190
/* Get the backend pid for lock wait checking. */
186191
res = PQexec(conns[i], "SELECT pg_backend_pid()");
@@ -750,6 +755,28 @@ try_complete_step(Step *step, int flags)
750755

751756
if (waiting) /* waiting to acquire a lock */
752757
{
758+
/*
759+
* Since it takes time to perform the lock-check query,
760+
* some data --- notably, NOTICE messages --- might have
761+
* arrived since we looked. We must call PQconsumeInput
762+
* and then PQisBusy to collect and process any such
763+
* messages. In the (unlikely) case that PQisBusy then
764+
* returns false, we might as well go examine the
765+
* available result.
766+
*/
767+
if (!PQconsumeInput(conn))
768+
{
769+
fprintf(stderr, "PQconsumeInput failed: %s\n",
770+
PQerrorMessage(conn));
771+
exit(1);
772+
}
773+
if (!PQisBusy(conn))
774+
break;
775+
776+
/*
777+
* conn is still busy, so conclude that the step really is
778+
* waiting.
779+
*/
753780
if (!(flags & STEP_RETRY))
754781
printf("step %s: %s <waiting ...>\n",
755782
step->name, step->sql);
@@ -880,3 +907,17 @@ printResultSet(PGresult *res)
880907
printf("\n");
881908
}
882909
}
910+
911+
/* notice processor, prefixes each message with the session name */
912+
static void
913+
isotesterNoticeProcessor(void *arg, const char *message)
914+
{
915+
printf("%s: %s", (char *) arg, message);
916+
}
917+
918+
/* notice processor, hides the message */
919+
static void
920+
blackholeNoticeProcessor(void *arg, const char *message)
921+
{
922+
/* do nothing */
923+
}

0 commit comments

Comments
 (0)