xref: /netbsd-src/lib/libperfuse/debug.c (revision e39ef1d61eee3ccba837ee281f1e098c864487aa)
1 /*  $NetBSD: debug.c,v 1.8 2011/12/29 04:25:49 riz Exp $ */
2 
3 /*-
4  *  Copyright (c) 2010 Emmanuel Dreyfus. All rights reserved.
5  *
6  *  Redistribution and use in source and binary forms, with or without
7  *  modification, are permitted provided that the following conditions
8  *  are met:
9  *  1. Redistributions of source code must retain the above copyright
10  *     notice, this list of conditions and the following disclaimer.
11  *  2. Redistributions in binary form must reproduce the above copyright
12  *     notice, this list of conditions and the following disclaimer in the
13  *     documentation and/or other materials provided with the distribution.
14  *
15  *  THIS SOFTWARE IS PROVIDED BY THE NETBSD FOUNDATION, INC. AND CONTRIBUTORS
16  *  ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED
17  *  TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
18  *  PURPOSE ARE DISCLAIMED.  IN NO EVENT SHALL THE FOUNDATION OR CONTRIBUTORS
19  *  BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
20  *  CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
21  *  SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
22  *  INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
23  *  CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
24  *  ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
25  *  POSSIBILITY OF SUCH DAMAGE.
26  */
27 
28 #include <puffs.h>
29 #include <stdio.h>
30 #include <sys/types.h>
31 
32 #include "perfuse_if.h"
33 #include "perfuse_priv.h"
34 #include "fuse.h"
35 
36 struct perfuse_opcode {
37 	int  opcode;
38 	const char *opname;
39 };
40 
41 const struct perfuse_opcode perfuse_opcode[] = {
42 	{ FUSE_LOOKUP, "LOOKUP" },
43 	{ FUSE_FORGET, "FORGET" },
44 	{ FUSE_GETATTR, "GETATTR" },
45 	{ FUSE_SETATTR, "SETATTR" },
46 	{ FUSE_READLINK, "READLINK" },
47 	{ FUSE_SYMLINK, "SYMLINK" },
48 	{ FUSE_MKNOD, "MKNOD" },
49 	{ FUSE_MKDIR, "MKDIR" },
50 	{ FUSE_UNLINK, "UNLINK" },
51 	{ FUSE_RMDIR, "RMDIR" },
52 	{ FUSE_RENAME, "RENAME" },
53 	{ FUSE_LINK, "LINK" },
54 	{ FUSE_OPEN, "OPEN" },
55 	{ FUSE_READ, "READ" },
56 	{ FUSE_WRITE, "WRITE" },
57 	{ FUSE_STATFS, "STATFS" },
58 	{ FUSE_RELEASE, "RELEASE" },
59 	{ FUSE_FSYNC, "FSYNC" },
60 	{ FUSE_SETXATTR, "SETXATTR" },
61 	{ FUSE_GETXATTR, "GETXATTR" },
62 	{ FUSE_LISTXATTR, "LISTXATTR" },
63 	{ FUSE_REMOVEXATTR, "REMOVEXATTR" },
64 	{ FUSE_FLUSH, "FLUSH" },
65 	{ FUSE_INIT, "INIT" },
66 	{ FUSE_OPENDIR, "OPENDIR" },
67 	{ FUSE_READDIR, "READDIR" },
68 	{ FUSE_RELEASEDIR, "RELEASEDIR" },
69 	{ FUSE_FSYNCDIR, "FSYNCDIR" },
70 	{ FUSE_GETLK, "GETLK" },
71 	{ FUSE_SETLK, "SETLK" },
72 	{ FUSE_SETLKW, "SETLKW" },
73 	{ FUSE_ACCESS, "ACCESS" },
74 	{ FUSE_CREATE, "CREATE" },
75 	{ FUSE_INTERRUPT, "INTERRUPT" },
76 	{ FUSE_BMAP, "BMAP" },
77 	{ FUSE_DESTROY, "DESTROY" },
78 	{ FUSE_IOCTL, "IOCTL" },
79 	{ FUSE_POLL, "POLL" },
80 	{ FUSE_CUSE_INIT, "CUSE_INIT" },
81 	{ 0, "UNKNOWN" },
82 };
83 
84 const char *perfuse_qtypestr[] = {
85 	"READDIR",
86 	"READ",
87 	"WRITE",
88 	"AFTERWRITE",
89 	"OPEN",
90 	"AFTERXCHG"
91 };
92 
93 const char *
94 perfuse_opname(opcode)
95 	int opcode;
96 {
97 	const struct perfuse_opcode *po;
98 
99 	for (po = perfuse_opcode; po->opcode; po++) {
100 		if (po->opcode == opcode)
101 			return po->opname;
102 	}
103 
104 	return po->opname; /* "UNKNOWN" */
105 }
106 
107 char *
108 perfuse_opdump_in(ps, pm)
109 	struct perfuse_state *ps;
110 	perfuse_msg_t *pm;
111 {
112 	struct fuse_in_header *fih;
113 	static char buf[BUFSIZ] = "";
114 
115 	fih = GET_INHDR(ps, pm);
116 
117 	switch(fih->opcode) {
118 	case FUSE_LOOKUP:
119 		(void)snprintf(buf, sizeof(buf), "path = \"%s\"",
120 			       _GET_INPAYLOAD(ps, pm, const char *));
121 		break;
122 	default:
123 		buf[0] = '\0';
124 		break;
125 	}
126 
127 	return buf;
128 }
129 
130 void
131 perfuse_trace_dump(pu, fp)
132 	struct puffs_usermount *pu;
133 	FILE *fp;
134 {
135 	struct perfuse_state *ps;
136 	struct perfuse_trace *pt;
137 	struct timespec ts_min[FUSE_OPCODE_MAX];
138 	struct timespec ts_max[FUSE_OPCODE_MAX];
139 	struct timespec ts_total[FUSE_OPCODE_MAX];
140 	int count[FUSE_OPCODE_MAX];
141 	uint64_t avg;
142 	int i;
143 
144 	if (!(perfuse_diagflags & PDF_TRACE))
145 		return;
146 
147 	ps = puffs_getspecific(pu);
148 
149 	(void)ftruncate(fileno(fp), 0);
150 	(void)fseek(fp, 0, SEEK_SET);
151 
152 	(void)memset(&ts_min, 0, sizeof(ts_min));
153 	(void)memset(&ts_max, 0, sizeof(ts_max));
154 	(void)memset(&ts_total, 0, sizeof(ts_total));
155 	(void)memset(&count, 0, sizeof(count));
156 
157 	fprintf(fp, "Last %"PRId64" operations\n", ps->ps_tracecount);
158 
159 	TAILQ_FOREACH(pt, &ps->ps_trace, pt_list) {
160 		const char *quote = pt->pt_path[0] != '\0' ? "\"" : "";
161 
162 		fprintf(fp, "%" PRIu64 ".%09ld %s %s%s%s %s ",
163 			pt->pt_start.tv_sec, pt->pt_start.tv_nsec,
164 			perfuse_opname(pt->pt_opcode),
165 			quote, pt->pt_path, quote,
166 			pt->pt_extra);
167 
168 		if (pt->pt_status == done) {
169 			struct timespec ts;
170 
171 			ts.tv_sec = 0;	/* delint */
172 			ts.tv_nsec = 0;	/* delint */
173 			timespecsub(&pt->pt_end, &pt->pt_start, &ts);
174 
175 			fprintf(fp, "error = %d elapsed = %" PRIu64 ".%09lu ",
176 				pt->pt_error, ts.tv_sec, ts.tv_nsec);
177 
178 			count[pt->pt_opcode]++;
179 			timespecadd(&ts_total[pt->pt_opcode],
180 				    &ts,
181 				    &ts_total[pt->pt_opcode]);
182 
183 			if (timespeccmp(&ts, &ts_min[pt->pt_opcode], <) ||
184 			    (count[pt->pt_opcode] == 1))
185 				ts_min[pt->pt_opcode] = ts;
186 
187 			if (timespeccmp(&ts, &ts_max[pt->pt_opcode], >))
188 				ts_max[pt->pt_opcode] = ts;
189 		} else {
190 			fprintf(fp, "ongoing ");
191 		}
192 
193 		fprintf(fp, "\n");
194 	}
195 
196 	fprintf(fp, "\nStatistics by operation\n");
197 	fprintf(fp, "operation\tcount\tmin\tavg\tmax\n");
198 	for (i = 0; i < FUSE_OPCODE_MAX; i++) {
199 		time_t min;
200 
201 		if (count[i] != 0) {
202 			avg = timespec2ns(&ts_total[i]) / count[i];
203 			min = ts_min[i].tv_sec;
204 		} else {
205 			avg = 0;
206 			min = 0;
207 		}
208 
209 		fprintf(fp, "%s\t%d\t%" PRId64 ".%09ld\t%" PRId64
210 		    ".%09ld\t%" PRId64 ".%09ld\t\n",
211 			perfuse_opname(i), count[i],
212 			min, ts_min[i].tv_nsec,
213 			(time_t)(avg / 1000000000L), (long)(avg % 1000000000L),
214 			ts_max[i].tv_sec, ts_max[i].tv_nsec);
215 	}
216 
217 	(void)fflush(fp);
218 	return;
219 }
220