Fixes #K open
[akaros.git] / kern / drivers / dev / kprof.c
index 1377b15..476a279 100644 (file)
@@ -50,6 +50,8 @@ struct kprof
        uint64_t        *buf;   /* keep in sync with cellsize */
        size_t          buf_sz;
        spinlock_t lock;
+       struct queue *systrace;
+       bool            mpstat_ipi;
 };
 struct kprof kprof;
 
@@ -60,18 +62,30 @@ struct kprof kprof;
 char *outformat = "%016llx %29.29s %016llx\n";
 #define FORMATSIZE 64
 enum{
-       Kprofdirqid,
+       Kprofdirqid = 0,
        Kprofdataqid,
        Kprofctlqid,
        Kprofoprofileqid,
+       Kptraceqid,
+       Kprintxqid,
+       Kmpstatqid,
+       Kmpstatrawqid,
 };
+
 struct dirtab kproftab[]={
        {".",           {Kprofdirqid, 0, QTDIR},0,      DMDIR|0550},
        {"kpdata",      {Kprofdataqid},         0,      0600},
        {"kpctl",       {Kprofctlqid},          0,      0600},
        {"kpoprofile",  {Kprofoprofileqid},     0,      0600},
+       {"kptrace",     {Kptraceqid},           0,      0600},
+       {"kprintx",     {Kprintxqid},           0,      0600},
+       {"mpstat",      {Kmpstatqid},           0,      0600},
+       {"mpstat-raw",  {Kmpstatrawqid},                0,      0600},
 };
 
+static size_t mpstatraw_len(void);
+static size_t mpstat_len(void);
+
 static struct chan*
 kprofattach(char *spec)
 {
@@ -83,16 +97,20 @@ kprofattach(char *spec)
        kprof.nbuf = (kprof.maxpc-kprof.minpc) >> LRES;
        n = kprof.nbuf*CELLSIZE;
        if(kprof.buf == 0) {
-               printk("Allocate %d bytes\n", n);
                kprof.buf = kzmalloc(n, KMALLOC_WAIT);
                if(kprof.buf == 0)
                        error(Enomem);
        }
-       kproftab[1].length = kprof.nbuf * FORMATSIZE;
+       kproftab[Kprofdataqid].length = kprof.nbuf * FORMATSIZE;
        kprof.buf_sz = n;
        /* NO, I'm not sure how we should do this yet. */
        int alloc_cpu_buffers(void);
        alloc_cpu_buffers();
+       kprof.systrace = qopen(2 << 20, 0, 0, 0);
+       if (! kprof.systrace) {
+               printk("systrace allocate failed. No system call tracing\n");
+       }
+       kprof.mpstat_ipi = TRUE;
        return devattach('K', spec);
 }
 
@@ -134,24 +152,27 @@ kproftimer(uintptr_t pc)
 
 static void setup_timers(void)
 {
-       void handler(struct alarm_waiter *waiter)
+       void kprof_alarm(struct alarm_waiter *waiter, struct hw_trapframe *hw_tf)
        {
                struct timer_chain *tchain = &per_cpu_info[core_id()].tchain;
-               kproftimer(per_cpu_info[core_id()].rip);
+               kproftimer(get_hwtf_pc(hw_tf));
                set_awaiter_rel(waiter, 1000);
                __set_alarm(tchain, waiter);
        }
        struct timer_chain *tchain = &per_cpu_info[core_id()].tchain;
        struct alarm_waiter *waiter = kmalloc(sizeof(struct alarm_waiter), 0);
-       init_awaiter(waiter, handler);
+       init_awaiter_irq(waiter, kprof_alarm);
        set_awaiter_rel(waiter, 1000);
        set_alarm(tchain, waiter);
 }
+
 static void
 kprofinit(void)
 {
        if(CELLSIZE != sizeof kprof.buf[0])
                panic("kprof size");
+       kproftab[Kmpstatqid].length = mpstat_len();
+       kproftab[Kmpstatrawqid].length = mpstatraw_len();
 }
 
 static struct walkqid*
@@ -163,6 +184,12 @@ kprofwalk(struct chan *c, struct chan *nc, char **name, int nname)
 static int
 kprofstat(struct chan *c, uint8_t *db, int n)
 {
+       kproftab[Kprofoprofileqid].length = oproflen();
+       if (kprof.systrace)
+               kproftab[Kptraceqid].length = qlen(kprof.systrace);
+       else
+               kproftab[Kptraceqid].length = 0;
+
        return devstat(c, db, n, kproftab, ARRAY_SIZE(kproftab), devgen);
 }
 
@@ -170,7 +197,7 @@ static struct chan*
 kprofopen(struct chan *c, int omode)
 {
        if(c->qid.type & QTDIR){
-               if(omode != OREAD)
+               if(openmode(omode) != OREAD)
                        error(Eperm);
        }
        c->mode = openmode(omode);
@@ -184,6 +211,88 @@ kprofclose(struct chan*unused)
 {
 }
 
+static size_t mpstat_len(void)
+{
+       size_t each_row = 7 + NR_CPU_STATES * 26;
+       return each_row * (num_cpus + 1) + 1;
+}
+
+static long mpstat_read(void *va, long n, int64_t off)
+{
+       size_t bufsz = mpstat_len();
+       char *buf = kmalloc(bufsz, KMALLOC_WAIT);
+       int len = 0;
+       struct per_cpu_info *pcpui;
+       uint64_t cpu_total;
+       struct timespec ts;
+
+       /* the IPI interferes with other cores, might want to disable that. */
+       if (kprof.mpstat_ipi)
+               send_broadcast_ipi(I_POKE_CORE);
+
+       len += snprintf(buf + len, bufsz - len, "  CPU: ");
+       for (int j = 0; j < NR_CPU_STATES; j++)
+               len += snprintf(buf + len, bufsz - len, "%23s%s", cpu_state_names[j],
+                               j != NR_CPU_STATES - 1 ? "   " : "  \n");
+
+       for (int i = 0; i < num_cpus; i++) {
+               pcpui = &per_cpu_info[i];
+               cpu_total = 0;
+               len += snprintf(buf + len, bufsz - len, "%5d: ", i);
+               for (int j = 0; j < NR_CPU_STATES; j++)
+                       cpu_total += pcpui->state_ticks[j];
+               cpu_total = MAX(cpu_total, 1);  /* for the divide later */
+               for (int j = 0; j < NR_CPU_STATES; j++) {
+                       tsc2timespec(pcpui->state_ticks[j], &ts);
+                       len += snprintf(buf + len, bufsz - len, "%10d.%06d (%3d%%)%s",
+                                       ts.tv_sec, ts.tv_nsec / 1000,
+                                       MIN((pcpui->state_ticks[j] * 100) / cpu_total, 100),
+                                       j != NR_CPU_STATES - 1 ? ", " : " \n");
+               }
+       }
+       n = readstr(off, va, n, buf);
+       kfree(buf);
+       return n;
+}
+
+static size_t mpstatraw_len(void)
+{
+       size_t header_row = 27 + NR_CPU_STATES * 7 + 1;
+       size_t cpu_row = 7 + NR_CPU_STATES * 17;
+       return header_row + cpu_row * num_cpus + 1;
+}
+
+static long mpstatraw_read(void *va, long n, int64_t off)
+{
+       size_t bufsz = mpstatraw_len();
+       char *buf = kmalloc(bufsz, KMALLOC_WAIT);
+       int len = 0;
+       struct per_cpu_info *pcpui;
+
+       /* could spit it all out in binary, though then it'd be harder to process
+        * the data across a mnt (if we export #K).  probably not a big deal. */
+
+       /* header line: version, num_cpus, tsc freq, state names */
+       len += snprintf(buf + len, bufsz - len, "v%03d %5d %16llu", 1, num_cpus,
+                       system_timing.tsc_freq);
+       for (int j = 0; j < NR_CPU_STATES; j++)
+               len += snprintf(buf + len, bufsz - len, " %6s", cpu_state_names[j]);
+       len += snprintf(buf + len, bufsz - len, "\n");
+
+       for (int i = 0; i < num_cpus; i++) {
+               pcpui = &per_cpu_info[i];
+               len += snprintf(buf + len, bufsz - len, "%5d: ", i);
+               for (int j = 0; j < NR_CPU_STATES; j++) {
+                       len += snprintf(buf + len, bufsz - len, "%16llx%s",
+                                       pcpui->state_ticks[j],
+                                       j != NR_CPU_STATES - 1 ? " " : "\n");
+               }
+       }
+       n = readstr(off, va, n, buf);
+       kfree(buf);
+       return n;
+}
+
 static long
 kprofread(struct chan *c, void *va, long n, int64_t off)
 {
@@ -192,8 +301,6 @@ kprofread(struct chan *c, void *va, long n, int64_t off)
        uintptr_t offset = off;
        uint64_t pc;
        int snp_ret, ret = 0;
-       /* the oprofile queue */
-       extern struct queue *opq;
 
        switch((int)c->qid.path){
        case Kprofdirqid:
@@ -259,7 +366,26 @@ kprofread(struct chan *c, void *va, long n, int64_t off)
                n = ret;
                break;
        case Kprofoprofileqid:
-               n = qread(opq, va, n);
+               n = oprofread(va,n);
+               break;
+       case Kptraceqid:
+               if (kprof.systrace) {
+                       printd("Kptraceqid: kprof.systrace %p len %p\n", kprof.systrace, qlen(kprof.systrace));
+                       if (qlen(kprof.systrace) > 0)
+                               n = qread(kprof.systrace, va, n);
+                       else
+                               n = 0;
+               } else
+                       error("no systrace queue");
+               break;
+       case Kprintxqid:
+               n = readstr(offset, va, n, printx_on ? "on" : "off");
+               break;
+       case Kmpstatqid:
+               n = mpstat_read(va, n, offset);
+               break;
+       case Kmpstatrawqid:
+               n = mpstatraw_read(va, n, offset);
                break;
        default:
                n = 0;
@@ -278,7 +404,16 @@ static void kprof_clear(struct kprof *kp)
 static long
 kprofwrite(struct chan *c, void *a, long n, int64_t unused)
 {
+       ERRSTACK(1);
        uintptr_t pc;
+       struct cmdbuf *cb;
+       cb = parsecmd(a, n);
+
+       if (waserror()) {
+               kfree(cb);
+               nexterror();
+       }
+
        switch((int)(c->qid.path)){
        case Kprofctlqid:
                if(strncmp(a, "startclr", 8) == 0){
@@ -286,14 +421,17 @@ kprofwrite(struct chan *c, void *a, long n, int64_t unused)
                        kprof.time = 1;
                }else if(strncmp(a, "start", 5) == 0) {
                        kprof.time = 1;
+                       /* this sets up the timer on the *calling* core! */
                        setup_timers();
                } else if(strncmp(a, "stop", 4) == 0) {
+                       /* TODO: stop the timers! */
                        kprof.time = 0;
                } else if(strncmp(a, "clear", 5) == 0) {
                        kprof_clear(&kprof);
-               }else if(strncmp(a, "opstart", 8) == 0) {
-                       /* maybe have enable/disable for it. */
+               }else if(strncmp(a, "opstart", 7) == 0) {
+                       oprofile_control_trace(1);
                }else if(strncmp(a, "opstop", 6) == 0) {
+                       oprofile_control_trace(0);
                } else  {
                        error("startclr|start|stop|clear|opstart|opstop");
                }
@@ -306,12 +444,90 @@ kprofwrite(struct chan *c, void *a, long n, int64_t unused)
                pc = strtoul(a, 0, 0);
                oprofile_add_trace(pc);
                break;
+       case Kprintxqid:
+               if (!strncmp(a, "on", 2))
+                       set_printx(1);
+               else if (!strncmp(a, "off", 3))
+                       set_printx(0);
+               else if (!strncmp(a, "toggle", 6))      /* why not. */
+                       set_printx(2);
+               else
+                       error("invalid option to Kprintx %s\n", a);
+               break;
+       case Kmpstatqid:
+       case Kmpstatrawqid:
+               if (cb->nf < 1)
+                       error("mpstat bad option (reset|ipi|on|off)");
+               if (!strcmp(cb->f[0], "reset")) {
+                       for (int i = 0; i < num_cpus; i++)
+                               reset_cpu_state_ticks(i);
+               } else if (!strcmp(cb->f[0], "on")) {
+                       /* TODO: enable the ticks */ ;
+               } else if (!strcmp(cb->f[0], "off")) {
+                       /* TODO: disable the ticks */ ;
+               } else if (!strcmp(cb->f[0], "ipi")) {
+                       if (cb->nf < 2)
+                               error("need another arg: ipi [on|off]");
+                       if (!strcmp(cb->f[1], "on"))
+                               kprof.mpstat_ipi = TRUE;
+                       else if (!strcmp(cb->f[1], "off"))
+                               kprof.mpstat_ipi = FALSE;
+                       else
+                               error("ipi [on|off]");
+               } else {
+                       error("mpstat bad option (reset|ipi|on|off)");
+               }
+               break;
        default:
                error(Ebadusefd);
        }
+       kfree(cb);
+       poperror();
        return n;
 }
 
+void kprof_write_sysrecord(char *pretty_buf, size_t len)
+{
+       int wrote;
+       if (kprof.systrace) {
+               /* TODO: need qio work so we can simply add the buf as extra data */
+               wrote = qiwrite(kprof.systrace, pretty_buf, len);
+               /* based on the current queue settings, we only drop when we're running
+                * out of memory.  odds are, we won't make it this far. */
+               if (wrote != len)
+                       printk("DROPPED %s", pretty_buf);
+       }
+}
+
+void trace_printk(const char *fmt, ...)
+{
+       va_list ap;
+       struct timespec ts_now;
+       size_t bufsz = 160;     /* 2x terminal width */
+       size_t len = 0;
+       char *buf = kmalloc(bufsz, 0);
+
+       if (!buf)
+               return;
+       tsc2timespec(read_tsc(), &ts_now);
+       len += snprintf(buf + len, bufsz - len, "[%7d.%09d] /* ", ts_now.tv_sec,
+                       ts_now.tv_nsec);
+       va_start(ap, fmt);
+       len += vsnprintf(buf + len, bufsz - len, fmt, ap);
+       va_start(ap, fmt);
+       va_end(ap);
+       len += snprintf(buf + len, bufsz - len, " */\n");
+       va_start(ap, fmt);
+       /* snprintf null terminates the buffer, and does not count that as part of
+        * the len.  if we maxed out the buffer, let's make sure it has a \n */
+       if (len == bufsz - 1) {
+               assert(buf[bufsz - 1] == '\0');
+               buf[bufsz - 2] = '\n';
+       }
+       kprof_write_sysrecord(buf, len);
+       kfree(buf);
+}
+
 struct dev kprofdevtab __devtab = {
        'K',
        "kprof",