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