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