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