summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
Diffstat (limited to 'src')
-rw-r--r--src/test/isolation/expected/insert-conflict-specconflict.out38
-rw-r--r--src/test/isolation/expected/plpgsql-toast.out15
-rw-r--r--src/test/isolation/expected/vacuum-concurrent-drop.out6
-rw-r--r--src/test/isolation/isolationtester.c59
-rw-r--r--src/test/isolation/specs/plpgsql-toast.spec10
5 files changed, 106 insertions, 22 deletions
diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out b/src/test/isolation/expected/insert-conflict-specconflict.out
index 5726bdb8e89..20cc421b872 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/expected/plpgsql-toast.out b/src/test/isolation/expected/plpgsql-toast.out
index 43411533f1d..fc557da5e77 100644
--- a/src/test/isolation/expected/plpgsql-toast.out
+++ b/src/test/isolation/expected/plpgsql-toast.out
@@ -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>
diff --git a/src/test/isolation/expected/vacuum-concurrent-drop.out b/src/test/isolation/expected/vacuum-concurrent-drop.out
index bb92e80b923..cf348d7e5df 100644
--- a/src/test/isolation/expected/vacuum-concurrent-drop.out
+++ b/src/test/isolation/expected/vacuum-concurrent-drop.out
@@ -10,7 +10,7 @@ step drop_and_commit:
DROP TABLE part2;
COMMIT;
-WARNING: skipping vacuum of "part2" --- relation no longer exists
+s2: WARNING: skipping vacuum of "part2" --- relation no longer exists
step vac_specified: <... completed>
starting permutation: lock vac_all_parts drop_and_commit
@@ -35,7 +35,7 @@ step drop_and_commit:
DROP TABLE part2;
COMMIT;
-WARNING: skipping analyze of "part2" --- relation no longer exists
+s2: WARNING: skipping analyze of "part2" --- relation no longer exists
step analyze_specified: <... completed>
starting permutation: lock analyze_all_parts drop_and_commit
@@ -60,7 +60,7 @@ step drop_and_commit:
DROP TABLE part2;
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>
starting permutation: lock vac_analyze_all_parts drop_and_commit
diff --git a/src/test/isolation/isolationtester.c b/src/test/isolation/isolationtester.c
index d32dbb7d68c..1d1cc123062 100644
--- a/src/test/isolation/isolationtester.c
+++ b/src/test/isolation/isolationtester.c
@@ -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 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 */
static void
@@ -172,16 +174,19 @@ main(int argc, char **argv)
}
/*
- * Suppress NOTIFY messages, which otherwise pop into results at odd
- * places.
+ * Set up notice processors for the user-defined connections, so that
+ * 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 (PQresultStatus(res) != PGRES_COMMAND_OK)
- {
- fprintf(stderr, "message level setup failed: %s", PQerrorMessage(conns[i]));
- exit_nicely();
- }
- PQclear(res);
+ if (i != 0)
+ PQsetNoticeProcessor(conns[i],
+ isotesterNoticeProcessor,
+ (void *) (testspec->sessions[i - 1]->name));
+ else
+ PQsetNoticeProcessor(conns[i],
+ blackholeNoticeProcessor,
+ NULL);
/* Get the backend pid for lock wait checking. */
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 */
{
+ /*
+ * 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);
@@ -881,3 +908,17 @@ printResultSet(PGresult *res)
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 */
+}
diff --git a/src/test/isolation/specs/plpgsql-toast.spec b/src/test/isolation/specs/plpgsql-toast.spec
index e6228c9ef68..fe7090addbb 100644
--- a/src/test/isolation/specs/plpgsql-toast.spec
+++ b/src/test/isolation/specs/plpgsql-toast.spec
@@ -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;
$$;
}