ia64/xen-unstable
changeset 1113:143fb3c2e3b5
bitkeeper revision 1.741 (403a3ee3r3VblO5vtoFGItOp9rvEpg)
Add Xen trace buffer and supporting tools.
Add Xen trace buffer and supporting tools.
author | mwilli2@equilibrium.research.intel-research.net |
---|---|
date | Mon Feb 23 17:56:51 2004 +0000 (2004-02-23) |
parents | dbdb7faab4c9 |
children | bc02f2f73b0e |
files | .rootkeys tools/Makefile tools/xentrace/Makefile tools/xentrace/xentrace.c tools/xentrace/xentrace_cpusplit.py tools/xentrace/xentrace_format.py xen/arch/i386/setup.c xen/common/dom0_ops.c xen/common/trace.c xen/include/hypervisor-ifs/dom0_ops.h xen/include/xeno/config.h xen/include/xeno/trace.h |
line diff
1.1 --- a/.rootkeys Mon Feb 23 15:55:27 2004 +0000 1.2 +++ b/.rootkeys Mon Feb 23 17:56:51 2004 +0000 1.3 @@ -86,6 +86,10 @@ 3fbd0a3dTwnDcfdw0-v46dPbX98zDw tools/xc/ 1.4 3fbd0a42l40lM0IICw2jXbQBVZSdZg tools/xc/py/Xc.c 1.5 3fbd4bd6GtGwZGxYUJPOheYIR7bPaA tools/xc/py/XenoUtil.py 1.6 3fbd0a40yT6G3M9hMpaz5xTUdl0E4g tools/xc/py/setup.py 1.7 +403a3edbrr8RE34gkbR40zep98SXbg tools/xentrace/Makefile 1.8 +403a3edbVpV2E_wq1zeEkJ_n4Uu2eg tools/xentrace/xentrace.c 1.9 +403a3edb0lzD0Fojc-NYNoXr3SYrnA tools/xentrace/xentrace_cpusplit.py 1.10 +403a3edblCUrzSj0mmKhO5HOPrOrSQ tools/xentrace/xentrace_format.py 1.11 3f72f1bdJPsV3JCnBqs9ddL9tr6D2g xen/COPYING 1.12 3ddb79bcbOVHh38VJzc97-JEGD4dJQ xen/Makefile 1.13 3ddb79bcWnTwYsQRWl_PaneJfa6p0w xen/Rules.mk 1.14 @@ -150,6 +154,7 @@ 3ddb79bdB9RNMnkQnUyZ5C9hhMSQQw xen/commo 1.15 3ddb79bd0gVQYmL2zvuJnldvD0AGxQ xen/common/softirq.c 1.16 3e7f358awXBC3Vw-wFRwPw18qL1khg xen/common/string.c 1.17 3ddb79bdQqFHtHRGEO2dsxGgo6eAhw xen/common/timer.c 1.18 +403a3edbejm33XLTGMuinKEwQBrOIg xen/common/trace.c 1.19 3ddb79bd3zgV33PHdt-cgh3sxcb1hw xen/common/vsprintf.c 1.20 3ddb79c0ppNeJtjC4va8j41ADCnchA xen/drivers/Makefile 1.21 3ddb79beWzgPS8ozf2BL2g3ZkiWhhQ xen/drivers/block/Makefile 1.22 @@ -491,6 +496,7 @@ 3ddb79c0BnA20PbgmuMPSGIBljNRQw xen/inclu 1.23 3ddb79c2HFkXuRxi1CriJtSFmY6Ybw xen/include/xeno/timer.h 1.24 3ddb79c2_m8lT9jDKse_tePj7zcnNQ xen/include/xeno/timex.h 1.25 3ddb79c2e2C14HkndNEJlYwXaPrF5A xen/include/xeno/tqueue.h 1.26 +403a3edbG9K5uZjuY19_LORbQGmFbA xen/include/xeno/trace.h 1.27 3ddb79c1-kVvF8cVa0k3ZHDdBMj01Q xen/include/xeno/types.h 1.28 3f055a3dwldYR102YcSuBaxIf9t3Jw xen/include/xeno/vbd.h 1.29 3e8827bdaqPeZAWGVOwswgY9bWSx4g xen/include/xeno/version.h
2.1 --- a/tools/Makefile Mon Feb 23 15:55:27 2004 +0000 2.2 +++ b/tools/Makefile Mon Feb 23 17:56:51 2004 +0000 2.3 @@ -22,18 +22,21 @@ all: 2.4 $(MAKE) -C xc 2.5 $(MAKE) -C misc 2.6 $(MAKE) -C examples 2.7 + $(MAKE) -C xentrace 2.8 2.9 install: all 2.10 $(MAKE) -C balloon install 2.11 $(MAKE) -C xc install 2.12 $(MAKE) -C misc install 2.13 $(MAKE) -C examples install 2.14 + $(MAKE) -C xentrace install 2.15 2.16 dist: all 2.17 $(MAKE) -C balloon dist 2.18 $(MAKE) -C xc dist 2.19 $(MAKE) -C misc dist 2.20 $(MAKE) -C examples dist 2.21 + $(MAKE) -C xentrace dist 2.22 2.23 clean: 2.24 $(MAKE) -C balloon clean 2.25 @@ -41,4 +44,5 @@ clean: 2.26 $(MAKE) -C misc clean 2.27 $(MAKE) -C examples clean 2.28 $(MAKE) -C nsplitd clean 2.29 + $(MAKE) -C xentrace clean 2.30
3.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 3.2 +++ b/tools/xentrace/Makefile Mon Feb 23 17:56:51 2004 +0000 3.3 @@ -0,0 +1,32 @@ 3.4 + 3.5 +CC = gcc 3.6 +CFLAGS = -Wall -O3 3.7 +CFLAGS += -I../../xen/include -I../../xenolinux-sparse/include 3.8 + 3.9 +HDRS = $(wildcard *.h) 3.10 +OBJS = $(patsubst %.c,%.o,$(wildcard *.c)) 3.11 + 3.12 +BIN = xentrace 3.13 +SCRIPTS = $(wildcard *.py) 3.14 + 3.15 +all: $(BIN) 3.16 + 3.17 +install: all 3.18 + mkdir -p /usr/bin 3.19 + cp $(BIN) /usr/bin 3.20 + cp $(SCRIPTS) /usr/bin 3.21 + chmod 755 /usr/bin/$(BIN) 3.22 + for i in $(SCRIPTS); do chmod 755 /usr/bin/$$i; done 3.23 + 3.24 +dist: all 3.25 + mkdir -p ../../../install/bin 3.26 + cp $(BIN) ../../../install/bin 3.27 + chmod 755 ../../../install/bin/$(BIN) 3.28 + cp $(SCRIPTS) ../../../install/bin 3.29 + for i in $(SCRIPTS); do chmod 755 ../../../install/bin/$i; done 3.30 + 3.31 +clean: 3.32 + $(RM) *.a *.so *.o *.rpm $(BIN) 3.33 + 3.34 +%: %.c $(HDRS) Makefile 3.35 + $(CC) $(CFLAGS) -o $@ $< -lxc
4.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 4.2 +++ b/tools/xentrace/xentrace.c Mon Feb 23 17:56:51 2004 +0000 4.3 @@ -0,0 +1,428 @@ 4.4 +/****************************************************************************** 4.5 + * 4.6 + * tools/xentrace/xentrace.c 4.7 + * 4.8 + * Tool for collecting trace buffer data from Xen. 4.9 + * 4.10 + * Copyright (C) 2004 by Intel Research Cambridge 4.11 + * 4.12 + * Author: Mark Williamson, mark.a.williamson@intel.com 4.13 + * Date: February 2004 4.14 + * 4.15 + *****************************************************************************/ 4.16 + 4.17 +#include <time.h> 4.18 +#include <stdlib.h> 4.19 +#include <sys/mman.h> 4.20 +#include <stdio.h> 4.21 +#include <sys/types.h> 4.22 +#include <sys/stat.h> 4.23 +#include <fcntl.h> 4.24 +#include <unistd.h> 4.25 +#include <errno.h> 4.26 +#include <argp.h> 4.27 +#include <signal.h> 4.28 + 4.29 +#include "../xc/lib/xc_private.h" 4.30 + 4.31 +#define TRACE_BUFFER /* need to define this for trace.h */ 4.32 +#include <xeno/trace.h> 4.33 + 4.34 +extern FILE *stdout; 4.35 + 4.36 +/***** Compile time configuration of defaults ********************************/ 4.37 + 4.38 +#define NUM_CPUS 1 /* XXX this ought to be removed and replaced with something 4.39 + * cleverer to dynamically query the machine - I'll use a 4.40 + * dom0 op once I've implemented it! :-) */ 4.41 + 4.42 +/* when we've got more records than this waiting, we log it to the output */ 4.43 +#define NEW_DATA_THRESH 1 4.44 + 4.45 +/* sleep for this long (milliseconds) between checking the trace buffers */ 4.46 +#define POLL_SLEEP_MILLIS 100 4.47 + 4.48 +/***** The code **************************************************************/ 4.49 + 4.50 +typedef struct settings_st { 4.51 + char *outfile; 4.52 + unsigned int num_cpus; 4.53 + struct timespec poll_sleep; 4.54 + unsigned long new_data_thresh; 4.55 +} settings_t; 4.56 + 4.57 +settings_t opts; 4.58 + 4.59 +int interrupted = 0; /* gets set if we get a SIGHUP */ 4.60 + 4.61 +void close_handler(int signal) 4.62 +{ 4.63 + interrupted = 1; 4.64 + fprintf(stderr,"Received signal %d, now exiting\n", signal); 4.65 +} 4.66 + 4.67 +/** 4.68 + * millis_to_timespec - convert a time in milliseconds to a struct timespec 4.69 + * @millis: time interval in milliseconds 4.70 + */ 4.71 +struct timespec millis_to_timespec(unsigned long millis) 4.72 +{ 4.73 + struct timespec spec; 4.74 + 4.75 + spec.tv_sec = millis / 1000; 4.76 + spec.tv_nsec = (millis % 1000) * 1000; 4.77 + 4.78 + return spec; 4.79 +} 4.80 + 4.81 + 4.82 +/** 4.83 + * print_rec - plain print an event given a pointer to its start 4.84 + * @cpu: CPU the data came from 4.85 + * @data: pointer to the start of the event data 4.86 + * @out: file stream to print out to 4.87 + * 4.88 + * Takes a pointer to a record and prints out the data. 4.89 + */ 4.90 +void print_rec(unsigned int cpu, struct t_rec *rec, FILE *out) 4.91 +{ 4.92 + fprintf(out, "%u %llu %lu %lu %lu %lu %lu %lu\n", 4.93 + cpu, rec->cycles, rec->event, rec->d1, rec->d2, 4.94 + rec->d3, rec->d4, rec->d5); 4.95 +} 4.96 + 4.97 + 4.98 +/** 4.99 + * get_tbuf_ptrs - get pointer to trace buffers 4.100 + * 4.101 + * Does a dom0 op to fetch a "pointer" to the trace buffers. The pointer can't 4.102 + * be dereferenced immediately, since it is a physical address of memory in Xen 4.103 + * space - they are used in this program to mmap the right area from /dev/mem. 4.104 + */ 4.105 +struct t_buf *get_tbuf_ptrs() 4.106 +{ 4.107 + int ret; 4.108 + dom0_op_t op; /* dom0 op we'll build */ 4.109 + int xc_handle = xc_interface_open(); /* for accessing control interface */ 4.110 + 4.111 + op.cmd = DOM0_GETTBUFS; 4.112 + op.interface_version = DOM0_INTERFACE_VERSION; 4.113 + 4.114 + ret = do_dom0_op(xc_handle, &op); 4.115 + 4.116 + xc_interface_close(xc_handle); 4.117 + 4.118 + if(ret) { 4.119 + PERROR("Failure to get trace buffer pointer from Xen"); 4.120 + exit(EXIT_FAILURE); 4.121 + } 4.122 + 4.123 + return op.u.gettbufs.phys_addr; 4.124 +} 4.125 + 4.126 +/** 4.127 + * map_tbufs - memory map Xen trace buffers into user space 4.128 + * @tbufs: physical address of the trace buffers 4.129 + * 4.130 + * Given the physical address of the Xen trace buffers, maps them into process 4.131 + * address space by memory mapping /dev/mem. Returns a pointer to the location 4.132 + * the buffers have been mapped to. 4.133 + */ 4.134 +struct t_buf *map_tbufs(struct t_buf *tbufs_phys) 4.135 +{ 4.136 + int dm_fd; /* file descriptor for /dev/mem */ 4.137 + struct t_buf *tbufs_mapped; 4.138 + 4.139 + dm_fd = open("/dev/mem", O_RDONLY); 4.140 + 4.141 + if(dm_fd < 0) { 4.142 + PERROR("Open /dev/mem when mapping trace buffers\n"); 4.143 + exit(EXIT_FAILURE); 4.144 + } 4.145 + 4.146 + tbufs_mapped = (struct t_buf *)mmap(NULL, opts.num_cpus * TB_SIZE, 4.147 + PROT_READ, MAP_SHARED, 4.148 + dm_fd, (off_t)tbufs_phys); 4.149 + 4.150 + close(dm_fd); 4.151 + 4.152 + if(tbufs_mapped == MAP_FAILED) { 4.153 + PERROR("Failed to mmap trace buffers"); 4.154 + exit(EXIT_FAILURE); 4.155 + } 4.156 + 4.157 + return tbufs_mapped; 4.158 +} 4.159 + 4.160 + 4.161 +/** 4.162 + * init_bufs_ptrs - initialises an array of pointers to the trace buffers 4.163 + * @bufs_mapped: the userspace address where the trace buffers are mapped 4.164 + * 4.165 + * Initialises an array of pointers to individual trace buffers within the 4.166 + * mapped region containing all trace buffers. 4.167 + */ 4.168 +struct t_buf **init_bufs_ptrs(void *bufs_mapped) 4.169 +{ 4.170 + int i; 4.171 + struct t_buf **user_ptrs; 4.172 + 4.173 + user_ptrs = (struct t_buf **)calloc(opts.num_cpus, sizeof(struct t_buf *)); 4.174 + 4.175 + if(!user_ptrs) { 4.176 + PERROR( "Failed to allocate memory for buffer pointers\n"); 4.177 + exit(EXIT_FAILURE); 4.178 + } 4.179 + 4.180 + /* initialise pointers to the trace buffers - given the size of a trace 4.181 + * buffer and the value of bufs_maped, we can easily calculate these */ 4.182 + for(i = 0; i<opts.num_cpus; i++) 4.183 + user_ptrs[i] = (struct t_buf *)( 4.184 + (unsigned long)bufs_mapped + TB_SIZE * i); 4.185 + 4.186 + return user_ptrs; 4.187 +} 4.188 + 4.189 + 4.190 +/** 4.191 + * init_rec_ptrs - initialises data area pointers to locations in user space 4.192 + * @tbufs_phys: physical base address of the trace buffer area 4.193 + * @tbufs_mapped: user virtual address of base of trace buffer area 4.194 + * @meta: array of user-space pointers to struct t_buf's of metadata 4.195 + * 4.196 + * Initialises data area pointers to the locations that data areas have been 4.197 + * mapped in user space. Note that the trace buffer metadata contains physical 4.198 + * pointers - the array returned allows more convenient access to them. 4.199 + */ 4.200 +struct t_rec **init_rec_ptrs(struct t_buf *tbufs_phys, 4.201 + struct t_buf *tbufs_mapped, 4.202 + struct t_buf **meta) 4.203 +{ 4.204 + int i; 4.205 + struct t_rec **data; 4.206 + 4.207 + data = calloc(opts.num_cpus, sizeof(struct t_rec *)); 4.208 + 4.209 + if(!data) { 4.210 + PERROR( "Failed to allocate memory for data pointers\n"); 4.211 + exit(EXIT_FAILURE); 4.212 + } 4.213 + 4.214 + for(i = 0; i<opts.num_cpus; i++) { 4.215 + data[i] = (struct t_rec *)( 4.216 + (unsigned long)meta[i]->data 4.217 + - (unsigned long)tbufs_phys 4.218 + + (unsigned long)tbufs_mapped 4.219 + ); 4.220 + } 4.221 + 4.222 + return data; 4.223 +} 4.224 + 4.225 +/** 4.226 + * init_tail_idxs - initialise an array of tail indexes 4.227 + * @bufs: array of pointers to trace buffer metadata in struct t_buf's 4.228 + * 4.229 + * The tail indexes indicate where we're read to so far in the data array of a 4.230 + * trace buffer. Each entry in this table corresponds to the tail index for a 4.231 + * particular trace buffer. 4.232 + */ 4.233 +int *init_tail_idxs(struct t_buf **bufs) 4.234 +{ 4.235 + int i; 4.236 + int *tails = calloc(opts.num_cpus, sizeof(unsigned int)); 4.237 + 4.238 + if(!tails) { 4.239 + PERROR("Failed to allocate memory for tail pointers\n"); 4.240 + exit(EXIT_FAILURE); 4.241 + } 4.242 + 4.243 + for(i = 0; i<opts.num_cpus; i++) 4.244 + tails[i] = bufs[i]->head; 4.245 + 4.246 + return tails; 4.247 +} 4.248 + 4.249 + 4.250 +/** 4.251 + * monitor_tbufs - monitor the contents of tbufs and output to a file 4.252 + * @logfile: the FILE * representing the file to log to 4.253 + */ 4.254 +int monitor_tbufs(FILE *logfile) 4.255 +{ 4.256 + int i, j; 4.257 + void *tbufs_mapped; /* pointer to where the tbufs are mapped */ 4.258 + struct t_buf **meta; /* pointers to the trace buffer metadata */ 4.259 + struct t_rec **data; /* pointers to the trace buffer data areas 4.260 + * where they are mapped into user space. */ 4.261 + int *tails; /* store tail indexes for the trace buffers */ 4.262 + struct t_buf *tbufs_phys; /* physical address of the tbufs */ 4.263 + 4.264 + /* setup access to trace buffers */ 4.265 + tbufs_phys = get_tbuf_ptrs(); 4.266 + tbufs_mapped = map_tbufs(tbufs_phys); 4.267 + 4.268 + /* build arrays of convenience ptrs */ 4.269 + meta = init_bufs_ptrs (tbufs_mapped); 4.270 + data = init_rec_ptrs (tbufs_phys, tbufs_mapped, meta); 4.271 + tails = init_tail_idxs (meta); 4.272 + 4.273 + /* now, scan buffers for events */ 4.274 + while(!interrupted) { 4.275 + for(i = 0; i < opts.num_cpus; i++) { 4.276 + signed long newdata = meta[i]->head - tails[i]; 4.277 + signed long prewrap = newdata; 4.278 + 4.279 + /* correct newdata and prewrap in case of a pointer wrap */ 4.280 + if(newdata < 0) { 4.281 + newdata += meta[i]->size; 4.282 + prewrap = meta[i]->size - tails[i]; 4.283 + } 4.284 + 4.285 + if(newdata >= opts.new_data_thresh) { 4.286 + /* output pre-wrap data */ 4.287 + for(j = 0; j < prewrap; j++) 4.288 + print_rec(i, data[i] + tails[i] + j, logfile); 4.289 + 4.290 + /* output post-wrap data, if any */ 4.291 + for(j = 0; j < (newdata - prewrap); j++) 4.292 + print_rec(i, data[i] + j, logfile); 4.293 + 4.294 + tails[i] += newdata; 4.295 + if(tails[i] >= meta[i]->size) tails[i] = 0; 4.296 + } 4.297 + } 4.298 + nanosleep(&opts.poll_sleep, NULL); 4.299 + } 4.300 + 4.301 + /* cleanup */ 4.302 + free(meta); 4.303 + free(data); 4.304 + free(tails); 4.305 + /* don't need to munmap - cleanup is automatic */ 4.306 + fclose(logfile); 4.307 + 4.308 + return 0; 4.309 +} 4.310 + 4.311 + 4.312 +/****************************************************************************** 4.313 + * Various declarations / definitions GNU argp needs to do its work 4.314 + *****************************************************************************/ 4.315 + 4.316 + 4.317 +/* command parser for GNU argp - see GNU docs for more info */ 4.318 +error_t cmd_parser(int key, char *arg, struct argp_state *state) 4.319 +{ 4.320 + settings_t *setup = (settings_t *)state->input; 4.321 + 4.322 + switch(key) 4.323 + { 4.324 + case 't': /* set new records threshold for logging */ 4.325 + { 4.326 + char *inval; 4.327 + setup->new_data_thresh = strtol(arg, &inval, 0); 4.328 + if(inval == arg) argp_usage(state); 4.329 + } 4.330 + 4.331 + break; 4.332 + 4.333 + case 's': /* set sleep time (given in milliseconds) */ 4.334 + { 4.335 + char *inval; 4.336 + setup->poll_sleep = millis_to_timespec(strtol(arg, &inval, 0)); 4.337 + if(inval == arg) argp_usage(state); 4.338 + } 4.339 + break; 4.340 + 4.341 + case 'n': /* set number of CPU trace buffers to map */ 4.342 + { 4.343 + char *inval; 4.344 + setup->num_cpus = strtol(arg, &inval, 0); 4.345 + if(inval == arg) argp_usage(state); 4.346 + } 4.347 + break; 4.348 + 4.349 + case ARGP_KEY_ARG: 4.350 + if(state->arg_num == 0) 4.351 + setup->outfile = arg; 4.352 + else 4.353 + argp_usage(state); 4.354 + break; 4.355 + 4.356 + default: 4.357 + return ARGP_ERR_UNKNOWN; 4.358 + } 4.359 + 4.360 + return 0; 4.361 +} 4.362 + 4.363 +#define xstr(x) str(x) 4.364 +#define str(x) #x 4.365 + 4.366 +const struct argp_option cmd_opts[] = 4.367 +{ 4.368 + { .name = "log-thresh", .key='t', .arg="l", 4.369 + .doc = 4.370 + "Set number, l, of new records required to trigger a write to output " 4.371 + "(default " xstr(NEW_DATA_THRESH) ")." }, 4.372 + 4.373 + { .name = "poll-sleep", .key='s', .arg="p", 4.374 + .doc = 4.375 + "Set sleep time, p, in milliseconds between polling the trace buffer " 4.376 + "for new data (default " xstr(POLL_SLEEP_MILLIS) ")." }, 4.377 + 4.378 + { .name = "num-cpus", .key = 'n', .arg="i", 4.379 + .doc = 4.380 + "Set number, i, of CPU trace buffers to map. This should not exceed " 4.381 + "the number of CPUs in the system (default " xstr(NUM_CPUS) ")." }, 4.382 + 4.383 + {0} 4.384 +}; 4.385 + 4.386 +const struct argp parser_def = 4.387 +{ 4.388 + .options = cmd_opts, 4.389 + .parser = cmd_parser, 4.390 + .args_doc = "[output file]", 4.391 + .doc = 4.392 + "Tool to capure Xen trace buffer data" 4.393 + "\v" 4.394 + "This tool is used to capture trace buffer data from Xen. The data is " 4.395 + "output as space-separated decimal numbers, represented in ASCII, in " 4.396 + "the following order:\n\n" 4.397 + " CPU TSC EVENT DATA1 DATA2 DATA3 DATA4 DATA5\n" 4.398 +}; 4.399 + 4.400 + 4.401 +const char *argp_program_version = "xentrace v1.0"; 4.402 +const char *argp_program_bug_address = "<mark.a.williamson@intel.com>"; 4.403 + 4.404 + 4.405 +int main(int argc, char **argv) 4.406 +{ 4.407 + int ret; 4.408 + FILE *logfile = stdout; 4.409 + 4.410 + const struct sigaction act = { .sa_handler = close_handler }; 4.411 + 4.412 + opts.outfile = 0; 4.413 + opts.num_cpus = 1; 4.414 + opts.poll_sleep = millis_to_timespec(POLL_SLEEP_MILLIS); 4.415 + opts.new_data_thresh = NEW_DATA_THRESH; 4.416 + 4.417 + argp_parse(&parser_def, argc, argv, 0, 0, &opts); 4.418 + 4.419 + if(opts.outfile) { 4.420 + logfile = fopen(opts.outfile, "w"); 4.421 + } 4.422 + 4.423 + /* ensure that if we get a signal, we'll do cleanup, then exit */ 4.424 + sigaction(SIGHUP, &act, 0); 4.425 + sigaction(SIGTERM, &act, 0); 4.426 + sigaction(SIGINT, &act, 0); 4.427 + 4.428 + ret = monitor_tbufs(logfile); 4.429 + 4.430 + return ret; 4.431 +}
5.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 5.2 +++ b/tools/xentrace/xentrace_cpusplit.py Mon Feb 23 17:56:51 2004 +0000 5.3 @@ -0,0 +1,59 @@ 5.4 +#!/usr/bin/env python 5.5 + 5.6 +# by Mark Williamson, (C) 2004 Intel Research Cambridge 5.7 + 5.8 +# Program for separating trace buffer data into per-cpu log files. 5.9 + 5.10 +import re, sys, signal 5.11 + 5.12 +def usage(): 5.13 + print >> sys.stderr, \ 5.14 + "Usage: " + sys.argv[0] + """ base-name 5.15 + Separates ASCII trace buffer data on stdin into per-CPU trace 5.16 + files. The trace files are named by appending the CPU number 5.17 + to the base name supplied on the command line. 5.18 + 5.19 + Depending on your system and the volume of trace buffer data, 5.20 + this script may not be able to keep up with the output of xentrace 5.21 + if it is piped directly. In these circumstances you should have 5.22 + xentrace output to a file for processing off-line. 5.23 + """ 5.24 + sys.exit(1) 5.25 + 5.26 +def sighand(x,y): 5.27 + global interrupted 5.28 + interrupted = 1 5.29 + 5.30 +signal.signal(signal.SIGTERM, sighand) 5.31 +signal.signal(signal.SIGHUP, sighand) 5.32 +signal.signal(signal.SIGINT, sighand) 5.33 + 5.34 +r = re.compile("(\d) .*") 5.35 + 5.36 +if len(sys.argv) < 2: 5.37 + usage() 5.38 +else: 5.39 + base_name = sys.argv[1] 5.40 + 5.41 +files = {} 5.42 +interrupted = 0 5.43 + 5.44 +while not interrupted: 5.45 + try: 5.46 + line = sys.stdin.readline() 5.47 + if not line: break 5.48 + 5.49 + m = r.match(line) 5.50 + 5.51 + if not m: print >> sys.stderr, "Invalid input line." 5.52 + 5.53 + cpu = m.group(1) 5.54 + 5.55 + if not files.has_key(base_name + str(cpu)): 5.56 + files[base_name + str(cpu)] = open(base_name + str(cpu), "w") 5.57 + 5.58 + print >> files[base_name + str(cpu)], line, 5.59 + 5.60 + except IOError: sys.exit() 5.61 + 5.62 +# files closed automatically
6.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 6.2 +++ b/tools/xentrace/xentrace_format.py Mon Feb 23 17:56:51 2004 +0000 6.3 @@ -0,0 +1,96 @@ 6.4 +#!/usr/bin/env python 6.5 + 6.6 +# by Mark Williamson, (C) 2004 Intel Research Cambridge 6.7 + 6.8 +# Program for reformatting trace buffer output according to user-supplied rules 6.9 + 6.10 +import re, sys, string, signal 6.11 + 6.12 +def usage(): 6.13 + print >> sys.stderr, \ 6.14 + "Usage: " + sys.argv[0] + """ defs-file 6.15 + Parses trace data in ASCII format and reformats it according to the 6.16 + rules in a file of definitions. The rules in this file should have 6.17 + the format ({ and } show grouping and are not part of the syntax): 6.18 + 6.19 + {event_id}{whitespace}{text format string} 6.20 + 6.21 + The textual format string may include the format specifiers: 6.22 + %(cpu)s, %(tsc), %(event)s, %(1)s, %(2)s, %(3)s, %(4)s, %(5)s 6.23 + 6.24 + Which correspond to the CPU number, event ID, timestamp counter and 6.25 + the 5 data fields from the trace record. There should be one such 6.26 + rule for each type of event. 6.27 + 6.28 + Depending on your system and the volume of trace buffer data, 6.29 + this script may not be able to keep up with the output of xentrace 6.30 + if it is piped directly. In these circumstances you should have 6.31 + xentrace output to a file for processing off-line. 6.32 + """ 6.33 + sys.exit(1) 6.34 + 6.35 +def read_defs(defs_file): 6.36 + defs = {} 6.37 + 6.38 + fd = open(defs_file) 6.39 + 6.40 + reg = re.compile('(\d+)\s+(\S.*)') 6.41 + 6.42 + while True: 6.43 + line = fd.readline() 6.44 + if not line: 6.45 + break 6.46 + 6.47 + m = reg.match(line) 6.48 + 6.49 + if not m: print >> sys.stderr, "Bad format file" ; sys.exit(1) 6.50 + 6.51 + defs[m.group(1)] = m.group(2) 6.52 + 6.53 + return defs 6.54 + 6.55 +def sighand(x,y): 6.56 + global interrupted 6.57 + interrupted = 1 6.58 + 6.59 +##### Main code 6.60 + 6.61 +if len(sys.argv) < 2: 6.62 + usage() 6.63 + 6.64 +signal.signal(signal.SIGTERM, sighand) 6.65 +signal.signal(signal.SIGHUP, sighand) 6.66 +signal.signal(signal.SIGINT, sighand) 6.67 + 6.68 +interrupted = 0 6.69 + 6.70 +defs = read_defs(sys.argv[1]) 6.71 + 6.72 +reg = re.compile('(\d+) (\d+) (\d+) (.*)') 6.73 + 6.74 +while not interrupted: 6.75 + try: 6.76 + line = sys.stdin.readline() 6.77 + if not line: 6.78 + break 6.79 + 6.80 + m = reg.match(line) 6.81 + 6.82 + if not m: print >> sys.stderr, "Invalid input line." 6.83 + 6.84 + s = string.split(m.group(4)) 6.85 + 6.86 + args = {'cpu' : m.group(1), 6.87 + 'tsc' : m.group(2), 6.88 + 'event' : m.group(3) } 6.89 + 6.90 + i = 0 6.91 + for item in s: 6.92 + args[str(i)] = item 6.93 + i += 1 6.94 + 6.95 + if defs.has_key(m.group(3)): print defs[m.group(3)] % args 6.96 + # silently skip lines we don't have a format for - a 'complain' option 6.97 + # should be added if needed 6.98 + 6.99 + except IOError: sys.exit()
7.1 --- a/xen/arch/i386/setup.c Mon Feb 23 15:55:27 2004 +0000 7.2 +++ b/xen/arch/i386/setup.c Mon Feb 23 17:56:51 2004 +0000 7.3 @@ -14,6 +14,7 @@ 7.4 #include <asm/desc.h> 7.5 #include <asm/domain_page.h> 7.6 #include <asm/pdb.h> 7.7 +#include <xeno/trace.h> 7.8 7.9 struct cpuinfo_x86 boot_cpu_data = { 0 }; 7.10 /* Lots of nice things, since we only target PPro+. */ 7.11 @@ -449,4 +450,8 @@ void __init start_of_day(void) 7.12 #endif 7.13 7.14 watchdog_on = 1; 7.15 + 7.16 +#ifdef TRACE_BUFFER 7.17 + init_trace_bufs(); /* initialise trace buffers */ 7.18 +#endif 7.19 }
8.1 --- a/xen/common/dom0_ops.c Mon Feb 23 15:55:27 2004 +0000 8.2 +++ b/xen/common/dom0_ops.c Mon Feb 23 17:56:51 2004 +0000 8.3 @@ -16,6 +16,7 @@ 8.4 #include <asm/domain_page.h> 8.5 #include <asm/msr.h> 8.6 #include <asm/pdb.h> 8.7 +#include <xeno/trace.h> 8.8 8.9 extern unsigned int alloc_new_dom_mem(struct task_struct *, unsigned int); 8.10 8.11 @@ -431,6 +432,16 @@ long do_dom0_op(dom0_op_t *u_dom0_op) 8.12 ret = 0; 8.13 } 8.14 break; 8.15 + 8.16 +#ifdef TRACE_BUFFER 8.17 + case DOM0_GETTBUFS: 8.18 + { 8.19 + op->u.gettbufs.phys_addr = get_tb_ptr(); 8.20 + copy_to_user(u_dom0_op, op, sizeof(*op)); 8.21 + ret = 0; 8.22 + } 8.23 + break; 8.24 +#endif 8.25 8.26 case DOM0_READCONSOLE: 8.27 {
9.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 9.2 +++ b/xen/common/trace.c Mon Feb 23 17:56:51 2004 +0000 9.3 @@ -0,0 +1,103 @@ 9.4 +/****************************************************************************** 9.5 + * 9.6 + * common/trace.c 9.7 + * 9.8 + * Xen Trace Buffer 9.9 + * 9.10 + * Copyright (C) 2004 by Intel Research Cambridge 9.11 + * 9.12 + * Author: Mark Williamson, mark.a.williamson@intel.com 9.13 + * Date: January 2004 9.14 + * 9.15 + * The trace buffer code is designed to allow debugging traces of Xen to be 9.16 + * generated on UP / SMP machines. Each trace entry is timestamped so that 9.17 + * it's possible to reconstruct a chronological record of trace events. 9.18 + * 9.19 + * See also include/xeno/trace.h and the dom0 op in 9.20 + * include/hypervisor-ifs/dom0_ops.h 9.21 + * 9.22 + *****************************************************************************/ 9.23 + 9.24 +#include <xeno/config.h> 9.25 + 9.26 +#ifdef TRACE_BUFFER /* don't compile this stuff in unless explicitly enabled */ 9.27 + 9.28 +#include <asm/timex.h> 9.29 +#include <asm/types.h> 9.30 +#include <asm/io.h> 9.31 +#include <xeno/lib.h> 9.32 +#include <xeno/sched.h> 9.33 +#include <xeno/slab.h> 9.34 +#include <xeno/smp.h> 9.35 +#include <xeno/spinlock.h> 9.36 +#include <xeno/trace.h> 9.37 +#include <asm/atomic.h> 9.38 + 9.39 + 9.40 + 9.41 +/* Pointers to the meta-data objects for all system trace buffers */ 9.42 +struct t_buf *t_bufs[NR_CPUS]; 9.43 + 9.44 +/* a flag recording whether initialisation has been done */ 9.45 +atomic_t tb_init_done = ATOMIC_INIT(0); 9.46 + 9.47 + 9.48 +/** 9.49 + * init_trace_bufs - performs initialisation of the per-cpu trace buffers. 9.50 + * 9.51 + * This function is called at start of day in order to initialise the per-cpu 9.52 + * trace buffers. The trace buffers are then available for debugging use, via 9.53 + * the %TRACE_xD macros exported in <xeno/trace.h>. 9.54 + */ 9.55 +void init_trace_bufs() 9.56 +{ 9.57 + int i; 9.58 + void *d; /* trace buffer area pointer */ 9.59 + 9.60 + d = kmalloc(smp_num_cpus * TB_SIZE, GFP_KERNEL); 9.61 + 9.62 + if( d == NULL ) { 9.63 + printk("Xen trace buffers: memory allocation failed\n"); 9.64 + return; 9.65 + } 9.66 + 9.67 + for(i = 0; i < smp_num_cpus; i++) { 9.68 + struct t_buf *buf = t_bufs[i] 9.69 + = (struct t_buf *)( (unsigned int)d + TB_SIZE * i ); 9.70 + 9.71 + /* for use in Xen */ 9.72 + buf->vdata = (struct t_rec *) 9.73 + ( (unsigned int)buf + sizeof(struct t_buf) ); 9.74 + buf->head_ptr = buf->vdata; 9.75 + spin_lock_init(&buf->lock); 9.76 + 9.77 + /* for use in user space */ 9.78 + buf->data = (struct t_rec *)__pa(buf->vdata); 9.79 + buf->head = 0; 9.80 + 9.81 + /* for use in both */ 9.82 + buf->size = (TB_SIZE - sizeof(struct t_buf)) / sizeof(struct t_rec); 9.83 + } 9.84 + 9.85 + printk("Xen trace buffers: initialised\n"); 9.86 + 9.87 + wmb(); /* above must be visible before tb_init_done flag set */ 9.88 + 9.89 + atomic_set(&tb_init_done, 1); 9.90 +} 9.91 + 9.92 + 9.93 + 9.94 +/** 9.95 + * get_tb_ptr - return physical address of the trace buffers. 9.96 + * 9.97 + * Called by the %DOM0_GETTBUFS dom0 op to fetch the physical address of the 9.98 + * trace buffers. 9.99 + */ 9.100 +struct t_buf *get_tb_ptr() 9.101 +{ 9.102 + /* a physical address (user space maps this using /dev/mem) */ 9.103 + return (struct t_buf *)__pa(t_bufs[0]); 9.104 +} 9.105 + 9.106 +#endif /* #ifdef TRACE_BUFFER */
10.1 --- a/xen/include/hypervisor-ifs/dom0_ops.h Mon Feb 23 15:55:27 2004 +0000 10.2 +++ b/xen/include/hypervisor-ifs/dom0_ops.h Mon Feb 23 17:56:51 2004 +0000 10.3 @@ -17,7 +17,7 @@ 10.4 * This makes sure that old versions of dom0 tools will stop working in a 10.5 * well-defined way (rather than crashing the machine, for instance). 10.6 */ 10.7 -#define DOM0_INTERFACE_VERSION 0xAAAA0005 10.8 +#define DOM0_INTERFACE_VERSION 0xAAAA0006 10.9 10.10 10.11 /* 10.12 @@ -210,6 +210,14 @@ typedef struct dom0_pincpudomain_st 10.13 int cpu; /* -1 implies unpin */ 10.14 } dom0_pincpudomain_t; 10.15 10.16 +/* Get trace buffers physical base pointer */ 10.17 +#define DOM0_GETTBUFS 21 10.18 +typedef struct dom0_gettbufs_st 10.19 +{ 10.20 + /* OUT variable - location of the trace buffers */ 10.21 + struct t_buf *phys_addr; 10.22 +} dom0_gettbufs_t; 10.23 + 10.24 typedef struct dom0_op_st 10.25 { 10.26 unsigned long cmd; 10.27 @@ -232,6 +240,7 @@ typedef struct dom0_op_st 10.28 dom0_settime_t settime; 10.29 dom0_readconsole_t readconsole; 10.30 dom0_pincpudomain_t pincpudomain; 10.31 + dom0_gettbufs_t gettbufs; 10.32 } u; 10.33 } dom0_op_t; 10.34
11.1 --- a/xen/include/xeno/config.h Mon Feb 23 15:55:27 2004 +0000 11.2 +++ b/xen/include/xeno/config.h Mon Feb 23 17:56:51 2004 +0000 11.3 @@ -149,6 +149,7 @@ 11.4 #define DPRINTK(_f, _a...) printk("(file=%s, line=%d) " _f, \ 11.5 __FILE__ , __LINE__ , ## _a ) 11.6 #define STACK_GUARD 11.7 +#define TRACE_BUFFER 11.8 #else 11.9 #define DPRINTK(_f, _a...) ((void)0) 11.10 #endif
12.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000 12.2 +++ b/xen/include/xeno/trace.h Mon Feb 23 17:56:51 2004 +0000 12.3 @@ -0,0 +1,179 @@ 12.4 +/****************************************************************************** 12.5 + * 12.6 + * include/xeno/trace.h 12.7 + * 12.8 + * Xen Trace Buffer 12.9 + * 12.10 + * Copyright (C) 2003 by Intel Research Cambridge 12.11 + * 12.12 + * Author: Mark Williamson, mark.a.williamson@intel.com 12.13 + * Date: January 2004 12.14 + * 12.15 + * The trace buffer code is designed to allow debugging traces of Xen to be 12.16 + * generated on UP / SMP machines. Each trace entry is timestamped so that 12.17 + * it's possible to reconstruct a chronological record of trace events. 12.18 + * 12.19 + * Access to the trace buffers is via a dom0 hypervisor op and analysis of 12.20 + * trace buffer contents can then be performed using a userland tool. 12.21 + * 12.22 + * See also common/trace.c and the dom0 op in include/hypervisor-ifs/dom0_ops.h 12.23 + * 12.24 + *****************************************************************************/ 12.25 + 12.26 +#ifdef TRACE_BUFFER 12.27 + 12.28 +#ifndef __XENO_TRACE_H__ 12.29 +#define __XENO_TRACE_H__ 12.30 + 12.31 +#ifdef __KERNEL__ 12.32 + 12.33 +#include <xeno/spinlock.h> 12.34 +#include <asm/page.h> 12.35 +#include <xeno/types.h> 12.36 +#include <xeno/sched.h> 12.37 +#include <asm/atomic.h> 12.38 +#include <asm/current.h> 12.39 +#include <asm/msr.h> 12.40 + 12.41 +#endif /* #ifdef __KERNEL__ */ 12.42 + 12.43 +/****************************************************************************** 12.44 + * Data structure declarations 12.45 + *****************************************************************************/ 12.46 + 12.47 +/* This structure represents a single trace buffer record. */ 12.48 +struct t_rec { 12.49 + u64 cycles; /* 64 bit cycle counter timestamp */ 12.50 + u32 event; /* 32 bit event ID */ 12.51 + u32 d1, d2, d3, d4, d5; /* event data items */ 12.52 +}; 12.53 + 12.54 +/* This structure contains the metadata for a single trace buffer. The head 12.55 + * field, indexes into an array of struct t_rec's. 12.56 + */ 12.57 +struct t_buf { 12.58 + struct t_rec *data; /* pointer to data area. physical address 12.59 + * for convenience in user space code */ 12.60 + 12.61 + unsigned int size; /* size of the data area, in t_recs */ 12.62 + unsigned int head; /* array index of the most recent record */ 12.63 + 12.64 +#ifdef __KERNEL__ 12.65 + struct t_rec *head_ptr; /* pointer to the head record */ 12.66 + struct t_rec *vdata; /* virtual address pointer to data, 12.67 + * for use in Xen */ 12.68 + spinlock_t lock; /* ensure mutually exlusive access (for inserts) */ 12.69 +#endif /* #ifdef __KERNEL__ */ 12.70 + 12.71 + /* never add anything here - the kernel stuff must be the last elements */ 12.72 +}; 12.73 + 12.74 +/****************************************************************************** 12.75 + * Functions 12.76 + *****************************************************************************/ 12.77 + 12.78 +#ifdef __KERNEL__ 12.79 + 12.80 +/* Used to initialise trace buffer functionality */ 12.81 +void init_trace_bufs(); 12.82 + 12.83 +/* used to retrieve the physical address of the trace buffers */ 12.84 +struct t_buf *get_tb_ptr(); 12.85 + 12.86 +/** 12.87 + * trace - Enters a trace tuple into the trace buffer for the current CPU. 12.88 + * @event: the event type being logged 12.89 + * @d1...d5: the data items for the event being logged 12.90 + * 12.91 + * Logs a trace record into the appropriate buffer. Returns nonzero on 12.92 + * failure, otherwise 0. Failure occurs only if the trace buffers are not yet 12.93 + * initialised. 12.94 + */ 12.95 +static inline int trace(u32 event, u32 d1, u32 d2, u32 d3, u32 d4, u32 d5) 12.96 +{ 12.97 + extern struct t_buf *t_bufs[]; /* global array of pointers to bufs */ 12.98 + extern atomic_t tb_init_done; /* set when buffers are initialised */ 12.99 + unsigned long flags; /* for saving interrupt flags */ 12.100 + struct t_buf *buf; /* the buffer we're working on */ 12.101 + struct t_rec *rec; /* next record to fill out */ 12.102 + 12.103 + 12.104 + if(!atomic_read(&tb_init_done)) return -1; 12.105 + 12.106 + buf = t_bufs[smp_processor_id()]; 12.107 + rec = buf->head_ptr; 12.108 + 12.109 + spin_lock_irqsave(&buf->lock, flags); 12.110 + /* interrupts _disabled locally_ during the following code */ 12.111 + 12.112 + rdtscll(rec->cycles); 12.113 + rec->event = event; 12.114 + rec->d1 = d1; 12.115 + rec->d2 = d2; 12.116 + rec->d3 = d3; 12.117 + rec->d4 = d4; 12.118 + rec->d5 = d5; 12.119 + 12.120 + wmb(); /* above must be visible before reader sees index updated */ 12.121 + 12.122 + if( likely( buf->head_ptr < ( buf->vdata + buf->size - 1) ) ) { 12.123 + buf->head_ptr++; 12.124 + buf->head++; 12.125 + } else { 12.126 + buf->head = 0; 12.127 + buf->head_ptr = buf->vdata; 12.128 + } 12.129 + 12.130 + spin_unlock_irqrestore(&buf->lock, flags); 12.131 + /* Interrupts now _re-enabled locally_ */ 12.132 + 12.133 + return 0; 12.134 +} 12.135 + 12.136 + 12.137 +#endif /* #ifdef __KERNEL__ */ 12.138 + 12.139 + 12.140 +/****************************************************************************** 12.141 + * Macros 12.142 + *****************************************************************************/ 12.143 + 12.144 +/* How much space is allowed for a single trace buffer, including data and 12.145 + * metadata (and maybe some waste). 12.146 + */ 12.147 +#define TB_SIZE PAGE_SIZE 12.148 + 12.149 +#ifdef __KERNEL__ 12.150 + 12.151 +/* avoids troubling the caller with casting their arguments to a trace macro */ 12.152 +#define trace_do_casts(e,d1,d2,d3,d4,d5) \ 12.153 + trace(e, \ 12.154 + (unsigned long)d1, \ 12.155 + (unsigned long)d2, \ 12.156 + (unsigned long)d3, \ 12.157 + (unsigned long)d4, \ 12.158 + (unsigned long)d5) 12.159 + 12.160 +/* convenience macros for calling the trace function */ 12.161 +#define TRACE_0D(event) trace_do_casts(event,0, 0, 0, 0, 0 ) 12.162 +#define TRACE_1D(event,d) trace_do_casts(event,d, 0, 0, 0, 0 ) 12.163 +#define TRACE_2D(event,d1,d2) trace_do_casts(event,d1,d2,0, 0, 0 ) 12.164 +#define TRACE_3D(event,d1,d2,d3) trace_do_casts(event,d1,d2,d3,0, 0 ) 12.165 +#define TRACE_4D(event,d1,d2,d3,d4) trace_do_casts(event,d1,d2,d3,d4,0 ) 12.166 +#define TRACE_5D(event,d1,d2,d3,d4,d5) trace_do_casts(event,d1,d2,d3,d4,d5) 12.167 + 12.168 +#endif /* #ifdef __KERNEL__ */ 12.169 + 12.170 +#endif /* #ifndef __XENO_TRACE_H__ */ 12.171 + 12.172 +#else /* #ifdef TRACE_BUFFER */ 12.173 + 12.174 +/* define out macros so that they can be left in code when tracing is disabled */ 12.175 +#define TRACE_0D(event) ((void)0) 12.176 +#define TRACE_1D(event,d) ((void)0) 12.177 +#define TRACE_2D(event,d1,d2) ((void)0) 12.178 +#define TRACE_3D(event,d1,d2,d3) ((void)0) 12.179 +#define TRACE_4D(event,d1,d2,d3,d4) ((void)0) 12.180 +#define TRACE_5D(event,d1,d2,d3,d4,d5) ((void)0) 12.181 + 12.182 +#endif /* #ifdef TRACE_BUFFER */