1berry/postgres
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Don't drop NOTICE messages in isolation tests.

Browse Source 
For its entire existence, isolationtester.c has forced client_min_messages
to WARNING, but that seems like a very poor choice of test design.  It
should be up to individual test scripts to manage whether they emit notices
and to ensure that the results are stable.  (There were no NOTICE messages
in the original set of isolation tests, so this was certainly dead code
when committed, but perhaps it was needed at some earlier point.)

It's possible that the original motivation was due to platform-dependent
variations in the timing of stdout vs. stderr output.  That should be
moot since commits 73bcb76b7/6eda3e9c2, but just in case, adjust
isotesterNoticeProcessor to print to stdout not stderr.  (stderr seems
like the wrong thing anyway: it should be for error printouts not expected
test output.)

Back-patch of commit ebd499282 into v12.  I'll separately push this
into older branches, but this is as much change as v12 needs.

Discussion: https://postgr.es/m/14616.1564251339@sss.pgh.pa.us
Discussion: https://postgr.es/m/E1i7IqC-0000Uc-5H@gemulon.postgresql.org
This commit is contained in:
Tom Lane 2019-09-10 12:04:57 -04:00
parent 97fb88ea4a
commit b1016834d3
4 changed files with 54 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

38
src/test/isolation/expected/insert-conflict-specconflict.out
View File

@ -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

15
src/test/isolation/expected/plpgsql-toast.out
View File

@ -22,7 +22,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'x = %', x;
raise notice 'length(x) = %', length(x);
end;
$$;
<waiting ...>
@ -35,6 +35,7 @@ step unlock:
pg_advisory_unlock
t
s1: NOTICE: length(x) = 6000
step assign1: <... completed>
starting permutation: lock assign2 vacuum unlock
@ -59,7 +60,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'x = %', x;
raise notice 'length(x) = %', length(x);
end;
$$;
<waiting ...>
@ -72,6 +73,7 @@ step unlock:
pg_advisory_unlock
t
s1: NOTICE: length(x) = 6000
step assign2: <... completed>
starting permutation: lock assign3 vacuum unlock
@ -97,7 +99,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
<waiting ...>
@ -110,6 +112,7 @@ step unlock:
pg_advisory_unlock
t
s1: NOTICE: length(r) = 6004
step assign3: <... completed>
starting permutation: lock assign4 vacuum unlock
@ -134,7 +137,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
<waiting ...>
@ -147,6 +150,7 @@ step unlock:
pg_advisory_unlock
t
s1: NOTICE: length(r) = 6004
step assign4: <... completed>
starting permutation: lock assign5 vacuum unlock
@ -173,7 +177,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
<waiting ...>
@ -186,4 +190,5 @@ step unlock:
pg_advisory_unlock
t
s1: NOTICE: length(r) = 6002
step assign5: <... completed>

14
src/test/isolation/isolationtester.c
View File

@ -187,18 +187,6 @@ main(int argc, char **argv)
blackholeNoticeProcessor,
NULL);
/*
* Suppress NOTIFY messages, which otherwise pop into results at odd
* places.
*/
res = PQexec(conns[i], "SET client_min_messages = warning;");
if (PQresultStatus(res) != PGRES_COMMAND_OK)
{
fprintf(stderr, "message level setup failed: %s", PQerrorMessage(conns[i]));
exit(1);
}
PQclear(res);
/* Get the backend pid for lock wait checking. */
res = PQexec(conns[i], "SELECT pg_catalog.pg_backend_pid()");
if (PQresultStatus(res) == PGRES_TUPLES_OK)
@ -921,7 +909,7 @@ printResultSet(PGresult *res)
static void
isotesterNoticeProcessor(void *arg, const char *message)
{
fprintf(stderr, "%s: %s", (char *) arg, message);
printf("%s: %s", (char *) arg, message);
}
/* notice processor, hides the message */

10
src/test/isolation/specs/plpgsql-toast.spec
View File

@ -40,7 +40,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'x = %', x;
raise notice 'length(x) = %', length(x);
end;
$$;
}
@ -56,7 +56,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'x = %', x;
raise notice 'length(x) = %', length(x);
end;
$$;
}
@ -73,7 +73,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
}
@ -89,7 +89,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
}
@ -107,7 +107,7 @@ do $$
delete from test1;
commit;
perform pg_advisory_lock(1);
raise notice 'r = %', r;
raise notice 'length(r) = %', length(r::text);
end;
$$;
}