mirror of
https://git.postgresql.org/git/postgresql.git
synced 2024-08-23 16:37:18 +02:00
Sync isolationtester's handling of notice/warning messages with HEAD.
Back-patch relevant parts of these commits:30717637c
Fix isolationtester race condition for notices sent before blockingebd499282
Don't drop NOTICE messages in isolation testsa28e10e82
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
This commit is contained in:
parent
8459f908c6
commit
b5784042ae
@ -13,7 +13,11 @@ pg_advisory_locksess lock
|
|||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
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 ...>
|
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 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;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
@ -30,10 +34,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: called for k1
|
||||||
|
s1: NOTICE: blocking 2
|
||||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
|
|
||||||
@ -50,6 +58,10 @@ step controller_unlock_1_2: SELECT pg_advisory_unlock(1, 2);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: called for k1
|
||||||
|
s1: NOTICE: blocking 2
|
||||||
|
s1: NOTICE: called for k1
|
||||||
|
s1: NOTICE: blocking 2
|
||||||
step s1_upsert: <... completed>
|
step s1_upsert: <... completed>
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
@ -69,7 +81,11 @@ pg_advisory_locksess lock
|
|||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
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 ...>
|
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 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;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
@ -86,10 +102,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: called for k1
|
||||||
|
s1: NOTICE: blocking 2
|
||||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
|
|
||||||
@ -106,6 +126,10 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
step s2_upsert: <... completed>
|
step s2_upsert: <... completed>
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
@ -127,7 +151,11 @@ key data
|
|||||||
|
|
||||||
step s1_begin: BEGIN;
|
step s1_begin: BEGIN;
|
||||||
step s2_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 ...>
|
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 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;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
@ -144,10 +172,14 @@ step controller_unlock_1_3: SELECT pg_advisory_unlock(1, 3);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: called for k1
|
||||||
|
s1: NOTICE: blocking 2
|
||||||
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
step controller_unlock_2_3: SELECT pg_advisory_unlock(2, 3);
|
||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
|
|
||||||
@ -163,10 +195,16 @@ step controller_unlock_2_2: SELECT pg_advisory_unlock(2, 2);
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
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;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
|
|
||||||
step s1_commit: COMMIT;
|
step s1_commit: COMMIT;
|
||||||
|
s2: NOTICE: called for k1
|
||||||
|
s2: NOTICE: blocking 2
|
||||||
step s2_upsert: <... completed>
|
step s2_upsert: <... completed>
|
||||||
step controller_show: SELECT * FROM upserttest;
|
step controller_show: SELECT * FROM upserttest;
|
||||||
key data
|
key data
|
||||||
|
@ -22,7 +22,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'x = %', x;
|
raise notice 'length(x) = %', length(x);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
<waiting ...>
|
<waiting ...>
|
||||||
@ -35,6 +35,7 @@ step unlock:
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: length(x) = 6000
|
||||||
step assign1: <... completed>
|
step assign1: <... completed>
|
||||||
|
|
||||||
starting permutation: lock assign2 vacuum unlock
|
starting permutation: lock assign2 vacuum unlock
|
||||||
@ -59,7 +60,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'x = %', x;
|
raise notice 'length(x) = %', length(x);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
<waiting ...>
|
<waiting ...>
|
||||||
@ -72,6 +73,7 @@ step unlock:
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: length(x) = 6000
|
||||||
step assign2: <... completed>
|
step assign2: <... completed>
|
||||||
|
|
||||||
starting permutation: lock assign3 vacuum unlock
|
starting permutation: lock assign3 vacuum unlock
|
||||||
@ -97,7 +99,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
<waiting ...>
|
<waiting ...>
|
||||||
@ -110,6 +112,7 @@ step unlock:
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: length(r) = 6004
|
||||||
step assign3: <... completed>
|
step assign3: <... completed>
|
||||||
|
|
||||||
starting permutation: lock assign4 vacuum unlock
|
starting permutation: lock assign4 vacuum unlock
|
||||||
@ -134,7 +137,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
<waiting ...>
|
<waiting ...>
|
||||||
@ -147,6 +150,7 @@ step unlock:
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: length(r) = 6004
|
||||||
step assign4: <... completed>
|
step assign4: <... completed>
|
||||||
|
|
||||||
starting permutation: lock assign5 vacuum unlock
|
starting permutation: lock assign5 vacuum unlock
|
||||||
@ -173,7 +177,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
<waiting ...>
|
<waiting ...>
|
||||||
@ -186,4 +190,5 @@ step unlock:
|
|||||||
pg_advisory_unlock
|
pg_advisory_unlock
|
||||||
|
|
||||||
t
|
t
|
||||||
|
s1: NOTICE: length(r) = 6002
|
||||||
step assign5: <... completed>
|
step assign5: <... completed>
|
||||||
|
@ -10,7 +10,7 @@ step drop_and_commit:
|
|||||||
DROP TABLE part2;
|
DROP TABLE part2;
|
||||||
COMMIT;
|
COMMIT;
|
||||||
|
|
||||||
WARNING: skipping vacuum of "part2" --- relation no longer exists
|
s2: WARNING: skipping vacuum of "part2" --- relation no longer exists
|
||||||
step vac_specified: <... completed>
|
step vac_specified: <... completed>
|
||||||
|
|
||||||
starting permutation: lock vac_all_parts drop_and_commit
|
starting permutation: lock vac_all_parts drop_and_commit
|
||||||
@ -35,7 +35,7 @@ step drop_and_commit:
|
|||||||
DROP TABLE part2;
|
DROP TABLE part2;
|
||||||
COMMIT;
|
COMMIT;
|
||||||
|
|
||||||
WARNING: skipping analyze of "part2" --- relation no longer exists
|
s2: WARNING: skipping analyze of "part2" --- relation no longer exists
|
||||||
step analyze_specified: <... completed>
|
step analyze_specified: <... completed>
|
||||||
|
|
||||||
starting permutation: lock analyze_all_parts drop_and_commit
|
starting permutation: lock analyze_all_parts drop_and_commit
|
||||||
@ -60,7 +60,7 @@ step drop_and_commit:
|
|||||||
DROP TABLE part2;
|
DROP TABLE part2;
|
||||||
COMMIT;
|
COMMIT;
|
||||||
|
|
||||||
WARNING: skipping vacuum of "part2" --- relation no longer exists
|
s2: WARNING: skipping vacuum of "part2" --- relation no longer exists
|
||||||
step vac_analyze_specified: <... completed>
|
step vac_analyze_specified: <... completed>
|
||||||
|
|
||||||
starting permutation: lock vac_analyze_all_parts drop_and_commit
|
starting permutation: lock vac_analyze_all_parts drop_and_commit
|
||||||
|
@ -48,6 +48,8 @@ static int step_qsort_cmp(const void *a, const void *b);
|
|||||||
static int step_bsearch_cmp(const void *a, const void *b);
|
static int step_bsearch_cmp(const void *a, const void *b);
|
||||||
|
|
||||||
static void printResultSet(PGresult *res);
|
static void printResultSet(PGresult *res);
|
||||||
|
static void isotesterNoticeProcessor(void *arg, const char *message);
|
||||||
|
static void blackholeNoticeProcessor(void *arg, const char *message);
|
||||||
|
|
||||||
/* close all connections and exit */
|
/* close all connections and exit */
|
||||||
static void
|
static void
|
||||||
@ -172,16 +174,19 @@ main(int argc, char **argv)
|
|||||||
}
|
}
|
||||||
|
|
||||||
/*
|
/*
|
||||||
* Suppress NOTIFY messages, which otherwise pop into results at odd
|
* Set up notice processors for the user-defined connections, so that
|
||||||
* places.
|
* messages can get printed prefixed with the session names. The
|
||||||
|
* control connection gets a "blackhole" processor instead (hides all
|
||||||
|
* messages).
|
||||||
*/
|
*/
|
||||||
res = PQexec(conns[i], "SET client_min_messages = warning;");
|
if (i != 0)
|
||||||
if (PQresultStatus(res) != PGRES_COMMAND_OK)
|
PQsetNoticeProcessor(conns[i],
|
||||||
{
|
isotesterNoticeProcessor,
|
||||||
fprintf(stderr, "message level setup failed: %s", PQerrorMessage(conns[i]));
|
(void *) (testspec->sessions[i - 1]->name));
|
||||||
exit_nicely();
|
else
|
||||||
}
|
PQsetNoticeProcessor(conns[i],
|
||||||
PQclear(res);
|
blackholeNoticeProcessor,
|
||||||
|
NULL);
|
||||||
|
|
||||||
/* Get the backend pid for lock wait checking. */
|
/* Get the backend pid for lock wait checking. */
|
||||||
res = PQexec(conns[i], "SELECT pg_backend_pid()");
|
res = PQexec(conns[i], "SELECT pg_backend_pid()");
|
||||||
@ -751,6 +756,28 @@ try_complete_step(Step *step, int flags)
|
|||||||
|
|
||||||
if (waiting) /* waiting to acquire a lock */
|
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))
|
if (!(flags & STEP_RETRY))
|
||||||
printf("step %s: %s <waiting ...>\n",
|
printf("step %s: %s <waiting ...>\n",
|
||||||
step->name, step->sql);
|
step->name, step->sql);
|
||||||
@ -881,3 +908,17 @@ printResultSet(PGresult *res)
|
|||||||
printf("\n");
|
printf("\n");
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/* notice processor, prefixes each message with the session name */
|
||||||
|
static void
|
||||||
|
isotesterNoticeProcessor(void *arg, const char *message)
|
||||||
|
{
|
||||||
|
printf("%s: %s", (char *) arg, message);
|
||||||
|
}
|
||||||
|
|
||||||
|
/* notice processor, hides the message */
|
||||||
|
static void
|
||||||
|
blackholeNoticeProcessor(void *arg, const char *message)
|
||||||
|
{
|
||||||
|
/* do nothing */
|
||||||
|
}
|
||||||
|
@ -40,7 +40,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'x = %', x;
|
raise notice 'length(x) = %', length(x);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
}
|
}
|
||||||
@ -56,7 +56,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'x = %', x;
|
raise notice 'length(x) = %', length(x);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
}
|
}
|
||||||
@ -73,7 +73,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
}
|
}
|
||||||
@ -89,7 +89,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
}
|
}
|
||||||
@ -107,7 +107,7 @@ do $$
|
|||||||
delete from test1;
|
delete from test1;
|
||||||
commit;
|
commit;
|
||||||
perform pg_advisory_lock(1);
|
perform pg_advisory_lock(1);
|
||||||
raise notice 'r = %', r;
|
raise notice 'length(r) = %', length(r::text);
|
||||||
end;
|
end;
|
||||||
$$;
|
$$;
|
||||||
}
|
}
|
||||||
|
Loading…
Reference in New Issue
Block a user