LCOV - code coverage report
Current view: top level - src/test/isolation - isolationtester.c (source / functions) Hit Total Coverage
Test: PostgreSQL 13devel Lines: 292 350 83.4 %
Date: 2019-11-15 22:06:47 Functions: 15 15 100.0 %
Legend: Lines: hit not hit

          Line data    Source code
       1             : /*
       2             :  * src/test/isolation/isolationtester.c
       3             :  *
       4             :  * isolationtester.c
       5             :  *      Runs an isolation test specified by a spec file.
       6             :  */
       7             : 
       8             : #include "postgres_fe.h"
       9             : 
      10             : #include <sys/time.h>
      11             : #ifdef HAVE_SYS_SELECT_H
      12             : #include <sys/select.h>
      13             : #endif
      14             : 
      15             : #include "datatype/timestamp.h"
      16             : #include "isolationtester.h"
      17             : #include "libpq-fe.h"
      18             : #include "pg_getopt.h"
      19             : #include "pqexpbuffer.h"
      20             : 
      21             : #define PREP_WAITING "isolationtester_waiting"
      22             : 
      23             : /*
      24             :  * conns[0] is the global setup, teardown, and watchdog connection.  Additional
      25             :  * connections represent spec-defined sessions.  We also track the backend
      26             :  * PID, in numeric and string formats, for each connection.
      27             :  */
      28             : static PGconn **conns = NULL;
      29             : static int *backend_pids = NULL;
      30             : static const char **backend_pid_strs = NULL;
      31             : static int  nconns = 0;
      32             : 
      33             : static void run_testspec(TestSpec *testspec);
      34             : static void run_all_permutations(TestSpec *testspec);
      35             : static void run_all_permutations_recurse(TestSpec *testspec, int nsteps,
      36             :                                          Step **steps);
      37             : static void run_named_permutations(TestSpec *testspec);
      38             : static void run_permutation(TestSpec *testspec, int nsteps, Step **steps);
      39             : 
      40             : #define STEP_NONBLOCK   0x1     /* return 0 as soon as cmd waits for a lock */
      41             : #define STEP_RETRY      0x2     /* this is a retry of a previously-waiting cmd */
      42             : static bool try_complete_step(TestSpec *testspec, Step *step, int flags);
      43             : 
      44             : static int  step_qsort_cmp(const void *a, const void *b);
      45             : static int  step_bsearch_cmp(const void *a, const void *b);
      46             : 
      47             : static void printResultSet(PGresult *res);
      48             : static void isotesterNoticeProcessor(void *arg, const char *message);
      49             : static void blackholeNoticeProcessor(void *arg, const char *message);
      50             : 
      51             : static void
      52         200 : disconnect_atexit(void)
      53             : {
      54             :     int         i;
      55             : 
      56         886 :     for (i = 0; i < nconns; i++)
      57         686 :         if (conns[i])
      58         686 :             PQfinish(conns[i]);
      59         200 : }
      60             : 
      61             : int
      62         208 : main(int argc, char **argv)
      63             : {
      64             :     const char *conninfo;
      65             :     TestSpec   *testspec;
      66             :     int         i,
      67             :                 j;
      68             :     int         n;
      69             :     PGresult   *res;
      70             :     PQExpBufferData wait_query;
      71             :     int         opt;
      72             :     int         nallsteps;
      73             :     Step      **allsteps;
      74             : 
      75         208 :     while ((opt = getopt(argc, argv, "V")) != -1)
      76             :     {
      77           8 :         switch (opt)
      78             :         {
      79             :             case 'V':
      80           8 :                 puts("isolationtester (PostgreSQL) " PG_VERSION);
      81           8 :                 exit(0);
      82             :             default:
      83           0 :                 fprintf(stderr, "Usage: isolationtester [CONNINFO]\n");
      84           0 :                 return EXIT_FAILURE;
      85             :         }
      86             :     }
      87             : 
      88             :     /*
      89             :      * Make stdout unbuffered to match stderr; and ensure stderr is unbuffered
      90             :      * too, which it should already be everywhere except sometimes in Windows.
      91             :      */
      92         200 :     setbuf(stdout, NULL);
      93         200 :     setbuf(stderr, NULL);
      94             : 
      95             :     /*
      96             :      * If the user supplies a non-option parameter on the command line, use it
      97             :      * as the conninfo string; otherwise default to setting dbname=postgres
      98             :      * and using environment variables or defaults for all other connection
      99             :      * parameters.
     100             :      */
     101         200 :     if (argc > optind)
     102         200 :         conninfo = argv[optind];
     103             :     else
     104           0 :         conninfo = "dbname = postgres";
     105             : 
     106             :     /* Read the test spec from stdin */
     107         200 :     spec_yyparse();
     108         200 :     testspec = &parseresult;
     109             : 
     110             :     /* Create a lookup table of all steps. */
     111         200 :     nallsteps = 0;
     112         686 :     for (i = 0; i < testspec->nsessions; i++)
     113         486 :         nallsteps += testspec->sessions[i]->nsteps;
     114             : 
     115         200 :     allsteps = pg_malloc(nallsteps * sizeof(Step *));
     116             : 
     117         200 :     n = 0;
     118         686 :     for (i = 0; i < testspec->nsessions; i++)
     119             :     {
     120        2302 :         for (j = 0; j < testspec->sessions[i]->nsteps; j++)
     121        1816 :             allsteps[n++] = testspec->sessions[i]->steps[j];
     122             :     }
     123             : 
     124         200 :     qsort(allsteps, nallsteps, sizeof(Step *), &step_qsort_cmp);
     125         200 :     testspec->nallsteps = nallsteps;
     126         200 :     testspec->allsteps = allsteps;
     127             : 
     128             :     /* Verify that all step names are unique */
     129        1816 :     for (i = 1; i < testspec->nallsteps; i++)
     130             :     {
     131        1616 :         if (strcmp(testspec->allsteps[i - 1]->name,
     132        1616 :                    testspec->allsteps[i]->name) == 0)
     133             :         {
     134           0 :             fprintf(stderr, "duplicate step name: %s\n",
     135           0 :                     testspec->allsteps[i]->name);
     136           0 :             exit(1);
     137             :         }
     138             :     }
     139             : 
     140         200 :     printf("Parsed test spec with %d sessions\n", testspec->nsessions);
     141             : 
     142             :     /*
     143             :      * Establish connections to the database, one for each session and an
     144             :      * extra for lock wait detection and global work.
     145             :      */
     146         200 :     nconns = 1 + testspec->nsessions;
     147         200 :     conns = (PGconn **) pg_malloc0(nconns * sizeof(PGconn *));
     148         200 :     backend_pids = pg_malloc0(nconns * sizeof(*backend_pids));
     149         200 :     backend_pid_strs = pg_malloc0(nconns * sizeof(*backend_pid_strs));
     150         200 :     atexit(disconnect_atexit);
     151             : 
     152         886 :     for (i = 0; i < nconns; i++)
     153             :     {
     154         686 :         conns[i] = PQconnectdb(conninfo);
     155         686 :         if (PQstatus(conns[i]) != CONNECTION_OK)
     156             :         {
     157           0 :             fprintf(stderr, "Connection %d to database failed: %s",
     158           0 :                     i, PQerrorMessage(conns[i]));
     159           0 :             exit(1);
     160             :         }
     161             : 
     162             :         /*
     163             :          * Set up notice processors for the user-defined connections, so that
     164             :          * messages can get printed prefixed with the session names.  The
     165             :          * control connection gets a "blackhole" processor instead (hides all
     166             :          * messages).
     167             :          */
     168         686 :         if (i != 0)
     169         486 :             PQsetNoticeProcessor(conns[i],
     170             :                                  isotesterNoticeProcessor,
     171         486 :                                  (void *) (testspec->sessions[i - 1]->name));
     172             :         else
     173         200 :             PQsetNoticeProcessor(conns[i],
     174             :                                  blackholeNoticeProcessor,
     175             :                                  NULL);
     176             : 
     177             :         /* Save each connection's backend PID for subsequent use. */
     178         686 :         backend_pids[i] = PQbackendPID(conns[i]);
     179         686 :         backend_pid_strs[i] = psprintf("%d", backend_pids[i]);
     180             :     }
     181             : 
     182             :     /* Set the session index fields in steps. */
     183         686 :     for (i = 0; i < testspec->nsessions; i++)
     184             :     {
     185         486 :         Session    *session = testspec->sessions[i];
     186             :         int         stepindex;
     187             : 
     188        2302 :         for (stepindex = 0; stepindex < session->nsteps; stepindex++)
     189        1816 :             session->steps[stepindex]->session = i;
     190             :     }
     191             : 
     192             :     /*
     193             :      * Build the query we'll use to detect lock contention among sessions in
     194             :      * the test specification.  Most of the time, we could get away with
     195             :      * simply checking whether a session is waiting for *any* lock: we don't
     196             :      * exactly expect concurrent use of test tables.  However, autovacuum will
     197             :      * occasionally take AccessExclusiveLock to truncate a table, and we must
     198             :      * ignore that transient wait.
     199             :      */
     200         200 :     initPQExpBuffer(&wait_query);
     201         200 :     appendPQExpBufferStr(&wait_query,
     202             :                          "SELECT pg_catalog.pg_isolation_test_session_is_blocked($1, '{");
     203             :     /* The spec syntax requires at least one session; assume that here. */
     204         200 :     appendPQExpBufferStr(&wait_query, backend_pid_strs[1]);
     205         486 :     for (i = 2; i < nconns; i++)
     206         286 :         appendPQExpBuffer(&wait_query, ",%s", backend_pid_strs[i]);
     207         200 :     appendPQExpBufferStr(&wait_query, "}')");
     208             : 
     209         200 :     res = PQprepare(conns[0], PREP_WAITING, wait_query.data, 0, NULL);
     210         200 :     if (PQresultStatus(res) != PGRES_COMMAND_OK)
     211             :     {
     212           0 :         fprintf(stderr, "prepare of lock wait query failed: %s",
     213             :                 PQerrorMessage(conns[0]));
     214           0 :         exit(1);
     215             :     }
     216         200 :     PQclear(res);
     217         200 :     termPQExpBuffer(&wait_query);
     218             : 
     219             :     /*
     220             :      * Run the permutations specified in the spec, or all if none were
     221             :      * explicitly specified.
     222             :      */
     223         200 :     run_testspec(testspec);
     224             : 
     225         200 :     return 0;
     226             : }
     227             : 
     228             : static int *piles;
     229             : 
     230             : /*
     231             :  * Run the permutations specified in the spec, or all if none were
     232             :  * explicitly specified.
     233             :  */
     234             : static void
     235         200 : run_testspec(TestSpec *testspec)
     236             : {
     237             :     int         i;
     238             : 
     239         200 :     if (testspec->permutations)
     240         168 :         run_named_permutations(testspec);
     241             :     else
     242          32 :         run_all_permutations(testspec);
     243             : 
     244             :     /*
     245             :      * Verify that all steps have been used, complaining about anything
     246             :      * defined but not used.
     247             :      */
     248        2016 :     for (i = 0; i < testspec->nallsteps; i++)
     249             :     {
     250        1816 :         if (!testspec->allsteps[i]->used)
     251          12 :             fprintf(stderr, "unused step name: %s\n",
     252          12 :                     testspec->allsteps[i]->name);
     253             :     }
     254         200 : }
     255             : 
     256             : /*
     257             :  * Run all permutations of the steps and sessions.
     258             :  */
     259             : static void
     260          32 : run_all_permutations(TestSpec *testspec)
     261             : {
     262             :     int         nsteps;
     263             :     int         i;
     264             :     Step      **steps;
     265             : 
     266             :     /* Count the total number of steps in all sessions */
     267          32 :     nsteps = 0;
     268         100 :     for (i = 0; i < testspec->nsessions; i++)
     269          68 :         nsteps += testspec->sessions[i]->nsteps;
     270             : 
     271          32 :     steps = pg_malloc(sizeof(Step *) * nsteps);
     272             : 
     273             :     /*
     274             :      * To generate the permutations, we conceptually put the steps of each
     275             :      * session on a pile. To generate a permutation, we pick steps from the
     276             :      * piles until all piles are empty. By picking steps from piles in
     277             :      * different order, we get different permutations.
     278             :      *
     279             :      * A pile is actually just an integer which tells how many steps we've
     280             :      * already picked from this pile.
     281             :      */
     282          32 :     piles = pg_malloc(sizeof(int) * testspec->nsessions);
     283         100 :     for (i = 0; i < testspec->nsessions; i++)
     284          68 :         piles[i] = 0;
     285             : 
     286          32 :     run_all_permutations_recurse(testspec, 0, steps);
     287          32 : }
     288             : 
     289             : static void
     290        3188 : run_all_permutations_recurse(TestSpec *testspec, int nsteps, Step **steps)
     291             : {
     292             :     int         i;
     293        3188 :     int         found = 0;
     294             : 
     295       11406 :     for (i = 0; i < testspec->nsessions; i++)
     296             :     {
     297             :         /* If there's any more steps in this pile, pick it and recurse */
     298        8218 :         if (piles[i] < testspec->sessions[i]->nsteps)
     299             :         {
     300        3156 :             steps[nsteps] = testspec->sessions[i]->steps[piles[i]];
     301        3156 :             piles[i]++;
     302             : 
     303        3156 :             run_all_permutations_recurse(testspec, nsteps + 1, steps);
     304             : 
     305        3156 :             piles[i]--;
     306             : 
     307        3156 :             found = 1;
     308             :         }
     309             :     }
     310             : 
     311             :     /* If all the piles were empty, this permutation is completed. Run it */
     312        3188 :     if (!found)
     313         990 :         run_permutation(testspec, nsteps, steps);
     314        3188 : }
     315             : 
     316             : /*
     317             :  * Run permutations given in the test spec
     318             :  */
     319             : static void
     320         168 : run_named_permutations(TestSpec *testspec)
     321             : {
     322             :     int         i,
     323             :                 j;
     324             : 
     325        1874 :     for (i = 0; i < testspec->npermutations; i++)
     326             :     {
     327        1706 :         Permutation *p = testspec->permutations[i];
     328             :         Step      **steps;
     329             : 
     330        1706 :         steps = pg_malloc(p->nsteps * sizeof(Step *));
     331             : 
     332             :         /* Find all the named steps using the lookup table */
     333       14520 :         for (j = 0; j < p->nsteps; j++)
     334             :         {
     335       25628 :             Step      **this = (Step **) bsearch(p->stepnames[j],
     336       12814 :                                                  testspec->allsteps,
     337       12814 :                                                  testspec->nallsteps,
     338             :                                                  sizeof(Step *),
     339             :                                                  &step_bsearch_cmp);
     340             : 
     341       12814 :             if (this == NULL)
     342             :             {
     343           0 :                 fprintf(stderr, "undefined step \"%s\" specified in permutation\n",
     344           0 :                         p->stepnames[j]);
     345           0 :                 exit(1);
     346             :             }
     347       12814 :             steps[j] = *this;
     348             :         }
     349             : 
     350             :         /* And run them */
     351        1706 :         run_permutation(testspec, p->nsteps, steps);
     352             : 
     353        1706 :         free(steps);
     354             :     }
     355         168 : }
     356             : 
     357             : static int
     358        5022 : step_qsort_cmp(const void *a, const void *b)
     359             : {
     360        5022 :     Step       *stepa = *((Step **) a);
     361        5022 :     Step       *stepb = *((Step **) b);
     362             : 
     363        5022 :     return strcmp(stepa->name, stepb->name);
     364             : }
     365             : 
     366             : static int
     367       39444 : step_bsearch_cmp(const void *a, const void *b)
     368             : {
     369       39444 :     char       *stepname = (char *) a;
     370       39444 :     Step       *step = *((Step **) b);
     371             : 
     372       39444 :     return strcmp(stepname, step->name);
     373             : }
     374             : 
     375             : /*
     376             :  * If a step caused an error to be reported, print it out and clear it.
     377             :  */
     378             : static void
     379       18280 : report_error_message(Step *step)
     380             : {
     381       18280 :     if (step->errormsg)
     382             :     {
     383         590 :         fprintf(stdout, "%s\n", step->errormsg);
     384         590 :         free(step->errormsg);
     385         590 :         step->errormsg = NULL;
     386             :     }
     387       18280 : }
     388             : 
     389             : /*
     390             :  * As above, but reports messages possibly emitted by multiple steps.  This is
     391             :  * useful when we have a blocked command awakened by another one; we want to
     392             :  * report all messages identically, for the case where we don't care which
     393             :  * one fails due to a timeout such as deadlock timeout.
     394             :  */
     395             : static void
     396       19112 : report_multiple_error_messages(Step *step, int nextra, Step **extrastep)
     397             : {
     398             :     PQExpBufferData buffer;
     399             :     int         n;
     400             : 
     401       19112 :     if (nextra == 0)
     402             :     {
     403       18264 :         report_error_message(step);
     404       18264 :         return;
     405             :     }
     406             : 
     407         848 :     initPQExpBuffer(&buffer);
     408         848 :     appendPQExpBufferStr(&buffer, step->name);
     409             : 
     410        1710 :     for (n = 0; n < nextra; ++n)
     411         862 :         appendPQExpBuffer(&buffer, " %s", extrastep[n]->name);
     412             : 
     413         848 :     if (step->errormsg)
     414             :     {
     415           4 :         fprintf(stdout, "error in steps %s: %s\n", buffer.data,
     416             :                 step->errormsg);
     417           4 :         free(step->errormsg);
     418           4 :         step->errormsg = NULL;
     419             :     }
     420             : 
     421        1710 :     for (n = 0; n < nextra; ++n)
     422             :     {
     423         862 :         if (extrastep[n]->errormsg == NULL)
     424         698 :             continue;
     425         164 :         fprintf(stdout, "error in steps %s: %s\n",
     426         164 :                 buffer.data, extrastep[n]->errormsg);
     427         164 :         free(extrastep[n]->errormsg);
     428         164 :         extrastep[n]->errormsg = NULL;
     429             :     }
     430             : 
     431         848 :     termPQExpBuffer(&buffer);
     432             : }
     433             : 
     434             : /*
     435             :  * Run one permutation
     436             :  */
     437             : static void
     438        2696 : run_permutation(TestSpec *testspec, int nsteps, Step **steps)
     439             : {
     440             :     PGresult   *res;
     441             :     int         i;
     442             :     int         w;
     443        2696 :     int         nwaiting = 0;
     444        2696 :     int         nerrorstep = 0;
     445             :     Step      **waiting;
     446             :     Step      **errorstep;
     447             : 
     448        2696 :     waiting = pg_malloc(sizeof(Step *) * testspec->nsessions);
     449        2696 :     errorstep = pg_malloc(sizeof(Step *) * testspec->nsessions);
     450             : 
     451        2696 :     printf("\nstarting permutation:");
     452       21804 :     for (i = 0; i < nsteps; i++)
     453             :     {
     454             :         /* Track the permutation as in-use */
     455       19108 :         steps[i]->used = true;
     456       19108 :         printf(" %s", steps[i]->name);
     457             :     }
     458        2696 :     printf("\n");
     459             : 
     460             :     /* Perform setup */
     461        5432 :     for (i = 0; i < testspec->nsetupsqls; i++)
     462             :     {
     463        2736 :         res = PQexec(conns[0], testspec->setupsqls[i]);
     464        2736 :         if (PQresultStatus(res) == PGRES_TUPLES_OK)
     465             :         {
     466           0 :             printResultSet(res);
     467             :         }
     468        2736 :         else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     469             :         {
     470           0 :             fprintf(stderr, "setup failed: %s", PQerrorMessage(conns[0]));
     471           0 :             exit(1);
     472             :         }
     473        2736 :         PQclear(res);
     474             :     }
     475             : 
     476             :     /* Perform per-session setup */
     477        9164 :     for (i = 0; i < testspec->nsessions; i++)
     478             :     {
     479        6468 :         if (testspec->sessions[i]->setupsql)
     480             :         {
     481        4358 :             res = PQexec(conns[i + 1], testspec->sessions[i]->setupsql);
     482        4358 :             if (PQresultStatus(res) == PGRES_TUPLES_OK)
     483             :             {
     484          46 :                 printResultSet(res);
     485             :             }
     486        4312 :             else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     487             :             {
     488           0 :                 fprintf(stderr, "setup of session %s failed: %s",
     489           0 :                         testspec->sessions[i]->name,
     490           0 :                         PQerrorMessage(conns[i + 1]));
     491           0 :                 exit(1);
     492             :             }
     493        4358 :             PQclear(res);
     494             :         }
     495             :     }
     496             : 
     497             :     /* Perform steps */
     498       21804 :     for (i = 0; i < nsteps; i++)
     499             :     {
     500       19108 :         Step       *step = steps[i];
     501       19108 :         PGconn     *conn = conns[1 + step->session];
     502       19108 :         Step       *oldstep = NULL;
     503             :         bool        mustwait;
     504             : 
     505             :         /*
     506             :          * Check whether the session that needs to perform the next step is
     507             :          * still blocked on an earlier step.  If so, wait for it to finish.
     508             :          *
     509             :          * (In older versions of this tool, we allowed precisely one session
     510             :          * to be waiting at a time.  If we reached a step that required that
     511             :          * session to execute the next command, we would declare the whole
     512             :          * permutation invalid, cancel everything, and move on to the next
     513             :          * one.  Unfortunately, that made it impossible to test the deadlock
     514             :          * detector using this framework, unless the number of processes
     515             :          * involved in the deadlock was precisely two.  We now assume that if
     516             :          * we reach a step that is still blocked, we need to wait for it to
     517             :          * unblock itself.)
     518             :          */
     519       20646 :         for (w = 0; w < nwaiting; ++w)
     520             :         {
     521        1542 :             if (step->session == waiting[w]->session)
     522             :             {
     523           4 :                 oldstep = waiting[w];
     524             : 
     525             :                 /* Wait for previous step on this connection. */
     526           4 :                 try_complete_step(testspec, oldstep, STEP_RETRY);
     527             : 
     528             :                 /* Remove that step from the waiting[] array. */
     529           4 :                 if (w + 1 < nwaiting)
     530           0 :                     memmove(&waiting[w], &waiting[w + 1],
     531           0 :                             (nwaiting - (w + 1)) * sizeof(Step *));
     532           4 :                 nwaiting--;
     533             : 
     534           4 :                 break;
     535             :             }
     536             :         }
     537       19108 :         if (oldstep != NULL)
     538             :         {
     539             :             /*
     540             :              * Check for completion of any steps that were previously waiting.
     541             :              * Remove any that have completed from waiting[], and include them
     542             :              * in the list for report_multiple_error_messages().
     543             :              */
     544           4 :             w = 0;
     545           4 :             nerrorstep = 0;
     546          28 :             while (w < nwaiting)
     547             :             {
     548          20 :                 if (try_complete_step(testspec, waiting[w],
     549             :                                       STEP_NONBLOCK | STEP_RETRY))
     550             :                 {
     551             :                     /* Still blocked on a lock, leave it alone. */
     552          18 :                     w++;
     553             :                 }
     554             :                 else
     555             :                 {
     556             :                     /* This one finished, too! */
     557           2 :                     errorstep[nerrorstep++] = waiting[w];
     558           2 :                     if (w + 1 < nwaiting)
     559           0 :                         memmove(&waiting[w], &waiting[w + 1],
     560           0 :                                 (nwaiting - (w + 1)) * sizeof(Step *));
     561           2 :                     nwaiting--;
     562             :                 }
     563             :             }
     564             : 
     565             :             /* Report all errors together. */
     566           4 :             report_multiple_error_messages(oldstep, nerrorstep, errorstep);
     567             :         }
     568             : 
     569             :         /* Send the query for this step. */
     570       19108 :         if (!PQsendQuery(conn, step->sql))
     571             :         {
     572           0 :             fprintf(stdout, "failed to send query for step %s: %s\n",
     573             :                     step->name, PQerrorMessage(conn));
     574           0 :             exit(1);
     575             :         }
     576             : 
     577             :         /* Try to complete this step without blocking.  */
     578       19108 :         mustwait = try_complete_step(testspec, step, STEP_NONBLOCK);
     579             : 
     580             :         /* Check for completion of any steps that were previously waiting. */
     581       19108 :         w = 0;
     582       19108 :         nerrorstep = 0;
     583       39752 :         while (w < nwaiting)
     584             :         {
     585        1536 :             if (try_complete_step(testspec, waiting[w],
     586             :                                   STEP_NONBLOCK | STEP_RETRY))
     587         676 :                 w++;
     588             :             else
     589             :             {
     590         860 :                 errorstep[nerrorstep++] = waiting[w];
     591         860 :                 if (w + 1 < nwaiting)
     592          34 :                     memmove(&waiting[w], &waiting[w + 1],
     593          34 :                             (nwaiting - (w + 1)) * sizeof(Step *));
     594         860 :                 nwaiting--;
     595             :             }
     596             :         }
     597             : 
     598             :         /* Report any error from this step, and any steps that it unblocked. */
     599       19108 :         report_multiple_error_messages(step, nerrorstep, errorstep);
     600             : 
     601             :         /* If this step is waiting, add it to the array of waiters. */
     602       19108 :         if (mustwait)
     603         882 :             waiting[nwaiting++] = step;
     604             :     }
     605             : 
     606             :     /* Wait for any remaining queries. */
     607        2712 :     for (w = 0; w < nwaiting; ++w)
     608             :     {
     609          16 :         try_complete_step(testspec, waiting[w], STEP_RETRY);
     610          16 :         report_error_message(waiting[w]);
     611             :     }
     612             : 
     613             :     /* Perform per-session teardown */
     614        9164 :     for (i = 0; i < testspec->nsessions; i++)
     615             :     {
     616        6468 :         if (testspec->sessions[i]->teardownsql)
     617             :         {
     618         406 :             res = PQexec(conns[i + 1], testspec->sessions[i]->teardownsql);
     619         406 :             if (PQresultStatus(res) == PGRES_TUPLES_OK)
     620             :             {
     621         170 :                 printResultSet(res);
     622             :             }
     623         236 :             else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     624             :             {
     625           0 :                 fprintf(stderr, "teardown of session %s failed: %s",
     626           0 :                         testspec->sessions[i]->name,
     627           0 :                         PQerrorMessage(conns[i + 1]));
     628             :                 /* don't exit on teardown failure */
     629             :             }
     630         406 :             PQclear(res);
     631             :         }
     632             :     }
     633             : 
     634             :     /* Perform teardown */
     635        2696 :     if (testspec->teardownsql)
     636             :     {
     637        2646 :         res = PQexec(conns[0], testspec->teardownsql);
     638        2646 :         if (PQresultStatus(res) == PGRES_TUPLES_OK)
     639             :         {
     640          66 :             printResultSet(res);
     641             :         }
     642        2580 :         else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     643             :         {
     644           0 :             fprintf(stderr, "teardown failed: %s",
     645             :                     PQerrorMessage(conns[0]));
     646             :             /* don't exit on teardown failure */
     647             :         }
     648        2646 :         PQclear(res);
     649             :     }
     650             : 
     651        2696 :     free(waiting);
     652        2696 :     free(errorstep);
     653        2696 : }
     654             : 
     655             : /*
     656             :  * Our caller already sent the query associated with this step.  Wait for it
     657             :  * to either complete or (if given the STEP_NONBLOCK flag) to block while
     658             :  * waiting for a lock.  We assume that any lock wait will persist until we
     659             :  * have executed additional steps in the permutation.
     660             :  *
     661             :  * When calling this function on behalf of a given step for a second or later
     662             :  * time, pass the STEP_RETRY flag.  This only affects the messages printed.
     663             :  *
     664             :  * If the query returns an error, the message is saved in step->errormsg.
     665             :  * Caller should call report_error_message shortly after this, to have it
     666             :  * printed and cleared.
     667             :  *
     668             :  * If the STEP_NONBLOCK flag was specified and the query is waiting to acquire
     669             :  * a lock, returns true.  Otherwise, returns false.
     670             :  */
     671             : static bool
     672       20684 : try_complete_step(TestSpec *testspec, Step *step, int flags)
     673             : {
     674       20684 :     PGconn     *conn = conns[1 + step->session];
     675             :     fd_set      read_set;
     676             :     struct timeval start_time;
     677             :     struct timeval timeout;
     678       20684 :     int         sock = PQsocket(conn);
     679             :     int         ret;
     680             :     PGresult   *res;
     681             :     PGnotify   *notify;
     682       20684 :     bool        canceled = false;
     683             : 
     684       20684 :     if (sock < 0)
     685             :     {
     686           0 :         fprintf(stderr, "invalid socket: %s", PQerrorMessage(conn));
     687           0 :         exit(1);
     688             :     }
     689             : 
     690       20684 :     gettimeofday(&start_time, NULL);
     691       20684 :     FD_ZERO(&read_set);
     692             : 
     693       20684 :     while (PQisBusy(conn))
     694             :     {
     695       45700 :         FD_SET(sock, &read_set);
     696       45700 :         timeout.tv_sec = 0;
     697       45700 :         timeout.tv_usec = 10000;    /* Check for lock waits every 10ms. */
     698             : 
     699       45700 :         ret = select(sock + 1, &read_set, NULL, NULL, &timeout);
     700       45700 :         if (ret < 0)         /* error in select() */
     701             :         {
     702           0 :             if (errno == EINTR)
     703           0 :                 continue;
     704           0 :             fprintf(stderr, "select failed: %s\n", strerror(errno));
     705           0 :             exit(1);
     706             :         }
     707       45700 :         else if (ret == 0)      /* select() timeout: check for lock wait */
     708             :         {
     709             :             struct timeval current_time;
     710             :             int64       td;
     711             : 
     712             :             /* If it's OK for the step to block, check whether it has. */
     713       25936 :             if (flags & STEP_NONBLOCK)
     714             :             {
     715             :                 bool        waiting;
     716             : 
     717       45978 :                 res = PQexecPrepared(conns[0], PREP_WAITING, 1,
     718       30652 :                                      &backend_pid_strs[step->session + 1],
     719             :                                      NULL, NULL, 0);
     720       30652 :                 if (PQresultStatus(res) != PGRES_TUPLES_OK ||
     721       15326 :                     PQntuples(res) != 1)
     722             :                 {
     723           0 :                     fprintf(stderr, "lock wait query failed: %s",
     724             :                             PQerrorMessage(conns[0]));
     725           0 :                     exit(1);
     726             :                 }
     727       15326 :                 waiting = ((PQgetvalue(res, 0, 0))[0] == 't');
     728       15326 :                 PQclear(res);
     729             : 
     730       15326 :                 if (waiting)    /* waiting to acquire a lock */
     731             :                 {
     732             :                     /*
     733             :                      * Since it takes time to perform the lock-check query,
     734             :                      * some data --- notably, NOTICE messages --- might have
     735             :                      * arrived since we looked.  We must call PQconsumeInput
     736             :                      * and then PQisBusy to collect and process any such
     737             :                      * messages.  In the (unlikely) case that PQisBusy then
     738             :                      * returns false, we might as well go examine the
     739             :                      * available result.
     740             :                      */
     741        1576 :                     if (!PQconsumeInput(conn))
     742             :                     {
     743           0 :                         fprintf(stderr, "PQconsumeInput failed: %s\n",
     744             :                                 PQerrorMessage(conn));
     745           0 :                         exit(1);
     746             :                     }
     747        1576 :                     if (!PQisBusy(conn))
     748           0 :                         break;
     749             : 
     750             :                     /*
     751             :                      * conn is still busy, so conclude that the step really is
     752             :                      * waiting.
     753             :                      */
     754        1576 :                     if (!(flags & STEP_RETRY))
     755         882 :                         printf("step %s: %s <waiting ...>\n",
     756             :                                step->name, step->sql);
     757        1576 :                     return true;
     758             :                 }
     759             :                 /* else, not waiting */
     760             :             }
     761             : 
     762             :             /* Figure out how long we've been waiting for this step. */
     763       24360 :             gettimeofday(&current_time, NULL);
     764       24360 :             td = (int64) current_time.tv_sec - (int64) start_time.tv_sec;
     765       24360 :             td *= USECS_PER_SEC;
     766       24360 :             td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
     767             : 
     768             :             /*
     769             :              * After 180 seconds, try to cancel the query.
     770             :              *
     771             :              * If the user tries to test an invalid permutation, we don't want
     772             :              * to hang forever, especially when this is running in the
     773             :              * buildfarm.  This will presumably lead to this permutation
     774             :              * failing, but remaining permutations and tests should still be
     775             :              * OK.
     776             :              */
     777       24360 :             if (td > 180 * USECS_PER_SEC && !canceled)
     778             :             {
     779           0 :                 PGcancel   *cancel = PQgetCancel(conn);
     780             : 
     781           0 :                 if (cancel != NULL)
     782             :                 {
     783             :                     char        buf[256];
     784             : 
     785           0 :                     if (PQcancel(cancel, buf, sizeof(buf)))
     786           0 :                         canceled = true;
     787             :                     else
     788           0 :                         fprintf(stderr, "PQcancel failed: %s\n", buf);
     789           0 :                     PQfreeCancel(cancel);
     790             :                 }
     791             :             }
     792             : 
     793             :             /*
     794             :              * After 200 seconds, just give up and die.
     795             :              *
     796             :              * Since cleanup steps won't be run in this case, this may cause
     797             :              * later tests to fail.  That stinks, but it's better than waiting
     798             :              * forever for the server to respond to the cancel.
     799             :              */
     800       24360 :             if (td > 200 * USECS_PER_SEC)
     801             :             {
     802           0 :                 fprintf(stderr, "step %s timed out after 200 seconds\n",
     803             :                         step->name);
     804           0 :                 exit(1);
     805             :             }
     806             :         }
     807       19764 :         else if (!PQconsumeInput(conn)) /* select(): data available */
     808             :         {
     809           0 :             fprintf(stderr, "PQconsumeInput failed: %s\n",
     810             :                     PQerrorMessage(conn));
     811           0 :             exit(1);
     812             :         }
     813             :     }
     814             : 
     815       19108 :     if (flags & STEP_RETRY)
     816         882 :         printf("step %s: <... completed>\n", step->name);
     817             :     else
     818       18226 :         printf("step %s: %s\n", step->name, step->sql);
     819             : 
     820       57736 :     while ((res = PQgetResult(conn)))
     821             :     {
     822       19520 :         switch (PQresultStatus(res))
     823             :         {
     824             :             case PGRES_COMMAND_OK:
     825       13478 :                 break;
     826             :             case PGRES_TUPLES_OK:
     827        5284 :                 printResultSet(res);
     828        5284 :                 break;
     829             :             case PGRES_FATAL_ERROR:
     830         758 :                 if (step->errormsg != NULL)
     831             :                 {
     832           0 :                     printf("WARNING: this step had a leftover error message\n");
     833           0 :                     printf("%s\n", step->errormsg);
     834             :                 }
     835             : 
     836             :                 /*
     837             :                  * Detail may contain XID values, so we want to just show
     838             :                  * primary.  Beware however that libpq-generated error results
     839             :                  * may not contain subfields, only an old-style message.
     840             :                  */
     841             :                 {
     842         758 :                     const char *sev = PQresultErrorField(res,
     843             :                                                          PG_DIAG_SEVERITY);
     844         758 :                     const char *msg = PQresultErrorField(res,
     845             :                                                          PG_DIAG_MESSAGE_PRIMARY);
     846             : 
     847         758 :                     if (sev && msg)
     848         758 :                         step->errormsg = psprintf("%s:  %s", sev, msg);
     849             :                     else
     850           0 :                         step->errormsg = pg_strdup(PQresultErrorMessage(res));
     851             :                 }
     852         758 :                 break;
     853             :             default:
     854           0 :                 printf("unexpected result status: %s\n",
     855             :                        PQresStatus(PQresultStatus(res)));
     856             :         }
     857       19520 :         PQclear(res);
     858             :     }
     859             : 
     860             :     /* Report any available NOTIFY messages, too */
     861       19108 :     PQconsumeInput(conn);
     862       38258 :     while ((notify = PQnotifies(conn)) != NULL)
     863             :     {
     864             :         /* Try to identify which session it came from */
     865          42 :         const char *sendername = NULL;
     866             :         char        pidstring[32];
     867             : 
     868          42 :         for (int i = 0; i < testspec->nsessions; i++)
     869             :         {
     870          42 :             if (notify->be_pid == backend_pids[i + 1])
     871             :             {
     872          42 :                 sendername = testspec->sessions[i]->name;
     873          42 :                 break;
     874             :             }
     875             :         }
     876          42 :         if (sendername == NULL)
     877             :         {
     878             :             /* Doesn't seem to be any test session, so show the hard way */
     879           0 :             snprintf(pidstring, sizeof(pidstring), "PID %d", notify->be_pid);
     880           0 :             sendername = pidstring;
     881             :         }
     882          42 :         printf("%s: NOTIFY \"%s\" with payload \"%s\" from %s\n",
     883             :                testspec->sessions[step->session]->name,
     884             :                notify->relname, notify->extra, sendername);
     885          42 :         PQfreemem(notify);
     886          42 :         PQconsumeInput(conn);
     887             :     }
     888             : 
     889       19108 :     return false;
     890             : }
     891             : 
     892             : static void
     893        5566 : printResultSet(PGresult *res)
     894             : {
     895             :     int         nFields;
     896             :     int         i,
     897             :                 j;
     898             : 
     899             :     /* first, print out the attribute names */
     900        5566 :     nFields = PQnfields(res);
     901       13978 :     for (i = 0; i < nFields; i++)
     902        8412 :         printf("%-15s", PQfname(res, i));
     903        5566 :     printf("\n\n");
     904             : 
     905             :     /* next, print out the rows */
     906       13486 :     for (i = 0; i < PQntuples(res); i++)
     907             :     {
     908       21450 :         for (j = 0; j < nFields; j++)
     909       13530 :             printf("%-15s", PQgetvalue(res, i, j));
     910        7920 :         printf("\n");
     911             :     }
     912        5566 : }
     913             : 
     914             : /* notice processor, prefixes each message with the session name */
     915             : static void
     916         964 : isotesterNoticeProcessor(void *arg, const char *message)
     917             : {
     918         964 :     printf("%s: %s", (char *) arg, message);
     919         964 : }
     920             : 
     921             : /* notice processor, hides the message */
     922             : static void
     923         550 : blackholeNoticeProcessor(void *arg, const char *message)
     924             : {
     925             :     /* do nothing */
     926         550 : }

Generated by: LCOV version 1.13