Source-Changes-HG archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
[src/trunk]: src Add a FUSE trace facility, with statistics collection. This ...
details: https://anonhg.NetBSD.org/src/rev/0dc6232ab881
branches: trunk
changeset: 772299:0dc6232ab881
user: manu <manu%NetBSD.org@localhost>
date: Wed Dec 28 17:33:52 2011 +0000
description:
Add a FUSE trace facility, with statistics collection. This should help
tracking bugs and performance issues
diffstat:
lib/libperfuse/debug.c | 117 +++++++++++++++++++++++++++++++++++++++++-
lib/libperfuse/fuse.h | 3 +-
lib/libperfuse/ops.c | 58 ++++++++++++++++++++-
lib/libperfuse/perfuse.c | 3 +-
lib/libperfuse/perfuse_if.h | 4 +-
lib/libperfuse/perfuse_priv.h | 19 ++++++-
usr.sbin/perfused/perfused.8 | 20 ++++++-
usr.sbin/perfused/perfused.c | 34 +++++++++++-
usr.sbin/perfused/perfused.h | 4 +-
9 files changed, 253 insertions(+), 9 deletions(-)
diffs (truncated from 463 to 300 lines):
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/debug.c
--- a/lib/libperfuse/debug.c Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/debug.c Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: debug.c,v 1.5 2010/10/03 05:46:47 manu Exp $ */
+/* $NetBSD: debug.c,v 1.6 2011/12/28 17:33:52 manu Exp $ */
/*-
* Copyright (c) 2010 Emmanuel Dreyfus. All rights reserved.
@@ -26,9 +26,11 @@
*/
#include <puffs.h>
+#include <stdio.h>
#include <sys/types.h>
#include "perfuse_if.h"
+#include "perfuse_priv.h"
#include "fuse.h"
struct perfuse_opcode {
@@ -101,3 +103,116 @@
return po->opname; /* "UNKNOWN" */
}
+
+char *
+perfuse_opdump_in(ps, pm)
+ struct perfuse_state *ps;
+ perfuse_msg_t *pm;
+{
+ struct fuse_in_header *fih;
+ static char buf[BUFSIZ] = "";
+
+ fih = GET_INHDR(ps, pm);
+
+ switch(fih->opcode) {
+ case FUSE_LOOKUP:
+ (void)snprintf(buf, sizeof(buf), "path = \"%s\"",
+ _GET_INPAYLOAD(ps, pm, const char *));
+ break;
+ default:
+ buf[0] = '\0';
+ break;
+ }
+
+ return buf;
+}
+
+void
+perfuse_trace_dump(pu, fp)
+ struct puffs_usermount *pu;
+ FILE *fp;
+{
+ struct perfuse_state *ps;
+ struct perfuse_trace *pt;
+ struct timespec ts_min[FUSE_OPCODE_MAX];
+ struct timespec ts_max[FUSE_OPCODE_MAX];
+ struct timespec ts_total[FUSE_OPCODE_MAX];
+ int count[FUSE_OPCODE_MAX];
+ uint64_t avg;
+ int i;
+
+ if (!(perfuse_diagflags & PDF_TRACE))
+ return;
+
+ ps = puffs_getspecific(pu);
+
+ (void)ftruncate(fileno(fp), 0);
+ (void)fseek(fp, 0, SEEK_SET);
+
+ (void)memset(&ts_min, 0, sizeof(ts_min));
+ (void)memset(&ts_max, 0, sizeof(ts_max));
+ (void)memset(&ts_total, 0, sizeof(ts_total));
+ (void)memset(&count, 0, sizeof(count));
+
+ fprintf(fp, "Last %"PRId64" operations\n", ps->ps_tracecount);
+
+ TAILQ_FOREACH(pt, &ps->ps_trace, pt_list) {
+ const char *quote = pt->pt_path[0] != '\0' ? "\"" : "";
+
+ fprintf(fp, "%lu.%09ld %s %s%s%s %s ",
+ pt->pt_start.tv_sec, pt->pt_start.tv_nsec,
+ perfuse_opname(pt->pt_opcode),
+ quote, pt->pt_path, quote,
+ pt->pt_extra);
+
+ if (pt->pt_status == done) {
+ struct timespec ts;
+
+ ts.tv_sec = 0; /* delint */
+ ts.tv_nsec = 0; /* delint */
+ timespecsub(&pt->pt_end, &pt->pt_start, &ts);
+
+ fprintf(fp, "error = %d elapsed = %lu.%09lu ",
+ pt->pt_error, ts.tv_sec, ts.tv_nsec);
+
+ count[pt->pt_opcode]++;
+ timespecadd(&ts_total[pt->pt_opcode],
+ &ts,
+ &ts_total[pt->pt_opcode]);
+
+ if (timespeccmp(&ts, &ts_min[pt->pt_opcode], <) ||
+ (count[pt->pt_opcode] == 1))
+ ts_min[pt->pt_opcode] = ts;
+
+ if (timespeccmp(&ts, &ts_max[pt->pt_opcode], >))
+ ts_max[pt->pt_opcode] = ts;
+ } else {
+ fprintf(fp, "ongoing ");
+ }
+
+ fprintf(fp, "\n");
+ }
+
+ fprintf(fp, "\nStatistics by operation\n");
+ fprintf(fp, "operation\tcount\tmin\tavg\tmax\n");
+ for (i = 0; i < FUSE_OPCODE_MAX; i++) {
+ time_t min;
+
+ if (count[i] != 0) {
+ avg = timespec2ns(&ts_total[i]) / count[i];
+ min = ts_min[i].tv_sec;
+ } else {
+ avg = 0;
+ min = 0;
+ }
+
+ fprintf(fp, "%s\t%d\t%ld.%09ld\t%ld.%09ld\t%ld.%09ld\t\n",
+ perfuse_opname(i), count[i],
+ min, ts_min[i].tv_nsec,
+ (time_t)(avg / 1000000000L), (long)(avg % 1000000000L),
+ ts_max[i].tv_sec, ts_max[i].tv_nsec);
+ }
+
+ (void)fflush(fp);
+ return;
+}
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/fuse.h
--- a/lib/libperfuse/fuse.h Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/fuse.h Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: fuse.h,v 1.4 2011/06/28 16:19:16 manu Exp $ */
+/* $NetBSD: fuse.h,v 1.5 2011/12/28 17:33:53 manu Exp $ */
/*-
* Copyright (c) 2010 Emmanuel Dreyfus. All rights reserved.
@@ -169,6 +169,7 @@
FUSE_DESTROY = 38,
FUSE_IOCTL = 39,
FUSE_POLL = 40,
+ FUSE_OPCODE_MAX,
FUSE_CUSE_INIT = 4096
};
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/ops.c
--- a/lib/libperfuse/ops.c Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/ops.c Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: ops.c,v 1.48 2011/12/16 05:34:54 manu Exp $ */
+/* $NetBSD: ops.c,v 1.49 2011/12/28 17:33:53 manu Exp $ */
/*-
* Copyright (c) 2010-2011 Emmanuel Dreyfus. All rights reserved.
@@ -37,6 +37,7 @@
#include <sys/socket.h>
#include <sys/socket.h>
#include <sys/extattr.h>
+#include <sys/time.h>
#include <machine/vmparam.h>
#include "perfuse_priv.h"
@@ -205,6 +206,8 @@
{
struct perfuse_state *ps;
struct perfuse_node_data *pnd;
+ struct perfuse_trace *pt = NULL;
+ int opcode;
int error;
ps = puffs_getspecific(pu);
@@ -222,9 +225,62 @@
if (pnd)
pnd->pnd_flags |= PND_INXCHG;
+ /*
+ * Record FUSE call start if requested
+ */
+ opcode = ps->ps_get_inhdr(pm)->opcode;
+ if (perfuse_diagflags & PDF_TRACE) {
+ if ((pt = malloc(sizeof(*pt))) == NULL)
+ DERR(EX_OSERR, "malloc failed");
+
+ pt->pt_opcode = opcode;
+ pt->pt_status = inxchg;
+
+ if (opc == 0)
+ (void)strcpy(pt->pt_path, "");
+ else
+ (void)strlcpy(pt->pt_path,
+ perfuse_node_path(opc),
+ sizeof(pt->pt_path));
+
+ (void)strlcpy(pt->pt_extra,
+ perfuse_opdump_in(ps, pm),
+ sizeof(pt->pt_extra));
+
+ if (clock_gettime(CLOCK_REALTIME, &pt->pt_start) != 0)
+ DERR(EX_OSERR, "clock_gettime failed");
+
+ TAILQ_INSERT_TAIL(&ps->ps_trace, pt, pt_list);
+ ps->ps_tracecount++;
+ }
+
+ /*
+ * Do actual FUSE exchange
+ */
if ((error = ps->ps_xchg_msg(pu, pm, len, wait)) != 0)
ps->ps_destroy_msg(pm);
+ /*
+ * Record FUSE call end if requested
+ */
+ if (perfuse_diagflags & PDF_TRACE) {
+ if (clock_gettime(CLOCK_REALTIME, &pt->pt_end) != 0)
+ DERR(EX_OSERR, "clock_gettime failed");
+
+ pt->pt_status = done;
+ pt->pt_error = error;
+ while (ps->ps_tracecount > PERFUSE_TRACECOUNT_MAX) {
+ struct perfuse_trace *fpt = TAILQ_FIRST(&ps->ps_trace);
+
+ if (fpt->pt_status != done)
+ break;
+
+ TAILQ_REMOVE(&ps->ps_trace, fpt, pt_list);
+ ps->ps_tracecount--;
+ free(fpt);
+ }
+ }
+
if (pnd) {
pnd->pnd_flags &= ~PND_INXCHG;
(void)dequeue_requests(ps, opc, PCQ_AFTERXCHG, DEQUEUE_ALL);
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/perfuse.c
--- a/lib/libperfuse/perfuse.c Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/perfuse.c Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: perfuse.c,v 1.23 2011/10/30 05:11:37 manu Exp $ */
+/* $NetBSD: perfuse.c,v 1.24 2011/12/28 17:33:53 manu Exp $ */
/*-
* Copyright (c) 2010-2011 Emmanuel Dreyfus. All rights reserved.
@@ -64,6 +64,7 @@
(void)memset(ps, 0, sizeof(*ps));
ps->ps_max_write = UINT_MAX;
ps->ps_max_readahead = UINT_MAX;
+ TAILQ_INIT(&ps->ps_trace);
/*
* Most of the time, access() is broken because the filesystem
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/perfuse_if.h
--- a/lib/libperfuse/perfuse_if.h Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/perfuse_if.h Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: perfuse_if.h,v 1.17 2011/10/30 05:11:37 manu Exp $ */
+/* $NetBSD: perfuse_if.h,v 1.18 2011/12/28 17:33:53 manu Exp $ */
/*-
* Copyright (c) 2010-2011 Emmanuel Dreyfus. All rights reserved.
@@ -54,6 +54,7 @@
#define PDF_SYSLOG 0x0400 /* use syslog */
#define PDF_FILENAME 0x0800 /* File names */
#define PDF_RESIZE 0x1000 /* Resize operations */
+#define PDF_TRACE 0x2000 /* Trace FUSE calls */
/*
* Diagnostic functions
@@ -206,5 +207,6 @@
void perfuse_fs_init(struct puffs_usermount *);
int perfuse_mainloop(struct puffs_usermount *);
int perfuse_unmount(struct puffs_usermount *);
+void perfuse_trace_dump(struct puffs_usermount *, FILE *);
#endif /* _PERFUSE_IF_H */
diff -r 7402d8c37d83 -r 0dc6232ab881 lib/libperfuse/perfuse_priv.h
--- a/lib/libperfuse/perfuse_priv.h Wed Dec 28 14:53:38 2011 +0000
+++ b/lib/libperfuse/perfuse_priv.h Wed Dec 28 17:33:52 2011 +0000
@@ -1,4 +1,4 @@
-/* $NetBSD: perfuse_priv.h,v 1.23 2011/10/30 05:11:37 manu Exp $ */
+/* $NetBSD: perfuse_priv.h,v 1.24 2011/12/28 17:33:53 manu Exp $ */
/*-
* Copyright (c) 2010-2011 Emmanuel Dreyfus. All rights reserved.
@@ -37,6 +37,19 @@
#include "perfuse_if.h"
#include "fuse.h"
+#define PERFUSE_TRACECOUNT_MAX 4096
+#define PERFUSE_TRACEPATH_MAX 256
Home |
Main Index |
Thread Index |
Old Index