Improving isolationtester's data output

I've been spending a lot of time looking at isolationtester results
over the past couple of days, and gotten really annoyed at how poorly
it formats query results.  In particular, any column heading or value
that is 15 characters or longer is not separated from the next column,
rendering the output quite confusing.

Attached is a little hack that tries to improve that case while making
minimal changes to the output files otherwise.

There's still a good deal to be desired here: notably, the code still
does nothing to ensure vertical alignment of successive lines when
there are wide headings or values.  But doing anything about that
would involve much-more-invasive changes of the output files.
If we wanted to buy into that, I'd think about discarding this
ad-hoc code altogether in favor of using one of libpq's fe-print.c
routines.  But I'm not really sure that the small legibility gains
that would result are worth massive changes in the output files.

Thoughts?

            regards, tom lane

diff --git a/src/test/isolation/expected/detach-partition-concurrently-3.out
b/src/test/isolation/expected/detach-partition-concurrently-3.out
index 96ee090d53..3f553711b3 100644
--- a/src/test/isolation/expected/detach-partition-concurrently-3.out
+++ b/src/test/isolation/expected/detach-partition-concurrently-3.out
@@ -9,7 +9,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -35,7 +35,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -54,7 +54,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -77,7 +77,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -95,7 +95,7 @@ a
 1
 step s2detach2: ALTER TABLE d3_listp DETACH PARTITION d3_listp2 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach2: <... completed>
@@ -121,7 +121,7 @@ a
 1
 step s2detach2: ALTER TABLE d3_listp DETACH PARTITION d3_listp2 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach2: <... completed>
@@ -150,7 +150,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -172,7 +172,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -194,7 +194,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -213,7 +213,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -233,7 +233,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -252,7 +252,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -276,7 +276,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -301,7 +301,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -324,7 +324,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -349,7 +349,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -369,7 +369,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -394,7 +394,7 @@ a
 1
 step s2detach: ALTER TABLE d3_listp DETACH PARTITION d3_listp1 CONCURRENTLY; <waiting ...>
 step s1cancel: SELECT pg_cancel_backend(pid), pg_sleep(0.1) FROM d3_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
diff --git a/src/test/isolation/expected/detach-partition-concurrently-4.out
b/src/test/isolation/expected/detach-partition-concurrently-4.out
index e5dc40d076..33ea6eccf6 100644
--- a/src/test/isolation/expected/detach-partition-concurrently-4.out
+++ b/src/test/isolation/expected/detach-partition-concurrently-4.out
@@ -10,7 +10,7 @@ a
 2
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -44,7 +44,7 @@ a
 2
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -74,7 +74,7 @@ step s1b: begin;
 step s1declare: declare f cursor for select * from d4_primary;
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -110,7 +110,7 @@ step s1b: begin;
 step s1declare: declare f cursor for select * from d4_primary;
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -150,7 +150,7 @@ step s1b: begin;
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently;
 step s1declare: declare f cursor for select * from d4_primary;
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2noop: UNLISTEN noop;
@@ -181,7 +181,7 @@ step s1b: begin;
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently;
 step s1declare: declare f cursor for select * from d4_primary;
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2noop: UNLISTEN noop;
@@ -220,7 +220,7 @@ a
 2
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -286,7 +286,7 @@ step s3insert: insert into d4_fk values (1);
 ERROR:  insert or update on table "d4_fk" violates foreign key constraint "d4_fk_a_fkey"
 step s3commit: commit;
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -320,7 +320,7 @@ a
 2
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
@@ -346,7 +346,7 @@ a
 2
 step s2detach: alter table d4_primary detach partition d4_primary1 concurrently; <waiting ...>
 step s1cancel: select pg_cancel_backend(pid), pg_sleep(0.1) from d4_pid;
-pg_cancel_backendpg_sleep
+pg_cancel_backend pg_sleep

 t
 step s2detach: <... completed>
diff --git a/src/test/isolation/expected/insert-conflict-specconflict.out
b/src/test/isolation/expected/insert-conflict-specconflict.out
index ae361fbd03..8f2bc9d562 100644
--- a/src/test/isolation/expected/insert-conflict-specconflict.out
+++ b/src/test/isolation/expected/insert-conflict-specconflict.out
@@ -2,7 +2,7 @@ Parsed test spec with 3 sessions

 starting permutation: controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1
controller_unlock_2_1controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_2_2 controller_show
controller_unlock_1_2controller_show 
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess),
generate_series(1,3)b(lock); 
-pg_advisory_locksess           lock
+pg_advisory_lock sess           lock

                1              1
                1              2
@@ -70,7 +70,7 @@ k1             inserted s2 with conflict update s1

 starting permutation: controller_locks controller_show s1_upsert s2_upsert controller_show controller_unlock_1_1
controller_unlock_2_1controller_unlock_1_3 controller_unlock_2_3 controller_show controller_unlock_1_2 controller_show
controller_unlock_2_2controller_show 
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess),
generate_series(1,3)b(lock); 
-pg_advisory_locksess           lock
+pg_advisory_lock sess           lock

                1              1
                1              2
@@ -138,7 +138,7 @@ k1             inserted s1 with conflict update s2

 starting permutation: controller_locks controller_show s1_insert_toast s2_insert_toast controller_show
controller_unlock_1_1controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show
controller_unlock_1_2controller_show_count controller_unlock_2_2 controller_show_count 
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess),
generate_series(1,3)b(lock); 
-pg_advisory_locksess           lock
+pg_advisory_lock sess           lock

                1              1
                1              2
@@ -206,7 +206,7 @@ count

 starting permutation: controller_locks controller_show s1_begin s2_begin s1_upsert s2_upsert controller_show
controller_unlock_1_1controller_unlock_2_1 controller_unlock_1_3 controller_unlock_2_3 controller_show
controller_unlock_1_2controller_show controller_unlock_2_2 controller_show s1_commit controller_show s2_commit
controller_show
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess),
generate_series(1,3)b(lock); 
-pg_advisory_locksess           lock
+pg_advisory_lock sess           lock

                1              1
                1              2
@@ -291,7 +291,7 @@ step s1_confirm_index_order: SELECT 'upserttest_key_uniq_idx'::regclass::int8 <

 t
 step controller_locks: SELECT pg_advisory_lock(sess, lock), sess, lock FROM generate_series(1, 2) a(sess),
generate_series(1,3)b(lock); 
-pg_advisory_locksess           lock
+pg_advisory_lock sess           lock

                1              1
                1              2
@@ -367,12 +367,12 @@ step controller_print_speculative_locks:
         AND pa.application_name LIKE 'isolation/insert-conflict-specconflict-s%'
     ORDER BY 1, 2, 3, 4;

-application_namelocktype       mode           granted
+application_name locktype       mode           granted

-isolation/insert-conflict-specconflict-s1spectoken      ShareLock      f
-isolation/insert-conflict-specconflict-s1transactionid  ExclusiveLock  t
-isolation/insert-conflict-specconflict-s2spectoken      ExclusiveLock  t
-isolation/insert-conflict-specconflict-s2transactionid  ExclusiveLock  t
+isolation/insert-conflict-specconflict-s1 spectoken      ShareLock      f
+isolation/insert-conflict-specconflict-s1 transactionid  ExclusiveLock  t
+isolation/insert-conflict-specconflict-s2 spectoken      ExclusiveLock  t
+isolation/insert-conflict-specconflict-s2 transactionid  ExclusiveLock  t
 step controller_unlock_2_4: SELECT pg_advisory_unlock(2, 4);
 pg_advisory_unlock

@@ -389,11 +389,11 @@ step controller_print_speculative_locks:
         AND pa.application_name LIKE 'isolation/insert-conflict-specconflict-s%'
     ORDER BY 1, 2, 3, 4;

-application_namelocktype       mode           granted
+application_name locktype       mode           granted

-isolation/insert-conflict-specconflict-s1transactionid  ExclusiveLock  t
-isolation/insert-conflict-specconflict-s1transactionid  ShareLock      f
-isolation/insert-conflict-specconflict-s2transactionid  ExclusiveLock  t
+isolation/insert-conflict-specconflict-s1 transactionid  ExclusiveLock  t
+isolation/insert-conflict-specconflict-s1 transactionid  ShareLock      f
+isolation/insert-conflict-specconflict-s2 transactionid  ExclusiveLock  t
 step s2_commit: COMMIT;
 s1: NOTICE:  blurt_and_lock_123() called for k1 in session 1
 s1: NOTICE:  acquiring advisory lock on 2
@@ -411,5 +411,5 @@ step controller_print_speculative_locks:
         AND pa.application_name LIKE 'isolation/insert-conflict-specconflict-s%'
     ORDER BY 1, 2, 3, 4;

-application_namelocktype       mode           granted
+application_name locktype       mode           granted

diff --git a/src/test/isolation/expected/partition-concurrent-attach.out
b/src/test/isolation/expected/partition-concurrent-attach.out
index 17fac39989..764ce04e03 100644
--- a/src/test/isolation/expected/partition-concurrent-attach.out
+++ b/src/test/isolation/expected/partition-concurrent-attach.out
@@ -44,6 +44,6 @@ step s1c: commit;
 step s2s: select tableoid::regclass, * from tpart;
 tableoid       i              j

-tpart_default_default110            xxx
-tpart_default_default120            yyy
-tpart_default_default150            zzz
+tpart_default_default 110            xxx
+tpart_default_default 120            yyy
+tpart_default_default 150            zzz
diff --git a/src/test/isolation/expected/tuplelock-update.out b/src/test/isolation/expected/tuplelock-update.out
index ea63022e93..e153f7a8d6 100644
--- a/src/test/isolation/expected/tuplelock-update.out
+++ b/src/test/isolation/expected/tuplelock-update.out
@@ -6,7 +6,7 @@ step s1_advlock:
         pg_advisory_lock(285714),
         pg_advisory_lock(571428);

-pg_advisory_lockpg_advisory_lockpg_advisory_lock
+pg_advisory_lock pg_advisory_lock pg_advisory_lock


 step s2_update: UPDATE pktab SET data = DEFAULT WHERE pg_advisory_lock_shared(142857) IS NOT NULL; <waiting ...>
diff --git a/src/test/isolation/isolationtester.c b/src/test/isolation/isolationtester.c
index 0a73d38dae..fe9acb1143 100644
--- a/src/test/isolation/isolationtester.c
+++ b/src/test/isolation/isolationtester.c
@@ -920,14 +920,26 @@ printResultSet(PGresult *res)
     /* first, print out the attribute names */
     nFields = PQnfields(res);
     for (i = 0; i < nFields; i++)
-        printf("%-15s", PQfname(res, i));
+    {
+        const char *itm = PQfname(res, i);
+
+        printf("%-15s", itm);
+        if (i < nFields - 1 && strlen(itm) >= 15)
+            printf(" ");
+    }
     printf("\n\n");

     /* next, print out the rows */
     for (i = 0; i < PQntuples(res); i++)
     {
         for (j = 0; j < nFields; j++)
-            printf("%-15s", PQgetvalue(res, i, j));
+        {
+            const char *itm = PQgetvalue(res, i, j);
+
+            printf("%-15s", itm);
+            if (j < nFields - 1 && strlen(itm) >= 15)
+                printf(" ");
+        }
         printf("\n");
     }
 }