test_asyncresponse.c (15196B)
1 /* Feel free to use this example code in any way 2 you see fit (Public Domain) */ 3 4 /** 5 * @file test_asyncresponse.c 6 * @brief Test for the "asyncresponse" tutorial example. The example 7 * is started as a child process on an ephemeral port and then 8 * exercised over HTTP, so that what is tested is exactly the 9 * code the tutorial prints. 10 * 11 * Beyond checking that the right bytes come back, the test 12 * verifies the two properties that the chapter is actually 13 * about: that the body of "/events" really trickles in rather 14 * than arriving in one piece at the end, and that the server 15 * burns no CPU while it waits. The latter is what tells a 16 * properly suspended connection apart from a content reader 17 * that returns zero in a loop---both deliver the same bytes. 18 * @author Christian Grothoff 19 */ 20 21 #include <sys/types.h> 22 #include <sys/wait.h> 23 #include <curl/curl.h> 24 #include <errno.h> 25 #include <pthread.h> 26 #include <signal.h> 27 #include <stdio.h> 28 #include <stdlib.h> 29 #include <string.h> 30 #include <time.h> 31 #include <unistd.h> 32 33 /** 34 * Milliseconds the example should spend per step. 35 */ 36 #define STEP_MS 50 37 38 /** 39 * Number of steps per job, and thus (STEPS * STEP_MS) milliseconds of 40 * work for one request. 41 */ 42 #define STEPS 20 43 44 /** 45 * Nominal duration of one job in milliseconds. 46 */ 47 #define JOB_MS (STEPS * STEP_MS) 48 49 /** 50 * Upper bound for any single request, in seconds. 51 */ 52 #define REQUEST_TIMEOUT 30 53 54 /** 55 * Largest response body we are prepared to keep. 56 */ 57 #define MAX_BODY 65536 58 59 60 /** 61 * What one HTTP request collected. 62 */ 63 struct Fetch 64 { 65 /** 66 * The body, as far as it was received. 67 */ 68 char body[MAX_BODY]; 69 70 /** 71 * Number of valid bytes in @e body. 72 */ 73 size_t len; 74 75 /** 76 * Number of times the write callback was invoked. 77 */ 78 unsigned int chunks; 79 80 /** 81 * Time of the first invocation of the write callback, in 82 * milliseconds since the start of the request. 83 */ 84 long first_ms; 85 86 /** 87 * Time of the last invocation of the write callback, in 88 * milliseconds since the start of the request. 89 */ 90 long last_ms; 91 92 /** 93 * Start of the request. 94 */ 95 struct timespec start; 96 97 /** 98 * Abort the transfer after this many callbacks; zero to never abort. 99 */ 100 unsigned int abort_after; 101 102 /** 103 * Result of curl_easy_perform(). 104 */ 105 CURLcode res; 106 }; 107 108 109 /** 110 * The example's process ID. 111 */ 112 static pid_t server_pid; 113 114 /** 115 * The port the example bound. 116 */ 117 static unsigned int server_port; 118 119 /** 120 * Number of checks that failed. 121 */ 122 static unsigned int failures; 123 124 125 /** 126 * Report the outcome of one check. 127 * 128 * @param ok non-zero if the check passed 129 * @param what what was being checked 130 */ 131 static void 132 check (int ok, 133 const char *what) 134 { 135 if (! ok) 136 failures++; 137 fprintf (stderr, 138 "%s: %s\n", 139 ok ? "PASS" : "FAIL", 140 what); 141 } 142 143 144 /** 145 * @return the current value of the monotonic clock, in milliseconds 146 */ 147 static long 148 now_ms (void) 149 { 150 struct timespec ts; 151 152 if (0 != clock_gettime (CLOCK_MONOTONIC, 153 &ts)) 154 return 0; 155 return (long) ts.tv_sec * 1000 + ts.tv_nsec / 1000000; 156 } 157 158 159 /** 160 * @param since the earlier point in time 161 * @return milliseconds elapsed since @a since 162 */ 163 static long 164 elapsed_ms (const struct timespec *since) 165 { 166 struct timespec ts; 167 168 if (0 != clock_gettime (CLOCK_MONOTONIC, 169 &ts)) 170 return 0; 171 return (long) (ts.tv_sec - since->tv_sec) * 1000 172 + (ts.tv_nsec - since->tv_nsec) / 1000000; 173 } 174 175 176 /** 177 * Read the CPU time consumed by process @a pid so far. Only 178 * implemented for Linux; everywhere else the test simply skips the 179 * check that uses it. 180 * 181 * @param pid the process to look at 182 * @param[out] ms where to store the sum of user and system time in 183 * milliseconds 184 * @return non-zero on success 185 */ 186 static int 187 cpu_time_ms (pid_t pid, 188 long *ms) 189 { 190 #ifdef __linux__ 191 char path[64]; 192 char buf[1024]; 193 char *p; 194 FILE *f; 195 size_t got; 196 unsigned long utime; 197 unsigned long stime; 198 long ticks; 199 200 snprintf (path, 201 sizeof (path), 202 "/proc/%ld/stat", 203 (long) pid); 204 f = fopen (path, 205 "r"); 206 if (NULL == f) 207 return 0; 208 got = fread (buf, 209 1, 210 sizeof (buf) - 1, 211 f); 212 fclose (f); 213 if (0 == got) 214 return 0; 215 buf[got] = '\0'; 216 /* The second field is the executable name and may contain spaces and 217 parentheses, so start parsing behind its closing one. */ 218 p = strrchr (buf, 219 ')'); 220 if (NULL == p) 221 return 0; 222 if (2 != sscanf (p + 1, 223 " %*c %*d %*d %*d %*d %*d %*u %*u %*u %*u %*u %lu %lu", 224 &utime, 225 &stime)) 226 return 0; 227 ticks = sysconf (_SC_CLK_TCK); 228 if (0 >= ticks) 229 return 0; 230 *ms = (long) ((utime + stime) * 1000 / (unsigned long) ticks); 231 return 1; 232 #else 233 (void) pid; 234 (void) ms; 235 return 0; 236 #endif 237 } 238 239 240 static size_t 241 write_cb (void *ptr, 242 size_t size, 243 size_t nmemb, 244 void *cls) 245 { 246 struct Fetch *f = cls; 247 size_t total = size * nmemb; 248 249 f->chunks++; 250 if (1 == f->chunks) 251 f->first_ms = elapsed_ms (&f->start); 252 f->last_ms = elapsed_ms (&f->start); 253 if ( (0 != f->abort_after) && 254 (f->chunks >= f->abort_after) ) 255 return 0; /* makes curl abort the transfer */ 256 if (total > sizeof (f->body) - f->len - 1) 257 total = sizeof (f->body) - f->len - 1; 258 memcpy (&f->body[f->len], 259 ptr, 260 total); 261 f->len += total; 262 f->body[f->len] = '\0'; 263 return size * nmemb; 264 } 265 266 267 /** 268 * Perform one GET against the example. 269 * 270 * @param path the path to request 271 * @param[out] f where to store what was received; @e abort_after has to 272 * be set by the caller, everything else is initialised here 273 * @return milliseconds the request took 274 */ 275 static long 276 fetch (const char *path, 277 struct Fetch *f) 278 { 279 CURL *curl; 280 char url[128]; 281 unsigned int abort_after = f->abort_after; 282 283 memset (f, 284 0, 285 sizeof (struct Fetch)); 286 f->abort_after = abort_after; 287 f->res = CURLE_FAILED_INIT; 288 snprintf (url, 289 sizeof (url), 290 "http://127.0.0.1:%u%s", 291 server_port, 292 path); 293 curl = curl_easy_init (); 294 if (NULL == curl) 295 return 0; 296 curl_easy_setopt (curl, CURLOPT_URL, url); 297 curl_easy_setopt (curl, CURLOPT_WRITEFUNCTION, &write_cb); 298 curl_easy_setopt (curl, CURLOPT_WRITEDATA, f); 299 curl_easy_setopt (curl, CURLOPT_TIMEOUT, (long) REQUEST_TIMEOUT); 300 curl_easy_setopt (curl, CURLOPT_NOSIGNAL, 1L); 301 clock_gettime (CLOCK_MONOTONIC, 302 &f->start); 303 f->res = curl_easy_perform (curl); 304 curl_easy_cleanup (curl); 305 return elapsed_ms (&f->start); 306 } 307 308 309 /** 310 * Thread body that streams "/events" in the background while the main 311 * thread does something else. 312 * 313 * @param cls a `struct Fetch` whose @e abort_after is already set 314 * @return always NULL 315 */ 316 static void * 317 background_stream (void *cls) 318 { 319 (void) fetch ("/events", 320 cls); 321 return NULL; 322 } 323 324 325 /** 326 * Start the example on an ephemeral port and learn which one it got. 327 * 328 * @return non-zero on success 329 */ 330 static int 331 start_server (void) 332 { 333 char steps[16]; 334 char step_ms[16]; 335 int fds[2]; 336 FILE *out; 337 char line[128]; 338 339 if (0 != pipe (fds)) 340 return 0; 341 snprintf (step_ms, 342 sizeof (step_ms), 343 "%u", 344 (unsigned int) STEP_MS); 345 snprintf (steps, 346 sizeof (steps), 347 "%u", 348 (unsigned int) STEPS); 349 server_pid = fork (); 350 if (-1 == server_pid) 351 { 352 close (fds[0]); 353 close (fds[1]); 354 return 0; 355 } 356 if (0 == server_pid) 357 { 358 close (fds[0]); 359 if (STDOUT_FILENO != fds[1]) 360 { 361 dup2 (fds[1], 362 STDOUT_FILENO); 363 close (fds[1]); 364 } 365 execl ("./asyncresponse", 366 "asyncresponse", 367 "0", 368 step_ms, 369 steps, 370 (char *) NULL); 371 fprintf (stderr, 372 "Failed to exec ./asyncresponse: %s\n", 373 strerror (errno)); 374 _exit (77); 375 } 376 close (fds[1]); 377 out = fdopen (fds[0], 378 "r"); 379 if (NULL == out) 380 { 381 close (fds[0]); 382 return 0; 383 } 384 if (NULL == fgets (line, 385 sizeof (line), 386 out)) 387 { 388 fclose (out); 389 return 0; 390 } 391 fclose (out); 392 if (1 != sscanf (line, 393 "Listening on port %u", 394 &server_port)) 395 { 396 fprintf (stderr, 397 "Unexpected greeting from the example: %s", 398 line); 399 return 0; 400 } 401 return 1; 402 } 403 404 405 /** 406 * "GET /slow" suspends in the access handler and is answered as a 407 * whole once the worker is done. 408 */ 409 static void 410 test_slow (void) 411 { 412 struct Fetch f; 413 long ms; 414 415 memset (&f, 416 0, 417 sizeof (f)); 418 ms = fetch ("/slow", 419 &f); 420 check (CURLE_OK == f.res, 421 "/slow completed"); 422 check (NULL != strstr (f.body, 423 "all 20 steps done"), 424 "/slow delivered the complete answer"); 425 /* The worker sleeps STEP_MS per step, so the answer cannot possibly 426 be ready earlier. Only a lower bound is checked: a loaded machine 427 may take arbitrarily longer. */ 428 check (ms >= JOB_MS / 2, 429 "/slow waited for the worker"); 430 } 431 432 433 /** 434 * "GET /events" streams as the worker produces, and the server stays 435 * idle in between. This is the check that a content reader returning 436 * zero in a loop would fail. 437 */ 438 static void 439 test_events_are_incremental (void) 440 { 441 struct Fetch f; 442 long cpu_before; 443 long cpu_after; 444 long ms; 445 int have_cpu; 446 447 memset (&f, 448 0, 449 sizeof (f)); 450 have_cpu = cpu_time_ms (server_pid, 451 &cpu_before); 452 ms = fetch ("/events", 453 &f); 454 check (CURLE_OK == f.res, 455 "/events completed"); 456 check (NULL != strstr (f.body, 457 "event: done"), 458 "/events delivered the final event"); 459 check (5 <= f.chunks, 460 "/events arrived in several pieces"); 461 /* The decisive one: the first piece has to show up long before the 462 last. A response that is assembled first and sent afterwards would 463 have first_ms very close to last_ms. */ 464 check (f.last_ms - f.first_ms >= JOB_MS / 2, 465 "/events trickled in rather than arriving at once"); 466 467 if (! have_cpu) 468 { 469 fprintf (stderr, 470 "SKIP: no way to read the server's CPU time on this " 471 "platform\n"); 472 return; 473 } 474 if (! cpu_time_ms (server_pid, 475 &cpu_after)) 476 { 477 fprintf (stderr, 478 "SKIP: could not read the server's CPU time\n"); 479 return; 480 } 481 /* The server spent almost all of that second waiting. If the 482 connection were not suspended, MHD would poll the content reader 483 as fast as it can and this would be close to 100% of one core. */ 484 fprintf (stderr, 485 "server used %ld ms of CPU during %ld ms of streaming\n", 486 cpu_after - cpu_before, 487 ms); 488 check ((cpu_after - cpu_before) * 4 < ms, 489 "server stayed idle while the connection was suspended"); 490 } 491 492 493 /** 494 * The event loop keeps serving other requests while jobs are parked. 495 */ 496 static void 497 test_loop_stays_responsive (void) 498 { 499 struct Fetch stream; 500 struct Fetch ping; 501 pthread_t tid; 502 long worst = 0; 503 long ms; 504 unsigned int i; 505 506 memset (&stream, 507 0, 508 sizeof (stream)); 509 if (0 != pthread_create (&tid, 510 NULL, 511 &background_stream, 512 &stream)) 513 { 514 check (0, 515 "could not start the background stream"); 516 return; 517 } 518 for (i = 0; i < 5; i++) 519 { 520 memset (&ping, 521 0, 522 sizeof (ping)); 523 ms = fetch ("/fast", 524 &ping); 525 if ( (CURLE_OK != ping.res) || 526 (NULL == strstr (ping.body, 527 "pong")) ) 528 worst = REQUEST_TIMEOUT * 1000; 529 else if (ms > worst) 530 worst = ms; 531 usleep (50 * 1000); 532 } 533 pthread_join (tid, 534 NULL); 535 fprintf (stderr, 536 "slowest /fast while a job was running: %ld ms\n", 537 worst); 538 check (worst < 500, 539 "/fast was served promptly while a job was suspended"); 540 } 541 542 543 /** 544 * A client that goes away in the middle must not take the server with 545 * it, and the worker behind it has to be cleaned up. 546 */ 547 static void 548 test_client_abort (void) 549 { 550 struct Fetch f; 551 struct Fetch ping; 552 553 memset (&f, 554 0, 555 sizeof (f)); 556 f.abort_after = 3; 557 (void) fetch ("/events", 558 &f); 559 check (CURLE_OK != f.res, 560 "aborted transfer was reported as such"); 561 memset (&ping, 562 0, 563 sizeof (ping)); 564 (void) fetch ("/fast", 565 &ping); 566 check ( (CURLE_OK == ping.res) && 567 (NULL != strstr (ping.body, 568 "pong")), 569 "server survived a client that hung up mid-stream"); 570 } 571 572 573 /** 574 * Stopping the daemon while a connection is suspended is an API 575 * violation, so the example has to resume everything first. If it got 576 * that wrong we would see a panic or a hang here instead of a clean 577 * exit. 578 */ 579 static void 580 test_clean_shutdown (void) 581 { 582 struct Fetch stream; 583 pthread_t tid; 584 int status; 585 pid_t got; 586 587 memset (&stream, 588 0, 589 sizeof (stream)); 590 if (0 != pthread_create (&tid, 591 NULL, 592 &background_stream, 593 &stream)) 594 { 595 check (0, 596 "could not start the background stream"); 597 return; 598 } 599 /* Give the job time to get going, so that its connection really is 600 suspended when the signal arrives. */ 601 usleep ((useconds_t) (STEP_MS * 3) * 1000); 602 kill (server_pid, 603 SIGTERM); 604 pthread_join (tid, 605 NULL); 606 got = waitpid (server_pid, 607 &status, 608 0); 609 server_pid = -1; 610 check (0 < got, 611 "reaped the server"); 612 check (WIFEXITED (status) && (0 == WEXITSTATUS (status)), 613 "server shut down cleanly with a suspended connection"); 614 } 615 616 617 int 618 main (void) 619 { 620 long deadline; 621 622 if (0 != curl_global_init (CURL_GLOBAL_ALL)) 623 return 77; 624 if (! start_server ()) 625 { 626 fprintf (stderr, 627 "Could not start ./asyncresponse\n"); 628 curl_global_cleanup (); 629 return 77; 630 } 631 fprintf (stderr, 632 "example listening on port %u\n", 633 server_port); 634 635 /* Wait for the listen socket to be usable. */ 636 deadline = now_ms () + 5000; 637 while (now_ms () < deadline) 638 { 639 struct Fetch f; 640 641 memset (&f, 642 0, 643 sizeof (f)); 644 (void) fetch ("/fast", 645 &f); 646 if (CURLE_OK == f.res) 647 break; 648 usleep (50 * 1000); 649 } 650 651 test_slow (); 652 test_events_are_incremental (); 653 test_loop_stays_responsive (); 654 test_client_abort (); 655 test_clean_shutdown (); 656 657 if (-1 != server_pid) 658 { 659 kill (server_pid, 660 SIGKILL); 661 waitpid (server_pid, 662 NULL, 663 0); 664 } 665 curl_global_cleanup (); 666 if (0 != failures) 667 fprintf (stderr, 668 "%u check(s) failed\n", 669 failures); 670 return (0 == failures) ? 0 : 1; 671 }