e0ab229650fb93ff9d8c4eeb5c16377a23e1b330
[akaros.git] / kern / drivers / dev / kprof.c
1 /*
2  * This file is part of the UCB release of Plan 9. It is subject to the license
3  * terms in the LICENSE file found in the top-level directory of this
4  * distribution and at http://akaros.cs.berkeley.edu/files/Plan9License. No
5  * part of the UCB release of Plan 9, including this file, may be copied,
6  * modified, propagated, or distributed except according to the terms contained
7  * in the LICENSE file.
8  */
9
10 #include <ros/profiler_records.h>
11 #include <arch/time.h>
12 #include <vfs.h>
13 #include <slab.h>
14 #include <kmalloc.h>
15 #include <kref.h>
16 #include <atomic.h>
17 #include <kthread.h>
18 #include <string.h>
19 #include <stdio.h>
20 #include <assert.h>
21 #include <error.h>
22 #include <pmap.h>
23 #include <smp.h>
24 #include <time.h>
25 #include <circular_buffer.h>
26 #include <umem.h>
27 #include <profiler.h>
28 #include <kprof.h>
29 #include <ros/procinfo.h>
30
31 #define KTRACE_BUFFER_SIZE (128 * 1024)
32 #define TRACE_PRINTK_BUFFER_SIZE (8 * 1024)
33
34 enum {
35         Kprofdirqid = 0,
36         Kprofdataqid,
37         Kprofctlqid,
38         Kptraceqid,
39         Kprintxqid,
40         Kmpstatqid,
41         Kmpstatrawqid,
42 };
43
44 struct trace_printk_buffer {
45         atomic_t in_use;
46         char buffer[TRACE_PRINTK_BUFFER_SIZE];
47 };
48
49 struct kprof {
50         qlock_t lock;
51         bool mpstat_ipi;
52         bool profiling;
53         bool opened;
54 };
55
56 struct dev kprofdevtab;
57 struct dirtab kproftab[] = {
58         {".",                   {Kprofdirqid,           0, QTDIR}, 0,   DMDIR|0550},
59         {"kpdata",              {Kprofdataqid},         0,      0600},
60         {"kpctl",               {Kprofctlqid},          0,      0600},
61         {"kptrace",             {Kptraceqid},           0,      0600},
62         {"kprintx",             {Kprintxqid},           0,      0600},
63         {"mpstat",              {Kmpstatqid},           0,      0600},
64         {"mpstat-raw",  {Kmpstatrawqid},        0,      0600},
65 };
66
67 static struct kprof kprof;
68 static bool ktrace_init_done = FALSE;
69 static spinlock_t ktrace_lock = SPINLOCK_INITIALIZER_IRQSAVE;
70 static struct circular_buffer ktrace_data;
71 static char ktrace_buffer[KTRACE_BUFFER_SIZE];
72 static char kprof_control_usage[128];
73
74 static size_t mpstat_len(void)
75 {
76         size_t each_row = 7 + NR_CPU_STATES * 26;
77
78         return each_row * (num_cores + 1) + 1;
79 }
80
81 static size_t mpstatraw_len(void)
82 {
83         size_t header_row = 27 + NR_CPU_STATES * 7 + 1;
84         size_t cpu_row = 7 + NR_CPU_STATES * 17;
85
86         return header_row + cpu_row * num_cores + 1;
87 }
88
89 static char *devname(void)
90 {
91         return kprofdevtab.name;
92 }
93
94 static struct chan *kprof_attach(char *spec)
95 {
96         return devattach(devname(), spec);
97 }
98
99 /* Start collecting samples from perf events into the profiler.
100  *
101  * This command only runs if the user successfully opened kpctl, which gives
102  * them a profiler (the global profiler, for now). */
103 static void kprof_start_profiler(void)
104 {
105         ERRSTACK(1);
106
107         qlock(&kprof.lock);
108         if (waserror()) {
109                 qunlock(&kprof.lock);
110                 nexterror();
111         }
112         if (!kprof.profiling) {
113                 profiler_start();
114                 kprof.profiling = TRUE;
115         }
116         poperror();
117         qunlock(&kprof.lock);
118 }
119
120 /* Stops collecting samples from perf events.
121  *
122  * This command only runs if the user successfully opened kpctl, which gives
123  * them a profiler (the global profiler, for now). */
124 static void kprof_stop_profiler(void)
125 {
126         ERRSTACK(1);
127
128         qlock(&kprof.lock);
129         if (waserror()) {
130                 qunlock(&kprof.lock);
131                 nexterror();
132         }
133         if (kprof.profiling) {
134                 profiler_stop();
135                 kprof.profiling = FALSE;
136         }
137         poperror();
138         qunlock(&kprof.lock);
139 }
140
141 /* Makes each core flush its results into the profiler queue.  You can do this
142  * while the profiler is still running.  However, this does not hang up the
143  * queue, so reads on kpdata will block. */
144 static void kprof_flush_profiler(void)
145 {
146         ERRSTACK(1);
147
148         qlock(&kprof.lock);
149         if (waserror()) {
150                 qunlock(&kprof.lock);
151                 nexterror();
152         }
153         if (kprof.profiling)
154                 profiler_trace_data_flush();
155         poperror();
156         qunlock(&kprof.lock);
157 }
158
159 static void kprof_init(void)
160 {
161         profiler_init();
162
163         qlock_init(&kprof.lock);
164         kprof.profiling = FALSE;
165         kprof.opened = FALSE;
166
167         for (int i = 0; i < ARRAY_SIZE(kproftab); i++)
168                 kproftab[i].length = 0;
169
170         kprof.mpstat_ipi = TRUE;
171         kproftab[Kmpstatqid].length = mpstat_len();
172         kproftab[Kmpstatrawqid].length = mpstatraw_len();
173
174         strlcpy(kprof_control_usage, "start|stop|flush",
175                 sizeof(kprof_control_usage));
176         profiler_append_configure_usage(kprof_control_usage,
177                                         sizeof(kprof_control_usage));
178 }
179
180 static void kprof_shutdown(void)
181 {
182 }
183
184 static struct walkqid *kprof_walk(struct chan *c, struct chan *nc, char **name,
185                                   int nname)
186 {
187         return devwalk(c, nc, name, nname, kproftab, ARRAY_SIZE(kproftab), devgen);
188 }
189
190 static size_t kprof_profdata_size(void)
191 {
192         return profiler_size();
193 }
194
195 static long kprof_profdata_read(void *dest, long size, int64_t off)
196 {
197         return profiler_read(dest, size);
198 }
199
200 static int kprof_stat(struct chan *c, uint8_t *db, int n)
201 {
202         kproftab[Kprofdataqid].length = kprof_profdata_size();
203         kproftab[Kptraceqid].length = kprof_tracedata_size();
204
205         return devstat(c, db, n, kproftab, ARRAY_SIZE(kproftab), devgen);
206 }
207
208 static struct chan *kprof_open(struct chan *c, int omode)
209 {
210         if (c->qid.type & QTDIR) {
211                 if (openmode(omode) != O_READ)
212                         error(EPERM, ERROR_FIXME);
213         }
214         switch ((int) c->qid.path) {
215         case Kprofctlqid:
216                 /* We have one global profiler.  Only one FD may be opened at a time for
217                  * it.  If we ever have separate profilers, we can create the profiler
218                  * here, and every open would get a separate instance. */
219                 qlock(&kprof.lock);
220                 if (kprof.opened) {
221                         qunlock(&kprof.lock);
222                         error(EBUSY, "Global profiler is already open");
223                 }
224                 kprof.opened = TRUE;
225                 /* TODO: have a real creation function for a non-global profiler */
226                 profiler_setup();
227                 qunlock(&kprof.lock);
228                 break;
229         }
230         c->mode = openmode(omode);
231         c->flag |= COPEN;
232         c->offset = 0;
233         return c;
234 }
235
236 static void kprof_close(struct chan *c)
237 {
238         if (c->flag & COPEN) {
239                 switch ((int) c->qid.path) {
240                 case Kprofctlqid:
241                         kprof_stop_profiler();
242                         qlock(&kprof.lock);
243                         profiler_cleanup();
244                         kprof.opened = FALSE;
245                         qunlock(&kprof.lock);
246                         break;
247                 }
248         }
249 }
250
251 static long mpstat_read(void *va, long n, int64_t off)
252 {
253         size_t bufsz = mpstat_len();
254         char *buf = kmalloc(bufsz, MEM_WAIT);
255         int len = 0;
256         struct per_cpu_info *pcpui;
257         uint64_t cpu_total;
258         struct timespec ts;
259
260         /* the IPI interferes with other cores, might want to disable that. */
261         if (kprof.mpstat_ipi)
262                 send_broadcast_ipi(I_POKE_CORE);
263
264         len += snprintf(buf + len, bufsz - len, "  CPU: ");
265         for (int j = 0; j < NR_CPU_STATES; j++)
266                 len += snprintf(buf + len, bufsz - len, "%23s%s", cpu_state_names[j],
267                                 j != NR_CPU_STATES - 1 ? "   " : "  \n");
268
269         for (int i = 0; i < num_cores; i++) {
270                 pcpui = &per_cpu_info[i];
271                 cpu_total = 0;
272                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
273                 for (int j = 0; j < NR_CPU_STATES; j++)
274                         cpu_total += pcpui->state_ticks[j];
275                 cpu_total = MAX(cpu_total, 1);  /* for the divide later */
276                 for (int j = 0; j < NR_CPU_STATES; j++) {
277                         ts = tsc2timespec(pcpui->state_ticks[j]);
278                         len += snprintf(buf + len, bufsz - len, "%10d.%06d (%3d%%)%s",
279                                         ts.tv_sec, ts.tv_nsec / 1000,
280                                         MIN((pcpui->state_ticks[j] * 100) / cpu_total, 100),
281                                         j != NR_CPU_STATES - 1 ? ", " : " \n");
282                 }
283         }
284         n = readstr(off, va, n, buf);
285         kfree(buf);
286         return n;
287 }
288
289 static long mpstatraw_read(void *va, long n, int64_t off)
290 {
291         size_t bufsz = mpstatraw_len();
292         char *buf = kmalloc(bufsz, MEM_WAIT);
293         int len = 0;
294         struct per_cpu_info *pcpui;
295
296         /* could spit it all out in binary, though then it'd be harder to process
297          * the data across a mnt (if we export #K).  probably not a big deal. */
298
299         /* header line: version, num_cores, tsc freq, state names */
300         len += snprintf(buf + len, bufsz - len, "v%03d %5d %16llu", 1, num_cores,
301                         __proc_global_info.tsc_freq);
302         for (int j = 0; j < NR_CPU_STATES; j++)
303                 len += snprintf(buf + len, bufsz - len, " %6s", cpu_state_names[j]);
304         len += snprintf(buf + len, bufsz - len, "\n");
305
306         for (int i = 0; i < num_cores; i++) {
307                 pcpui = &per_cpu_info[i];
308                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
309                 for (int j = 0; j < NR_CPU_STATES; j++) {
310                         len += snprintf(buf + len, bufsz - len, "%16llx%s",
311                                         pcpui->state_ticks[j],
312                                         j != NR_CPU_STATES - 1 ? " " : "\n");
313                 }
314         }
315         n = readstr(off, va, n, buf);
316         kfree(buf);
317         return n;
318 }
319
320 static long kprof_read(struct chan *c, void *va, long n, int64_t off)
321 {
322         uint64_t w, *bp;
323         char *a, *ea;
324         uintptr_t offset = off;
325         uint64_t pc;
326
327         switch ((int) c->qid.path) {
328         case Kprofdirqid:
329                 return devdirread(c, va, n, kproftab, ARRAY_SIZE(kproftab), devgen);
330         case Kprofdataqid:
331                 n = kprof_profdata_read(va, n, off);
332                 break;
333         case Kptraceqid:
334                 n = kprof_tracedata_read(va, n, off);
335                 break;
336         case Kprintxqid:
337                 n = readstr(offset, va, n, printx_on ? "on" : "off");
338                 break;
339         case Kmpstatqid:
340                 n = mpstat_read(va, n, offset);
341                 break;
342         case Kmpstatrawqid:
343                 n = mpstatraw_read(va, n, offset);
344                 break;
345         default:
346                 n = 0;
347                 break;
348         }
349         return n;
350 }
351
352 static long kprof_write(struct chan *c, void *a, long n, int64_t unused)
353 {
354         ERRSTACK(1);
355         struct cmdbuf *cb = parsecmd(a, n);
356
357         if (waserror()) {
358                 kfree(cb);
359                 nexterror();
360         }
361         switch ((int) c->qid.path) {
362         case Kprofctlqid:
363                 if (cb->nf < 1)
364                         error(EFAIL, kprof_control_usage);
365                 if (profiler_configure(cb))
366                         break;
367                 if (!strcmp(cb->f[0], "start")) {
368                         kprof_start_profiler();
369                 } else if (!strcmp(cb->f[0], "flush")) {
370                         kprof_flush_profiler();
371                 } else if (!strcmp(cb->f[0], "stop")) {
372                         kprof_stop_profiler();
373                 } else {
374                         error(EFAIL, kprof_control_usage);
375                 }
376                 break;
377         case Kprofdataqid:
378                 profiler_add_trace((uintptr_t) strtoul(a, 0, 0), 0);
379                 break;
380         case Kptraceqid:
381                 if (a && (n > 0)) {
382                         char *uptr = user_strdup_errno(current, a, n);
383
384                         if (uptr) {
385                                 trace_printk(false, "%s", uptr);
386                                 user_memdup_free(current, uptr);
387                         } else {
388                                 n = -1;
389                         }
390                 }
391                 break;
392         case Kprintxqid:
393                 if (!strncmp(a, "on", 2))
394                         set_printx(1);
395                 else if (!strncmp(a, "off", 3))
396                         set_printx(0);
397                 else if (!strncmp(a, "toggle", 6))
398                         set_printx(2);
399                 else
400                         error(EFAIL, "Invalid option to Kprintx %s\n", a);
401                 break;
402         case Kmpstatqid:
403         case Kmpstatrawqid:
404                 if (cb->nf < 1)
405                         error(EFAIL, "Bad mpstat option (reset|ipi|on|off)");
406                 if (!strcmp(cb->f[0], "reset")) {
407                         for (int i = 0; i < num_cores; i++)
408                                 reset_cpu_state_ticks(i);
409                 } else if (!strcmp(cb->f[0], "on")) {
410                         /* TODO: enable the ticks */ ;
411                 } else if (!strcmp(cb->f[0], "off")) {
412                         /* TODO: disable the ticks */ ;
413                 } else if (!strcmp(cb->f[0], "ipi")) {
414                         if (cb->nf < 2)
415                                 error(EFAIL, "Need another arg: ipi [on|off]");
416                         if (!strcmp(cb->f[1], "on"))
417                                 kprof.mpstat_ipi = TRUE;
418                         else if (!strcmp(cb->f[1], "off"))
419                                 kprof.mpstat_ipi = FALSE;
420                         else
421                                 error(EFAIL, "ipi [on|off]");
422                 } else {
423                         error(EFAIL, "Bad mpstat option (reset|ipi|on|off)");
424                 }
425                 break;
426         default:
427                 error(EBADFD, ERROR_FIXME);
428         }
429         kfree(cb);
430         poperror();
431         return n;
432 }
433
434 size_t kprof_tracedata_size(void)
435 {
436         return circular_buffer_size(&ktrace_data);
437 }
438
439 size_t kprof_tracedata_read(void *data, size_t size, size_t offset)
440 {
441         spin_lock_irqsave(&ktrace_lock);
442         if (likely(ktrace_init_done))
443                 size = circular_buffer_read(&ktrace_data, data, size, offset);
444         else
445                 size = 0;
446         spin_unlock_irqsave(&ktrace_lock);
447
448         return size;
449 }
450
451 void kprof_tracedata_write(const char *pretty_buf, size_t len)
452 {
453         spin_lock_irqsave(&ktrace_lock);
454         if (unlikely(!ktrace_init_done)) {
455                 circular_buffer_init(&ktrace_data, sizeof(ktrace_buffer),
456                                      ktrace_buffer);
457                 ktrace_init_done = TRUE;
458         }
459         circular_buffer_write(&ktrace_data, pretty_buf, len);
460         spin_unlock_irqsave(&ktrace_lock);
461 }
462
463 static struct trace_printk_buffer *kprof_get_printk_buffer(void)
464 {
465         static struct trace_printk_buffer boot_tpb;
466         static struct trace_printk_buffer *cpu_tpbs;
467         static atomic_t alloc_done;
468
469         if (unlikely(!num_cores))
470                 return &boot_tpb;
471         if (unlikely(!cpu_tpbs)) {
472                 /* Poor man per-CPU data structure. I really do no like littering global
473                  * data structures with module specific data.
474                  * We cannot take the ktrace_lock to protect the kzmalloc() call, as
475                  * that might trigger printk()s, and we would reenter here.
476                  * Let only one core into the kzmalloc() path, and let the others get
477                  * the boot_tpb until finished.
478                  */
479                 if (!atomic_cas(&alloc_done, 0, 1))
480                         return &boot_tpb;
481                 cpu_tpbs = kzmalloc(num_cores * sizeof(struct trace_printk_buffer), 0);
482         }
483
484         return cpu_tpbs + core_id_early();
485 }
486
487 void trace_vprintk(bool btrace, const char *fmt, va_list args)
488 {
489         struct print_buf {
490                 char *ptr;
491                 char *top;
492         };
493
494         void emit_print_buf_str(struct print_buf *pb, const char *str, ssize_t size)
495         {
496                 if (size < 0) {
497                         for (; *str && (pb->ptr < pb->top); str++)
498                                 *(pb->ptr++) = *str;
499                 } else {
500                         for (; (size > 0) && (pb->ptr < pb->top); str++, size--)
501                                 *(pb->ptr++) = *str;
502                 }
503         }
504
505         void bt_print(void *opaque, const char *str)
506         {
507                 struct print_buf *pb = (struct print_buf *) opaque;
508
509                 emit_print_buf_str(pb, "\t", 1);
510                 emit_print_buf_str(pb, str, -1);
511         }
512
513         static const size_t bufsz = TRACE_PRINTK_BUFFER_SIZE;
514         static const size_t usr_bufsz = (3 * bufsz) / 8;
515         static const size_t kp_bufsz = bufsz - usr_bufsz;
516         struct trace_printk_buffer *tpb = kprof_get_printk_buffer();
517         struct timespec ts_now = { 0, 0 };
518         struct print_buf pb;
519         char *usrbuf = tpb->buffer, *kpbuf = tpb->buffer + usr_bufsz;
520         const char *utop, *uptr;
521         char hdr[64];
522
523         if (!atomic_cas(&tpb->in_use, 0, 1))
524                 return;
525         if (likely(__proc_global_info.tsc_freq))
526                 ts_now = tsc2timespec(read_tsc());
527         snprintf(hdr, sizeof(hdr), "[%lu.%09lu]:cpu%d: ", ts_now.tv_sec,
528                  ts_now.tv_nsec, core_id_early());
529
530         pb.ptr = usrbuf + vsnprintf(usrbuf, usr_bufsz, fmt, args);
531         pb.top = usrbuf + usr_bufsz;
532
533         if (pb.ptr[-1] != '\n')
534                 emit_print_buf_str(&pb, "\n", 1);
535         if (btrace) {
536                 emit_print_buf_str(&pb, "\tBacktrace:\n", -1);
537                 gen_backtrace(bt_print, &pb);
538         }
539         /* snprintf null terminates the buffer, and does not count that as part of
540          * the len.  If we maxed out the buffer, let's make sure it has a \n.
541          */
542         if (pb.ptr == pb.top)
543                 pb.ptr[-1] = '\n';
544         utop = pb.ptr;
545
546         pb.ptr = kpbuf;
547         pb.top = kpbuf + kp_bufsz;
548         for (uptr = usrbuf; uptr < utop;) {
549                 const char *nlptr = memchr(uptr, '\n', utop - uptr);
550
551                 if (nlptr == NULL)
552                         nlptr = utop;
553                 emit_print_buf_str(&pb, hdr, -1);
554                 emit_print_buf_str(&pb, uptr, (nlptr - uptr) + 1);
555                 uptr = nlptr + 1;
556         }
557         kprof_tracedata_write(kpbuf, pb.ptr - kpbuf);
558         atomic_set(&tpb->in_use, 0);
559 }
560
561 void trace_printk(bool btrace, const char *fmt, ...)
562 {
563         va_list args;
564
565         va_start(args, fmt);
566         trace_vprintk(btrace, fmt, args);
567         va_end(args);
568 }
569
570 struct dev kprofdevtab __devtab = {
571         .name = "kprof",
572
573         .reset = devreset,
574         .init = kprof_init,
575         .shutdown = kprof_shutdown,
576         .attach = kprof_attach,
577         .walk = kprof_walk,
578         .stat = kprof_stat,
579         .open = kprof_open,
580         .create = devcreate,
581         .close = kprof_close,
582         .read = kprof_read,
583         .bread = devbread,
584         .write = kprof_write,
585         .bwrite = devbwrite,
586         .remove = devremove,
587         .wstat = devwstat,
588 };