ia64/xen-unstable

changeset 18456:dbac9ee4d761

xentrace 7/7: Add option to log to a circular buffer and dump to disk
on signal.

Signed-off-by: George Dunlap <george.dunlap@eu.citrix.com>
Signed-off-by: Trolle Selander <trolle.selander@eu.citrix.com>
author Keir Fraser <keir.fraser@citrix.com>
date Mon Sep 08 16:02:13 2008 +0100 (2008-09-08)
parents b8734df52a90
children bdf648aaa70c
files tools/xentrace/xentrace.c
line diff
     1.1 --- a/tools/xentrace/xentrace.c	Mon Sep 08 16:00:53 2008 +0100
     1.2 +++ b/tools/xentrace/xentrace.c	Mon Sep 08 16:02:13 2008 +0100
     1.3 @@ -56,6 +56,7 @@ typedef struct settings_st {
     1.4      unsigned long tbuf_size;
     1.5      unsigned long disk_rsvd;
     1.6      unsigned long timeout;
     1.7 +    unsigned long memory_buffer;
     1.8      uint8_t discard:1,
     1.9          disable_tracing:1;
    1.10  } settings_t;
    1.11 @@ -67,12 +68,245 @@ int interrupted = 0; /* gets set if we g
    1.12  static int xc_handle = -1;
    1.13  static int event_fd = -1;
    1.14  static int virq_port = -1;
    1.15 +static int outfd = 1;
    1.16  
    1.17  static void close_handler(int signal)
    1.18  {
    1.19      interrupted = 1;
    1.20  }
    1.21  
    1.22 +static struct {
    1.23 +    char * buf;
    1.24 +    unsigned long prod, cons, size;
    1.25 +    unsigned long pending_size, pending_prod;
    1.26 +} membuf = { 0 };
    1.27 +
    1.28 +#define MEMBUF_INDEX_RESET_THRESHOLD (1<<29)
    1.29 +
    1.30 +/* FIXME -- make a power of 2 so we can mask instead. */
    1.31 +#define MEMBUF_POINTER(_i) (membuf.buf + ((_i) % membuf.size))
    1.32 +#define MEMBUF_CONS_INCREMENT(_n)               \
    1.33 +    do {                                        \
    1.34 +        membuf.cons += (_n);                    \
    1.35 +    } while(0)
    1.36 +#define MEMBUF_PROD_SET(_x)                                             \
    1.37 +    do {                                                                \
    1.38 +        if ( (_x) < membuf.prod ) {                                     \
    1.39 +            fprintf(stderr, "%s: INTERNAL_ERROR: prod %lu, trying to set to %lu!\n", \
    1.40 +                    __func__, membuf.prod, (unsigned long)(_x));        \
    1.41 +            exit(1);                                                    \
    1.42 +        }                                                               \
    1.43 +        membuf.prod = (_x);                                             \
    1.44 +        if ( (_x) > MEMBUF_INDEX_RESET_THRESHOLD )                      \
    1.45 +        {                                                               \
    1.46 +            membuf.prod %= membuf.size;                                 \
    1.47 +            membuf.cons %= membuf.size;                                 \
    1.48 +            if( membuf.prod < membuf.cons )                             \
    1.49 +                membuf.prod += membuf.size;                             \
    1.50 +        }                                                               \
    1.51 +    } while(0) 
    1.52 +
    1.53 +struct cpu_change_record {
    1.54 +    uint32_t header;
    1.55 +    struct {
    1.56 +        int cpu;
    1.57 +        unsigned window_size;
    1.58 +    } data;
    1.59 +};
    1.60 +
    1.61 +#define CPU_CHANGE_HEADER                                           \
    1.62 +    (TRC_TRACE_CPU_CHANGE                                           \
    1.63 +     | (((sizeof(struct cpu_change_record)/sizeof(uint32_t)) - 1)   \
    1.64 +        << TRACE_EXTRA_SHIFT) )
    1.65 +
    1.66 +void membuf_alloc(unsigned long size)
    1.67 +{
    1.68 +    membuf.buf = malloc(size);
    1.69 +
    1.70 +    if(!membuf.buf)
    1.71 +    {
    1.72 +        fprintf(stderr, "%s: Couldn't malloc %lu bytes!\n",
    1.73 +                __func__, size);
    1.74 +        exit(1);
    1.75 +    }
    1.76 +
    1.77 +    membuf.prod = membuf.cons = 0;
    1.78 +    membuf.size = size;
    1.79 +}
    1.80 +
    1.81 +/*
    1.82 + * Reserve a new window in the buffer.  Move the 'consumer' forward size
    1.83 + * bytes, re-adjusting the cpu window sizes as necessary, and insert a
    1.84 + * cpu_change record.
    1.85 + */
    1.86 +void membuf_reserve_window(unsigned cpu, unsigned long window_size)
    1.87 +{
    1.88 +    struct cpu_change_record *rec;
    1.89 +    long need_to_consume, free, freed;
    1.90 +
    1.91 +    if ( membuf.pending_size > 0 )
    1.92 +    {
    1.93 +        fprintf(stderr, "%s: INTERNAL_ERROR: pending_size %lu\n",
    1.94 +                __func__, membuf.pending_size);
    1.95 +        exit(1);
    1.96 +    }
    1.97 +
    1.98 +    need_to_consume = window_size + sizeof(*rec);
    1.99 +
   1.100 +    if ( window_size > membuf.size )
   1.101 +    {
   1.102 +        fprintf(stderr, "%s: reserve size %lu larger than buffer size %lu!\n",
   1.103 +                __func__, window_size, membuf.size);
   1.104 +        exit(1);
   1.105 +    }
   1.106 +
   1.107 +    /* Subtract free space already in buffer. */
   1.108 +    free = membuf.size - (membuf.prod - membuf.cons);
   1.109 +    if( need_to_consume < free)
   1.110 +        goto start_window;
   1.111 +
   1.112 +    need_to_consume -= free;
   1.113 +
   1.114 +    /*
   1.115 +     * "Free" up full windows until we have enough for this window.
   1.116 +     * It's a bit wasteful to throw away partial buffers, but the only
   1.117 +     * other option is to scan throught he buffer headers.  Since the
   1.118 +     * common case is that it's going to be thrown away next anyway, I
   1.119 +     * think minimizing the overall impact is more important.
   1.120 +     */
   1.121 +    do {
   1.122 +        rec = (struct cpu_change_record *)MEMBUF_POINTER(membuf.cons);
   1.123 +        if( rec->header != CPU_CHANGE_HEADER )
   1.124 +        {
   1.125 +            fprintf(stderr, "%s: INTERNAL ERROR: no cpu_change record at consumer!\n",
   1.126 +                    __func__);
   1.127 +            exit(EXIT_FAILURE);
   1.128 +        }
   1.129 +
   1.130 +        freed = sizeof(*rec) + rec->data.window_size;
   1.131 +
   1.132 +        if ( need_to_consume > 0 )
   1.133 +        {
   1.134 +            MEMBUF_CONS_INCREMENT(freed);
   1.135 +            need_to_consume -= freed;
   1.136 +        }
   1.137 +    } while( need_to_consume > 0 );
   1.138 +
   1.139 +start_window:
   1.140 +    /*
   1.141 +     * Start writing "pending" data.  Update prod once all this data is
   1.142 +     * written.
   1.143 +     */
   1.144 +    membuf.pending_prod = membuf.prod;
   1.145 +    membuf.pending_size = window_size;
   1.146 +
   1.147 +    rec = (struct cpu_change_record *)MEMBUF_POINTER(membuf.pending_prod);
   1.148 +
   1.149 +    rec->header = CPU_CHANGE_HEADER;
   1.150 +    rec->data.cpu = cpu;
   1.151 +    rec->data.window_size = window_size;
   1.152 +
   1.153 +    membuf.pending_prod += sizeof(*rec);
   1.154 +}
   1.155 +
   1.156 +void membuf_write(void *start, unsigned long size) {
   1.157 +    char * p;
   1.158 +    unsigned long wsize;
   1.159 +
   1.160 +    if( (membuf.size - (membuf.prod - membuf.cons)) < size )
   1.161 +    {
   1.162 +        fprintf(stderr, "%s: INTERNAL ERROR: need %lu bytes, only have %lu!\n",
   1.163 +                __func__, size, membuf.prod - membuf.cons);
   1.164 +        exit(1);
   1.165 +    }
   1.166 +
   1.167 +    if( size > membuf.pending_size )
   1.168 +    {
   1.169 +        fprintf(stderr, "%s: INTERNAL ERROR: size %lu, pending %lu!\n",
   1.170 +                __func__, size, membuf.pending_size);
   1.171 +        exit(1);
   1.172 +    }
   1.173 +
   1.174 +    wsize = size;
   1.175 +    p = MEMBUF_POINTER(membuf.pending_prod);
   1.176 +
   1.177 +    /* If the buffer overlaps the "wrap", do an extra write */
   1.178 +    if ( p + size > membuf.buf + membuf.size )
   1.179 +    {
   1.180 +        int usize = ( membuf.buf + membuf.size ) - p;
   1.181 +
   1.182 +        memcpy(p, start, usize);
   1.183 +
   1.184 +        start += usize;
   1.185 +        wsize -= usize;
   1.186 +        p = membuf.buf;
   1.187 +    }
   1.188 +
   1.189 +    memcpy(p, start, wsize);
   1.190 +
   1.191 +    membuf.pending_prod += size;
   1.192 +    membuf.pending_size -= size;
   1.193 +
   1.194 +    if ( membuf.pending_size == 0 )
   1.195 +    {
   1.196 +        MEMBUF_PROD_SET(membuf.pending_prod);
   1.197 +    }
   1.198 +}
   1.199 +
   1.200 +void membuf_dump(void) {
   1.201 +    /* Dump circular memory buffer */
   1.202 +    int cons, prod, wsize, written;
   1.203 +    char * wstart;
   1.204 +
   1.205 +    fprintf(stderr, "Dumping memory buffer.\n");
   1.206 +
   1.207 +    cons = membuf.cons % membuf.size; 
   1.208 +    prod = membuf.prod % membuf.size;
   1.209 +   
   1.210 +    if(prod > cons)
   1.211 +    {
   1.212 +        /* Write in one go */
   1.213 +        wstart = membuf.buf + cons;
   1.214 +        wsize = prod - cons;
   1.215 +
   1.216 +        written = write(outfd, wstart, wsize);
   1.217 +        if ( written != wsize )
   1.218 +            goto fail;
   1.219 +    }
   1.220 +    else
   1.221 +    {
   1.222 +        /* Write in two pieces: cons->end, beginning->prod. */
   1.223 +        wstart = membuf.buf + cons;
   1.224 +        wsize = membuf.size - cons;
   1.225 +
   1.226 +        written = write(outfd, wstart, wsize);
   1.227 +        if ( written != wsize )
   1.228 +        {
   1.229 +            fprintf(stderr, "Write failed! (size %d, returned %d)\n",
   1.230 +                    wsize, written);
   1.231 +            goto fail;
   1.232 +        }
   1.233 +
   1.234 +        wstart = membuf.buf;
   1.235 +        wsize = prod;
   1.236 +
   1.237 +        written = write(outfd, wstart, wsize);
   1.238 +        if ( written != wsize )
   1.239 +        {
   1.240 +            fprintf(stderr, "Write failed! (size %d, returned %d)\n",
   1.241 +                    wsize, written);
   1.242 +            goto fail;
   1.243 +        }
   1.244 +    }
   1.245 +
   1.246 +    membuf.cons = membuf.prod = 0;
   1.247 +    
   1.248 +    return;
   1.249 +fail:
   1.250 +    exit(1);
   1.251 +    return;
   1.252 +}
   1.253 +
   1.254  /**
   1.255   * write_buffer - write a section of the trace buffer
   1.256   * @cpu      - source buffer CPU ID
   1.257 @@ -85,20 +319,20 @@ static void close_handler(int signal)
   1.258   * of the buffer write.
   1.259   */
   1.260  static void write_buffer(unsigned int cpu, unsigned char *start, int size,
   1.261 -               int total_size, int outfd)
   1.262 +                         int total_size)
   1.263  {
   1.264      struct statvfs stat;
   1.265      size_t written = 0;
   1.266      
   1.267 -    if ( opts.disk_rsvd != 0 )
   1.268 +    if ( opts.memory_buffer == 0 && opts.disk_rsvd != 0 )
   1.269      {
   1.270          unsigned long long freespace;
   1.271  
   1.272          /* Check that filesystem has enough space. */
   1.273          if ( fstatvfs (outfd, &stat) )
   1.274          {
   1.275 -                fprintf(stderr, "Statfs failed!\n");
   1.276 -                goto fail;
   1.277 +            fprintf(stderr, "Statfs failed!\n");
   1.278 +            goto fail;
   1.279          }
   1.280  
   1.281          freespace = stat.f_frsize * (unsigned long long)stat.f_bfree;
   1.282 @@ -112,8 +346,8 @@ static void write_buffer(unsigned int cp
   1.283  
   1.284          if ( freespace <= opts.disk_rsvd )
   1.285          {
   1.286 -                fprintf(stderr, "Disk space limit reached (free space: %lluMB, limit: %luMB).\n", freespace, opts.disk_rsvd);
   1.287 -                exit (EXIT_FAILURE);
   1.288 +            fprintf(stderr, "Disk space limit reached (free space: %lluMB, limit: %luMB).\n", freespace, opts.disk_rsvd);
   1.289 +            exit (EXIT_FAILURE);
   1.290          }
   1.291      }
   1.292  
   1.293 @@ -122,40 +356,46 @@ static void write_buffer(unsigned int cp
   1.294       * first write. */
   1.295      if ( total_size != 0 )
   1.296      {
   1.297 -        struct {
   1.298 -            uint32_t header;
   1.299 -            struct {
   1.300 -                unsigned cpu;
   1.301 -                unsigned byte_count;
   1.302 -            } extra;
   1.303 -        } rec;
   1.304 +        if ( opts.memory_buffer )
   1.305 +        {
   1.306 +            membuf_reserve_window(cpu, total_size);
   1.307 +        }
   1.308 +        else
   1.309 +        {
   1.310 +            struct cpu_change_record rec;
   1.311  
   1.312 -        rec.header = TRC_TRACE_CPU_CHANGE
   1.313 -            | ((sizeof(rec.extra)/sizeof(uint32_t)) << TRACE_EXTRA_SHIFT);
   1.314 -        rec.extra.cpu = cpu;
   1.315 -        rec.extra.byte_count = total_size;
   1.316 +            rec.header = CPU_CHANGE_HEADER;
   1.317 +            rec.data.cpu = cpu;
   1.318 +            rec.data.window_size = total_size;
   1.319  
   1.320 -        written = write(outfd, &rec, sizeof(rec));
   1.321 +            written = write(outfd, &rec, sizeof(rec));
   1.322 +            if ( written != sizeof(rec) )
   1.323 +            {
   1.324 +                fprintf(stderr, "Cannot write cpu change (write returned %zd)\n",
   1.325 +                        written);
   1.326 +                goto fail;
   1.327 +            }
   1.328 +        }
   1.329 +    }
   1.330  
   1.331 -        if ( written != sizeof(rec) )
   1.332 +    if ( opts.memory_buffer )
   1.333 +    {
   1.334 +        membuf_write(start, size);
   1.335 +    }
   1.336 +    else
   1.337 +    {
   1.338 +        written = write(outfd, start, size);
   1.339 +        if ( written != size )
   1.340          {
   1.341 -            fprintf(stderr, "Cannot write cpu change (write returned %zd)\n",
   1.342 -                    written);
   1.343 +            fprintf(stderr, "Write failed! (size %d, returned %zd)\n",
   1.344 +                    size, written);
   1.345              goto fail;
   1.346          }
   1.347      }
   1.348  
   1.349 -    written = write(outfd, start, size);
   1.350 -    if ( written != size )
   1.351 -    {
   1.352 -        fprintf(stderr, "Write failed! (size %d, returned %zd)\n",
   1.353 -                size, written);
   1.354 -        goto fail;
   1.355 -    }
   1.356 -
   1.357      return;
   1.358  
   1.359 - fail:
   1.360 +fail:
   1.361      PERROR("Failed to write trace data");
   1.362      exit(EXIT_FAILURE);
   1.363  }
   1.364 @@ -394,7 +634,7 @@ static void wait_for_event_or_timeout(un
   1.365   * monitor_tbufs - monitor the contents of tbufs and output to a file
   1.366   * @logfile:       the FILE * representing the file to log to
   1.367   */
   1.368 -static int monitor_tbufs(int outfd)
   1.369 +static int monitor_tbufs(void)
   1.370  {
   1.371      int i;
   1.372  
   1.373 @@ -429,9 +669,9 @@ static int monitor_tbufs(int outfd)
   1.374              meta[i]->cons = meta[i]->prod;
   1.375  
   1.376      /* now, scan buffers for events */
   1.377 -    while ( !interrupted )
   1.378 +    while ( 1 )
   1.379      {
   1.380 -        for ( i = 0; (i < num) && !interrupted; i++ )
   1.381 +        for ( i = 0; i < num; i++ )
   1.382          {
   1.383              unsigned long start_offset, end_offset, window_size, cons, prod;
   1.384                  
   1.385 @@ -463,8 +703,7 @@ static int monitor_tbufs(int outfd)
   1.386                  /* If window does not wrap, write in one big chunk */
   1.387                  write_buffer(i, data[i]+start_offset,
   1.388                               window_size,
   1.389 -                             window_size,
   1.390 -                             outfd);
   1.391 +                             window_size);
   1.392              }
   1.393              else
   1.394              {
   1.395 @@ -474,24 +713,29 @@ static int monitor_tbufs(int outfd)
   1.396                   */
   1.397                  write_buffer(i, data[i] + start_offset,
   1.398                               data_size - start_offset,
   1.399 -                             window_size,
   1.400 -                             outfd);
   1.401 +                             window_size);
   1.402                  write_buffer(i, data[i],
   1.403                               end_offset,
   1.404 -                             0,
   1.405 -                             outfd);
   1.406 +                             0);
   1.407              }
   1.408  
   1.409              xen_mb(); /* read buffer, then update cons. */
   1.410              meta[i]->cons = prod;
   1.411 +
   1.412          }
   1.413  
   1.414 +        if ( interrupted )
   1.415 +            break;
   1.416 +
   1.417          wait_for_event_or_timeout(opts.poll_sleep);
   1.418      }
   1.419  
   1.420 -    if(opts.disable_tracing)
   1.421 +    if ( opts.disable_tracing )
   1.422          disable_tbufs();
   1.423  
   1.424 +    if ( opts.memory_buffer )
   1.425 +        membuf_dump();
   1.426 +
   1.427      /* cleanup */
   1.428      free(meta);
   1.429      free(data);
   1.430 @@ -538,6 +782,8 @@ static void usage(void)
   1.431  "  -T  --time-interval=s   Run xentrace for s seconds and quit.\n" \
   1.432  "  -?, --help              Show this message\n" \
   1.433  "  -V, --version           Print program version\n" \
   1.434 +"  -M, --memory-buffer=b   Copy trace records to a circular memory buffer.\n" \
   1.435 +"                          Dump to file on exit.\n" \
   1.436  "\n" \
   1.437  "This tool is used to capture trace buffer data from Xen. The\n" \
   1.438  "data is output in a binary format, in the following order:\n" \
   1.439 @@ -553,6 +799,53 @@ static void usage(void)
   1.440      exit(EXIT_FAILURE);
   1.441  }
   1.442  
   1.443 +/* convert the argument string pointed to by arg to a long int representation,
   1.444 + * including suffixes such as 'M' and 'k'. */
   1.445 +#define MB (1024*1024)
   1.446 +#define KB (1024)
   1.447 +long sargtol(const char *restrict arg, int base)
   1.448 +{
   1.449 +    char *endp;
   1.450 +    long val;
   1.451 +
   1.452 +    errno = 0;
   1.453 +    val = strtol(arg, &endp, base);
   1.454 +    
   1.455 +    if ( errno != 0 )
   1.456 +    {
   1.457 +        fprintf(stderr, "Invalid option argument: %s\n", arg);
   1.458 +        fprintf(stderr, "Error: %s\n\n", strerror(errno));
   1.459 +        usage();
   1.460 +    }
   1.461 +    else if (endp == arg)
   1.462 +    {
   1.463 +        goto invalid;
   1.464 +    }
   1.465 +
   1.466 +    switch(*endp)
   1.467 +    {
   1.468 +    case '\0':
   1.469 +        break;
   1.470 +    case 'M':
   1.471 +        val *= MB;
   1.472 +        break;
   1.473 +    case 'K':
   1.474 +    case 'k':
   1.475 +        val *= KB;
   1.476 +        break;
   1.477 +    default:
   1.478 +        fprintf(stderr, "Unknown suffix %c\n", *endp);
   1.479 +        exit(1);
   1.480 +    }
   1.481 +
   1.482 +
   1.483 +    return val;
   1.484 +invalid:
   1.485 +    return 0;
   1.486 +    fprintf(stderr, "Invalid option argument: %s\n\n", arg);
   1.487 +    usage();
   1.488 +}
   1.489 +
   1.490  /* convert the argument string pointed to by arg to a long int representation */
   1.491  static long argtol(const char *restrict arg, int base)
   1.492  {
   1.493 @@ -606,6 +899,7 @@ static void parse_args(int argc, char **
   1.494          { "trace-buf-size", required_argument, 0, 'S' },
   1.495          { "reserve-disk-space", required_argument, 0, 'r' },
   1.496          { "time-interval",  required_argument, 0, 'T' },
   1.497 +        { "memory-buffer",  required_argument, 0, 'M' },
   1.498          { "discard-buffers", no_argument,      0, 'D' },
   1.499          { "dont-disable-tracing", no_argument, 0, 'x' },
   1.500          { "help",           no_argument,       0, '?' },
   1.501 @@ -613,7 +907,7 @@ static void parse_args(int argc, char **
   1.502          { 0, 0, 0, 0 }
   1.503      };
   1.504  
   1.505 -    while ( (option = getopt_long(argc, argv, "t:s:c:e:S:r:T:Dx?V",
   1.506 +    while ( (option = getopt_long(argc, argv, "t:s:c:e:S:r:T:M:Dx?V",
   1.507                      long_options, NULL)) != -1) 
   1.508      {
   1.509          switch ( option )
   1.510 @@ -655,6 +949,10 @@ static void parse_args(int argc, char **
   1.511              opts.timeout = argtol(optarg, 0);
   1.512              break;
   1.513  
   1.514 +        case 'M':
   1.515 +            opts.memory_buffer = sargtol(optarg, 0);
   1.516 +            break;
   1.517 +
   1.518          default:
   1.519              usage();
   1.520          }
   1.521 @@ -674,7 +972,7 @@ static void parse_args(int argc, char **
   1.522  
   1.523  int main(int argc, char **argv)
   1.524  {
   1.525 -    int outfd = 1, ret;
   1.526 +    int ret;
   1.527      struct sigaction act;
   1.528  
   1.529      opts.outfile = 0;
   1.530 @@ -720,6 +1018,9 @@ int main(int argc, char **argv)
   1.531          exit(EXIT_FAILURE);
   1.532      }
   1.533  
   1.534 +    if ( opts.memory_buffer > 0 )
   1.535 +        membuf_alloc(opts.memory_buffer);
   1.536 +
   1.537      /* ensure that if we get a signal, we'll do cleanup, then exit */
   1.538      act.sa_handler = close_handler;
   1.539      act.sa_flags = 0;
   1.540 @@ -729,7 +1030,7 @@ int main(int argc, char **argv)
   1.541      sigaction(SIGINT,  &act, NULL);
   1.542      sigaction(SIGALRM, &act, NULL);
   1.543  
   1.544 -    ret = monitor_tbufs(outfd);
   1.545 +    ret = monitor_tbufs();
   1.546  
   1.547      return ret;
   1.548  }