debug.c revision 1.10
1 /* $NetBSD: debug.c,v 1.10 2012/01/29 09:01:31 dholland 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 *perfuse_qtypestr[] = { 88 "READDIR", 89 "READ", 90 "WRITE", 91 "AFTERWRITE", 92 "OPEN", 93 "AFTERXCHG" 94 }; 95 96 const char * 97 perfuse_opname(opcode) 98 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 * 111 perfuse_opdump_in(ps, pm) 112 struct perfuse_state *ps; 113 perfuse_msg_t *pm; 114 { 115 struct fuse_in_header *fih; 116 static char buf[BUFSIZ] = ""; 117 118 fih = GET_INHDR(ps, pm); 119 120 switch(fih->opcode) { 121 case FUSE_LOOKUP: 122 (void)snprintf(buf, sizeof(buf), "path = \"%s\"", 123 _GET_INPAYLOAD(ps, pm, const char *)); 124 break; 125 default: 126 buf[0] = '\0'; 127 break; 128 } 129 130 return buf; 131 } 132 133 struct perfuse_trace * 134 perfuse_trace_begin(ps, opc, pm) 135 struct perfuse_state *ps; 136 puffs_cookie_t opc; 137 perfuse_msg_t *pm; 138 { 139 struct perfuse_trace *pt; 140 141 if ((pt = malloc(sizeof(*pt))) == NULL) 142 DERR(EX_OSERR, "malloc failed"); 143 144 pt->pt_opcode = ps->ps_get_inhdr(pm)->opcode; 145 pt->pt_status = inxchg; 146 147 if (clock_gettime(CLOCK_REALTIME, &pt->pt_start) != 0) 148 DERR(EX_OSERR, "clock_gettime failed"); 149 150 if (opc == 0) 151 (void)strcpy(pt->pt_path, ""); 152 else 153 (void)strlcpy(pt->pt_path, 154 perfuse_node_path(opc), 155 sizeof(pt->pt_path)); 156 157 (void)strlcpy(pt->pt_extra, 158 perfuse_opdump_in(ps, pm), 159 sizeof(pt->pt_extra)); 160 161 TAILQ_INSERT_TAIL(&ps->ps_trace, pt, pt_list); 162 ps->ps_tracecount++; 163 164 return pt; 165 } 166 167 void 168 perfuse_trace_end(ps, pt, error) 169 struct perfuse_state *ps; 170 struct perfuse_trace *pt; 171 int error; 172 { 173 if (clock_gettime(CLOCK_REALTIME, &pt->pt_end) != 0) 174 DERR(EX_OSERR, "clock_gettime failed"); 175 176 pt->pt_status = done; 177 pt->pt_error = error; 178 179 while (ps->ps_tracecount > PERFUSE_TRACECOUNT_MAX) { 180 struct perfuse_trace *fpt = TAILQ_FIRST(&ps->ps_trace); 181 182 if (fpt == NULL || fpt->pt_status != done) 183 break; 184 185 TAILQ_REMOVE(&ps->ps_trace, fpt, pt_list); 186 free(fpt); 187 ps->ps_tracecount--; 188 } 189 } 190 191 void 192 perfuse_trace_dump(pu, fp) 193 struct puffs_usermount *pu; 194 FILE *fp; 195 { 196 struct perfuse_state *ps; 197 struct perfuse_trace *pt; 198 struct timespec ts_min[FUSE_OPCODE_MAX]; 199 struct timespec ts_max[FUSE_OPCODE_MAX]; 200 struct timespec ts_total[FUSE_OPCODE_MAX]; 201 int count[FUSE_OPCODE_MAX]; 202 uint64_t avg; 203 int i; 204 205 if (!(perfuse_diagflags & PDF_TRACE)) 206 return; 207 208 ps = puffs_getspecific(pu); 209 210 (void)ftruncate(fileno(fp), 0); 211 (void)fseek(fp, 0, SEEK_SET); 212 213 (void)memset(&ts_min, 0, sizeof(ts_min)); 214 (void)memset(&ts_max, 0, sizeof(ts_max)); 215 (void)memset(&ts_total, 0, sizeof(ts_total)); 216 (void)memset(&count, 0, sizeof(count)); 217 218 fprintf(fp, "Last %"PRId64" operations\n", ps->ps_tracecount); 219 220 TAILQ_FOREACH(pt, &ps->ps_trace, pt_list) { 221 const char *quote = pt->pt_path[0] != '\0' ? "\"" : ""; 222 223 fprintf(fp, "%lld.%09ld %s %s%s%s %s ", 224 (long long)pt->pt_start.tv_sec, pt->pt_start.tv_nsec, 225 perfuse_opname(pt->pt_opcode), 226 quote, pt->pt_path, quote, 227 pt->pt_extra); 228 229 if (pt->pt_status == done) { 230 struct timespec ts; 231 232 ts.tv_sec = 0; /* delint */ 233 ts.tv_nsec = 0; /* delint */ 234 timespecsub(&pt->pt_end, &pt->pt_start, &ts); 235 236 fprintf(fp, "error = %d elapsed = %lld.%09lu ", 237 pt->pt_error, (long long)ts.tv_sec, 238 ts.tv_nsec); 239 240 count[pt->pt_opcode]++; 241 timespecadd(&ts_total[pt->pt_opcode], 242 &ts, 243 &ts_total[pt->pt_opcode]); 244 245 if (timespeccmp(&ts, &ts_min[pt->pt_opcode], <) || 246 (count[pt->pt_opcode] == 1)) 247 ts_min[pt->pt_opcode] = ts; 248 249 if (timespeccmp(&ts, &ts_max[pt->pt_opcode], >)) 250 ts_max[pt->pt_opcode] = ts; 251 } else { 252 fprintf(fp, "ongoing "); 253 } 254 255 fprintf(fp, "\n"); 256 } 257 258 fprintf(fp, "\nStatistics by operation\n"); 259 fprintf(fp, "operation\tcount\tmin\tavg\tmax\n"); 260 for (i = 0; i < FUSE_OPCODE_MAX; i++) { 261 time_t min; 262 263 if (count[i] != 0) { 264 avg = timespec2ns(&ts_total[i]) / count[i]; 265 min = ts_min[i].tv_sec; 266 } else { 267 avg = 0; 268 min = 0; 269 } 270 271 fprintf(fp, "%s\t%d\t%lld.%09ld\t%lld.%09ld\t%lld.%09ld\t\n", 272 perfuse_opname(i), count[i], 273 (long long)min, ts_min[i].tv_nsec, 274 (long long)(time_t)(avg / 1000000000L), 275 (long)(avg % 1000000000L), 276 (long long)ts_max[i].tv_sec, ts_max[i].tv_nsec); 277 } 278 279 (void)fflush(fp); 280 return; 281 } 282
Indexes created Mon Sep 22 05:09:51 GMT 2025