tools/tesh/run_context.c

   1 /* $Id$ */
   2
   3 /* run_context -- stuff in which TESH runs a command                        */
   4
   5 /* Copyright (c) 2007 Martin Quinson.                                       */
   6 /* All rights reserved.                                                     */
   7
   8 /* This program is free software; you can redistribute it and/or modify it
   9  * under the terms of the license (GNU LGPL) which comes with this package. */
  10
  11 #include "tesh.h"
  12
  13 #include <sys/types.h>
  14 #include <sys/wait.h>
  15
  16 XBT_LOG_EXTERNAL_DEFAULT_CATEGORY(tesh);
  17
  18 xbt_dynar_t bg_jobs = NULL;
  19 rctx_t armageddon_initiator = NULL;
  20 xbt_os_mutex_t armageddon_mutex = NULL;
  21
  22 /*
  23  * Module management
  24  */
  25
  26 static void kill_it(void*r) {
  27   rctx_t rctx = *(rctx_t*)r;
  28
  29   VERB2("Join thread %p which were running background cmd <%s>",rctx->runner,rctx->filepos);
  30   xbt_os_thread_join(rctx->runner,NULL);
  31   rctx_free(rctx);
  32 }
  33
  34 void rctx_init(void) {
  35   bg_jobs = xbt_dynar_new_sync(sizeof(rctx_t),kill_it);
  36   armageddon_mutex = xbt_os_mutex_init();
  37   armageddon_initiator = NULL;
  38 }
  39
  40 void rctx_exit(void) {
  41   if (bg_jobs) {
  42     /* Do not use xbt_dynar_free or it will lock the dynar, preventing armageddon from working */
  43     while (xbt_dynar_length(bg_jobs)) {
  44        rctx_t rctx;
  45        xbt_dynar_pop(bg_jobs,&rctx);
  46        kill_it(&rctx);
  47     }
  48     xbt_dynar_free(&bg_jobs);
  49   }
  50   xbt_os_mutex_destroy(armageddon_mutex);
  51 }
  52
  53 void rctx_wait_bg(void) {
  54   if (bg_jobs) {
  55     /* Do not use xbt_dynar_free or it will lock the dynar, preventing armageddon from working */
  56     while (xbt_dynar_length(bg_jobs)) {
  57        rctx_t rctx;
  58        xbt_dynar_pop(bg_jobs,&rctx);
  59        kill_it(&rctx);
  60     }
  61     xbt_dynar_free(&bg_jobs);
  62   }
  63   bg_jobs = xbt_dynar_new_sync(sizeof(rctx_t),kill_it);
  64 }
  65
  66 void rctx_armageddon(rctx_t initiator, int exitcode) {
  67   rctx_t rctx;
  68
  69   DEBUG2("Armageddon request by <%s> (exit=%d)",initiator->filepos,exitcode);
  70   xbt_os_mutex_lock(armageddon_mutex);
  71   if (armageddon_initiator != NULL) {
  72     VERB0("Armageddon already started. Let it go");
  73     xbt_os_mutex_unlock(initiator->interruption);
  74     xbt_os_mutex_unlock(armageddon_mutex);
  75     return;
  76   }
  77   DEBUG1("Armageddon request by <%s> got the lock. Let's go amok",initiator->filepos);
  78   armageddon_initiator = initiator;
  79   xbt_os_mutex_unlock(armageddon_mutex);
  80
  81   /* Kill any background commands */
  82   while (xbt_dynar_length(bg_jobs)) {
  83     xbt_dynar_pop(bg_jobs,&rctx);
  84     if (rctx != initiator) {
  85       INFO2("Kill <%s> because <%s> failed",rctx->filepos,initiator->filepos);
  86       xbt_os_mutex_lock(rctx->interruption);
  87       rctx->interrupted = 1;
  88       xbt_os_mutex_unlock(rctx->interruption);
  89       if (!rctx->reader_done) {
  90         kill(rctx->pid,SIGTERM);
  91         usleep(100);
  92         kill(rctx->pid,SIGKILL);
  93       }
  94     }
  95   }
  96
  97   VERB0("Shut everything down!");
  98   exit(exitcode);
  99 }
 100
 101 /*
 102  * Memory management
 103  */
 104
 105 void rctx_empty(rctx_t rc) {
 106   if (rc->cmd)
 107     free(rc->cmd);
 108   rc->cmd = NULL;
 109   if (rc->filepos)
 110     free(rc->filepos);
 111   rc->filepos = NULL;
 112   rc->is_empty = 1;
 113   rc->is_background = 0;
 114   rc->is_stoppable = 0;
 115   rc->output = e_output_check;
 116   rc->brokenpipe = 0;
 117   rc->timeout = 0;
 118   rc->interrupted = 0;
 119   xbt_strbuff_empty(rc->input);
 120   xbt_strbuff_empty(rc->output_wanted);
 121   xbt_strbuff_empty(rc->output_got);
 122 }
 123
 124 rctx_t rctx_new() {
 125   rctx_t res = xbt_new0(s_rctx_t,1);
 126
 127   res->input=xbt_strbuff_new();
 128   res->output_wanted=xbt_strbuff_new();
 129   res->output_got=xbt_strbuff_new();
 130   res->interruption = xbt_os_mutex_init();
 131   rctx_empty(res);
 132   return res;
 133 }
 134
 135 void rctx_free(rctx_t rctx) {
 136   DEBUG1("RCTX: Free %p", rctx);
 137   rctx_dump(rctx,"free");
 138   if (!rctx)
 139     return;
 140
 141   if (rctx->cmd)
 142     free(rctx->cmd);
 143   if (rctx->filepos)
 144     free(rctx->filepos);
 145   xbt_os_mutex_destroy(rctx->interruption);
 146   xbt_strbuff_free(rctx->input);
 147   xbt_strbuff_free(rctx->output_got);
 148   xbt_strbuff_free(rctx->output_wanted);
 149   free(rctx);
 150 }
 151
 152 void rctx_dump(rctx_t rctx, const char *str) {
 153   DEBUG9("%s RCTX %p={in%p={%d,%10s}, want={%d,%10s}, out={%d,%10s}}",
 154          str, rctx,
 155          rctx->input,              rctx->input->used,        rctx->input->data,
 156          rctx->output_wanted->used,rctx->output_wanted->data,
 157          rctx->output_got->used,   rctx->output_got->data);
 158   DEBUG5("%s RCTX %p=[cmd%p=%10s, pid=%d]",
 159          str,rctx,rctx->cmd,rctx->cmd,rctx->pid);
 160
 161 }
 162
 163 /*
 164  * Getting instructions from the file
 165  */
 166
 167 void rctx_pushline(const char* filepos, char kind, char *line) {
 168
 169   switch (kind) {
 170   case '$':
 171   case '&':
 172     if (rctx->cmd) {
 173       if (!rctx->is_empty) {
 174         ERROR2("[%s] More than one command in this chunk of lines (previous: %s).\n"
 175                " Dunno which input/output belongs to which command.",
 176                filepos,rctx->cmd);
 177         ERROR1("Test suite `%s': NOK (syntax error)",testsuite_name);
 178         rctx_armageddon(rctx,1);
 179         return;
 180       }
 181       rctx_start();
 182       VERB1("[%s] More than one command in this chunk of lines",filepos);
 183     }
 184     if (kind == '&')
 185       rctx->is_background = 1;
 186     else
 187       rctx->is_background = 0;
 188
 189     rctx->cmd = xbt_strdup(line);
 190     rctx->filepos = xbt_strdup(filepos);
 191     INFO3("[%s] %s%s",filepos,rctx->cmd,
 192           ((rctx->is_background)?" (background command)":""));
 193
 194     break;
 195
 196   case '<':
 197     rctx->is_empty = 0;
 198     xbt_strbuff_append(rctx->input,line);
 199     xbt_strbuff_append(rctx->input,"\n");
 200     break;
 201
 202   case '>':
 203     rctx->is_empty = 0;
 204     xbt_strbuff_append(rctx->output_wanted,line);
 205     xbt_strbuff_append(rctx->output_wanted,"\n");
 206     break;
 207
 208   case '!':
 209     if (rctx->cmd)
 210       rctx_start();
 211
 212     if (!strncmp(line,"timeout no",strlen("timeout no"))) {
 213       VERB1("[%s] (disable timeout)", filepos);
 214       timeout_value = -1;
 215     } else if (!strncmp(line,"timeout ",strlen("timeout "))) {
 216       timeout_value=atoi(line+strlen("timeout"));
 217       VERB2("[%s] (new timeout value: %d)",
 218              filepos,timeout_value);
 219
 220     } else if (!strncmp(line,"expect signal ",strlen("expect signal "))) {
 221       rctx->expected_signal = strdup(line + strlen("expect signal "));
 222       xbt_str_trim(rctx->expected_signal," \n");
 223            VERB2("[%s] (next command must raise signal %s)",
 224                  filepos, rctx->expected_signal);
 225
 226     } else if (!strncmp(line,"expect return ",strlen("expect return "))) {
 227       rctx->expected_return = atoi(line+strlen("expect return "));
 228       VERB2("[%s] (next command must return code %d)",
 229             filepos, rctx->expected_return);
 230
 231     } else if (!strncmp(line,"output ignore",strlen("output ignore"))) {
 232       rctx->output = e_output_ignore;
 233       VERB1("[%s] (ignore output of next command)", filepos);
 234
 235     } else if (!strncmp(line,"output display",strlen("output display"))) {
 236       rctx->output = e_output_display;
 237       VERB1("[%s] (ignore output of next command)", filepos);
 238
 239     } else {
 240       ERROR2("%s: Malformed metacommand: %s",filepos,line);
 241       ERROR1("Test suite `%s': NOK (syntax error)",testsuite_name);
 242       rctx_armageddon(rctx,1);
 243       return;
 244     }
 245     break;
 246   }
 247 }
 248
 249 /*
 250  * Actually doing the job
 251  */
 252
 253 /* The IO of the childs are handled by the two following threads
 254    (one pair per child) */
 255
 256 static void* thread_writer(void *r) {
 257   int posw;
 258   rctx_t rctx = (rctx_t)r;
 259   for (posw=0; posw<rctx->input->used && !rctx->brokenpipe; ) {
 260     int got;
 261     DEBUG1("Still %d chars to write",rctx->input->used-posw);
 262     got=write(rctx->child_to,rctx->input->data+posw,rctx->input->used-posw);
 263     if (got>0)
 264       posw+=got;
 265     if (got<0) {
 266       if (errno == EPIPE) {
 267         rctx->brokenpipe = 1;
 268       } else if (errno!=EINTR && errno!=EAGAIN && errno!=EPIPE) {
 269         perror("Error while writing input to child");
 270         ERROR1("Test suite `%s': NOK (system error)",testsuite_name);
 271         rctx_armageddon(rctx,4);
 272         return NULL;
 273       }
 274     }
 275     DEBUG1("written %d chars so far",posw);
 276
 277     if (got <= 0)
 278       usleep(100);
 279   }
 280   rctx->input->data[0]='\0';
 281   rctx->input->used=0;
 282   close(rctx->child_to);
 283
 284   return NULL;
 285 }
 286 static void *thread_reader(void *r) {
 287   rctx_t rctx = (rctx_t)r;
 288   char *buffout=malloc(4096);
 289   int posr, got_pid;
 290
 291   do {
 292     posr=read(rctx->child_from,buffout,4095);
 293     if (posr<0 && errno!=EINTR && errno!=EAGAIN) {
 294       perror("Error while reading output of child");
 295       ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 296       rctx_armageddon(rctx,4);
 297       return NULL;
 298     }
 299     if (posr>0) {
 300       buffout[posr]='\0';
 301       xbt_strbuff_append(rctx->output_got,buffout);
 302     } else {
 303       usleep(100);
 304     }
 305   } while (!rctx->timeout && posr!=0);
 306   free(buffout);
 307
 308   /* let this thread wait for the child so that the main thread can detect the timeout without blocking on the wait */
 309   got_pid = waitpid(rctx->pid,&rctx->status,0);
 310   if (got_pid != rctx->pid) {
 311     perror(bprintf("Cannot wait for the child %s",rctx->cmd));
 312     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 313     rctx_armageddon(rctx,4);
 314     return NULL;
 315   }
 316
 317   rctx->reader_done = 1;
 318   return NULL;
 319 }
 320
 321 /* Start a new child, plug the pipes as expected and fire up the
 322    helping threads. Is also waits for the child to end if this is a
 323    foreground job, or fire up a thread to wait otherwise. */
 324
 325 void rctx_start(void) {
 326   int child_in[2];
 327   int child_out[2];
 328
 329   VERB2("Start %s %s",rctx->cmd,(rctx->is_background?"(background job)":""));
 330   if (pipe(child_in) || pipe(child_out)) {
 331     perror("Cannot open the pipes");
 332     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 333     rctx_armageddon(rctx,4);
 334   }
 335
 336   rctx->pid=fork();
 337   if (rctx->pid<0) {
 338     perror("Cannot fork the command");
 339     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 340     rctx_armageddon(rctx,4);
 341     return;
 342   }
 343
 344   if (rctx->pid) { /* father */
 345     close(child_in[0]);
 346     rctx->child_to = child_in[1];
 347
 348     close(child_out[1]);
 349     rctx->child_from = child_out[0];
 350
 351     if (timeout_value > 0)
 352        rctx->end_time = time(NULL) + timeout_value;
 353     else
 354        rctx->end_time = -1;
 355
 356     rctx->reader_done = 0;
 357     rctx->reader = xbt_os_thread_create("reader",thread_reader,(void*)rctx);
 358     rctx->writer = xbt_os_thread_create("writer",thread_writer,(void*)rctx);
 359
 360   } else { /* child */
 361
 362     close(child_in[1]);
 363     dup2(child_in[0],0);
 364     close(child_in[0]);
 365
 366     close(child_out[0]);
 367     dup2(child_out[1],1);
 368     dup2(child_out[1],2);
 369     close(child_out[1]);
 370
 371     execlp ("/bin/sh", "sh", "-c", rctx->cmd, NULL);
 372   }
 373
 374   rctx->is_stoppable = 1;
 375
 376   if (!rctx->is_background) {
 377     rctx_wait(rctx);
 378   } else {
 379     /* Damn. Copy the rctx and launch a thread to handle it */
 380     rctx_t old = rctx;
 381     xbt_os_thread_t runner;
 382
 383     rctx = rctx_new();
 384     DEBUG2("RCTX: new bg=%p, new fg=%p",old,rctx);
 385
 386     DEBUG2("Launch a thread to wait for %s %d",old->cmd,old->pid);
 387     runner = xbt_os_thread_create(old->cmd,rctx_wait,(void*)old);
 388     old->runner = runner;
 389     VERB3("Launched thread %p to wait for %s %d",
 390           runner,old->cmd, old->pid);
 391     xbt_dynar_push(bg_jobs,&old);
 392   }
 393 }
 394
 395 /* Waits for the child to end (or to timeout), and check its
 396    ending conditions. This is launched from rctx_start but either in main
 397    thread (for foreground jobs) or in a separate one for background jobs.
 398    That explains the prototype, forced by xbt_os_thread_create. */
 399
 400 void *rctx_wait(void* r) {
 401   rctx_t rctx = (rctx_t)r;
 402   int errcode = 0;
 403   int now = time(NULL);
 404
 405   rctx_dump(rctx,"wait");
 406
 407   if (!rctx->is_stoppable)
 408     THROW1(unknown_error,0,"Cmd '%s' not started yet. Cannot wait it",
 409            rctx->cmd);
 410
 411   /* Wait for the child to die or the timeout to happen (or an armageddon to happen) */
 412   while (!rctx->interrupted && !rctx->reader_done && (rctx->end_time <0 ||rctx->end_time >= now)) {
 413     usleep(100);
 414     now = time(NULL);
 415   }
 416
 417   xbt_os_mutex_lock(rctx->interruption);
 418   if (!rctx->interrupted && rctx->end_time > 0 && rctx->end_time < now) {
 419     INFO1("<%s> timeouted. Kill the process.",rctx->filepos);
 420     rctx->timeout = 1;
 421     kill(rctx->pid,SIGTERM);
 422     usleep(100);
 423     kill(rctx->pid,SIGKILL);
 424     rctx->reader_done = 1;
 425   }
 426
 427   /* Make sure helper threads die.
 428      Cannot block since they wait for the child we just killed
 429      if not already dead. */
 430   xbt_os_thread_join(rctx->writer,NULL);
 431   xbt_os_thread_join(rctx->reader,NULL);
 432
 433   /*  xbt_os_mutex_unlock(rctx->interruption);
 434   if (rctx->interrupted)
 435     return NULL;
 436     xbt_os_mutex_lock(rctx->interruption);*/
 437
 438   xbt_strbuff_chomp(rctx->output_got);
 439   xbt_strbuff_chomp(rctx->output_wanted);
 440   xbt_strbuff_trim(rctx->output_got);
 441   xbt_strbuff_trim(rctx->output_wanted);
 442
 443   /* Check for broken pipe */
 444   if (rctx->brokenpipe)
 445     VERB0("Warning: Child did not consume all its input (I got broken pipe)");
 446
 447   /* Check for timeouts */
 448   if (rctx->timeout) {
 449     if (rctx->output_got->data[0])
 450       INFO2("<%s> Output on timeout:\n%s",
 451             rctx->filepos,rctx->output_got->data);
 452     else
 453       INFO1("<%s> No output before timeout",
 454             rctx->filepos);
 455     ERROR3("Test suite `%s': NOK (<%s> timeout after %d sec)",
 456            testsuite_name,rctx->filepos,timeout_value);
 457     DEBUG2("<%s> Interrupted = %d", rctx->filepos, rctx->interrupted);
 458     if (!rctx->interrupted) {
 459       rctx_armageddon(rctx, 3);
 460       return NULL;
 461     }
 462   }
 463
 464   DEBUG2("RCTX=%p (pid=%d)",rctx,rctx->pid);
 465   DEBUG3("Status(%s|%d)=%d",rctx->cmd,rctx->pid,rctx->status);
 466
 467   if (!rctx->interrupted) {
 468     if (WIFSIGNALED(rctx->status) && !rctx->expected_signal) {
 469       ERROR3("Test suite `%s': NOK (<%s> got signal %s)",
 470              testsuite_name, rctx->filepos,
 471              signal_name(WTERMSIG(rctx->status),NULL));
 472       errcode = WTERMSIG(rctx->status)+4;
 473     }
 474
 475     if (WIFSIGNALED(rctx->status) && rctx->expected_signal &&
 476         strcmp(signal_name(WTERMSIG(rctx->status),rctx->expected_signal),
 477                rctx->expected_signal)) {
 478       ERROR4("Test suite `%s': NOK (%s got signal %s instead of %s)",
 479              testsuite_name, rctx->filepos,
 480              signal_name(WTERMSIG(rctx->status),rctx->expected_signal),
 481              rctx->expected_signal);
 482       errcode = WTERMSIG(rctx->status)+4;
 483     }
 484
 485     if (!WIFSIGNALED(rctx->status) && rctx->expected_signal) {
 486       ERROR3("Test suite `%s': NOK (child %s expected signal %s)",
 487              testsuite_name, rctx->filepos,
 488              rctx->expected_signal);
 489       errcode = 5;
 490     }
 491
 492     if (WIFEXITED(rctx->status) && WEXITSTATUS(rctx->status) != rctx->expected_return ) {
 493       if (rctx->expected_return)
 494         ERROR4("Test suite `%s': NOK (<%s> returned code %d instead of %d)",
 495                testsuite_name, rctx->filepos,
 496                WEXITSTATUS(rctx->status), rctx->expected_return);
 497       else
 498         ERROR3("Test suite `%s': NOK (<%s> returned code %d)",
 499                testsuite_name, rctx->filepos, WEXITSTATUS(rctx->status));
 500       errcode = 40+WEXITSTATUS(rctx->status);
 501
 502     }
 503     rctx->expected_return = 0;
 504
 505     if(rctx->expected_signal){
 506       free(rctx->expected_signal);
 507       rctx->expected_signal = NULL;
 508     }
 509   }
 510
 511   if (   rctx->output == e_output_check
 512       && (    rctx->output_got->used != rctx->output_wanted->used
 513            || strcmp(rctx->output_got->data, rctx->output_wanted->data))) {
 514     if (XBT_LOG_ISENABLED(tesh,xbt_log_priority_info)) {
 515        char *diff= xbt_str_diff(rctx->output_wanted->data,rctx->output_got->data);
 516        ERROR2("Output of <%s> mismatch:\n%s",rctx->filepos,diff);
 517        free(diff);
 518     }
 519     ERROR2("Test suite `%s': NOK (<%s> output mismatch)",
 520            testsuite_name,rctx->filepos);
 521
 522     errcode=2;
 523   } else if (rctx->output == e_output_ignore) {
 524     INFO1("(ignoring the output of <%s> as requested)",rctx->filepos);
 525   } else if (rctx->output == e_output_display) {
 526     xbt_dynar_t a = xbt_str_split(rctx->output_got->data, "\n");
 527     char *out = xbt_str_join(a,"\n||");
 528     xbt_dynar_free(&a);
 529     INFO1("Here is the (ignored) command output: \n||%s",out);
 530     free(out);
 531   } else if (errcode || rctx->interrupted) {
 532     /* checking output, and matching */
 533     xbt_dynar_t a = xbt_str_split(rctx->output_got->data, "\n");
 534     char *out = xbt_str_join(a,"\n||");
 535     xbt_dynar_free(&a);
 536     INFO2("Output of <%s> so far: \n||%s",rctx->filepos,out);
 537     free(out);
 538   }
 539
 540   if (!rctx->is_background) {
 541     rctx_empty(rctx);
 542   }
 543   if (errcode) {
 544     if (!rctx->interrupted) {
 545       rctx_armageddon(rctx, errcode);
 546       return NULL;
 547     }
 548   }
 549
 550   xbt_os_mutex_unlock(rctx->interruption);
 551   return NULL;
 552 }
 553