Migrated position dependent initialization, to label based
[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 // get_fn_name is slowing down the kprocread
11 //      have an array of translated fns
12 //      or a "next" iterator, since we're walking in order
13 //
14 // irqsave locks
15 //
16 // kprof struct should be a ptr, have them per core
17 //              we'll probably need to track the length still, so userspace knows how
18 //              big it is
19 //
20 //              will also want more files in the kprof dir for each cpu or something
21 //
22 // maybe don't use slot 0 and 1 as total and 'not kernel' ticks
23 //
24 // fix the failed assert XXX
25
26 #include <vfs.h>
27 #include <kfs.h>
28 #include <slab.h>
29 #include <kmalloc.h>
30 #include <kref.h>
31 #include <string.h>
32 #include <stdio.h>
33 #include <assert.h>
34 #include <error.h>
35 #include <cpio.h>
36 #include <pmap.h>
37 #include <smp.h>
38 #include <ip.h>
39 #include <oprofile.h>
40
41 struct dev kprofdevtab;
42
43 static char *devname(void)
44 {
45         return kprofdevtab.name;
46 }
47
48 #define LRES    3               /* log of PC resolution */
49 #define CELLSIZE        8       /* sizeof of count cell */
50
51 struct kprof
52 {
53         uintptr_t       minpc;
54         uintptr_t       maxpc;
55         int     nbuf;
56         int     time;
57         uint64_t        *buf;   /* keep in sync with cellsize */
58         size_t          buf_sz;
59         spinlock_t lock;
60         struct queue *systrace;
61         bool            mpstat_ipi;
62 };
63 struct kprof kprof;
64
65 /* output format. Nice fixed size. That makes it seekable.
66  * small subtle bit here. You have to convert offset FROM FORMATSIZE units
67  * to CELLSIZE units in a few places.
68  */
69 char *outformat = "%016llx %29.29s %016llx\n";
70 #define FORMATSIZE 64
71 enum{
72         Kprofdirqid = 0,
73         Kprofdataqid,
74         Kprofctlqid,
75         Kprofoprofileqid,
76         Kptraceqid,
77         Kprintxqid,
78         Kmpstatqid,
79         Kmpstatrawqid,
80 };
81
82 struct dirtab kproftab[]={
83         {".",           {Kprofdirqid, 0, QTDIR},0,      DMDIR|0550},
84         {"kpdata",      {Kprofdataqid},         0,      0600},
85         {"kpctl",       {Kprofctlqid},          0,      0600},
86         {"kpoprofile",  {Kprofoprofileqid},     0,      0600},
87         {"kptrace",     {Kptraceqid},           0,      0600},
88         {"kprintx",     {Kprintxqid},           0,      0600},
89         {"mpstat",      {Kmpstatqid},           0,      0600},
90         {"mpstat-raw",  {Kmpstatrawqid},                0,      0600},
91 };
92
93 static size_t mpstatraw_len(void);
94 static size_t mpstat_len(void);
95
96 static struct alarm_waiter *oprof_alarms;
97 static unsigned int oprof_timer_period = 1000;
98
99 static void oprof_alarm_handler(struct alarm_waiter *waiter,
100                                 struct hw_trapframe *hw_tf)
101 {
102         int coreid = core_id();
103         struct timer_chain *tchain = &per_cpu_info[coreid].tchain;
104         if (in_kernel(hw_tf))
105                 oprofile_add_backtrace(get_hwtf_pc(hw_tf), get_hwtf_fp(hw_tf));
106         else
107                 oprofile_add_userpc(get_hwtf_pc(hw_tf));
108         reset_alarm_rel(tchain, waiter, oprof_timer_period);
109 }
110
111 static struct chan*
112 kprofattach(char *spec)
113 {
114         // Did we initialise completely?
115         if ( !(oprof_alarms && kprof.buf && kprof.systrace) )
116                 error(ENOMEM, NULL);
117
118         return devattach(devname(), spec);
119 }
120
121 static void
122 kproftimer(uintptr_t pc)
123 {
124         if(kprof.time == 0)
125                 return;
126
127         /*
128          * if the pc corresponds to the idle loop, don't consider it.
129
130         if(m->inidle)
131                 return;
132          */
133         /*
134          *  if the pc is coming out of spllo or splx,
135          *  use the pc saved when we went splhi.
136
137         if(pc>=PTR2UINT(spllo) && pc<=PTR2UINT(spldone))
138                 pc = m->splpc;
139          */
140
141 //      ilock(&kprof);
142         /* this is weird. What we do is assume that all the time since the last
143          * measurement went into this PC. It's the best
144          * we can do I suppose. And we are sampling at 1 ms. for now.
145          * better ideas welcome.
146          */
147         kprof.buf[0] += 1; //Total count of ticks.
148         if(kprof.minpc<=pc && pc<kprof.maxpc){
149                 pc -= kprof.minpc;
150                 pc >>= LRES;
151                 kprof.buf[pc] += 1;
152         }else
153                 kprof.buf[1] += 1; // Why?
154 //      iunlock(&kprof);
155 }
156
157 static void setup_timers(void)
158 {
159         void kprof_alarm(struct alarm_waiter *waiter, struct hw_trapframe *hw_tf)
160         {
161                 struct timer_chain *tchain = &per_cpu_info[core_id()].tchain;
162                 kproftimer(get_hwtf_pc(hw_tf));
163                 set_awaiter_rel(waiter, 1000);
164                 set_alarm(tchain, waiter);
165         }
166         struct timer_chain *tchain = &per_cpu_info[core_id()].tchain;
167         struct alarm_waiter *waiter = kmalloc(sizeof(struct alarm_waiter), 0);
168         init_awaiter_irq(waiter, kprof_alarm);
169         set_awaiter_rel(waiter, 1000);
170         set_alarm(tchain, waiter);
171 }
172
173 static void kprofinit(void)
174 {
175         uint32_t n;
176
177         static_assert(CELLSIZE == sizeof kprof.buf[0]); // kprof size
178
179         /* allocate when first used */
180         kprof.minpc = KERN_LOAD_ADDR;
181         kprof.maxpc = (uintptr_t) &etext;
182         kprof.nbuf = (kprof.maxpc-kprof.minpc) >> LRES;
183         n = kprof.nbuf*CELLSIZE;
184         kprof.buf = kzmalloc(n, KMALLOC_WAIT);
185         if (kprof.buf)
186                 kprof.buf_sz = n;
187
188         /* no, i'm not sure how we should do this yet. */
189         int alloc_cpu_buffers(void);
190         alloc_cpu_buffers();
191         oprof_alarms = kzmalloc(sizeof(struct alarm_waiter) * num_cores,
192                                 KMALLOC_WAIT);
193         if (!oprof_alarms)
194                 error(ENOMEM, NULL);
195
196         for (int i = 0; i < num_cores; i++)
197                 init_awaiter_irq(&oprof_alarms[i], oprof_alarm_handler);
198
199         kprof.systrace = qopen(2 << 20, 0, 0, 0);
200         if (!kprof.systrace) {
201                 printk("systrace allocate failed. No system call tracing\n");
202         }
203         kprof.mpstat_ipi = TRUE;
204
205         kproftab[Kprofdataqid].length = kprof.nbuf * FORMATSIZE;
206         kproftab[Kmpstatqid].length = mpstat_len();
207         kproftab[Kmpstatrawqid].length = mpstatraw_len();
208 }
209
210 static void kprofshutdown(void)
211 {
212         kfree(oprof_alarms); oprof_alarms = NULL;
213         kfree(kprof.buf); kprof.buf = NULL;
214         qfree(kprof.systrace); kprof.systrace = NULL;
215         void free_cpu_buffers(void);
216         free_cpu_buffers();
217 }
218
219 static struct walkqid*
220 kprofwalk(struct chan *c, struct chan *nc, char **name, int nname)
221 {
222         return devwalk(c, nc, name, nname, kproftab, ARRAY_SIZE(kproftab), devgen);
223 }
224
225 static int
226 kprofstat(struct chan *c, uint8_t *db, int n)
227 {
228         kproftab[Kprofoprofileqid].length = oproflen();
229         if (kprof.systrace)
230                 kproftab[Kptraceqid].length = qlen(kprof.systrace);
231         else
232                 kproftab[Kptraceqid].length = 0;
233
234         return devstat(c, db, n, kproftab, ARRAY_SIZE(kproftab), devgen);
235 }
236
237 static struct chan*
238 kprofopen(struct chan *c, int omode)
239 {
240         if(c->qid.type & QTDIR){
241                 if(openmode(omode) != O_READ)
242                         error(EPERM, NULL);
243         }
244         c->mode = openmode(omode);
245         c->flag |= COPEN;
246         c->offset = 0;
247         return c;
248 }
249
250 static void
251 kprofclose(struct chan*unused)
252 {
253 }
254
255 static size_t mpstat_len(void)
256 {
257         size_t each_row = 7 + NR_CPU_STATES * 26;
258         return each_row * (num_cores + 1) + 1;
259 }
260
261 static long mpstat_read(void *va, long n, int64_t off)
262 {
263         size_t bufsz = mpstat_len();
264         char *buf = kmalloc(bufsz, KMALLOC_WAIT);
265         int len = 0;
266         struct per_cpu_info *pcpui;
267         uint64_t cpu_total;
268         struct timespec ts;
269
270         /* the IPI interferes with other cores, might want to disable that. */
271         if (kprof.mpstat_ipi)
272                 send_broadcast_ipi(I_POKE_CORE);
273
274         len += snprintf(buf + len, bufsz - len, "  CPU: ");
275         for (int j = 0; j < NR_CPU_STATES; j++)
276                 len += snprintf(buf + len, bufsz - len, "%23s%s", cpu_state_names[j],
277                                 j != NR_CPU_STATES - 1 ? "   " : "  \n");
278
279         for (int i = 0; i < num_cores; i++) {
280                 pcpui = &per_cpu_info[i];
281                 cpu_total = 0;
282                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
283                 for (int j = 0; j < NR_CPU_STATES; j++)
284                         cpu_total += pcpui->state_ticks[j];
285                 cpu_total = MAX(cpu_total, 1);  /* for the divide later */
286                 for (int j = 0; j < NR_CPU_STATES; j++) {
287                         tsc2timespec(pcpui->state_ticks[j], &ts);
288                         len += snprintf(buf + len, bufsz - len, "%10d.%06d (%3d%%)%s",
289                                         ts.tv_sec, ts.tv_nsec / 1000,
290                                         MIN((pcpui->state_ticks[j] * 100) / cpu_total, 100),
291                                         j != NR_CPU_STATES - 1 ? ", " : " \n");
292                 }
293         }
294         n = readstr(off, va, n, buf);
295         kfree(buf);
296         return n;
297 }
298
299 static size_t mpstatraw_len(void)
300 {
301         size_t header_row = 27 + NR_CPU_STATES * 7 + 1;
302         size_t cpu_row = 7 + NR_CPU_STATES * 17;
303         return header_row + cpu_row * num_cores + 1;
304 }
305
306 static long mpstatraw_read(void *va, long n, int64_t off)
307 {
308         size_t bufsz = mpstatraw_len();
309         char *buf = kmalloc(bufsz, KMALLOC_WAIT);
310         int len = 0;
311         struct per_cpu_info *pcpui;
312
313         /* could spit it all out in binary, though then it'd be harder to process
314          * the data across a mnt (if we export #K).  probably not a big deal. */
315
316         /* header line: version, num_cores, tsc freq, state names */
317         len += snprintf(buf + len, bufsz - len, "v%03d %5d %16llu", 1, num_cores,
318                         system_timing.tsc_freq);
319         for (int j = 0; j < NR_CPU_STATES; j++)
320                 len += snprintf(buf + len, bufsz - len, " %6s", cpu_state_names[j]);
321         len += snprintf(buf + len, bufsz - len, "\n");
322
323         for (int i = 0; i < num_cores; i++) {
324                 pcpui = &per_cpu_info[i];
325                 len += snprintf(buf + len, bufsz - len, "%5d: ", i);
326                 for (int j = 0; j < NR_CPU_STATES; j++) {
327                         len += snprintf(buf + len, bufsz - len, "%16llx%s",
328                                         pcpui->state_ticks[j],
329                                         j != NR_CPU_STATES - 1 ? " " : "\n");
330                 }
331         }
332         n = readstr(off, va, n, buf);
333         kfree(buf);
334         return n;
335 }
336
337 static long
338 kprofread(struct chan *c, void *va, long n, int64_t off)
339 {
340         uint64_t w, *bp;
341         char *a, *ea;
342         uintptr_t offset = off;
343         uint64_t pc;
344         int snp_ret, ret = 0;
345
346         switch((int)c->qid.path){
347         case Kprofdirqid:
348                 return devdirread(c, va, n, kproftab, ARRAY_SIZE(kproftab), devgen);
349
350         case Kprofdataqid:
351
352                 if (n < FORMATSIZE){
353                         n = 0;
354                         break;
355                 }
356                 a = va;
357                 ea = a + n;
358
359                 /* we check offset later before deref bp.  offset / FORMATSIZE is how
360                  * many entries we're skipping/offsetting. */
361                 bp = kprof.buf + offset/FORMATSIZE;
362                 pc = kprof.minpc + ((offset/FORMATSIZE)<<LRES);
363                 while((a < ea) && (n >= FORMATSIZE)){
364                         /* what a pain. We need to manage the
365                          * fact that the *prints all make room for
366                          * \0
367                          */
368                         char print[FORMATSIZE+1];
369                         char *name;
370                         int amt_read;
371
372                         if (pc >= kprof.maxpc)
373                                 break;
374                         /* pc is also our exit for bp.  should be in lockstep */
375                         // XXX this assert fails, fix it!
376                         //assert(bp < kprof.buf + kprof.nbuf);
377                         /* do not attempt to filter these results based on w < threshold.
378                          * earlier, we computed bp/pc based on assuming a full-sized file,
379                          * and skipping entries will result in read() calls thinking they
380                          * received earlier entries when they really received later ones.
381                          * imagine a case where there are 1000 skipped items, and read()
382                          * asks for chunks of 32.  it'll get chunks of the next 32 valid
383                          * items, over and over (1000/32 times). */
384                         w = *bp++;
385
386                         if (pc == kprof.minpc)
387                                 name = "Total";
388                         else if (pc == kprof.minpc + 8)
389                                 name = "User";
390                         else
391                                 name = get_fn_name(pc);
392
393                         snp_ret = snprintf(print, sizeof(print), outformat, pc, name, w);
394                         assert(snp_ret == FORMATSIZE);
395                         if ((pc != kprof.minpc) && (pc != kprof.minpc + 8))
396                                 kfree(name);
397
398                         amt_read = readmem(offset % FORMATSIZE, a, n, print, FORMATSIZE);
399                         offset = 0;     /* future loops have no offset */
400
401                         a += amt_read;
402                         n -= amt_read;
403                         ret += amt_read;
404
405                         pc += (1 << LRES);
406                 }
407                 n = ret;
408                 break;
409         case Kprofoprofileqid:
410                 n = oprofread(va,n);
411                 break;
412         case Kptraceqid:
413                 if (kprof.systrace) {
414                         printd("Kptraceqid: kprof.systrace %p len %p\n", kprof.systrace, qlen(kprof.systrace));
415                         if (qlen(kprof.systrace) > 0)
416                                 n = qread(kprof.systrace, va, n);
417                         else
418                                 n = 0;
419                 } else
420                         error(EFAIL, "no systrace queue");
421                 break;
422         case Kprintxqid:
423                 n = readstr(offset, va, n, printx_on ? "on" : "off");
424                 break;
425         case Kmpstatqid:
426                 n = mpstat_read(va, n, offset);
427                 break;
428         case Kmpstatrawqid:
429                 n = mpstatraw_read(va, n, offset);
430                 break;
431         default:
432                 n = 0;
433                 break;
434         }
435         return n;
436 }
437
438 static void kprof_clear(struct kprof *kp)
439 {
440         spin_lock(&kp->lock);
441         memset(kp->buf, 0, kp->buf_sz);
442         spin_unlock(&kp->lock);
443 }
444
445 static void manage_oprof_timer(int coreid, struct cmdbuf *cb)
446 {
447         struct timer_chain *tchain = &per_cpu_info[coreid].tchain;
448         struct alarm_waiter *waiter = &oprof_alarms[coreid];
449         if (!strcmp(cb->f[2], "on")) {
450                 /* pcpu waiters already inited.  will set/reset each time (1 ms
451                  * default). */
452                 reset_alarm_rel(tchain, waiter, oprof_timer_period);
453         } else if (!strcmp(cb->f[2], "off")) {
454                 /* since the alarm handler runs and gets reset within IRQ context, then
455                  * we should never fail to cancel the alarm if it was already running
456                  * (tchain locks synchronize us).  but it might not be set at all, which
457                  * is fine. */
458                 unset_alarm(tchain, waiter);
459         } else {
460                 error(EFAIL, "optimer needs on|off");
461         }
462 }
463
464 static long
465 kprofwrite(struct chan *c, void *a, long n, int64_t unused)
466 {
467         ERRSTACK(1);
468         uintptr_t pc;
469         struct cmdbuf *cb;
470         char *ctlstring = "startclr|start|stop|clear|opstart|opstop|optimer";
471         cb = parsecmd(a, n);
472
473         if (waserror()) {
474                 kfree(cb);
475                 nexterror();
476         }
477
478         switch((int)(c->qid.path)){
479         case Kprofctlqid:
480                 if (cb->nf < 1)
481                         error(EFAIL, ctlstring);
482
483                 /* Kprof: a "which kaddr are we at when the timer goes off".  not used
484                  * much anymore */
485                 if (!strcmp(cb->f[0], "startclr")) {
486                         kprof_clear(&kprof);
487                         kprof.time = 1;
488                 } else if (!strcmp(cb->f[0], "start")) {
489                         kprof.time = 1;
490                         /* this sets up the timer on the *calling* core! */
491                         setup_timers();
492                 } else if (!strcmp(cb->f[0], "stop")) {
493                         /* TODO: stop the timers! */
494                         kprof.time = 0;
495                 } else if (!strcmp(cb->f[0], "clear")) {
496                         kprof_clear(&kprof);
497
498                 /* oprof: samples and traces using oprofile */
499                 } else if (!strcmp(cb->f[0], "optimer")) {
500                         if (cb->nf < 3)
501                                 error(EFAIL, "optimer [<0|1|..|n|all> <on|off>] [period USEC]");
502                         if (!strcmp(cb->f[1], "period")) {
503                                 oprof_timer_period = strtoul(cb->f[2], 0, 10);
504                         } else if (!strcmp(cb->f[1], "all")) {
505                                 for (int i = 0; i < num_cores; i++)
506                                         manage_oprof_timer(i, cb);
507                         } else {
508                                 int pcoreid = strtoul(cb->f[1], 0, 10);
509                                 if (pcoreid >= num_cores)
510                                         error(EFAIL, "no such coreid %d", pcoreid);
511                                 manage_oprof_timer(pcoreid, cb);
512                         }
513                 } else if (!strcmp(cb->f[0], "opstart")) {
514                         oprofile_control_trace(1);
515                 } else if (!strcmp(cb->f[0], "opstop")) {
516                         oprofile_control_trace(0);
517                 } else {
518                         error(EFAIL, ctlstring);
519                 }
520                 break;
521
522                 /* The format is a long as text. We strtoul, and jam it into the
523                  * trace buffer.
524                  */
525         case Kprofoprofileqid:
526                 pc = strtoul(a, 0, 0);
527                 oprofile_add_trace(pc);
528                 break;
529         case Kprintxqid:
530                 if (!strncmp(a, "on", 2))
531                         set_printx(1);
532                 else if (!strncmp(a, "off", 3))
533                         set_printx(0);
534                 else if (!strncmp(a, "toggle", 6))      /* why not. */
535                         set_printx(2);
536                 else
537                         error(EFAIL, "invalid option to Kprintx %s\n", a);
538                 break;
539         case Kmpstatqid:
540         case Kmpstatrawqid:
541                 if (cb->nf < 1)
542                         error(EFAIL, "mpstat bad option (reset|ipi|on|off)");
543                 if (!strcmp(cb->f[0], "reset")) {
544                         for (int i = 0; i < num_cores; i++)
545                                 reset_cpu_state_ticks(i);
546                 } else if (!strcmp(cb->f[0], "on")) {
547                         /* TODO: enable the ticks */ ;
548                 } else if (!strcmp(cb->f[0], "off")) {
549                         /* TODO: disable the ticks */ ;
550                 } else if (!strcmp(cb->f[0], "ipi")) {
551                         if (cb->nf < 2)
552                                 error(EFAIL, "need another arg: ipi [on|off]");
553                         if (!strcmp(cb->f[1], "on"))
554                                 kprof.mpstat_ipi = TRUE;
555                         else if (!strcmp(cb->f[1], "off"))
556                                 kprof.mpstat_ipi = FALSE;
557                         else
558                                 error(EFAIL, "ipi [on|off]");
559                 } else {
560                         error(EFAIL, "mpstat bad option (reset|ipi|on|off)");
561                 }
562                 break;
563         default:
564                 error(EBADFD, NULL);
565         }
566         kfree(cb);
567         poperror();
568         return n;
569 }
570
571 void kprof_write_sysrecord(char *pretty_buf, size_t len)
572 {
573         int wrote;
574         if (kprof.systrace) {
575                 /* TODO: need qio work so we can simply add the buf as extra data */
576                 wrote = qiwrite(kprof.systrace, pretty_buf, len);
577                 /* based on the current queue settings, we only drop when we're running
578                  * out of memory.  odds are, we won't make it this far. */
579                 if (wrote != len)
580                         printk("DROPPED %s", pretty_buf);
581         }
582 }
583
584 void trace_printk(const char *fmt, ...)
585 {
586         va_list ap;
587         struct timespec ts_now;
588         size_t bufsz = 160;     /* 2x terminal width */
589         size_t len = 0;
590         char *buf = kmalloc(bufsz, 0);
591
592         if (!buf)
593                 return;
594         tsc2timespec(read_tsc(), &ts_now);
595         len += snprintf(buf + len, bufsz - len, "[%7d.%09d] /* ", ts_now.tv_sec,
596                         ts_now.tv_nsec);
597         va_start(ap, fmt);
598         len += vsnprintf(buf + len, bufsz - len, fmt, ap);
599         va_start(ap, fmt);
600         va_end(ap);
601         len += snprintf(buf + len, bufsz - len, " */\n");
602         va_start(ap, fmt);
603         /* snprintf null terminates the buffer, and does not count that as part of
604          * the len.  if we maxed out the buffer, let's make sure it has a \n */
605         if (len == bufsz - 1) {
606                 assert(buf[bufsz - 1] == '\0');
607                 buf[bufsz - 2] = '\n';
608         }
609         kprof_write_sysrecord(buf, len);
610         kfree(buf);
611 }
612
613 struct dev kprofdevtab __devtab = {
614         .name = "kprof",
615
616         .reset = devreset,
617         .init = kprofinit,
618         .shutdown = kprofshutdown,
619         .attach = kprofattach,
620         .walk = kprofwalk,
621         .stat = kprofstat,
622         .open = kprofopen,
623         .create = devcreate,
624         .close = kprofclose,
625         .read = kprofread,
626         .bread = devbread,
627         .write = kprofwrite,
628         .bwrite = devbwrite,
629         .remove = devremove,
630         .wstat = devwstat,
631 };