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   VERB1("Join thread %p which were running a background cmd",rctx->runner);
  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(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     xbt_dynar_free(&bg_jobs);
  43   xbt_os_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_os_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_os_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_os_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_os_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_os_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_os_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,"timeout no",strlen("timeout no"))) {
 204       VERB1("[%s] (disable timeout)", filepos);
 205       timeout_value = -1;
 206     } else if (!strncmp(line,"timeout ",strlen("timeout "))) {
 207       timeout_value=atoi(line+strlen("timeout"));
 208       VERB2("[%s] (new timeout value: %d)",
 209              filepos,timeout_value);
 210
 211     } else if (!strncmp(line,"expect signal ",strlen("expect signal "))) {
 212       rctx->expected_signal = strdup(line + strlen("expect signal "));
 213       xbt_str_trim(rctx->expected_signal," \n");
 214            VERB2("[%s] (next command must raise signal %s)",
 215                  filepos, rctx->expected_signal);
 216
 217     } else if (!strncmp(line,"expect return ",strlen("expect return "))) {
 218       rctx->expected_return = atoi(line+strlen("expect return "));
 219       VERB2("[%s] (next command must return code %d)",
 220             filepos, rctx->expected_return);
 221
 222     } else if (!strncmp(line,"output ignore",strlen("output ignore"))) {
 223       rctx->output = e_output_ignore;
 224       VERB1("[%s] (ignore output of next command)", filepos);
 225
 226     } else if (!strncmp(line,"output display",strlen("output display"))) {
 227       rctx->output = e_output_display;
 228       VERB1("[%s] (ignore output of next command)", filepos);
 229
 230     } else {
 231       ERROR2("%s: Malformed metacommand: %s",filepos,line);
 232       ERROR1("Test suite `%s': NOK (syntax error)",testsuite_name);
 233       rctx_armageddon(rctx,1);
 234     }
 235     break;
 236   }
 237 }
 238
 239 /*
 240  * Actually doing the job
 241  */
 242
 243 /* The IO of the childs are handled by the two following threads
 244    (one pair per child) */
 245
 246 static void* thread_writer(void *r) {
 247   int posw;
 248   rctx_t rctx = (rctx_t)r;
 249   for (posw=0; posw<rctx->input->used && !rctx->brokenpipe; ) {
 250     int got;
 251     DEBUG1("Still %d chars to write",rctx->input->used-posw);
 252     got=write(rctx->child_to,rctx->input->data+posw,rctx->input->used-posw);
 253     if (got>0)
 254       posw+=got;
 255     if (got<0) {
 256       if (errno == EPIPE) {
 257         rctx->brokenpipe = 1;
 258       } else if (errno!=EINTR && errno!=EAGAIN && errno!=EPIPE) {
 259         perror("Error while writing input to child");
 260         ERROR1("Test suite `%s': NOK (system error)",testsuite_name);
 261         rctx_armageddon(rctx,4);
 262       }
 263     }
 264     DEBUG1("written %d chars so far",posw);
 265
 266     if (got <= 0)
 267       usleep(100);
 268   }
 269   rctx->input->data[0]='\0';
 270   rctx->input->used=0;
 271   close(rctx->child_to);
 272
 273   return NULL;
 274 }
 275 static void *thread_reader(void *r) {
 276   rctx_t rctx = (rctx_t)r;
 277   char *buffout=malloc(4096);
 278   int posr, got_pid;
 279
 280   do {
 281     posr=read(rctx->child_from,buffout,4095);
 282     if (posr<0 && errno!=EINTR && errno!=EAGAIN) {
 283       perror("Error while reading output of child");
 284       ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 285       rctx_armageddon(rctx,4);
 286     }
 287     if (posr>0) {
 288       buffout[posr]='\0';
 289       buff_append(rctx->output_got,buffout);
 290     } else {
 291       usleep(100);
 292     }
 293   } while (!rctx->timeout && posr!=0);
 294   free(buffout);
 295
 296   /* let this thread wait for the child so that the main thread can detect the timeout without blocking on the wait */
 297   got_pid = waitpid(rctx->pid,&rctx->status,0);
 298   if (got_pid != rctx->pid) {
 299     perror(bprintf("Cannot wait for the child %s",rctx->cmd));
 300     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 301     rctx_armageddon(rctx,4);
 302   }
 303
 304   rctx->reader_done = 1;
 305   return NULL;
 306 }
 307
 308 /* Start a new child, plug the pipes as expected and fire up the
 309    helping threads. Is also waits for the child to end if this is a
 310    foreground job, or fire up a thread to wait otherwise. */
 311
 312 void rctx_start(void) {
 313   int child_in[2];
 314   int child_out[2];
 315
 316   VERB2("Start %s %s",rctx->cmd,(rctx->is_background?"(background job)":""));
 317   if (pipe(child_in) || pipe(child_out)) {
 318     perror("Cannot open the pipes");
 319     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 320     rctx_armageddon(rctx,4);
 321   }
 322
 323   rctx->pid=fork();
 324   if (rctx->pid<0) {
 325     perror("Cannot fork the command");
 326     ERROR1("Test suite `%s': NOK (system error)", testsuite_name);
 327     rctx_armageddon(rctx,4);
 328   }
 329
 330   if (rctx->pid) { /* father */
 331     close(child_in[0]);
 332     rctx->child_to = child_in[1];
 333
 334     close(child_out[1]);
 335     rctx->child_from = child_out[0];
 336
 337     if (timeout_value > 0)
 338        rctx->end_time = time(NULL) + timeout_value;
 339     else
 340        rctx->end_time = -1;
 341
 342     rctx->reader_done = 0;
 343     rctx->reader = xbt_os_thread_create(thread_reader,(void*)rctx);
 344     rctx->writer = xbt_os_thread_create(thread_writer,(void*)rctx);
 345
 346   } else { /* child */
 347
 348     close(child_in[1]);
 349     dup2(child_in[0],0);
 350     close(child_in[0]);
 351
 352     close(child_out[0]);
 353     dup2(child_out[1],1);
 354     dup2(child_out[1],2);
 355     close(child_out[1]);
 356
 357     execlp ("/bin/sh", "sh", "-c", rctx->cmd, NULL);
 358   }
 359
 360   rctx->is_stoppable = 1;
 361
 362   if (!rctx->is_background) {
 363     rctx_wait(rctx);
 364   } else {
 365     /* Damn. Copy the rctx and launch a thread to handle it */
 366     rctx_t old = rctx;
 367     xbt_os_thread_t runner;
 368
 369     rctx = rctx_new();
 370     DEBUG2("RCTX: new bg=%p, new fg=%p",old,rctx);
 371
 372     DEBUG2("Launch a thread to wait for %s %d",old->cmd,old->pid);
 373     runner = xbt_os_thread_create(rctx_wait,(void*)old);
 374     old->runner = runner;
 375     VERB3("Launched thread %p to wait for %s %d",
 376           runner,old->cmd, old->pid);
 377     xbt_dynar_push(bg_jobs,&old);
 378   }
 379 }
 380
 381 /* Waits for the child to end (or to timeout), and check its
 382    ending conditions. This is launched from rctx_start but either in main
 383    thread (for foreground jobs) or in a separate one for background jobs.
 384    That explains the prototype, forced by xbt_os_thread_create. */
 385
 386 void *rctx_wait(void* r) {
 387   rctx_t rctx = (rctx_t)r;
 388   int errcode = 0;
 389   int now = time(NULL);
 390
 391   rctx_dump(rctx,"wait");
 392
 393   if (!rctx->is_stoppable)
 394     THROW1(unknown_error,0,"Cmd '%s' not started yet. Cannot wait it",
 395            rctx->cmd);
 396
 397   /* Wait for the child to die or the timeout to happen (or an armageddon to happen) */
 398   while (!rctx->interrupted && !rctx->reader_done && (rctx->end_time <0 ||rctx->end_time >= now)) {
 399     usleep(100);
 400     now = time(NULL);
 401   }
 402
 403   xbt_os_mutex_lock(rctx->interruption);
 404
 405   if (!rctx->interrupted && rctx->end_time > 0 && rctx->end_time < now) {
 406     INFO1("<%s> timeouted. Kill the process.",rctx->filepos);
 407     rctx->timeout = 1;
 408     kill(rctx->pid,SIGTERM);
 409     usleep(100);
 410     kill(rctx->pid,SIGKILL);
 411     rctx->reader_done = 1;
 412   }
 413
 414   /* Make sure helper threads die.
 415      Cannot block since they wait for the child we just killed
 416      if not already dead. */
 417   xbt_os_thread_join(rctx->writer,NULL);
 418   xbt_os_thread_join(rctx->reader,NULL);
 419
 420   /*  xbt_os_mutex_unlock(rctx->interruption);
 421   if (rctx->interrupted)
 422     return NULL;
 423     xbt_os_mutex_lock(rctx->interruption);*/
 424
 425   buff_chomp(rctx->output_got);
 426   buff_chomp(rctx->output_wanted);
 427   buff_trim(rctx->output_got);
 428   buff_trim(rctx->output_wanted);
 429
 430   /* Check for broken pipe */
 431   if (rctx->brokenpipe)
 432     VERB0("Warning: Child did not consume all its input (I got broken pipe)");
 433
 434   /* Check for timeouts */
 435   if (rctx->timeout) {
 436     if (rctx->output_got->data[0])
 437       INFO2("<%s> Output on timeout:\n%s",
 438             rctx->filepos,rctx->output_got->data);
 439     else
 440       INFO1("<%s> No output before timeout",
 441             rctx->filepos);
 442     ERROR3("Test suite `%s': NOK (<%s> timeout after %d sec)",
 443            testsuite_name,rctx->filepos,timeout_value);
 444     if (!rctx->interrupted)
 445       rctx_armageddon(rctx, 3);
 446   }
 447
 448   DEBUG2("RCTX=%p (pid=%d)",rctx,rctx->pid);
 449   DEBUG3("Status(%s|%d)=%d",rctx->cmd,rctx->pid,rctx->status);
 450
 451   if (!rctx->interrupted) {
 452     if (WIFSIGNALED(rctx->status) && !rctx->expected_signal) {
 453       ERROR3("Test suite `%s': NOK (<%s> got signal %s)",
 454              testsuite_name, rctx->filepos,
 455              signal_name(WTERMSIG(rctx->status),NULL));
 456       errcode = WTERMSIG(rctx->status)+4;
 457     }
 458
 459     if (WIFSIGNALED(rctx->status) && rctx->expected_signal &&
 460         strcmp(signal_name(WTERMSIG(rctx->status),rctx->expected_signal),
 461                rctx->expected_signal)) {
 462       ERROR4("Test suite `%s': NOK (%s got signal %s instead of %s)",
 463              testsuite_name, rctx->filepos,
 464              signal_name(WTERMSIG(rctx->status),rctx->expected_signal),
 465              rctx->expected_signal);
 466       errcode = WTERMSIG(rctx->status)+4;
 467     }
 468
 469     if (!WIFSIGNALED(rctx->status) && rctx->expected_signal) {
 470       ERROR3("Test suite `%s': NOK (child %s expected signal %s)",
 471              testsuite_name, rctx->filepos,
 472              rctx->expected_signal);
 473       errcode = 5;
 474     }
 475
 476     if (WIFEXITED(rctx->status) && WEXITSTATUS(rctx->status) != rctx->expected_return ) {
 477       if (rctx->expected_return)
 478         ERROR4("Test suite `%s': NOK (<%s> returned code %d instead of %d)",
 479                testsuite_name, rctx->filepos,
 480                WEXITSTATUS(rctx->status), rctx->expected_return);
 481       else
 482         ERROR3("Test suite `%s': NOK (<%s> returned code %d)",
 483                testsuite_name, rctx->filepos, WEXITSTATUS(rctx->status));
 484       errcode = 40+WEXITSTATUS(rctx->status);
 485
 486     }
 487     rctx->expected_return = 0;
 488
 489     if(rctx->expected_signal){
 490       free(rctx->expected_signal);
 491       rctx->expected_signal = NULL;
 492     }
 493   }
 494
 495   if (   rctx->output == e_output_check
 496       && (    rctx->output_got->used != rctx->output_wanted->used
 497            || strcmp(rctx->output_got->data, rctx->output_wanted->data))) {
 498     if (XBT_LOG_ISENABLED(tesh,xbt_log_priority_info)) {
 499        char *diff= xbt_str_diff(rctx->output_wanted->data,rctx->output_got->data);
 500        ERROR2("Output of <%s> mismatch:\n%s",rctx->filepos,diff);
 501        free(diff);
 502     }
 503     ERROR2("Test suite `%s': NOK (<%s> output mismatch)",
 504            testsuite_name,rctx->filepos);
 505
 506     errcode=2;
 507   } else if (rctx->output == e_output_ignore) {
 508     INFO1("(ignoring the output of <%s> as requested)",rctx->filepos);
 509   } else if (rctx->output == e_output_display) {
 510     xbt_dynar_t a = xbt_str_split(rctx->output_got->data, "\n");
 511     char *out = xbt_str_join(a,"\n||");
 512     xbt_dynar_free(&a);
 513     INFO1("Here is the (ignored) command output: \n||%s",out);
 514     free(out);
 515   } else if (errcode || rctx->interrupted) {
 516     /* checking output, and matching */
 517     xbt_dynar_t a = xbt_str_split(rctx->output_got->data, "\n");
 518     char *out = xbt_str_join(a,"\n||");
 519     xbt_dynar_free(&a);
 520     INFO2("Output of <%s> so far: \n||%s",rctx->filepos,out);
 521     free(out);
 522   }
 523
 524   if (!rctx->is_background) {
 525     rctx_empty(rctx);
 526   }
 527   if (errcode) {
 528     if (!rctx->interrupted)
 529       rctx_armageddon(rctx, errcode);
 530   }
 531   xbt_os_mutex_unlock(rctx->interruption);
 532
 533   return NULL;
 534 }
 535