Clean up profiler configure and usage functions.
[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
30 #define KTRACE_BUFFER_SIZE (128 * 1024)
31 #define TRACE_PRINTK_BUFFER_SIZE (8 * 1024)
32
33 enum {
34         Kprofdirqid = 0,
35         Kprofdataqid,
36         Kprofctlqid,
37         Kptraceqid,
38         Kprintxqid,
39         Kmpstatqid,
40         Kmpstatrawqid,
41 };
42
43 struct trace_printk_buffer {
44         atomic_t in_use;
45         char buffer[TRACE_PRINTK_BUFFER_SIZE];
46 };
47
48 struct kprof {
49         qlock_t lock;
50         struct alarm_waiter *alarms;
51         bool mpstat_ipi;
52         bool profiling;
53         char *pdata;
54         size_t psize;
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 static void kprof_profdata_clear(void)
134 {
135         kfree(kprof.pdata);
136         kprof.pdata = NULL;
137         kprof.psize = 0;
138 }
139
140 static void kprof_start_profiler(void)
141 {
142         ERRSTACK(2);
143
144         qlock(&kprof.lock);
145         if (waserror()) {
146                 qunlock(&kprof.lock);
147                 nexterror();
148         }
149         if (!kprof.profiling) {
150                 profiler_setup();
151                 if (waserror()) {
152                         kprof.profiling = FALSE;
153                         profiler_cleanup();
154                         nexterror();
155                 }
156                 profiler_control_trace(1);
157                 kprof.profiling = TRUE;
158                 kprof_profdata_clear();
159                 poperror();
160         }
161         poperror();
162         qunlock(&kprof.lock);
163 }
164
165 static void kprof_fetch_profiler_data(void)
166 {
167         size_t psize = kprof.psize + profiler_size();
168         char *ndata = krealloc(kprof.pdata, psize, KMALLOC_WAIT);
169
170         if (!ndata)
171                 error(ENOMEM, ERROR_FIXME);
172         kprof.pdata = ndata;
173         while (kprof.psize < psize) {
174                 size_t csize = profiler_read(kprof.pdata + kprof.psize,
175                                              psize - kprof.psize);
176
177                 if (csize == 0)
178                         break;
179                 kprof.psize += csize;
180         }
181 }
182
183 static void kprof_stop_profiler(void)
184 {
185         ERRSTACK(1);
186
187         qlock(&kprof.lock);
188         if (waserror()) {
189                 qunlock(&kprof.lock);
190                 nexterror();
191         }
192         if (kprof.profiling) {
193                 profiler_control_trace(0);
194                 kprof_fetch_profiler_data();
195                 profiler_cleanup();
196
197                 kprof.profiling = FALSE;
198         }
199         poperror();
200         qunlock(&kprof.lock);
201 }
202
203 static void kprof_flush_profiler(void)
204 {
205         ERRSTACK(1);
206
207         qlock(&kprof.lock);
208         if (waserror()) {
209                 qunlock(&kprof.lock);
210                 nexterror();
211         }
212         if (kprof.profiling) {
213                 profiler_trace_data_flush();
214                 kprof_fetch_profiler_data();
215         }
216         poperror();
217         qunlock(&kprof.lock);
218 }
219
220 static void kprof_init(void)
221 {
222         int i;
223         ERRSTACK(1);
224
225         profiler_init();
226
227         qlock_init(&kprof.lock);
228         kprof.profiling = FALSE;
229         kprof.pdata = NULL;
230         kprof.psize = 0;
231
232         kprof.alarms = kzmalloc(sizeof(struct alarm_waiter) * num_cores,
233                                 KMALLOC_WAIT);
234         if (!kprof.alarms)
235                 error(ENOMEM, ERROR_FIXME);
236         if (waserror()) {
237                 kfree(kprof.alarms);
238                 kprof.alarms = NULL;
239                 nexterror();
240         }
241         for (i = 0; i < num_cores; i++)
242                 init_awaiter_irq(&kprof.alarms[i], kprof_alarm_handler);
243
244         for (i = 0; i < ARRAY_SIZE(kproftab); i++)
245                 kproftab[i].length = 0;
246
247         kprof.mpstat_ipi = TRUE;
248         kproftab[Kmpstatqid].length = mpstat_len();
249         kproftab[Kmpstatrawqid].length = mpstatraw_len();
250
251         strlcpy(kprof_control_usage, "clear|start|stop|flush|timer",
252                 sizeof(kprof_control_usage));
253         profiler_append_configure_usage(kprof_control_usage,
254                                         sizeof(kprof_control_usage));
255
256         poperror();
257 }
258
259 static void kprof_shutdown(void)
260 {
261         kprof_stop_profiler();
262         kprof_profdata_clear();
263
264         kfree(kprof.alarms);
265         kprof.alarms = NULL;
266 }
267
268 static void kprofclear(void)
269 {
270         qlock(&kprof.lock);
271         kprof_profdata_clear();
272         qunlock(&kprof.lock);
273 }
274
275 static struct walkqid *kprof_walk(struct chan *c, struct chan *nc, char **name,
276                                   int nname)
277 {
278         return devwalk(c, nc, name, nname, kproftab, ARRAY_SIZE(kproftab), devgen);
279 }
280
281 static size_t kprof_profdata_size(void)
282 {
283         return kprof.pdata != NULL ? kprof.psize : profiler_size();
284 }
285
286 static long kprof_profdata_read(void *dest, long size, int64_t off)
287 {
288         qlock(&kprof.lock);
289         if (kprof.pdata && off < kprof.psize) {
290                 size = MIN(kprof.psize - off, size);
291                 memcpy(dest, kprof.pdata + off, size);
292         } else {
293                 size = 0;
294         }
295         qunlock(&kprof.lock);
296
297         return size;
298 }
299
300 static int kprof_stat(struct chan *c, uint8_t *db, int n)
301 {
302         kproftab[Kprofdataqid].length = kprof_profdata_size();
303         kproftab[Kptraceqid].length = kprof_tracedata_size();
304
305         return devstat(c, db, n, kproftab, ARRAY_SIZE(kproftab), devgen);
306 }
307
308 static struct chan *kprof_open(struct chan *c, int omode)
309 {
310         if (c->qid.type & QTDIR) {
311                 if (openmode(omode) != O_READ)
312                         error(EPERM, ERROR_FIXME);
313         }
314         c->mode = openmode(omode);
315         c->flag |= COPEN;
316         c->offset = 0;
317         return c;
318 }
319
320 static void kprof_close(struct chan *c)
321 {
322 }
323
324 static long mpstat_read(void *va, long n, int64_t off)
325 {
326         size_t bufsz = mpstat_len();
327         char *buf = kmalloc(bufsz, KMALLOC_WAIT);
328         int len = 0;
329         struct per_cpu_info *pcpui;
330         uint64_t cpu_total;
331         struct timespec ts;
332
333         /* the IPI interferes with other cores, might want to disable that. */
334         if (kprof.mpstat_ipi)
335                 send_broadcast_ipi(I_POKE_CORE);
336
337         len += snprintf(buf + len, bufsz - len, "  CPU: ");
338         for (int j = 0; j < NR_CPU_STATES; j++)
339                 len += snprintf(buf + len, bufsz - len, "%23s%s", cpu_state_names[j],
340                                 j != NR_CPU_STATES - 1 ? "   " : "  \n");
341
342         for (int i = 0; i < num_cores; i++) {
343                 pcpui = &per_cpu_info[i];
344                 cpu_total = 0;
345                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
346                 for (int j = 0; j < NR_CPU_STATES; j++)
347                         cpu_total += pcpui->state_ticks[j];
348                 cpu_total = MAX(cpu_total, 1);  /* for the divide later */
349                 for (int j = 0; j < NR_CPU_STATES; j++) {
350                         tsc2timespec(pcpui->state_ticks[j], &ts);
351                         len += snprintf(buf + len, bufsz - len, "%10d.%06d (%3d%%)%s",
352                                         ts.tv_sec, ts.tv_nsec / 1000,
353                                         MIN((pcpui->state_ticks[j] * 100) / cpu_total, 100),
354                                         j != NR_CPU_STATES - 1 ? ", " : " \n");
355                 }
356         }
357         n = readstr(off, va, n, buf);
358         kfree(buf);
359         return n;
360 }
361
362 static long mpstatraw_read(void *va, long n, int64_t off)
363 {
364         size_t bufsz = mpstatraw_len();
365         char *buf = kmalloc(bufsz, KMALLOC_WAIT);
366         int len = 0;
367         struct per_cpu_info *pcpui;
368
369         /* could spit it all out in binary, though then it'd be harder to process
370          * the data across a mnt (if we export #K).  probably not a big deal. */
371
372         /* header line: version, num_cores, tsc freq, state names */
373         len += snprintf(buf + len, bufsz - len, "v%03d %5d %16llu", 1, num_cores,
374                         system_timing.tsc_freq);
375         for (int j = 0; j < NR_CPU_STATES; j++)
376                 len += snprintf(buf + len, bufsz - len, " %6s", cpu_state_names[j]);
377         len += snprintf(buf + len, bufsz - len, "\n");
378
379         for (int i = 0; i < num_cores; i++) {
380                 pcpui = &per_cpu_info[i];
381                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
382                 for (int j = 0; j < NR_CPU_STATES; j++) {
383                         len += snprintf(buf + len, bufsz - len, "%16llx%s",
384                                         pcpui->state_ticks[j],
385                                         j != NR_CPU_STATES - 1 ? " " : "\n");
386                 }
387         }
388         n = readstr(off, va, n, buf);
389         kfree(buf);
390         return n;
391 }
392
393 static long kprof_read(struct chan *c, void *va, long n, int64_t off)
394 {
395         uint64_t w, *bp;
396         char *a, *ea;
397         uintptr_t offset = off;
398         uint64_t pc;
399
400         switch ((int) c->qid.path) {
401         case Kprofdirqid:
402                 return devdirread(c, va, n, kproftab, ARRAY_SIZE(kproftab), devgen);
403         case Kprofdataqid:
404                 n = kprof_profdata_read(va, n, off);
405                 break;
406         case Kptraceqid:
407                 n = kprof_tracedata_read(va, n, off);
408                 break;
409         case Kprintxqid:
410                 n = readstr(offset, va, n, printx_on ? "on" : "off");
411                 break;
412         case Kmpstatqid:
413                 n = mpstat_read(va, n, offset);
414                 break;
415         case Kmpstatrawqid:
416                 n = mpstatraw_read(va, n, offset);
417                 break;
418         default:
419                 n = 0;
420                 break;
421         }
422         return n;
423 }
424
425 static void kprof_manage_timer(int coreid, struct cmdbuf *cb)
426 {
427         if (!strcmp(cb->f[2], "on")) {
428                 kprof_enable_timer(coreid, 1);
429         } else if (!strcmp(cb->f[2], "off")) {
430                 kprof_enable_timer(coreid, 0);
431         } else {
432                 error(EFAIL, "timer needs on|off");
433         }
434 }
435
436 static long kprof_write(struct chan *c, void *a, long n, int64_t unused)
437 {
438         ERRSTACK(1);
439         struct cmdbuf *cb = parsecmd(a, n);
440
441         if (waserror()) {
442                 kfree(cb);
443                 nexterror();
444         }
445         switch ((int) c->qid.path) {
446         case Kprofctlqid:
447                 if (cb->nf < 1)
448                         error(EFAIL, kprof_control_usage);
449                 if (profiler_configure(cb))
450                         break;
451                 if (!strcmp(cb->f[0], "clear")) {
452                         kprofclear();
453                 } else if (!strcmp(cb->f[0], "timer")) {
454                         if (cb->nf < 3)
455                                 error(EFAIL, "timer {{all, N} {on, off}, period USEC}");
456                         if (!strcmp(cb->f[1], "period")) {
457                                 kprof_timer_period = strtoul(cb->f[2], 0, 10);
458                         } else if (!strcmp(cb->f[1], "all")) {
459                                 for (int i = 0; i < num_cores; i++)
460                                         kprof_manage_timer(i, cb);
461                         } else {
462                                 int pcoreid = strtoul(cb->f[1], 0, 10);
463
464                                 if (pcoreid >= num_cores)
465                                         error(EFAIL, "No such coreid %d", pcoreid);
466                                 kprof_manage_timer(pcoreid, cb);
467                         }
468                 } else if (!strcmp(cb->f[0], "start")) {
469                         kprof_start_profiler();
470                 } else if (!strcmp(cb->f[0], "flush")) {
471                         kprof_flush_profiler();
472                 } else if (!strcmp(cb->f[0], "stop")) {
473                         kprof_stop_profiler();
474                 } else {
475                         error(EFAIL, kprof_control_usage);
476                 }
477                 break;
478         case Kprofdataqid:
479                 profiler_add_trace((uintptr_t) strtoul(a, 0, 0), 0);
480                 break;
481         case Kptraceqid:
482                 if (a && (n > 0)) {
483                         char *uptr = user_strdup_errno(current, a, n);
484
485                         if (uptr) {
486                                 trace_printk(false, "%s", uptr);
487                                 user_memdup_free(current, uptr);
488                         } else {
489                                 n = -1;
490                         }
491                 }
492                 break;
493         case Kprintxqid:
494                 if (!strncmp(a, "on", 2))
495                         set_printx(1);
496                 else if (!strncmp(a, "off", 3))
497                         set_printx(0);
498                 else if (!strncmp(a, "toggle", 6))
499                         set_printx(2);
500                 else
501                         error(EFAIL, "Invalid option to Kprintx %s\n", a);
502                 break;
503         case Kmpstatqid:
504         case Kmpstatrawqid:
505                 if (cb->nf < 1)
506                         error(EFAIL, "Bad mpstat option (reset|ipi|on|off)");
507                 if (!strcmp(cb->f[0], "reset")) {
508                         for (int i = 0; i < num_cores; i++)
509                                 reset_cpu_state_ticks(i);
510                 } else if (!strcmp(cb->f[0], "on")) {
511                         /* TODO: enable the ticks */ ;
512                 } else if (!strcmp(cb->f[0], "off")) {
513                         /* TODO: disable the ticks */ ;
514                 } else if (!strcmp(cb->f[0], "ipi")) {
515                         if (cb->nf < 2)
516                                 error(EFAIL, "Need another arg: ipi [on|off]");
517                         if (!strcmp(cb->f[1], "on"))
518                                 kprof.mpstat_ipi = TRUE;
519                         else if (!strcmp(cb->f[1], "off"))
520                                 kprof.mpstat_ipi = FALSE;
521                         else
522                                 error(EFAIL, "ipi [on|off]");
523                 } else {
524                         error(EFAIL, "Bad mpstat option (reset|ipi|on|off)");
525                 }
526                 break;
527         default:
528                 error(EBADFD, ERROR_FIXME);
529         }
530         kfree(cb);
531         poperror();
532         return n;
533 }
534
535 size_t kprof_tracedata_size(void)
536 {
537         return circular_buffer_size(&ktrace_data);
538 }
539
540 size_t kprof_tracedata_read(void *data, size_t size, size_t offset)
541 {
542         spin_lock_irqsave(&ktrace_lock);
543         if (likely(ktrace_init_done))
544                 size = circular_buffer_read(&ktrace_data, data, size, offset);
545         else
546                 size = 0;
547         spin_unlock_irqsave(&ktrace_lock);
548
549         return size;
550 }
551
552 void kprof_tracedata_write(const char *pretty_buf, size_t len)
553 {
554         spin_lock_irqsave(&ktrace_lock);
555         if (unlikely(!ktrace_init_done)) {
556                 circular_buffer_init(&ktrace_data, sizeof(ktrace_buffer),
557                                      ktrace_buffer);
558                 ktrace_init_done = TRUE;
559         }
560         circular_buffer_write(&ktrace_data, pretty_buf, len);
561         spin_unlock_irqsave(&ktrace_lock);
562 }
563
564 static struct trace_printk_buffer *kprof_get_printk_buffer(void)
565 {
566         static struct trace_printk_buffer boot_tpb;
567         static struct trace_printk_buffer *cpu_tpbs;
568         static atomic_t alloc_done;
569
570         if (unlikely(!num_cores))
571                 return &boot_tpb;
572         if (unlikely(!cpu_tpbs)) {
573                 /* Poor man per-CPU data structure. I really do no like littering global
574                  * data structures with module specific data.
575                  * We cannot take the ktrace_lock to protect the kzmalloc() call, as
576                  * that might trigger printk()s, and we would reenter here.
577                  * Let only one core into the kzmalloc() path, and let the others get
578                  * the boot_tpb until finished.
579                  */
580                 if (!atomic_cas(&alloc_done, 0, 1))
581                         return &boot_tpb;
582                 cpu_tpbs = kzmalloc(num_cores * sizeof(struct trace_printk_buffer), 0);
583         }
584
585         return cpu_tpbs + core_id_early();
586 }
587
588 void trace_vprintk(bool btrace, const char *fmt, va_list args)
589 {
590         struct print_buf {
591                 char *ptr;
592                 char *top;
593         };
594
595         void emit_print_buf_str(struct print_buf *pb, const char *str, ssize_t size)
596         {
597                 if (size < 0) {
598                         for (; *str && (pb->ptr < pb->top); str++)
599                                 *(pb->ptr++) = *str;
600                 } else {
601                         for (; (size > 0) && (pb->ptr < pb->top); str++, size--)
602                                 *(pb->ptr++) = *str;
603                 }
604         }
605
606         void bt_print(void *opaque, const char *str)
607         {
608                 struct print_buf *pb = (struct print_buf *) opaque;
609
610                 emit_print_buf_str(pb, "\t", 1);
611                 emit_print_buf_str(pb, str, -1);
612         }
613
614         static const size_t bufsz = TRACE_PRINTK_BUFFER_SIZE;
615         static const size_t usr_bufsz = (3 * bufsz) / 8;
616         static const size_t kp_bufsz = bufsz - usr_bufsz;
617         struct trace_printk_buffer *tpb = kprof_get_printk_buffer();
618         struct timespec ts_now = { 0, 0 };
619         struct print_buf pb;
620         char *usrbuf = tpb->buffer, *kpbuf = tpb->buffer + usr_bufsz;
621         const char *utop, *uptr;
622         char hdr[64];
623
624         if (!atomic_cas(&tpb->in_use, 0, 1))
625                 return;
626         if (likely(system_timing.tsc_freq))
627                 tsc2timespec(read_tsc(), &ts_now);
628         snprintf(hdr, sizeof(hdr), "[%lu.%09lu]:cpu%d: ", ts_now.tv_sec,
629                  ts_now.tv_nsec, core_id_early());
630
631         pb.ptr = usrbuf + vsnprintf(usrbuf, usr_bufsz, fmt, args);
632         pb.top = usrbuf + usr_bufsz;
633
634         if (pb.ptr[-1] != '\n')
635                 emit_print_buf_str(&pb, "\n", 1);
636         if (btrace) {
637                 emit_print_buf_str(&pb, "\tBacktrace:\n", -1);
638                 gen_backtrace(bt_print, &pb);
639         }
640         /* snprintf null terminates the buffer, and does not count that as part of
641          * the len.  If we maxed out the buffer, let's make sure it has a \n.
642          */
643         if (pb.ptr == pb.top)
644                 pb.ptr[-1] = '\n';
645         utop = pb.ptr;
646
647         pb.ptr = kpbuf;
648         pb.top = kpbuf + kp_bufsz;
649         for (uptr = usrbuf; uptr < utop;) {
650                 const char *nlptr = memchr(uptr, '\n', utop - uptr);
651
652                 if (nlptr == NULL)
653                         nlptr = utop;
654                 emit_print_buf_str(&pb, hdr, -1);
655                 emit_print_buf_str(&pb, uptr, (nlptr - uptr) + 1);
656                 uptr = nlptr + 1;
657         }
658         kprof_tracedata_write(kpbuf, pb.ptr - kpbuf);
659         atomic_set(&tpb->in_use, 0);
660 }
661
662 void trace_printk(bool btrace, const char *fmt, ...)
663 {
664         va_list args;
665
666         va_start(args, fmt);
667         trace_vprintk(btrace, fmt, args);
668         va_end(args);
669 }
670
671 struct dev kprofdevtab __devtab = {
672         .name = "kprof",
673
674         .reset = devreset,
675         .init = kprof_init,
676         .shutdown = kprof_shutdown,
677         .attach = kprof_attach,
678         .walk = kprof_walk,
679         .stat = kprof_stat,
680         .open = kprof_open,
681         .create = devcreate,
682         .close = kprof_close,
683         .read = kprof_read,
684         .bread = devbread,
685         .write = kprof_write,
686         .bwrite = devbwrite,
687         .remove = devremove,
688         .wstat = devwstat,
689 };