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