LCOV - code coverage report
Current view: top level - src/test/isolation - isolationtester.c (source / functions) Hit Total Coverage
Test: PostgreSQL 15devel Lines: 331 416 79.6 %
Date: 2021-12-05 01:09:12 Functions: 16 16 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.
      26             :  */
      27             : typedef struct IsoConnInfo
      28             : {
      29             :     /* The libpq connection object for this connection. */
      30             :     PGconn     *conn;
      31             :     /* The backend PID, in numeric and string formats. */
      32             :     int         backend_pid;
      33             :     const char *backend_pid_str;
      34             :     /* Name of the associated session. */
      35             :     const char *sessionname;
      36             :     /* Active step on this connection, or NULL if idle. */
      37             :     PermutationStep *active_step;
      38             :     /* Number of NOTICE messages received from connection. */
      39             :     int         total_notices;
      40             : } IsoConnInfo;
      41             : 
      42             : static IsoConnInfo *conns = NULL;
      43             : static int  nconns = 0;
      44             : 
      45             : /* Flag indicating some new NOTICE has arrived */
      46             : static bool any_new_notice = false;
      47             : 
      48             : /* Maximum time to wait before giving up on a step (in usec) */
      49             : static int64 max_step_wait = 300 * USECS_PER_SEC;
      50             : 
      51             : 
      52             : static void check_testspec(TestSpec *testspec);
      53             : static void run_testspec(TestSpec *testspec);
      54             : static void run_all_permutations(TestSpec *testspec);
      55             : static void run_all_permutations_recurse(TestSpec *testspec, int *piles,
      56             :                                          int nsteps, PermutationStep **steps);
      57             : static void run_named_permutations(TestSpec *testspec);
      58             : static void run_permutation(TestSpec *testspec, int nsteps,
      59             :                             PermutationStep **steps);
      60             : 
      61             : /* Flag bits for try_complete_step(s) */
      62             : #define STEP_NONBLOCK   0x1     /* return as soon as cmd waits for a lock */
      63             : #define STEP_RETRY      0x2     /* this is a retry of a previously-waiting cmd */
      64             : 
      65             : static int  try_complete_steps(TestSpec *testspec, PermutationStep **waiting,
      66             :                                int nwaiting, int flags);
      67             : static bool try_complete_step(TestSpec *testspec, PermutationStep *pstep,
      68             :                               int flags);
      69             : 
      70             : static int  step_qsort_cmp(const void *a, const void *b);
      71             : static int  step_bsearch_cmp(const void *a, const void *b);
      72             : 
      73             : static bool step_has_blocker(PermutationStep *pstep);
      74             : static void printResultSet(PGresult *res);
      75             : static void isotesterNoticeProcessor(void *arg, const char *message);
      76             : static void blackholeNoticeProcessor(void *arg, const char *message);
      77             : 
      78             : static void
      79         226 : disconnect_atexit(void)
      80             : {
      81             :     int         i;
      82             : 
      83        1008 :     for (i = 0; i < nconns; i++)
      84         782 :         if (conns[i].conn)
      85         782 :             PQfinish(conns[i].conn);
      86         226 : }
      87             : 
      88             : int
      89         236 : main(int argc, char **argv)
      90             : {
      91             :     const char *conninfo;
      92             :     const char *env_wait;
      93             :     TestSpec   *testspec;
      94             :     PGresult   *res;
      95             :     PQExpBufferData wait_query;
      96             :     int         opt;
      97             :     int         i;
      98             : 
      99         236 :     while ((opt = getopt(argc, argv, "V")) != -1)
     100             :     {
     101          10 :         switch (opt)
     102             :         {
     103          10 :             case 'V':
     104          10 :                 puts("isolationtester (PostgreSQL) " PG_VERSION);
     105          10 :                 exit(0);
     106           0 :             default:
     107           0 :                 fprintf(stderr, "Usage: isolationtester [CONNINFO]\n");
     108           0 :                 return EXIT_FAILURE;
     109             :         }
     110             :     }
     111             : 
     112             :     /*
     113             :      * Make stdout unbuffered to match stderr; and ensure stderr is unbuffered
     114             :      * too, which it should already be everywhere except sometimes in Windows.
     115             :      */
     116         226 :     setbuf(stdout, NULL);
     117         226 :     setbuf(stderr, NULL);
     118             : 
     119             :     /*
     120             :      * If the user supplies a non-option parameter on the command line, use it
     121             :      * as the conninfo string; otherwise default to setting dbname=postgres
     122             :      * and using environment variables or defaults for all other connection
     123             :      * parameters.
     124             :      */
     125         226 :     if (argc > optind)
     126         226 :         conninfo = argv[optind];
     127             :     else
     128           0 :         conninfo = "dbname = postgres";
     129             : 
     130             :     /*
     131             :      * If PGISOLATIONTIMEOUT is set in the environment, adopt its value (given
     132             :      * in seconds) as the max time to wait for any one step to complete.
     133             :      */
     134         226 :     env_wait = getenv("PGISOLATIONTIMEOUT");
     135         226 :     if (env_wait != NULL)
     136           0 :         max_step_wait = ((int64) atoi(env_wait)) * USECS_PER_SEC;
     137             : 
     138             :     /* Read the test spec from stdin */
     139         226 :     spec_yyparse();
     140         226 :     testspec = &parseresult;
     141             : 
     142             :     /* Perform post-parse checking, and fill in linking fields */
     143         226 :     check_testspec(testspec);
     144             : 
     145         226 :     printf("Parsed test spec with %d sessions\n", testspec->nsessions);
     146             : 
     147             :     /*
     148             :      * Establish connections to the database, one for each session and an
     149             :      * extra for lock wait detection and global work.
     150             :      */
     151         226 :     nconns = 1 + testspec->nsessions;
     152         226 :     conns = (IsoConnInfo *) pg_malloc0(nconns * sizeof(IsoConnInfo));
     153         226 :     atexit(disconnect_atexit);
     154             : 
     155        1008 :     for (i = 0; i < nconns; i++)
     156             :     {
     157         782 :         if (i == 0)
     158         226 :             conns[i].sessionname = "control connection";
     159             :         else
     160         556 :             conns[i].sessionname = testspec->sessions[i - 1]->name;
     161             : 
     162         782 :         conns[i].conn = PQconnectdb(conninfo);
     163         782 :         if (PQstatus(conns[i].conn) != CONNECTION_OK)
     164             :         {
     165           0 :             fprintf(stderr, "Connection %d failed: %s",
     166           0 :                     i, PQerrorMessage(conns[i].conn));
     167           0 :             exit(1);
     168             :         }
     169             : 
     170             :         /*
     171             :          * Set up notice processors for the user-defined connections, so that
     172             :          * messages can get printed prefixed with the session names.  The
     173             :          * control connection gets a "blackhole" processor instead (hides all
     174             :          * messages).
     175             :          */
     176         782 :         if (i != 0)
     177         556 :             PQsetNoticeProcessor(conns[i].conn,
     178             :                                  isotesterNoticeProcessor,
     179         556 :                                  (void *) &conns[i]);
     180             :         else
     181         226 :             PQsetNoticeProcessor(conns[i].conn,
     182             :                                  blackholeNoticeProcessor,
     183             :                                  NULL);
     184             : 
     185             :         /* Save each connection's backend PID for subsequent use. */
     186         782 :         conns[i].backend_pid = PQbackendPID(conns[i].conn);
     187         782 :         conns[i].backend_pid_str = psprintf("%d", conns[i].backend_pid);
     188             :     }
     189             : 
     190             :     /*
     191             :      * Build the query we'll use to detect lock contention among sessions in
     192             :      * the test specification.  Most of the time, we could get away with
     193             :      * simply checking whether a session is waiting for *any* lock: we don't
     194             :      * exactly expect concurrent use of test tables.  However, autovacuum will
     195             :      * occasionally take AccessExclusiveLock to truncate a table, and we must
     196             :      * ignore that transient wait.
     197             :      */
     198         226 :     initPQExpBuffer(&wait_query);
     199         226 :     appendPQExpBufferStr(&wait_query,
     200             :                          "SELECT pg_catalog.pg_isolation_test_session_is_blocked($1, '{");
     201             :     /* The spec syntax requires at least one session; assume that here. */
     202         226 :     appendPQExpBufferStr(&wait_query, conns[1].backend_pid_str);
     203         556 :     for (i = 2; i < nconns; i++)
     204         330 :         appendPQExpBuffer(&wait_query, ",%s", conns[i].backend_pid_str);
     205         226 :     appendPQExpBufferStr(&wait_query, "}')");
     206             : 
     207         226 :     res = PQprepare(conns[0].conn, PREP_WAITING, wait_query.data, 0, NULL);
     208         226 :     if (PQresultStatus(res) != PGRES_COMMAND_OK)
     209             :     {
     210           0 :         fprintf(stderr, "prepare of lock wait query failed: %s",
     211           0 :                 PQerrorMessage(conns[0].conn));
     212           0 :         exit(1);
     213             :     }
     214         226 :     PQclear(res);
     215         226 :     termPQExpBuffer(&wait_query);
     216             : 
     217             :     /*
     218             :      * Run the permutations specified in the spec, or all if none were
     219             :      * explicitly specified.
     220             :      */
     221         226 :     run_testspec(testspec);
     222             : 
     223         226 :     return 0;
     224             : }
     225             : 
     226             : /*
     227             :  * Validity-check the test spec and fill in cross-links between nodes.
     228             :  */
     229             : static void
     230         226 : check_testspec(TestSpec *testspec)
     231             : {
     232             :     int         nallsteps;
     233             :     Step      **allsteps;
     234             :     int         i,
     235             :                 j,
     236             :                 k;
     237             : 
     238             :     /* Create a sorted lookup table of all steps. */
     239         226 :     nallsteps = 0;
     240         782 :     for (i = 0; i < testspec->nsessions; i++)
     241         556 :         nallsteps += testspec->sessions[i]->nsteps;
     242             : 
     243         226 :     allsteps = pg_malloc(nallsteps * sizeof(Step *));
     244             : 
     245         226 :     k = 0;
     246         782 :     for (i = 0; i < testspec->nsessions; i++)
     247             :     {
     248        2712 :         for (j = 0; j < testspec->sessions[i]->nsteps; j++)
     249        2156 :             allsteps[k++] = testspec->sessions[i]->steps[j];
     250             :     }
     251             : 
     252         226 :     qsort(allsteps, nallsteps, sizeof(Step *), step_qsort_cmp);
     253             : 
     254             :     /* Verify that all step names are unique. */
     255        2156 :     for (i = 1; i < nallsteps; i++)
     256             :     {
     257        1930 :         if (strcmp(allsteps[i - 1]->name,
     258        1930 :                    allsteps[i]->name) == 0)
     259             :         {
     260           0 :             fprintf(stderr, "duplicate step name: %s\n",
     261           0 :                     allsteps[i]->name);
     262           0 :             exit(1);
     263             :         }
     264             :     }
     265             : 
     266             :     /* Set the session index fields in steps. */
     267         782 :     for (i = 0; i < testspec->nsessions; i++)
     268             :     {
     269         556 :         Session    *session = testspec->sessions[i];
     270             : 
     271        2712 :         for (j = 0; j < session->nsteps; j++)
     272        2156 :             session->steps[j]->session = i;
     273             :     }
     274             : 
     275             :     /*
     276             :      * If we have manually-specified permutations, link PermutationSteps to
     277             :      * Steps, and fill in blocker links.
     278             :      */
     279        2104 :     for (i = 0; i < testspec->npermutations; i++)
     280             :     {
     281        1878 :         Permutation *p = testspec->permutations[i];
     282             : 
     283       16086 :         for (j = 0; j < p->nsteps; j++)
     284             :         {
     285       14208 :             PermutationStep *pstep = p->steps[j];
     286       14208 :             Step      **this = (Step **) bsearch(pstep->name,
     287             :                                                  allsteps,
     288             :                                                  nallsteps,
     289             :                                                  sizeof(Step *),
     290             :                                                  step_bsearch_cmp);
     291             : 
     292       14208 :             if (this == NULL)
     293             :             {
     294           0 :                 fprintf(stderr, "undefined step \"%s\" specified in permutation\n",
     295             :                         pstep->name);
     296           0 :                 exit(1);
     297             :             }
     298       14208 :             pstep->step = *this;
     299             : 
     300             :             /* Mark the step used, for check below */
     301       14208 :             pstep->step->used = true;
     302             :         }
     303             : 
     304             :         /*
     305             :          * Identify any blocker steps.  We search only the current
     306             :          * permutation, since steps not used there couldn't be concurrent.
     307             :          * Note that it's OK to reference later permutation steps, so this
     308             :          * can't be combined with the previous loop.
     309             :          */
     310       16086 :         for (j = 0; j < p->nsteps; j++)
     311             :         {
     312       14208 :             PermutationStep *pstep = p->steps[j];
     313             : 
     314       14296 :             for (k = 0; k < pstep->nblockers; k++)
     315             :             {
     316          88 :                 PermutationStepBlocker *blocker = pstep->blockers[k];
     317             :                 int         n;
     318             : 
     319          88 :                 if (blocker->blocktype == PSB_ONCE)
     320          22 :                     continue;   /* nothing to link to */
     321             : 
     322          66 :                 blocker->step = NULL;
     323         284 :                 for (n = 0; n < p->nsteps; n++)
     324             :                 {
     325         284 :                     PermutationStep *otherp = p->steps[n];
     326             : 
     327         284 :                     if (strcmp(otherp->name, blocker->stepname) == 0)
     328             :                     {
     329          66 :                         blocker->step = otherp->step;
     330          66 :                         break;
     331             :                     }
     332             :                 }
     333          66 :                 if (blocker->step == NULL)
     334             :                 {
     335           0 :                     fprintf(stderr, "undefined blocking step \"%s\" referenced in permutation step \"%s\"\n",
     336             :                             blocker->stepname, pstep->name);
     337           0 :                     exit(1);
     338             :                 }
     339             :                 /* can't block on completion of step of own session */
     340          66 :                 if (blocker->step->session == pstep->step->session)
     341             :                 {
     342           0 :                     fprintf(stderr, "permutation step \"%s\" cannot block on its own session\n",
     343             :                             pstep->name);
     344           0 :                     exit(1);
     345             :                 }
     346             :             }
     347             :         }
     348             :     }
     349             : 
     350             :     /*
     351             :      * If we have manually-specified permutations, verify that all steps have
     352             :      * been used, warning about anything defined but not used.  We can skip
     353             :      * this when using automatically-generated permutations.
     354             :      */
     355         226 :     if (testspec->permutations)
     356             :     {
     357        2180 :         for (i = 0; i < nallsteps; i++)
     358             :         {
     359        1986 :             if (!allsteps[i]->used)
     360          12 :                 fprintf(stderr, "unused step name: %s\n", allsteps[i]->name);
     361             :         }
     362             :     }
     363             : 
     364         226 :     free(allsteps);
     365         226 : }
     366             : 
     367             : /*
     368             :  * Run the permutations specified in the spec, or all if none were
     369             :  * explicitly specified.
     370             :  */
     371             : static void
     372         226 : run_testspec(TestSpec *testspec)
     373             : {
     374         226 :     if (testspec->permutations)
     375         194 :         run_named_permutations(testspec);
     376             :     else
     377          32 :         run_all_permutations(testspec);
     378         226 : }
     379             : 
     380             : /*
     381             :  * Run all permutations of the steps and sessions.
     382             :  */
     383             : static void
     384          32 : run_all_permutations(TestSpec *testspec)
     385             : {
     386             :     int         nsteps;
     387             :     int         i;
     388             :     PermutationStep *steps;
     389             :     PermutationStep **stepptrs;
     390             :     int        *piles;
     391             : 
     392             :     /* Count the total number of steps in all sessions */
     393          32 :     nsteps = 0;
     394         100 :     for (i = 0; i < testspec->nsessions; i++)
     395          68 :         nsteps += testspec->sessions[i]->nsteps;
     396             : 
     397             :     /* Create PermutationStep workspace array */
     398          32 :     steps = (PermutationStep *) pg_malloc0(sizeof(PermutationStep) * nsteps);
     399          32 :     stepptrs = (PermutationStep **) pg_malloc(sizeof(PermutationStep *) * nsteps);
     400         202 :     for (i = 0; i < nsteps; i++)
     401         170 :         stepptrs[i] = steps + i;
     402             : 
     403             :     /*
     404             :      * To generate the permutations, we conceptually put the steps of each
     405             :      * session on a pile. To generate a permutation, we pick steps from the
     406             :      * piles until all piles are empty. By picking steps from piles in
     407             :      * different order, we get different permutations.
     408             :      *
     409             :      * A pile is actually just an integer which tells how many steps we've
     410             :      * already picked from this pile.
     411             :      */
     412          32 :     piles = pg_malloc(sizeof(int) * testspec->nsessions);
     413         100 :     for (i = 0; i < testspec->nsessions; i++)
     414          68 :         piles[i] = 0;
     415             : 
     416          32 :     run_all_permutations_recurse(testspec, piles, 0, stepptrs);
     417             : 
     418          32 :     free(steps);
     419          32 :     free(stepptrs);
     420          32 :     free(piles);
     421          32 : }
     422             : 
     423             : static void
     424        3188 : run_all_permutations_recurse(TestSpec *testspec, int *piles,
     425             :                              int nsteps, PermutationStep **steps)
     426             : {
     427             :     int         i;
     428        3188 :     bool        found = false;
     429             : 
     430       11406 :     for (i = 0; i < testspec->nsessions; i++)
     431             :     {
     432             :         /* If there's any more steps in this pile, pick it and recurse */
     433        8218 :         if (piles[i] < testspec->sessions[i]->nsteps)
     434             :         {
     435        3156 :             Step       *newstep = testspec->sessions[i]->steps[piles[i]];
     436             : 
     437             :             /*
     438             :              * These automatically-generated PermutationSteps never have
     439             :              * blocker conditions.  So we need only fill these fields, relying
     440             :              * on run_all_permutations() to have zeroed the rest:
     441             :              */
     442        3156 :             steps[nsteps]->name = newstep->name;
     443        3156 :             steps[nsteps]->step = newstep;
     444             : 
     445        3156 :             piles[i]++;
     446             : 
     447        3156 :             run_all_permutations_recurse(testspec, piles, nsteps + 1, steps);
     448             : 
     449        3156 :             piles[i]--;
     450             : 
     451        3156 :             found = true;
     452             :         }
     453             :     }
     454             : 
     455             :     /* If all the piles were empty, this permutation is completed. Run it */
     456        3188 :     if (!found)
     457         990 :         run_permutation(testspec, nsteps, steps);
     458        3188 : }
     459             : 
     460             : /*
     461             :  * Run permutations given in the test spec
     462             :  */
     463             : static void
     464         194 : run_named_permutations(TestSpec *testspec)
     465             : {
     466             :     int         i;
     467             : 
     468        2072 :     for (i = 0; i < testspec->npermutations; i++)
     469             :     {
     470        1878 :         Permutation *p = testspec->permutations[i];
     471             : 
     472        1878 :         run_permutation(testspec, p->nsteps, p->steps);
     473             :     }
     474         194 : }
     475             : 
     476             : static int
     477        6224 : step_qsort_cmp(const void *a, const void *b)
     478             : {
     479        6224 :     Step       *stepa = *((Step **) a);
     480        6224 :     Step       *stepb = *((Step **) b);
     481             : 
     482        6224 :     return strcmp(stepa->name, stepb->name);
     483             : }
     484             : 
     485             : static int
     486       44432 : step_bsearch_cmp(const void *a, const void *b)
     487             : {
     488       44432 :     char       *stepname = (char *) a;
     489       44432 :     Step       *step = *((Step **) b);
     490             : 
     491       44432 :     return strcmp(stepname, step->name);
     492             : }
     493             : 
     494             : /*
     495             :  * Run one permutation
     496             :  */
     497             : static void
     498        2868 : run_permutation(TestSpec *testspec, int nsteps, PermutationStep **steps)
     499             : {
     500             :     PGresult   *res;
     501             :     int         i;
     502        2868 :     int         nwaiting = 0;
     503             :     PermutationStep **waiting;
     504             : 
     505        2868 :     waiting = pg_malloc(sizeof(PermutationStep *) * testspec->nsessions);
     506             : 
     507        2868 :     printf("\nstarting permutation:");
     508       23370 :     for (i = 0; i < nsteps; i++)
     509       20502 :         printf(" %s", steps[i]->name);
     510        2868 :     printf("\n");
     511             : 
     512             :     /* Perform setup */
     513        5774 :     for (i = 0; i < testspec->nsetupsqls; i++)
     514             :     {
     515        2906 :         res = PQexec(conns[0].conn, testspec->setupsqls[i]);
     516        2906 :         if (PQresultStatus(res) == PGRES_TUPLES_OK)
     517             :         {
     518           0 :             printResultSet(res);
     519             :         }
     520        2906 :         else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     521             :         {
     522           0 :             fprintf(stderr, "setup failed: %s", PQerrorMessage(conns[0].conn));
     523           0 :             exit(1);
     524             :         }
     525        2906 :         PQclear(res);
     526             :     }
     527             : 
     528             :     /* Perform per-session setup */
     529        9800 :     for (i = 0; i < testspec->nsessions; i++)
     530             :     {
     531        6932 :         if (testspec->sessions[i]->setupsql)
     532             :         {
     533        4432 :             res = PQexec(conns[i + 1].conn, testspec->sessions[i]->setupsql);
     534        4432 :             if (PQresultStatus(res) == PGRES_TUPLES_OK)
     535             :             {
     536          52 :                 printResultSet(res);
     537             :             }
     538        4380 :             else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     539             :             {
     540           0 :                 fprintf(stderr, "setup of session %s failed: %s",
     541           0 :                         conns[i + 1].sessionname,
     542           0 :                         PQerrorMessage(conns[i + 1].conn));
     543           0 :                 exit(1);
     544             :             }
     545        4432 :             PQclear(res);
     546             :         }
     547             :     }
     548             : 
     549             :     /* Perform steps */
     550       23370 :     for (i = 0; i < nsteps; i++)
     551             :     {
     552       20502 :         PermutationStep *pstep = steps[i];
     553       20502 :         Step       *step = pstep->step;
     554       20502 :         IsoConnInfo *iconn = &conns[1 + step->session];
     555       20502 :         PGconn     *conn = iconn->conn;
     556             :         bool        mustwait;
     557             :         int         j;
     558             : 
     559             :         /*
     560             :          * Check whether the session that needs to perform the next step is
     561             :          * still blocked on an earlier step.  If so, wait for it to finish.
     562             :          */
     563       20502 :         if (iconn->active_step != NULL)
     564             :         {
     565             :             struct timeval start_time;
     566             : 
     567          62 :             gettimeofday(&start_time, NULL);
     568             : 
     569         124 :             while (iconn->active_step != NULL)
     570             :             {
     571          62 :                 PermutationStep *oldstep = iconn->active_step;
     572             : 
     573             :                 /*
     574             :                  * Wait for oldstep.  But even though we don't use
     575             :                  * STEP_NONBLOCK, it might not complete because of blocker
     576             :                  * conditions.
     577             :                  */
     578          62 :                 if (!try_complete_step(testspec, oldstep, STEP_RETRY))
     579             :                 {
     580             :                     /* Done, so remove oldstep from the waiting[] array. */
     581             :                     int         w;
     582             : 
     583          88 :                     for (w = 0; w < nwaiting; w++)
     584             :                     {
     585          88 :                         if (oldstep == waiting[w])
     586          62 :                             break;
     587             :                     }
     588          62 :                     if (w >= nwaiting)
     589           0 :                         abort();    /* can't happen */
     590          62 :                     if (w + 1 < nwaiting)
     591           0 :                         memmove(&waiting[w], &waiting[w + 1],
     592           0 :                                 (nwaiting - (w + 1)) * sizeof(PermutationStep *));
     593          62 :                     nwaiting--;
     594             :                 }
     595             : 
     596             :                 /*
     597             :                  * Check for other steps that have finished.  We should do
     598             :                  * this if oldstep completed, as it might have unblocked
     599             :                  * something.  On the other hand, if oldstep hasn't completed,
     600             :                  * we must poll all the active steps in hopes of unblocking
     601             :                  * oldstep.  So either way, poll them.
     602             :                  */
     603          62 :                 nwaiting = try_complete_steps(testspec, waiting, nwaiting,
     604             :                                               STEP_NONBLOCK | STEP_RETRY);
     605             : 
     606             :                 /*
     607             :                  * If the target session is still busy, apply a timeout to
     608             :                  * keep from hanging indefinitely, which could happen with
     609             :                  * incorrect blocker annotations.  Use the same 2 *
     610             :                  * max_step_wait limit as try_complete_step does for deciding
     611             :                  * to die.  (We don't bother with trying to cancel anything,
     612             :                  * since it's unclear what to cancel in this case.)
     613             :                  */
     614          62 :                 if (iconn->active_step != NULL)
     615             :                 {
     616             :                     struct timeval current_time;
     617             :                     int64       td;
     618             : 
     619           0 :                     gettimeofday(&current_time, NULL);
     620           0 :                     td = (int64) current_time.tv_sec - (int64) start_time.tv_sec;
     621           0 :                     td *= USECS_PER_SEC;
     622           0 :                     td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
     623           0 :                     if (td > 2 * max_step_wait)
     624             :                     {
     625           0 :                         fprintf(stderr, "step %s timed out after %d seconds\n",
     626           0 :                                 iconn->active_step->name,
     627           0 :                                 (int) (td / USECS_PER_SEC));
     628           0 :                         fprintf(stderr, "active steps are:");
     629           0 :                         for (j = 1; j < nconns; j++)
     630             :                         {
     631           0 :                             IsoConnInfo *oconn = &conns[j];
     632             : 
     633           0 :                             if (oconn->active_step != NULL)
     634           0 :                                 fprintf(stderr, " %s",
     635           0 :                                         oconn->active_step->name);
     636             :                         }
     637           0 :                         fprintf(stderr, "\n");
     638           0 :                         exit(1);
     639             :                     }
     640             :                 }
     641             :             }
     642             :         }
     643             : 
     644             :         /* Send the query for this step. */
     645       20502 :         if (!PQsendQuery(conn, step->sql))
     646             :         {
     647           0 :             fprintf(stdout, "failed to send query for step %s: %s\n",
     648             :                     step->name, PQerrorMessage(conn));
     649           0 :             exit(1);
     650             :         }
     651             : 
     652             :         /* Remember we launched a step. */
     653       20502 :         iconn->active_step = pstep;
     654             : 
     655             :         /* Remember target number of NOTICEs for any blocker conditions. */
     656       20590 :         for (j = 0; j < pstep->nblockers; j++)
     657             :         {
     658          88 :             PermutationStepBlocker *blocker = pstep->blockers[j];
     659             : 
     660          88 :             if (blocker->blocktype == PSB_NUM_NOTICES)
     661           2 :                 blocker->target_notices = blocker->num_notices +
     662           2 :                     conns[blocker->step->session + 1].total_notices;
     663             :         }
     664             : 
     665             :         /* Try to complete this step without blocking.  */
     666       20502 :         mustwait = try_complete_step(testspec, pstep, STEP_NONBLOCK);
     667             : 
     668             :         /* Check for completion of any steps that were previously waiting. */
     669       20502 :         nwaiting = try_complete_steps(testspec, waiting, nwaiting,
     670             :                                       STEP_NONBLOCK | STEP_RETRY);
     671             : 
     672             :         /* If this step is waiting, add it to the array of waiters. */
     673       20502 :         if (mustwait)
     674        1108 :             waiting[nwaiting++] = pstep;
     675             :     }
     676             : 
     677             :     /* Wait for any remaining queries. */
     678        2868 :     nwaiting = try_complete_steps(testspec, waiting, nwaiting, STEP_RETRY);
     679        2868 :     if (nwaiting != 0)
     680             :     {
     681           0 :         fprintf(stderr, "failed to complete permutation due to mutually-blocking steps\n");
     682           0 :         exit(1);
     683             :     }
     684             : 
     685             :     /* Perform per-session teardown */
     686        9800 :     for (i = 0; i < testspec->nsessions; i++)
     687             :     {
     688        6932 :         if (testspec->sessions[i]->teardownsql)
     689             :         {
     690         418 :             res = PQexec(conns[i + 1].conn, testspec->sessions[i]->teardownsql);
     691         418 :             if (PQresultStatus(res) == PGRES_TUPLES_OK)
     692             :             {
     693         170 :                 printResultSet(res);
     694             :             }
     695         248 :             else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     696             :             {
     697           0 :                 fprintf(stderr, "teardown of session %s failed: %s",
     698           0 :                         conns[i + 1].sessionname,
     699           0 :                         PQerrorMessage(conns[i + 1].conn));
     700             :                 /* don't exit on teardown failure */
     701             :             }
     702         418 :             PQclear(res);
     703             :         }
     704             :     }
     705             : 
     706             :     /* Perform teardown */
     707        2868 :     if (testspec->teardownsql)
     708             :     {
     709        2770 :         res = PQexec(conns[0].conn, testspec->teardownsql);
     710        2770 :         if (PQresultStatus(res) == PGRES_TUPLES_OK)
     711             :         {
     712          72 :             printResultSet(res);
     713             :         }
     714        2698 :         else if (PQresultStatus(res) != PGRES_COMMAND_OK)
     715             :         {
     716           0 :             fprintf(stderr, "teardown failed: %s",
     717           0 :                     PQerrorMessage(conns[0].conn));
     718             :             /* don't exit on teardown failure */
     719             :         }
     720        2770 :         PQclear(res);
     721             :     }
     722             : 
     723        2868 :     free(waiting);
     724        2868 : }
     725             : 
     726             : /*
     727             :  * Check for completion of any waiting step(s).
     728             :  * Remove completed ones from the waiting[] array,
     729             :  * and return the new value of nwaiting.
     730             :  * See try_complete_step for the meaning of the flags.
     731             :  */
     732             : static int
     733       23440 : try_complete_steps(TestSpec *testspec, PermutationStep **waiting,
     734             :                    int nwaiting, int flags)
     735             : {
     736             :     int         old_nwaiting;
     737             :     bool        have_blocker;
     738             : 
     739             :     do
     740             :     {
     741       23440 :         int         w = 0;
     742             : 
     743             :         /* Reset latch; we only care about notices received within loop. */
     744       23440 :         any_new_notice = false;
     745             : 
     746             :         /* Likewise, these variables reset for each retry. */
     747       23440 :         old_nwaiting = nwaiting;
     748       23440 :         have_blocker = false;
     749             : 
     750             :         /* Scan the array, try to complete steps. */
     751       25438 :         while (w < nwaiting)
     752             :         {
     753        1998 :             if (try_complete_step(testspec, waiting[w], flags))
     754             :             {
     755             :                 /* Still blocked, leave it alone. */
     756         952 :                 if (waiting[w]->nblockers > 0)
     757          32 :                     have_blocker = true;
     758         952 :                 w++;
     759             :             }
     760             :             else
     761             :             {
     762             :                 /* Done, remove it from array. */
     763        1046 :                 if (w + 1 < nwaiting)
     764          42 :                     memmove(&waiting[w], &waiting[w + 1],
     765          42 :                             (nwaiting - (w + 1)) * sizeof(PermutationStep *));
     766        1046 :                 nwaiting--;
     767             :             }
     768             :         }
     769             : 
     770             :         /*
     771             :          * If any of the still-waiting steps have blocker conditions attached,
     772             :          * it's possible that one of the steps we examined afterwards has
     773             :          * released them (either by completing, or by sending a NOTICE).  If
     774             :          * any step completions or NOTICEs happened, repeat the loop until
     775             :          * none occurs.  Without this provision, completion timing could vary
     776             :          * depending on the order in which the steps appear in the array.
     777             :          */
     778       23440 :     } while (have_blocker && (nwaiting < old_nwaiting || any_new_notice));
     779       23432 :     return nwaiting;
     780             : }
     781             : 
     782             : /*
     783             :  * Our caller already sent the query associated with this step.  Wait for it
     784             :  * to either complete, or hit a blocking condition.
     785             :  *
     786             :  * When calling this function on behalf of a given step for a second or later
     787             :  * time, pass the STEP_RETRY flag.  Do not pass it on the first call.
     788             :  *
     789             :  * Returns true if the step was *not* completed, false if it was completed.
     790             :  * Reasons for non-completion are (a) the STEP_NONBLOCK flag was specified
     791             :  * and the query is waiting to acquire a lock, or (b) the step has an
     792             :  * unsatisfied blocker condition.  When STEP_NONBLOCK is given, we assume
     793             :  * that any lock wait will persist until we have executed additional steps.
     794             :  */
     795             : static bool
     796       22562 : try_complete_step(TestSpec *testspec, PermutationStep *pstep, int flags)
     797             : {
     798       22562 :     Step       *step = pstep->step;
     799       22562 :     IsoConnInfo *iconn = &conns[1 + step->session];
     800       22562 :     PGconn     *conn = iconn->conn;
     801             :     fd_set      read_set;
     802             :     struct timeval start_time;
     803             :     struct timeval timeout;
     804       22562 :     int         sock = PQsocket(conn);
     805             :     int         ret;
     806             :     PGresult   *res;
     807             :     PGnotify   *notify;
     808       22562 :     bool        canceled = false;
     809             : 
     810             :     /*
     811             :      * If the step is annotated with (*), then on the first call, force it to
     812             :      * wait.  This is useful for ensuring consistent output when the step
     813             :      * might or might not complete so fast that we don't observe it waiting.
     814             :      */
     815       22562 :     if (!(flags & STEP_RETRY))
     816             :     {
     817             :         int         i;
     818             : 
     819       20568 :         for (i = 0; i < pstep->nblockers; i++)
     820             :         {
     821          88 :             PermutationStepBlocker *blocker = pstep->blockers[i];
     822             : 
     823          88 :             if (blocker->blocktype == PSB_ONCE)
     824             :             {
     825          22 :                 printf("step %s: %s <waiting ...>\n",
     826             :                        step->name, step->sql);
     827          22 :                 return true;
     828             :             }
     829             :         }
     830             :     }
     831             : 
     832       22540 :     if (sock < 0)
     833             :     {
     834           0 :         fprintf(stderr, "invalid socket: %s", PQerrorMessage(conn));
     835           0 :         exit(1);
     836             :     }
     837             : 
     838       22540 :     gettimeofday(&start_time, NULL);
     839       22540 :     FD_ZERO(&read_set);
     840             : 
     841       55974 :     while (PQisBusy(conn))
     842             :     {
     843       35412 :         FD_SET(sock, &read_set);
     844       35412 :         timeout.tv_sec = 0;
     845       35412 :         timeout.tv_usec = 10000;    /* Check for lock waits every 10ms. */
     846             : 
     847       35412 :         ret = select(sock + 1, &read_set, NULL, NULL, &timeout);
     848       35412 :         if (ret < 0)         /* error in select() */
     849             :         {
     850           0 :             if (errno == EINTR)
     851           0 :                 continue;
     852           0 :             fprintf(stderr, "select failed: %s\n", strerror(errno));
     853           0 :             exit(1);
     854             :         }
     855       35412 :         else if (ret == 0)      /* select() timeout: check for lock wait */
     856             :         {
     857             :             struct timeval current_time;
     858             :             int64       td;
     859             : 
     860             :             /* If it's OK for the step to block, check whether it has. */
     861       14270 :             if (flags & STEP_NONBLOCK)
     862             :             {
     863             :                 bool        waiting;
     864             : 
     865       14262 :                 res = PQexecPrepared(conns[0].conn, PREP_WAITING, 1,
     866       14262 :                                      &conns[step->session + 1].backend_pid_str,
     867             :                                      NULL, NULL, 0);
     868       28524 :                 if (PQresultStatus(res) != PGRES_TUPLES_OK ||
     869       14262 :                     PQntuples(res) != 1)
     870             :                 {
     871           0 :                     fprintf(stderr, "lock wait query failed: %s",
     872           0 :                             PQerrorMessage(conns[0].conn));
     873           0 :                     exit(1);
     874             :                 }
     875       14262 :                 waiting = ((PQgetvalue(res, 0, 0))[0] == 't');
     876       14262 :                 PQclear(res);
     877             : 
     878       14262 :                 if (waiting)    /* waiting to acquire a lock */
     879             :                 {
     880             :                     /*
     881             :                      * Since it takes time to perform the lock-check query,
     882             :                      * some data --- notably, NOTICE messages --- might have
     883             :                      * arrived since we looked.  We must call PQconsumeInput
     884             :                      * and then PQisBusy to collect and process any such
     885             :                      * messages.  In the (unlikely) case that PQisBusy then
     886             :                      * returns false, we might as well go examine the
     887             :                      * available result.
     888             :                      */
     889        1978 :                     if (!PQconsumeInput(conn))
     890             :                     {
     891           0 :                         fprintf(stderr, "PQconsumeInput failed: %s\n",
     892             :                                 PQerrorMessage(conn));
     893           0 :                         exit(1);
     894             :                     }
     895        1978 :                     if (!PQisBusy(conn))
     896           0 :                         break;
     897             : 
     898             :                     /*
     899             :                      * conn is still busy, so conclude that the step really is
     900             :                      * waiting.
     901             :                      */
     902        1978 :                     if (!(flags & STEP_RETRY))
     903        1028 :                         printf("step %s: %s <waiting ...>\n",
     904             :                                step->name, step->sql);
     905        1978 :                     return true;
     906             :                 }
     907             :                 /* else, not waiting */
     908             :             }
     909             : 
     910             :             /* Figure out how long we've been waiting for this step. */
     911       12292 :             gettimeofday(&current_time, NULL);
     912       12292 :             td = (int64) current_time.tv_sec - (int64) start_time.tv_sec;
     913       12292 :             td *= USECS_PER_SEC;
     914       12292 :             td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
     915             : 
     916             :             /*
     917             :              * After max_step_wait microseconds, try to cancel the query.
     918             :              *
     919             :              * If the user tries to test an invalid permutation, we don't want
     920             :              * to hang forever, especially when this is running in the
     921             :              * buildfarm.  This will presumably lead to this permutation
     922             :              * failing, but remaining permutations and tests should still be
     923             :              * OK.
     924             :              */
     925       12292 :             if (td > max_step_wait && !canceled)
     926             :             {
     927           0 :                 PGcancel   *cancel = PQgetCancel(conn);
     928             : 
     929           0 :                 if (cancel != NULL)
     930             :                 {
     931             :                     char        buf[256];
     932             : 
     933           0 :                     if (PQcancel(cancel, buf, sizeof(buf)))
     934             :                     {
     935             :                         /*
     936             :                          * print to stdout not stderr, as this should appear
     937             :                          * in the test case's results
     938             :                          */
     939           0 :                         printf("isolationtester: canceling step %s after %d seconds\n",
     940             :                                step->name, (int) (td / USECS_PER_SEC));
     941           0 :                         canceled = true;
     942             :                     }
     943             :                     else
     944           0 :                         fprintf(stderr, "PQcancel failed: %s\n", buf);
     945           0 :                     PQfreeCancel(cancel);
     946             :                 }
     947             :             }
     948             : 
     949             :             /*
     950             :              * After twice max_step_wait, just give up and die.
     951             :              *
     952             :              * Since cleanup steps won't be run in this case, this may cause
     953             :              * later tests to fail.  That stinks, but it's better than waiting
     954             :              * forever for the server to respond to the cancel.
     955             :              */
     956       12292 :             if (td > 2 * max_step_wait)
     957             :             {
     958           0 :                 fprintf(stderr, "step %s timed out after %d seconds\n",
     959           0 :                         step->name, (int) (td / USECS_PER_SEC));
     960           0 :                 exit(1);
     961             :             }
     962             :         }
     963       21142 :         else if (!PQconsumeInput(conn)) /* select(): data available */
     964             :         {
     965           0 :             fprintf(stderr, "PQconsumeInput failed: %s\n",
     966             :                     PQerrorMessage(conn));
     967           0 :             exit(1);
     968             :         }
     969             :     }
     970             : 
     971             :     /*
     972             :      * The step is done, but we won't report it as complete so long as there
     973             :      * are blockers.
     974             :      */
     975       20562 :     if (step_has_blocker(pstep))
     976             :     {
     977          60 :         if (!(flags & STEP_RETRY))
     978          58 :             printf("step %s: %s <waiting ...>\n",
     979             :                    step->name, step->sql);
     980          60 :         return true;
     981             :     }
     982             : 
     983             :     /* Otherwise, go ahead and complete it. */
     984       20502 :     if (flags & STEP_RETRY)
     985        1108 :         printf("step %s: <... completed>\n", step->name);
     986             :     else
     987       19394 :         printf("step %s: %s\n", step->name, step->sql);
     988             : 
     989       41446 :     while ((res = PQgetResult(conn)))
     990             :     {
     991       20944 :         switch (PQresultStatus(res))
     992             :         {
     993       14346 :             case PGRES_COMMAND_OK:
     994             :             case PGRES_EMPTY_QUERY:
     995       14346 :                 break;
     996        5724 :             case PGRES_TUPLES_OK:
     997        5724 :                 printResultSet(res);
     998        5724 :                 break;
     999         874 :             case PGRES_FATAL_ERROR:
    1000             : 
    1001             :                 /*
    1002             :                  * Detail may contain XID values, so we want to just show
    1003             :                  * primary.  Beware however that libpq-generated error results
    1004             :                  * may not contain subfields, only an old-style message.
    1005             :                  */
    1006             :                 {
    1007         874 :                     const char *sev = PQresultErrorField(res,
    1008             :                                                          PG_DIAG_SEVERITY);
    1009         874 :                     const char *msg = PQresultErrorField(res,
    1010             :                                                          PG_DIAG_MESSAGE_PRIMARY);
    1011             : 
    1012         874 :                     if (sev && msg)
    1013         874 :                         printf("%s:  %s\n", sev, msg);
    1014             :                     else
    1015           0 :                         printf("%s\n", PQresultErrorMessage(res));
    1016             :                 }
    1017         874 :                 break;
    1018           0 :             default:
    1019           0 :                 printf("unexpected result status: %s\n",
    1020             :                        PQresStatus(PQresultStatus(res)));
    1021             :         }
    1022       20944 :         PQclear(res);
    1023             :     }
    1024             : 
    1025             :     /* Report any available NOTIFY messages, too */
    1026       20502 :     PQconsumeInput(conn);
    1027       20546 :     while ((notify = PQnotifies(conn)) != NULL)
    1028             :     {
    1029             :         /* Try to identify which session it came from */
    1030          44 :         const char *sendername = NULL;
    1031             :         char        pidstring[32];
    1032             :         int         i;
    1033             : 
    1034          44 :         for (i = 0; i < testspec->nsessions; i++)
    1035             :         {
    1036          44 :             if (notify->be_pid == conns[i + 1].backend_pid)
    1037             :             {
    1038          44 :                 sendername = conns[i + 1].sessionname;
    1039          44 :                 break;
    1040             :             }
    1041             :         }
    1042          44 :         if (sendername == NULL)
    1043             :         {
    1044             :             /* Doesn't seem to be any test session, so show the hard way */
    1045           0 :             snprintf(pidstring, sizeof(pidstring), "PID %d", notify->be_pid);
    1046           0 :             sendername = pidstring;
    1047             :         }
    1048          44 :         printf("%s: NOTIFY \"%s\" with payload \"%s\" from %s\n",
    1049             :                testspec->sessions[step->session]->name,
    1050             :                notify->relname, notify->extra, sendername);
    1051          44 :         PQfreemem(notify);
    1052          44 :         PQconsumeInput(conn);
    1053             :     }
    1054             : 
    1055             :     /* Connection is now idle. */
    1056       20502 :     iconn->active_step = NULL;
    1057             : 
    1058       20502 :     return false;
    1059             : }
    1060             : 
    1061             : /* Detect whether a step has any unsatisfied blocker conditions */
    1062             : static bool
    1063       20562 : step_has_blocker(PermutationStep *pstep)
    1064             : {
    1065             :     int         i;
    1066             : 
    1067       20650 :     for (i = 0; i < pstep->nblockers; i++)
    1068             :     {
    1069         148 :         PermutationStepBlocker *blocker = pstep->blockers[i];
    1070             :         IsoConnInfo *iconn;
    1071             : 
    1072         148 :         switch (blocker->blocktype)
    1073             :         {
    1074          22 :             case PSB_ONCE:
    1075             :                 /* Ignore; try_complete_step handles this specially */
    1076          22 :                 break;
    1077         124 :             case PSB_OTHER_STEP:
    1078             :                 /* Block if referenced step is active */
    1079         124 :                 iconn = &conns[1 + blocker->step->session];
    1080         124 :                 if (iconn->active_step &&
    1081          60 :                     iconn->active_step->step == blocker->step)
    1082          60 :                     return true;
    1083          64 :                 break;
    1084           2 :             case PSB_NUM_NOTICES:
    1085             :                 /* Block if not enough notices received yet */
    1086           2 :                 iconn = &conns[1 + blocker->step->session];
    1087           2 :                 if (iconn->total_notices < blocker->target_notices)
    1088           0 :                     return true;
    1089           2 :                 break;
    1090             :         }
    1091          88 :     }
    1092       20502 :     return false;
    1093             : }
    1094             : 
    1095             : static void
    1096        6018 : printResultSet(PGresult *res)
    1097             : {
    1098             :     PQprintOpt  popt;
    1099             : 
    1100        6018 :     memset(&popt, 0, sizeof(popt));
    1101        6018 :     popt.header = true;
    1102        6018 :     popt.align = true;
    1103        6018 :     popt.fieldSep = "|";
    1104        6018 :     PQprint(stdout, res, &popt);
    1105        6018 : }
    1106             : 
    1107             : /* notice processor for regular user sessions */
    1108             : static void
    1109        1040 : isotesterNoticeProcessor(void *arg, const char *message)
    1110             : {
    1111        1040 :     IsoConnInfo *myconn = (IsoConnInfo *) arg;
    1112             : 
    1113             :     /* Prefix the backend's message with the session name. */
    1114        1040 :     printf("%s: %s", myconn->sessionname, message);
    1115             :     /* Record notices, since we may need this to decide to unblock a step. */
    1116        1040 :     myconn->total_notices++;
    1117        1040 :     any_new_notice = true;
    1118        1040 : }
    1119             : 
    1120             : /* notice processor, hides the message */
    1121             : static void
    1122         734 : blackholeNoticeProcessor(void *arg, const char *message)
    1123             : {
    1124             :     /* do nothing */
    1125         734 : }

Generated by: LCOV version 1.14