PostgreSQL Source Code  git master
isolationtester.c
Go to the documentation of this file.
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. */
31  /* The backend PID, in numeric and string formats. */
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. */
38  /* Number of NOTICE messages received from connection. */
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
80 {
81  int i;
82 
83  for (i = 0; i < nconns; i++)
84  if (conns[i].conn)
85  PQfinish(conns[i].conn);
86 }
87 
88 int
89 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  while ((opt = getopt(argc, argv, "V")) != -1)
100  {
101  switch (opt)
102  {
103  case 'V':
104  puts("isolationtester (PostgreSQL) " PG_VERSION);
105  exit(0);
106  default:
107  fprintf(stderr, "Usage: isolationtester [CONNINFO]\n");
108  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  setbuf(stdout, NULL);
117  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  if (argc > optind)
126  conninfo = argv[optind];
127  else
128  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  env_wait = getenv("PGISOLATIONTIMEOUT");
135  if (env_wait != NULL)
136  max_step_wait = ((int64) atoi(env_wait)) * USECS_PER_SEC;
137 
138  /* Read the test spec from stdin */
139  spec_yyparse();
140  testspec = &parseresult;
141 
142  /* Perform post-parse checking, and fill in linking fields */
143  check_testspec(testspec);
144 
145  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  nconns = 1 + testspec->nsessions;
152  conns = (IsoConnInfo *) pg_malloc0(nconns * sizeof(IsoConnInfo));
153  atexit(disconnect_atexit);
154 
155  for (i = 0; i < nconns; i++)
156  {
157  if (i == 0)
158  conns[i].sessionname = "control connection";
159  else
160  conns[i].sessionname = testspec->sessions[i - 1]->name;
161 
162  conns[i].conn = PQconnectdb(conninfo);
163  if (PQstatus(conns[i].conn) != CONNECTION_OK)
164  {
165  fprintf(stderr, "Connection %d failed: %s",
166  i, PQerrorMessage(conns[i].conn));
167  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  if (i != 0)
177  PQsetNoticeProcessor(conns[i].conn,
179  (void *) &conns[i]);
180  else
181  PQsetNoticeProcessor(conns[i].conn,
183  NULL);
184 
185  /* Save each connection's backend PID for subsequent use. */
186  conns[i].backend_pid = PQbackendPID(conns[i].conn);
187  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  initPQExpBuffer(&wait_query);
199  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  appendPQExpBufferStr(&wait_query, conns[1].backend_pid_str);
203  for (i = 2; i < nconns; i++)
204  appendPQExpBuffer(&wait_query, ",%s", conns[i].backend_pid_str);
205  appendPQExpBufferStr(&wait_query, "}')");
206 
207  res = PQprepare(conns[0].conn, PREP_WAITING, wait_query.data, 0, NULL);
208  if (PQresultStatus(res) != PGRES_COMMAND_OK)
209  {
210  fprintf(stderr, "prepare of lock wait query failed: %s",
211  PQerrorMessage(conns[0].conn));
212  exit(1);
213  }
214  PQclear(res);
215  termPQExpBuffer(&wait_query);
216 
217  /*
218  * Run the permutations specified in the spec, or all if none were
219  * explicitly specified.
220  */
221  run_testspec(testspec);
222 
223  return 0;
224 }
225 
226 /*
227  * Validity-check the test spec and fill in cross-links between nodes.
228  */
229 static void
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  nallsteps = 0;
240  for (i = 0; i < testspec->nsessions; i++)
241  nallsteps += testspec->sessions[i]->nsteps;
242 
243  allsteps = pg_malloc(nallsteps * sizeof(Step *));
244 
245  k = 0;
246  for (i = 0; i < testspec->nsessions; i++)
247  {
248  for (j = 0; j < testspec->sessions[i]->nsteps; j++)
249  allsteps[k++] = testspec->sessions[i]->steps[j];
250  }
251 
252  qsort(allsteps, nallsteps, sizeof(Step *), step_qsort_cmp);
253 
254  /* Verify that all step names are unique. */
255  for (i = 1; i < nallsteps; i++)
256  {
257  if (strcmp(allsteps[i - 1]->name,
258  allsteps[i]->name) == 0)
259  {
260  fprintf(stderr, "duplicate step name: %s\n",
261  allsteps[i]->name);
262  exit(1);
263  }
264  }
265 
266  /* Set the session index fields in steps. */
267  for (i = 0; i < testspec->nsessions; i++)
268  {
269  Session *session = testspec->sessions[i];
270 
271  for (j = 0; j < session->nsteps; j++)
272  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  for (i = 0; i < testspec->npermutations; i++)
280  {
281  Permutation *p = testspec->permutations[i];
282 
283  for (j = 0; j < p->nsteps; j++)
284  {
285  PermutationStep *pstep = p->steps[j];
286  Step **this = (Step **) bsearch(pstep->name,
287  allsteps,
288  nallsteps,
289  sizeof(Step *),
291 
292  if (this == NULL)
293  {
294  fprintf(stderr, "undefined step \"%s\" specified in permutation\n",
295  pstep->name);
296  exit(1);
297  }
298  pstep->step = *this;
299 
300  /* Mark the step used, for check below */
301  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  for (j = 0; j < p->nsteps; j++)
311  {
312  PermutationStep *pstep = p->steps[j];
313 
314  for (k = 0; k < pstep->nblockers; k++)
315  {
316  PermutationStepBlocker *blocker = pstep->blockers[k];
317  int n;
318 
319  if (blocker->blocktype == PSB_ONCE)
320  continue; /* nothing to link to */
321 
322  blocker->step = NULL;
323  for (n = 0; n < p->nsteps; n++)
324  {
325  PermutationStep *otherp = p->steps[n];
326 
327  if (strcmp(otherp->name, blocker->stepname) == 0)
328  {
329  blocker->step = otherp->step;
330  break;
331  }
332  }
333  if (blocker->step == NULL)
334  {
335  fprintf(stderr, "undefined blocking step \"%s\" referenced in permutation step \"%s\"\n",
336  blocker->stepname, pstep->name);
337  exit(1);
338  }
339  /* can't block on completion of step of own session */
340  if (blocker->step->session == pstep->step->session)
341  {
342  fprintf(stderr, "permutation step \"%s\" cannot block on its own session\n",
343  pstep->name);
344  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  if (testspec->permutations)
356  {
357  for (i = 0; i < nallsteps; i++)
358  {
359  if (!allsteps[i]->used)
360  fprintf(stderr, "unused step name: %s\n", allsteps[i]->name);
361  }
362  }
363 
364  free(allsteps);
365 }
366 
367 /*
368  * Run the permutations specified in the spec, or all if none were
369  * explicitly specified.
370  */
371 static void
373 {
374  if (testspec->permutations)
375  run_named_permutations(testspec);
376  else
377  run_all_permutations(testspec);
378 }
379 
380 /*
381  * Run all permutations of the steps and sessions.
382  */
383 static void
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  nsteps = 0;
394  for (i = 0; i < testspec->nsessions; i++)
395  nsteps += testspec->sessions[i]->nsteps;
396 
397  /* Create PermutationStep workspace array */
398  steps = (PermutationStep *) pg_malloc0(sizeof(PermutationStep) * nsteps);
399  stepptrs = (PermutationStep **) pg_malloc(sizeof(PermutationStep *) * nsteps);
400  for (i = 0; i < nsteps; i++)
401  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  piles = pg_malloc(sizeof(int) * testspec->nsessions);
413  for (i = 0; i < testspec->nsessions; i++)
414  piles[i] = 0;
415 
416  run_all_permutations_recurse(testspec, piles, 0, stepptrs);
417 
418  free(steps);
419  free(stepptrs);
420  free(piles);
421 }
422 
423 static void
425  int nsteps, PermutationStep **steps)
426 {
427  int i;
428  bool found = false;
429 
430  for (i = 0; i < testspec->nsessions; i++)
431  {
432  /* If there's any more steps in this pile, pick it and recurse */
433  if (piles[i] < testspec->sessions[i]->nsteps)
434  {
435  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  steps[nsteps]->name = newstep->name;
443  steps[nsteps]->step = newstep;
444 
445  piles[i]++;
446 
447  run_all_permutations_recurse(testspec, piles, nsteps + 1, steps);
448 
449  piles[i]--;
450 
451  found = true;
452  }
453  }
454 
455  /* If all the piles were empty, this permutation is completed. Run it */
456  if (!found)
457  run_permutation(testspec, nsteps, steps);
458 }
459 
460 /*
461  * Run permutations given in the test spec
462  */
463 static void
465 {
466  int i;
467 
468  for (i = 0; i < testspec->npermutations; i++)
469  {
470  Permutation *p = testspec->permutations[i];
471 
472  run_permutation(testspec, p->nsteps, p->steps);
473  }
474 }
475 
476 static int
477 step_qsort_cmp(const void *a, const void *b)
478 {
479  Step *stepa = *((Step **) a);
480  Step *stepb = *((Step **) b);
481 
482  return strcmp(stepa->name, stepb->name);
483 }
484 
485 static int
486 step_bsearch_cmp(const void *a, const void *b)
487 {
488  char *stepname = (char *) a;
489  Step *step = *((Step **) b);
490 
491  return strcmp(stepname, step->name);
492 }
493 
494 /*
495  * Run one permutation
496  */
497 static void
498 run_permutation(TestSpec *testspec, int nsteps, PermutationStep **steps)
499 {
500  PGresult *res;
501  int i;
502  int nwaiting = 0;
504 
505  waiting = pg_malloc(sizeof(PermutationStep *) * testspec->nsessions);
506 
507  printf("\nstarting permutation:");
508  for (i = 0; i < nsteps; i++)
509  printf(" %s", steps[i]->name);
510  printf("\n");
511 
512  /* Perform setup */
513  for (i = 0; i < testspec->nsetupsqls; i++)
514  {
515  res = PQexec(conns[0].conn, testspec->setupsqls[i]);
516  if (PQresultStatus(res) == PGRES_TUPLES_OK)
517  {
518  printResultSet(res);
519  }
520  else if (PQresultStatus(res) != PGRES_COMMAND_OK)
521  {
522  fprintf(stderr, "setup failed: %s", PQerrorMessage(conns[0].conn));
523  exit(1);
524  }
525  PQclear(res);
526  }
527 
528  /* Perform per-session setup */
529  for (i = 0; i < testspec->nsessions; i++)
530  {
531  if (testspec->sessions[i]->setupsql)
532  {
533  res = PQexec(conns[i + 1].conn, testspec->sessions[i]->setupsql);
534  if (PQresultStatus(res) == PGRES_TUPLES_OK)
535  {
536  printResultSet(res);
537  }
538  else if (PQresultStatus(res) != PGRES_COMMAND_OK)
539  {
540  fprintf(stderr, "setup of session %s failed: %s",
541  conns[i + 1].sessionname,
542  PQerrorMessage(conns[i + 1].conn));
543  exit(1);
544  }
545  PQclear(res);
546  }
547  }
548 
549  /* Perform steps */
550  for (i = 0; i < nsteps; i++)
551  {
552  PermutationStep *pstep = steps[i];
553  Step *step = pstep->step;
554  IsoConnInfo *iconn = &conns[1 + step->session];
555  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  if (iconn->active_step != NULL)
564  {
565  struct timeval start_time;
566 
567  gettimeofday(&start_time, NULL);
568 
569  while (iconn->active_step != NULL)
570  {
571  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  if (!try_complete_step(testspec, oldstep, STEP_RETRY))
579  {
580  /* Done, so remove oldstep from the waiting[] array. */
581  int w;
582 
583  for (w = 0; w < nwaiting; w++)
584  {
585  if (oldstep == waiting[w])
586  break;
587  }
588  if (w >= nwaiting)
589  abort(); /* can't happen */
590  if (w + 1 < nwaiting)
591  memmove(&waiting[w], &waiting[w + 1],
592  (nwaiting - (w + 1)) * sizeof(PermutationStep *));
593  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  nwaiting = try_complete_steps(testspec, waiting, nwaiting,
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  if (iconn->active_step != NULL)
615  {
616  struct timeval current_time;
617  int64 td;
618 
619  gettimeofday(&current_time, NULL);
620  td = (int64) current_time.tv_sec - (int64) start_time.tv_sec;
621  td *= USECS_PER_SEC;
622  td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
623  if (td > 2 * max_step_wait)
624  {
625  fprintf(stderr, "step %s timed out after %d seconds\n",
626  iconn->active_step->name,
627  (int) (td / USECS_PER_SEC));
628  fprintf(stderr, "active steps are:");
629  for (j = 1; j < nconns; j++)
630  {
631  IsoConnInfo *oconn = &conns[j];
632 
633  if (oconn->active_step != NULL)
634  fprintf(stderr, " %s",
635  oconn->active_step->name);
636  }
637  fprintf(stderr, "\n");
638  exit(1);
639  }
640  }
641  }
642  }
643 
644  /* Send the query for this step. */
645  if (!PQsendQuery(conn, step->sql))
646  {
647  fprintf(stdout, "failed to send query for step %s: %s\n",
648  step->name, PQerrorMessage(conn));
649  exit(1);
650  }
651 
652  /* Remember we launched a step. */
653  iconn->active_step = pstep;
654 
655  /* Remember target number of NOTICEs for any blocker conditions. */
656  for (j = 0; j < pstep->nblockers; j++)
657  {
658  PermutationStepBlocker *blocker = pstep->blockers[j];
659 
660  if (blocker->blocktype == PSB_NUM_NOTICES)
661  blocker->target_notices = blocker->num_notices +
662  conns[blocker->step->session + 1].total_notices;
663  }
664 
665  /* Try to complete this step without blocking. */
666  mustwait = try_complete_step(testspec, pstep, STEP_NONBLOCK);
667 
668  /* Check for completion of any steps that were previously waiting. */
669  nwaiting = try_complete_steps(testspec, waiting, nwaiting,
671 
672  /* If this step is waiting, add it to the array of waiters. */
673  if (mustwait)
674  waiting[nwaiting++] = pstep;
675  }
676 
677  /* Wait for any remaining queries. */
678  nwaiting = try_complete_steps(testspec, waiting, nwaiting, STEP_RETRY);
679  if (nwaiting != 0)
680  {
681  fprintf(stderr, "failed to complete permutation due to mutually-blocking steps\n");
682  exit(1);
683  }
684 
685  /* Perform per-session teardown */
686  for (i = 0; i < testspec->nsessions; i++)
687  {
688  if (testspec->sessions[i]->teardownsql)
689  {
690  res = PQexec(conns[i + 1].conn, testspec->sessions[i]->teardownsql);
691  if (PQresultStatus(res) == PGRES_TUPLES_OK)
692  {
693  printResultSet(res);
694  }
695  else if (PQresultStatus(res) != PGRES_COMMAND_OK)
696  {
697  fprintf(stderr, "teardown of session %s failed: %s",
698  conns[i + 1].sessionname,
699  PQerrorMessage(conns[i + 1].conn));
700  /* don't exit on teardown failure */
701  }
702  PQclear(res);
703  }
704  }
705 
706  /* Perform teardown */
707  if (testspec->teardownsql)
708  {
709  res = PQexec(conns[0].conn, testspec->teardownsql);
710  if (PQresultStatus(res) == PGRES_TUPLES_OK)
711  {
712  printResultSet(res);
713  }
714  else if (PQresultStatus(res) != PGRES_COMMAND_OK)
715  {
716  fprintf(stderr, "teardown failed: %s",
717  PQerrorMessage(conns[0].conn));
718  /* don't exit on teardown failure */
719  }
720  PQclear(res);
721  }
722 
723  free(waiting);
724 }
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
734  int nwaiting, int flags)
735 {
736  int old_nwaiting;
737  bool have_blocker;
738 
739  do
740  {
741  int w = 0;
742 
743  /* Reset latch; we only care about notices received within loop. */
744  any_new_notice = false;
745 
746  /* Likewise, these variables reset for each retry. */
747  old_nwaiting = nwaiting;
748  have_blocker = false;
749 
750  /* Scan the array, try to complete steps. */
751  while (w < nwaiting)
752  {
753  if (try_complete_step(testspec, waiting[w], flags))
754  {
755  /* Still blocked, leave it alone. */
756  if (waiting[w]->nblockers > 0)
757  have_blocker = true;
758  w++;
759  }
760  else
761  {
762  /* Done, remove it from array. */
763  if (w + 1 < nwaiting)
764  memmove(&waiting[w], &waiting[w + 1],
765  (nwaiting - (w + 1)) * sizeof(PermutationStep *));
766  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  } while (have_blocker && (nwaiting < old_nwaiting || any_new_notice));
779  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 try_complete_step(TestSpec *testspec, PermutationStep *pstep, int flags)
797 {
798  Step *step = pstep->step;
799  IsoConnInfo *iconn = &conns[1 + step->session];
800  PGconn *conn = iconn->conn;
801  fd_set read_set;
802  struct timeval start_time;
803  struct timeval timeout;
804  int sock = PQsocket(conn);
805  int ret;
806  PGresult *res;
807  PGnotify *notify;
808  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  if (!(flags & STEP_RETRY))
816  {
817  int i;
818 
819  for (i = 0; i < pstep->nblockers; i++)
820  {
821  PermutationStepBlocker *blocker = pstep->blockers[i];
822 
823  if (blocker->blocktype == PSB_ONCE)
824  {
825  printf("step %s: %s <waiting ...>\n",
826  step->name, step->sql);
827  return true;
828  }
829  }
830  }
831 
832  if (sock < 0)
833  {
834  fprintf(stderr, "invalid socket: %s", PQerrorMessage(conn));
835  exit(1);
836  }
837 
838  gettimeofday(&start_time, NULL);
839  FD_ZERO(&read_set);
840 
841  while (PQisBusy(conn))
842  {
843  FD_SET(sock, &read_set);
844  timeout.tv_sec = 0;
845  timeout.tv_usec = 10000; /* Check for lock waits every 10ms. */
846 
847  ret = select(sock + 1, &read_set, NULL, NULL, &timeout);
848  if (ret < 0) /* error in select() */
849  {
850  if (errno == EINTR)
851  continue;
852  fprintf(stderr, "select failed: %s\n", strerror(errno));
853  exit(1);
854  }
855  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  if (flags & STEP_NONBLOCK)
862  {
863  bool waiting;
864 
865  res = PQexecPrepared(conns[0].conn, PREP_WAITING, 1,
866  &conns[step->session + 1].backend_pid_str,
867  NULL, NULL, 0);
868  if (PQresultStatus(res) != PGRES_TUPLES_OK ||
869  PQntuples(res) != 1)
870  {
871  fprintf(stderr, "lock wait query failed: %s",
872  PQerrorMessage(conns[0].conn));
873  exit(1);
874  }
875  waiting = ((PQgetvalue(res, 0, 0))[0] == 't');
876  PQclear(res);
877 
878  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  if (!PQconsumeInput(conn))
890  {
891  fprintf(stderr, "PQconsumeInput failed: %s\n",
892  PQerrorMessage(conn));
893  exit(1);
894  }
895  if (!PQisBusy(conn))
896  break;
897 
898  /*
899  * conn is still busy, so conclude that the step really is
900  * waiting.
901  */
902  if (!(flags & STEP_RETRY))
903  printf("step %s: %s <waiting ...>\n",
904  step->name, step->sql);
905  return true;
906  }
907  /* else, not waiting */
908  }
909 
910  /* Figure out how long we've been waiting for this step. */
911  gettimeofday(&current_time, NULL);
912  td = (int64) current_time.tv_sec - (int64) start_time.tv_sec;
913  td *= USECS_PER_SEC;
914  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  if (td > max_step_wait && !canceled)
926  {
927  PGcancel *cancel = PQgetCancel(conn);
928 
929  if (cancel != NULL)
930  {
931  char buf[256];
932 
933  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  printf("isolationtester: canceling step %s after %d seconds\n",
940  step->name, (int) (td / USECS_PER_SEC));
941  canceled = true;
942  }
943  else
944  fprintf(stderr, "PQcancel failed: %s\n", buf);
945  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  if (td > 2 * max_step_wait)
957  {
958  fprintf(stderr, "step %s timed out after %d seconds\n",
959  step->name, (int) (td / USECS_PER_SEC));
960  exit(1);
961  }
962  }
963  else if (!PQconsumeInput(conn)) /* select(): data available */
964  {
965  fprintf(stderr, "PQconsumeInput failed: %s\n",
966  PQerrorMessage(conn));
967  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  if (step_has_blocker(pstep))
976  {
977  if (!(flags & STEP_RETRY))
978  printf("step %s: %s <waiting ...>\n",
979  step->name, step->sql);
980  return true;
981  }
982 
983  /* Otherwise, go ahead and complete it. */
984  if (flags & STEP_RETRY)
985  printf("step %s: <... completed>\n", step->name);
986  else
987  printf("step %s: %s\n", step->name, step->sql);
988 
989  while ((res = PQgetResult(conn)))
990  {
991  switch (PQresultStatus(res))
992  {
993  case PGRES_COMMAND_OK:
994  case PGRES_EMPTY_QUERY:
995  break;
996  case PGRES_TUPLES_OK:
997  printResultSet(res);
998  break;
999  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  const char *sev = PQresultErrorField(res,
1009  const char *msg = PQresultErrorField(res,
1011 
1012  if (sev && msg)
1013  printf("%s: %s\n", sev, msg);
1014  else
1015  printf("%s\n", PQresultErrorMessage(res));
1016  }
1017  break;
1018  default:
1019  printf("unexpected result status: %s\n",
1020  PQresStatus(PQresultStatus(res)));
1021  }
1022  PQclear(res);
1023  }
1024 
1025  /* Report any available NOTIFY messages, too */
1026  PQconsumeInput(conn);
1027  while ((notify = PQnotifies(conn)) != NULL)
1028  {
1029  /* Try to identify which session it came from */
1030  const char *sendername = NULL;
1031  char pidstring[32];
1032  int i;
1033 
1034  for (i = 0; i < testspec->nsessions; i++)
1035  {
1036  if (notify->be_pid == conns[i + 1].backend_pid)
1037  {
1038  sendername = conns[i + 1].sessionname;
1039  break;
1040  }
1041  }
1042  if (sendername == NULL)
1043  {
1044  /* Doesn't seem to be any test session, so show the hard way */
1045  snprintf(pidstring, sizeof(pidstring), "PID %d", notify->be_pid);
1046  sendername = pidstring;
1047  }
1048  printf("%s: NOTIFY \"%s\" with payload \"%s\" from %s\n",
1049  testspec->sessions[step->session]->name,
1050  notify->relname, notify->extra, sendername);
1051  PQfreemem(notify);
1052  PQconsumeInput(conn);
1053  }
1054 
1055  /* Connection is now idle. */
1056  iconn->active_step = NULL;
1057 
1058  return false;
1059 }
1060 
1061 /* Detect whether a step has any unsatisfied blocker conditions */
1062 static bool
1064 {
1065  int i;
1066 
1067  for (i = 0; i < pstep->nblockers; i++)
1068  {
1069  PermutationStepBlocker *blocker = pstep->blockers[i];
1070  IsoConnInfo *iconn;
1071 
1072  switch (blocker->blocktype)
1073  {
1074  case PSB_ONCE:
1075  /* Ignore; try_complete_step handles this specially */
1076  break;
1077  case PSB_OTHER_STEP:
1078  /* Block if referenced step is active */
1079  iconn = &conns[1 + blocker->step->session];
1080  if (iconn->active_step &&
1081  iconn->active_step->step == blocker->step)
1082  return true;
1083  break;
1084  case PSB_NUM_NOTICES:
1085  /* Block if not enough notices received yet */
1086  iconn = &conns[1 + blocker->step->session];
1087  if (iconn->total_notices < blocker->target_notices)
1088  return true;
1089  break;
1090  }
1091  }
1092  return false;
1093 }
1094 
1095 static void
1097 {
1098  PQprintOpt popt;
1099 
1100  memset(&popt, 0, sizeof(popt));
1101  popt.header = true;
1102  popt.align = true;
1103  popt.fieldSep = "|";
1104  PQprint(stdout, res, &popt);
1105 }
1106 
1107 /* notice processor for regular user sessions */
1108 static void
1109 isotesterNoticeProcessor(void *arg, const char *message)
1110 {
1111  IsoConnInfo *myconn = (IsoConnInfo *) arg;
1112 
1113  /* Prefix the backend's message with the session name. */
1114  printf("%s: %s", myconn->sessionname, message);
1115  /* Record notices, since we may need this to decide to unblock a step. */
1116  myconn->total_notices++;
1117  any_new_notice = true;
1118 }
1119 
1120 /* notice processor, hides the message */
1121 static void
1122 blackholeNoticeProcessor(void *arg, const char *message)
1123 {
1124  /* do nothing */
1125 }
static void check_testspec(TestSpec *testspec)
char * extra
Definition: libpq-fe.h:189
void PQprint(FILE *fout, const PGresult *res, const PQprintOpt *po)
Definition: fe-print.c:68
PGresult * PQexecPrepared(PGconn *conn, const char *stmtName, int nParams, const char *const *paramValues, const int *paramLengths, const int *paramFormats, int resultFormat)
Definition: fe-exec.c:2254
PGresult * PQprepare(PGconn *conn, const char *stmtName, const char *query, int nParams, const Oid *paramTypes)
Definition: fe-exec.c:2237
char * PQerrorMessage(const PGconn *conn)
Definition: fe-connect.c:6744
int gettimeofday(struct timeval *tp, struct timezone *tzp)
Definition: gettimeofday.c:104
static int64 max_step_wait
static int try_complete_steps(TestSpec *testspec, PermutationStep **waiting, int nwaiting, int flags)
#define PG_DIAG_MESSAGE_PRIMARY
Definition: postgres_ext.h:58
PQnoticeProcessor PQsetNoticeProcessor(PGconn *conn, PQnoticeProcessor proc, void *arg)
Definition: fe-connect.c:6912
char * PQgetvalue(const PGresult *res, int tup_num, int field_num)
Definition: fe-exec.c:3642
PGnotify * PQnotifies(PGconn *conn)
Definition: fe-exec.c:2516
void * pg_malloc(size_t size)
Definition: fe_memutils.c:47
#define USECS_PER_SEC
Definition: timestamp.h:94
static void run_named_permutations(TestSpec *testspec)
void termPQExpBuffer(PQExpBuffer str)
Definition: pqexpbuffer.c:131
Session ** sessions
void appendPQExpBufferStr(PQExpBuffer str, const char *data)
Definition: pqexpbuffer.c:369
char ** setupsqls
bool used
void PQfreeCancel(PGcancel *cancel)
Definition: fe-connect.c:4375
int main(int argc, char **argv)
char * psprintf(const char *fmt,...)
Definition: psprintf.c:46
static void run_all_permutations(TestSpec *testspec)
char * teardownsql
char * PQresStatus(ExecStatusType status)
Definition: fe-exec.c:3186
void PQfinish(PGconn *conn)
Definition: fe-connect.c:4231
#define printf(...)
Definition: port.h:222
const char * sessionname
Permutation ** permutations
char * setupsql
int PQntuples(const PGresult *res)
Definition: fe-exec.c:3248
#define fprintf
Definition: port.h:220
static int step_qsort_cmp(const void *a, const void *b)
int getopt(int nargc, char *const *nargv, const char *ostr)
Definition: getopt.c:71
char * fieldSep
Definition: libpq-fe.h:209
ExecStatusType PQresultStatus(const PGresult *res)
Definition: fe-exec.c:3178
static void run_permutation(TestSpec *testspec, int nsteps, PermutationStep **steps)
char * name
int npermutations
static void blackholeNoticeProcessor(void *arg, const char *message)
static bool step_has_blocker(PermutationStep *pstep)
int PQsendQuery(PGconn *conn, const char *query)
Definition: fe-exec.c:1326
int optind
Definition: getopt.c:50
static void run_all_permutations_recurse(TestSpec *testspec, int *piles, int nsteps, PermutationStep **steps)
struct IsoConnInfo IsoConnInfo
char * name
void * pg_malloc0(size_t size)
Definition: fe_memutils.c:53
char * teardownsql
int be_pid
Definition: libpq-fe.h:188
static IsoConnInfo * conns
void appendPQExpBuffer(PQExpBuffer str, const char *fmt,...)
Definition: pqexpbuffer.c:267
static int step_bsearch_cmp(const void *a, const void *b)
static void disconnect_atexit(void)
static char * buf
Definition: pg_test_fsync.c:68
PGcancel * PQgetCancel(PGconn *conn)
Definition: fe-connect.c:4352
PermutationStepBlocker ** blockers
#define PG_DIAG_SEVERITY
Definition: postgres_ext.h:55
pqbool align
Definition: libpq-fe.h:204
#define select(n, r, w, e, timeout)
Definition: win32_port.h:464
#define STEP_RETRY
char * relname
Definition: libpq-fe.h:187
int PQbackendPID(const PGconn *conn)
Definition: fe-connect.c:6778
int PQconsumeInput(PGconn *conn)
Definition: fe-exec.c:1904
void PQclear(PGresult *res)
Definition: fe-exec.c:694
#define STEP_NONBLOCK
#define free(a)
Definition: header.h:65
char * PQresultErrorField(const PGresult *res, int fieldcode)
Definition: fe-exec.c:3233
static bool try_complete_step(TestSpec *testspec, PermutationStep *pstep, int flags)
int PQisBusy(PGconn *conn)
Definition: fe-exec.c:1951
static void isotesterNoticeProcessor(void *arg, const char *message)
PGconn * conn
#define PREP_WAITING
#define strerror
Definition: port.h:229
Step ** steps
char * sql
const char * name
Definition: encode.c:561
static void run_testspec(TestSpec *testspec)
int PQcancel(PGcancel *cancel, char *errbuf, int errbufsize)
Definition: fe-connect.c:4507
static bool any_new_notice
char * PQresultErrorMessage(const PGresult *res)
Definition: fe-exec.c:3194
PermutationStep * active_step
pqbool header
Definition: libpq-fe.h:203
int i
#define EXIT_FAILURE
Definition: settings.h:162
PGresult * PQexec(PGconn *conn, const char *query)
Definition: fe-exec.c:2193
void * arg
int session
const char * backend_pid_str
TestSpec parseresult
PermutationStep ** steps
#define EINTR
Definition: win32_port.h:343
#define qsort(a, b, c, d)
Definition: port.h:504
ConnStatusType PQstatus(const PGconn *conn)
Definition: fe-connect.c:6691
static int nconns
#define snprintf
Definition: port.h:216
int spec_yyparse(void)
void PQfreemem(void *ptr)
Definition: fe-exec.c:3796
static volatile sig_atomic_t waiting
Definition: latch.c:147
int PQsocket(const PGconn *conn)
Definition: fe-connect.c:6770
PGresult * PQgetResult(PGconn *conn)
Definition: fe-exec.c:1978
void initPQExpBuffer(PQExpBuffer str)
Definition: pqexpbuffer.c:92
static void printResultSet(PGresult *res)
PGconn * PQconnectdb(const char *conninfo)
Definition: fe-connect.c:713
PermutationStepBlockerType blocktype