This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
[RFC][PATCH 3/5][flight-recorder] Wraparound logging
- From: Masami Hiramatsu <masami dot hiramatsu dot pt at hitachi dot com>
- To: SystemTAP <systemtap at sources dot redhat dot com>
- Cc: Yumiko Sugita <yumiko dot sugita dot yf at hitachi dot com>, Satoshi Oshima <soshima at redhat dot com>, Hideo Aoki <haoki at redhat dot com>
- Date: Fri, 25 Aug 2006 22:35:08 +0900
- Subject: [RFC][PATCH 3/5][flight-recorder] Wraparound logging
- Organization: Systems Development Lab., Hitachi, Ltd., Japan
This patch enables stpd to write logfile cyclically when it runs
only on bulk mode.
This changes the format of the temporary percpu file. The original
format contains only the buffer content except for padding bytes
and headers. But new format contains whole relay buffer including
padding and headers into the temporary files.
It also appends the size of the sub-buffer and the offset of
the end of buffer to each temporary file if it doesn't merge
temporary files. These information will help external tools.
--
Masami HIRAMATSU
2nd Research Dept.
Hitachi, Ltd., Systems Development Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com
runtime/stpd/librelay.c | 98 +++++++++++++++++++++++++++++++++++++++++-------
runtime/stpd/stpd.c | 22 +++++++++-
2 files changed, 104 insertions(+), 16 deletions(-)
Index: src/runtime/stpd/librelay.c
===================================================================
--- src.orig/runtime/stpd/librelay.c 2006-08-25 15:02:17.000000000 +0900
+++ src/runtime/stpd/librelay.c 2006-08-25 19:11:44.000000000 +0900
@@ -76,6 +76,7 @@
static FILE *percpu_tmpfile[NR_CPUS];
static char *relay_buffer[NR_CPUS];
static pthread_t reader[NR_CPUS];
+static long percpu_fptr[NR_CPUS];
/* control channel */
static int control_channel;
@@ -83,6 +84,7 @@
/* flags */
extern int print_only, quiet, merge, verbose, background;
extern unsigned int buffer_size;
+extern long log_size;
extern char *modname;
extern char *modpath;
extern char *modoptions[];
@@ -215,6 +217,7 @@
close(relay_file[cpu]);
return -1;
}
+ percpu_fptr[cpu] = 0;
total_bufsize = params.subbuf_size * params.n_subbufs;
relay_buffer[cpu] = mmap(NULL, total_bufsize, PROT_READ,
@@ -277,7 +280,7 @@
static int process_subbufs(struct buf_info *info)
{
unsigned subbufs_ready, start_subbuf, end_subbuf, subbuf_idx, i;
- int len, cpu = info->cpu;
+ int cpu = info->cpu;
char *subbuf_ptr;
int subbufs_consumed = 0;
unsigned padding;
@@ -287,16 +290,22 @@
end_subbuf = start_subbuf + subbufs_ready;
for (i = start_subbuf; i < end_subbuf; i++) {
+ if (log_size &&
+ (percpu_fptr[cpu] + params.subbuf_size > log_size)) {
+ /* reset file pointer */
+ rewind(percpu_tmpfile[cpu]);
+ percpu_fptr[cpu] = 0;
+ }
subbuf_idx = i % params.n_subbufs;
subbuf_ptr = relay_buffer[cpu] + subbuf_idx * params.subbuf_size;
padding = *((unsigned *)subbuf_ptr);
- subbuf_ptr += sizeof(padding);
- len = (params.subbuf_size - sizeof(padding)) - padding;
- if (len) {
- if (fwrite_unlocked (subbuf_ptr, len, 1, percpu_tmpfile[cpu]) != 1) {
+ if (params.subbuf_size > sizeof(padding) + padding) {
+ /* write the whole one sub-buffer. */
+ if (fwrite_unlocked (subbuf_ptr, params.subbuf_size, 1, percpu_tmpfile[cpu]) != 1) {
print_err ("ERROR: couldn't write to output file for cpu %d, exiting: errcode = %d: %s\n", cpu, errno, strerror(errno));
- exit(1);
+ exit(1); //TODO: correct error handling.
}
+ percpu_fptr[cpu] += params.subbuf_size;
}
subbufs_consumed++;
}
@@ -557,18 +566,30 @@
long count=0, min, num[ncpus];
char buf[32], tmp[PATH_MAX];
FILE *ofp, *fp[ncpus];
+ unsigned padding[ncpus], remains[ncpus];
for (i = 0; i < ncpus; i++) {
+ struct stat fst;
sprintf (tmp, "%s%d", percpu_tmpfilebase, i);
fp[i] = fopen (tmp, "r");
if (!fp[i]) {
print_err ("ERROR: opening file %s.\n", tmp);
return -1;
}
- if (fread (buf, TIMESTAMP_SIZE, 1, fp[i]))
+ stat(tmp, &fst);
+ if (fst.st_size != percpu_fptr[i]) {
+ fseek (fp[i], percpu_fptr[i], SEEK_SET);
+ } else {
+ percpu_fptr[i] = 0;
+ }
+ if (fread (&padding[i], sizeof(unsigned), 1, fp[i]) &&
+ fread (buf, TIMESTAMP_SIZE, 1, fp[i])) {
+ remains[i] = params.subbuf_size -
+ (sizeof(unsigned) + padding[i] + TIMESTAMP_SIZE);
num[i] = *((int *)buf);
- else
+ } else {
num[i] = 0;
+ }
}
if (!outfile_name)
@@ -591,8 +612,9 @@
}
}
- while (1) {
+ while (remains[j] > 0) {
c = fgetc_unlocked (fp[j]);
+ remains[j]--;
if (c == 0 || c == EOF)
break;
if (!quiet)
@@ -604,11 +626,30 @@
count = min;
dropped++ ;
}
-
- if (fread (buf, TIMESTAMP_SIZE, 1, fp[j]))
+ if (remains[j] == 0) {
+ fseek (fp[j], padding[j], SEEK_CUR);/* skip padding */
+ if (ftell(fp[j]) == percpu_fptr[j])
+ goto eof;
+retry:
+ if (fread (&padding[j], sizeof(unsigned), 1, fp[j])) {
+ remains[j] = params.subbuf_size - sizeof(unsigned) - padding[j];
+ } else {
+ if (feof (fp[j]) && percpu_fptr[j]) {
+ rewind(fp[j]);
+ goto retry;
+ } else {
+ goto eof;
+ }
+ }
+ }
+
+ if (fread (buf, TIMESTAMP_SIZE, 1, fp[j])) {
num[j] = *((int *)buf);
- else
- num[j] = 0;
+ remains[j] -= TIMESTAMP_SIZE;
+ continue;
+ }
+eof:
+ num[j] = 0;
} while (min);
if (!print_only)
@@ -622,6 +663,35 @@
return 0;
}
+/* If not merge files, add a tailer information for other post-processing tools */
+static int finalize_percpu_files(void)
+{
+ int i;
+ FILE *fp;
+ char tmp[PATH_MAX];
+ long starting;
+
+ for (i = 0; i < ncpus; i++) {
+ struct stat fst;
+ sprintf (tmp, "%s%d", percpu_tmpfilebase, i);
+ fp = fopen (tmp, "a");
+ if (!fp) {
+ print_err ("ERROR: opening file %s.\n", tmp);
+ return -1;
+ }
+ stat(tmp, &fst);
+ if (fst.st_size == percpu_fptr[i]) {
+ starting = 0;
+ } else {
+ starting = percpu_fptr[i];
+ }
+ fwrite(&starting, sizeof(long), 1, fp);
+ fwrite(¶ms.subbuf_size, sizeof(unsigned), 1, fp);
+ fclose(fp);
+ }
+ return 0;
+}
+
static void cleanup_and_exit (int closed)
{
char tmpbuf[128];
@@ -662,6 +732,8 @@
if (merge) {
merge_output();
delete_percpu_files();
+ } else {
+ finalize_percpu_files();
}
}
Index: src/runtime/stpd/stpd.c
===================================================================
--- src.orig/runtime/stpd/stpd.c 2006-08-25 15:02:17.000000000 +0900
+++ src/runtime/stpd/stpd.c 2006-08-25 19:11:44.000000000 +0900
@@ -47,6 +47,7 @@
int driver_pid = 0;
int background = 0;
unsigned int buffer_size = 0;
+long log_size = 0;
char *modname = NULL;
char *modpath = NULL;
#define MAXMODOPTIONS 64
@@ -116,12 +117,13 @@
static void usage(char *prog)
{
fprintf(stderr, "\n%s [-B] [-m] [-p] [-q] [-r] [-c cmd ] [-t pid]\n"
- "\t[-b bufsize] [-o FILE] kmod-name [kmod-options]\n", prog);
+ "\t[-b bufsize] [-l logsize] [-o FILE] kmod-name [kmod-options]\n", prog);
fprintf(stderr, "-B Execute in background. (be seperated from console)\n");
fprintf(stderr, "-m Don't merge per-cpu files.\n");
fprintf(stderr, "-p Print only. Don't log to files.\n");
fprintf(stderr, "-q Quiet. Don't display trace to stdout.\n");
fprintf(stderr, "-r Disable running stp_check and loading relayfs module.\n");
+ fprintf(stderr, "-l log size. Sets maximum logging file size in MB.\n");
fprintf(stderr, "-c cmd. Command \'cmd\' will be run and stpd will exit when it does.\n");
fprintf(stderr, " _stp_target will contain the pid for the command.\n");
fprintf(stderr, "-t pid. Sets _stp_target to pid.\n");
@@ -141,7 +143,7 @@
pid_t pid;
struct statfs st;
- while ((c = getopt(argc, argv, "Bmpqrb:n:t:d:c:vo:u:")) != EOF)
+ while ((c = getopt(argc, argv, "Bmpqrb:l:n:t:d:c:vo:u:")) != EOF)
{
switch (c) {
case 'B':
@@ -174,6 +176,18 @@
buffer_size = size;
break;
}
+ case 'l':
+ {
+ unsigned size = (unsigned)atoi(optarg);
+ if (!size)
+ usage(argv[0]);
+ if (size > 2048) {
+ fprintf(stderr, "Maximum log size is 2048 (MB)\n");
+ exit(1);
+ }
+ log_size = (long)((size << 20) - 1);
+ break;
+ }
case 't':
target_pid = atoi(optarg);
break;
@@ -196,7 +210,9 @@
if (verbose) {
if (buffer_size)
- printf ("Using a buffer of %u bytes.\n", buffer_size);
+ printf ("Using a buffer of %u Mbytes.\n", buffer_size);
+ if (log_size)
+ printf ("Using logfiles of %ld Mbytes.\n", log_size);
}
if (optind < argc)