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