1 /* $NetBSD: debug.c,v 1.13 2018/11/16 02:39:02 manu 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 <stdlib.h>
31 #include <err.h>
32 #include <errno.h>
33 #include <sys/types.h>
34
35 #include "perfuse_if.h"
36 #include "perfuse_priv.h"
37 #include "fuse.h"
38
39 struct perfuse_opcode {
40 int opcode;
41 const char *opname;
42 };
43
44 const struct perfuse_opcode perfuse_opcode[] = {
45 { FUSE_LOOKUP, "LOOKUP" },
46 { FUSE_FORGET, "FORGET" },
47 { FUSE_GETATTR, "GETATTR" },
48 { FUSE_SETATTR, "SETATTR" },
49 { FUSE_READLINK, "READLINK" },
50 { FUSE_SYMLINK, "SYMLINK" },
51 { FUSE_MKNOD, "MKNOD" },
52 { FUSE_MKDIR, "MKDIR" },
53 { FUSE_UNLINK, "UNLINK" },
54 { FUSE_RMDIR, "RMDIR" },
55 { FUSE_RENAME, "RENAME" },
56 { FUSE_LINK, "LINK" },
57 { FUSE_OPEN, "OPEN" },
58 { FUSE_READ, "READ" },
59 { FUSE_WRITE, "WRITE" },
60 { FUSE_STATFS, "STATFS" },
61 { FUSE_RELEASE, "RELEASE" },
62 { FUSE_FSYNC, "FSYNC" },
63 { FUSE_SETXATTR, "SETXATTR" },
64 { FUSE_GETXATTR, "GETXATTR" },
65 { FUSE_LISTXATTR, "LISTXATTR" },
66 { FUSE_REMOVEXATTR, "REMOVEXATTR" },
67 { FUSE_FLUSH, "FLUSH" },
68 { FUSE_INIT, "INIT" },
69 { FUSE_OPENDIR, "OPENDIR" },
70 { FUSE_READDIR, "READDIR" },
71 { FUSE_RELEASEDIR, "RELEASEDIR" },
72 { FUSE_FSYNCDIR, "FSYNCDIR" },
73 { FUSE_GETLK, "GETLK" },
74 { FUSE_SETLK, "SETLK" },
75 { FUSE_SETLKW, "SETLKW" },
76 { FUSE_ACCESS, "ACCESS" },
77 { FUSE_CREATE, "CREATE" },
78 { FUSE_INTERRUPT, "INTERRUPT" },
79 { FUSE_BMAP, "BMAP" },
80 { FUSE_DESTROY, "DESTROY" },
81 { FUSE_IOCTL, "IOCTL" },
82 { FUSE_POLL, "POLL" },
83 { FUSE_CUSE_INIT, "CUSE_INIT" },
84 { 0, "UNKNOWN" },
85 };
86
87 const char * const perfuse_qtypestr[] = {
88 "READDIR",
89 "READ",
90 "WRITE",
91 "AFTERWRITE",
92 "OPEN",
93 "AFTERXCHG",
94 "REF"
95 };
96
97 const char *
perfuse_opname(int opcode)98 perfuse_opname(int opcode)
99 {
100 const struct perfuse_opcode *po;
101
102 for (po = perfuse_opcode; po->opcode; po++) {
103 if (po->opcode == opcode)
104 return po->opname;
105 }
106
107 return po->opname; /* "UNKNOWN" */
108 }
109
110 char *
perfuse_opdump_in(struct perfuse_state * ps,perfuse_msg_t * pm)111 perfuse_opdump_in(struct perfuse_state *ps, perfuse_msg_t *pm)
112 {
113 struct fuse_in_header *fih;
114 static char buf[BUFSIZ] = "";
115
116 fih = GET_INHDR(ps, pm);
117
118 switch(fih->opcode) {
119 case FUSE_LOOKUP:
120 (void)snprintf(buf, sizeof(buf), "path = \"%s\"",
121 _GET_INPAYLOAD(ps, pm, const char *));
122 break;
123 default:
124 buf[0] = '\0';
125 break;
126 }
127
128 return buf;
129 }
130
131 struct perfuse_trace *
perfuse_trace_begin(struct perfuse_state * ps,puffs_cookie_t opc,perfuse_msg_t * pm)132 perfuse_trace_begin(struct perfuse_state *ps, puffs_cookie_t opc,
133 perfuse_msg_t *pm)
134 {
135 struct perfuse_trace *pt;
136
137 if ((pt = malloc(sizeof(*pt))) == NULL)
138 DERR(EX_OSERR, "malloc failed");
139
140 pt->pt_opcode = ps->ps_get_inhdr(pm)->opcode;
141 pt->pt_status = inxchg;
142
143 if (clock_gettime(CLOCK_REALTIME, &pt->pt_start) != 0)
144 DERR(EX_OSERR, "clock_gettime failed");
145
146 if (opc == 0)
147 (void)strcpy(pt->pt_path, "");
148 else
149 (void)strlcpy(pt->pt_path,
150 perfuse_node_path(ps, opc),
151 sizeof(pt->pt_path));
152
153 (void)strlcpy(pt->pt_extra,
154 perfuse_opdump_in(ps, pm),
155 sizeof(pt->pt_extra));
156
157 TAILQ_INSERT_TAIL(&ps->ps_trace, pt, pt_list);
158 ps->ps_tracecount++;
159
160 return pt;
161 }
162
163 void
perfuse_trace_end(struct perfuse_state * ps,struct perfuse_trace * pt,int error)164 perfuse_trace_end(struct perfuse_state *ps, struct perfuse_trace *pt, int error)
165 {
166 if (clock_gettime(CLOCK_REALTIME, &pt->pt_end) != 0)
167 DERR(EX_OSERR, "clock_gettime failed");
168
169 pt->pt_status = done;
170 pt->pt_error = error;
171
172 while (ps->ps_tracecount > PERFUSE_TRACECOUNT_MAX) {
173 struct perfuse_trace *fpt = TAILQ_FIRST(&ps->ps_trace);
174
175 if (fpt == NULL || fpt->pt_status != done)
176 break;
177
178 TAILQ_REMOVE(&ps->ps_trace, fpt, pt_list);
179 free(fpt);
180 ps->ps_tracecount--;
181 }
182 }
183
184 void
perfuse_trace_dump(struct puffs_usermount * pu,FILE * fp)185 perfuse_trace_dump(struct puffs_usermount *pu, FILE *fp)
186 {
187 struct perfuse_state *ps;
188 struct perfuse_trace *pt;
189 struct timespec ts_min[FUSE_OPCODE_MAX];
190 struct timespec ts_max[FUSE_OPCODE_MAX];
191 struct timespec ts_total[FUSE_OPCODE_MAX];
192 int count[FUSE_OPCODE_MAX];
193 uint64_t avg;
194 int i;
195
196 if (!(perfuse_diagflags & PDF_TRACE))
197 return;
198
199 ps = puffs_getspecific(pu);
200
201 (void)ftruncate(fileno(fp), 0);
202 (void)fseek(fp, 0UL, SEEK_SET);
203
204 (void)memset(&ts_min, 0, sizeof(ts_min));
205 (void)memset(&ts_max, 0, sizeof(ts_max));
206 (void)memset(&ts_total, 0, sizeof(ts_total));
207 (void)memset(&count, 0, sizeof(count));
208
209 fprintf(fp, "Last %"PRId64" operations\n", ps->ps_tracecount);
210
211 TAILQ_FOREACH(pt, &ps->ps_trace, pt_list) {
212 const char *quote = pt->pt_path[0] != '\0' ? "\"" : "";
213
214 fprintf(fp, "%lld.%09ld %s %s%s%s %s ",
215 (long long)pt->pt_start.tv_sec, pt->pt_start.tv_nsec,
216 perfuse_opname(pt->pt_opcode),
217 quote, pt->pt_path, quote,
218 pt->pt_extra);
219
220 if (pt->pt_status == done) {
221 struct timespec ts;
222
223 ts.tv_sec = 0; /* delint */
224 ts.tv_nsec = 0; /* delint */
225 timespecsub(&pt->pt_end, &pt->pt_start, &ts);
226
227 fprintf(fp, "error = %d elapsed = %lld.%09lu ",
228 pt->pt_error, (long long)ts.tv_sec,
229 ts.tv_nsec);
230
231 count[pt->pt_opcode]++;
232 timespecadd(&ts_total[pt->pt_opcode],
233 &ts,
234 &ts_total[pt->pt_opcode]);
235
236 if (timespeccmp(&ts, &ts_min[pt->pt_opcode], <) ||
237 (count[pt->pt_opcode] == 1))
238 ts_min[pt->pt_opcode] = ts;
239
240 if (timespeccmp(&ts, &ts_max[pt->pt_opcode], >))
241 ts_max[pt->pt_opcode] = ts;
242 } else {
243 fprintf(fp, "ongoing ");
244 }
245
246 fprintf(fp, "\n");
247 }
248
249 fprintf(fp, "\nStatistics by operation\n");
250 fprintf(fp, "operation\tcount\tmin\tavg\tmax\n");
251 for (i = 0; i < FUSE_OPCODE_MAX; i++) {
252 time_t min;
253
254 if (count[i] != 0) {
255 avg = timespec2ns(&ts_total[i]) / count[i];
256 min = ts_min[i].tv_sec;
257 } else {
258 avg = 0;
259 min = 0;
260 }
261
262 fprintf(fp, "%s\t%d\t%lld.%09ld\t%lld.%09ld\t%lld.%09ld\t\n",
263 perfuse_opname(i), count[i],
264 (long long)min, ts_min[i].tv_nsec,
265 (long long)(time_t)(avg / 1000000000L),
266 (long)(avg % 1000000000L),
267 (long long)ts_max[i].tv_sec, ts_max[i].tv_nsec);
268 }
269
270 fprintf(fp, "\n\nGlobal statistics\n");
271 fprintf(fp, "Nodes: %d\n", ps->ps_nodecount);
272 fprintf(fp, "Exchanges: %d\n", ps->ps_xchgcount);
273
274 (void)fflush(fp);
275 return;
276 }
277