Disabling histories in uvmhist.

[Simon Burge <simonb%NetBSD.org@localhost>]

Hi folks,

While playing around with UVM histories recently to trace some non-UVM
events, I wanted to disable the normal histories since they were having
a pretty large impact on system performance - a libc recompile was about
4 time slower with the normal UVM histories enabled.

What I did was use a spare int in struct uvm_history as an "enabled"
flag, and default all histories to off, and add new UVMHIST_ENABLE() and
UVMHIST_DISABLE() macros.

To pick on example in the source tree, there's currently:

        UVMHIST_INIT(ubchist, 300);

If you wanted to enable that, you'd do instead:

        UVMHIST_INIT(ubchist, 300);
        UVMHIST_ENABLE(ubchist);

The attached patch is what I used.  Any interest in cleaning this up
some more and committing it?  I was thinking along the lines of maybe
kernel config options for enabling the existing histories (loanhist,
maphist, pdhist, and ubchist), but am still not sure of this.  One
option is to leave them disabled and just include a commented-out
UVMHIST_ENABLE() with each one.


Somewhat related to this, I also found that using "call uvmhist_dump()"
from DDB was pretty hit-or-miss for two reasons:

 1) We'd wedge at the splhigh() call in uvmhist_dump(), I assume
    since interrupts were in a pretty broken state when DDB became
    active.  Locally I've commented out the splhigh()/splx() calls in
    uvmhist_dump().  I'd also thought about adding a second parameter
    to uvmhist_dump() to toggle the SPL dance.

 2) printf() would sometimes block because the KPRINTF_MUTEX_ENTER()
    call would block.  Whether this was the same issue as 1) or
    because kprintf_slock was held I'm not sure.  I just used a local
    "printf_unlocked" to skip KPRINTF_MUTEX_ENTER().  One option is
    to use DDB's db_printf() instead.

Any more thoughts on these two issues?

Cheers,
Simon.

Index: uvm/uvm_stat.h
===================================================================
RCS file: /cvsroot/src/sys/uvm/uvm_stat.h,v
retrieving revision 1.43
diff -d -p -u -r1.43 uvm_stat.h
--- uvm/uvm_stat.h      25 May 2008 16:02:08 -0000      1.43
+++ uvm/uvm_stat.h      27 Jun 2008 08:45:14 -0000
@@ -72,7 +72,7 @@ struct uvm_history {
        LIST_ENTRY(uvm_history) list;   /* link on list of all histories */
        int n;                          /* number of entries */
        int f;                          /* next free one */
-       int unused;                     /* old location of lock */
+       int enabled;                    /* this history is enabled */
        struct uvm_history_ent *e;      /* the malloc'd entries */
        kmutex_t l;                     /* lock on this history */
 };
@@ -121,6 +121,7 @@ do { \
        (NAME).namelen = strlen(__STRING(NAME)); \
        (NAME).n = (N); \
        (NAME).f = 0; \
+       (NAME).enabled = 0; \
        mutex_init(&(NAME).l, MUTEX_SPIN, IPL_HIGH); \
        (NAME).e = (struct uvm_history_ent *) \
                malloc(sizeof(struct uvm_history_ent) * (N), M_TEMP, \
@@ -135,12 +136,23 @@ do { \
        (NAME).namelen = strlen(__STRING(NAME)); \
        (NAME).n = sizeof(BUF) / sizeof(struct uvm_history_ent); \
        (NAME).f = 0; \
+       (NAME).enabled = 0; \
        mutex_init(&(NAME).l, MUTEX_SPIN, IPL_HIGH); \
        (NAME).e = (struct uvm_history_ent *) (BUF); \
        memset((NAME).e, 0, sizeof(struct uvm_history_ent) * (NAME).n); \
        LIST_INSERT_HEAD(&uvm_histories, &(NAME), list); \
 } while (/*CONSTCOND*/ 0)
 
+#define        UVMHIST_ENABLE(NAME) \
+do { \
+       (NAME).enabled = 1; \
+} while (/*CONSTCOND*/ 0)
+
+#define        UVMHIST_DISABLE(NAME) \
+do { \
+       (NAME).enabled = 0; \
+} while (/*CONSTCOND*/ 0)
+
 #if defined(UVMHIST_PRINT)
 extern int uvmhist_print_enabled;
 #define UVMHIST_PRINTNOW(E) \
@@ -156,40 +168,47 @@ do { \
 
 #define UVMHIST_LOG(NAME,FMT,A,B,C,D) \
 do { \
-       int _i_; \
-       mutex_enter(&(NAME).l); \
-       _i_ = (NAME).f; \
-       (NAME).f = (_i_ + 1 < (NAME).n) ? _i_ + 1 : 0; \
-       mutex_exit(&(NAME).l); \
-       if (!cold) \
-               microtime(&(NAME).e[_i_].tv); \
-       (NAME).e[_i_].cpunum = cpu_number(); \
-       (NAME).e[_i_].fmt = (FMT); \
-       (NAME).e[_i_].fmtlen = strlen(FMT); \
-       (NAME).e[_i_].fn = _uvmhist_name; \
-       (NAME).e[_i_].fnlen = strlen(_uvmhist_name); \
-       (NAME).e[_i_].call = _uvmhist_call; \
-       (NAME).e[_i_].v[0] = (u_long)(A); \
-       (NAME).e[_i_].v[1] = (u_long)(B); \
-       (NAME).e[_i_].v[2] = (u_long)(C); \
-       (NAME).e[_i_].v[3] = (u_long)(D); \
-       UVMHIST_PRINTNOW(&((NAME).e[_i_])); \
+       if ((NAME).enabled) { \
+               int _i_; \
+               mutex_enter(&(NAME).l); \
+               _i_ = (NAME).f; \
+               (NAME).f = (_i_ + 1 < (NAME).n) ? _i_ + 1 : 0; \
+               mutex_exit(&(NAME).l); \
+               if (!cold) \
+                       microtime(&(NAME).e[_i_].tv); \
+               (NAME).e[_i_].cpunum = cpu_number(); \
+               (NAME).e[_i_].fmt = (FMT); \
+               (NAME).e[_i_].fmtlen = strlen(FMT); \
+               (NAME).e[_i_].fn = _uvmhist_name; \
+               (NAME).e[_i_].fnlen = strlen(_uvmhist_name); \
+               (NAME).e[_i_].call = _uvmhist_call; \
+               (NAME).e[_i_].v[0] = (u_long)(A); \
+               (NAME).e[_i_].v[1] = (u_long)(B); \
+               (NAME).e[_i_].v[2] = (u_long)(C); \
+               (NAME).e[_i_].v[3] = (u_long)(D); \
+               UVMHIST_PRINTNOW(&((NAME).e[_i_])); \
+       } \
 } while (/*CONSTCOND*/ 0)
 
-#define UVMHIST_CALLED(NAME) \
+#define UVMHIST_ENTER(NAME) \
 do { \
-       { \
+       if ((NAME).enabled) { \
                mutex_enter(&(NAME).l); \
                _uvmhist_call = _uvmhist_cnt++; \
                mutex_exit(&(NAME).l); \
        } \
+} while (/*CONSTCOND*/ 0)
+
+#define UVMHIST_CALLED(NAME) \
+do { \
+       UVMHIST_ENTER(NAME); \
        UVMHIST_LOG(NAME,"called!", 0, 0, 0, 0); \
 } while (/*CONSTCOND*/ 0)
 
 #define UVMHIST_FUNC(FNAME) \
        static int _uvmhist_cnt = 0; \
        static const char *const _uvmhist_name = FNAME; \
-       int _uvmhist_call;
+       int _uvmhist_call = 0;
 
 static __inline void uvmhist_print(struct uvm_history_ent *);