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

Generated by: LCOV version 1.13