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