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