[src/trunk]: src Add a BIOHIST option. As mentioned on tech-kern.

[pgoyette <pgoyette%NetBSD.org@localhost>]

details:   https://anonhg.NetBSD.org/src/rev/90700e101afe
branches:  trunk
changeset: 349873:90700e101afe
user:      pgoyette <pgoyette%NetBSD.org@localhost>
date:      Mon Dec 26 23:12:33 2016 +0000

description:
Add a BIOHIST option.  As mentioned on tech-kern.

diffstat:

 share/man/man4/ddb.4     |   4 ++-
 share/man/man4/options.4 |  28 +++++++++++++++++++++-
 sys/conf/files           |  11 ++++++++-
 sys/kern/init_main.c     |   5 ++-
 sys/kern/kern_history.c  |  17 ++++++++++++-
 sys/kern/vfs_bio.c       |  59 +++++++++++++++++++++++++++++++++++++++++++++--
 sys/sys/biohist.h        |  58 +++++++++++++++++++++++++++++++++++++++++++++++
 sys/sys/buf.h            |   3 +-
 sys/sys/kernhist.h       |   3 +-
 9 files changed, 176 insertions(+), 12 deletions(-)

diffs (truncated from 469 to 300 lines):

diff -r 396ceeb6e86d -r 90700e101afe share/man/man4/ddb.4
--- a/share/man/man4/ddb.4      Mon Dec 26 23:10:46 2016 +0000
+++ b/share/man/man4/ddb.4      Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-.\"    $NetBSD: ddb.4,v 1.161 2016/04/13 00:47:01 ozaki-r Exp $
+.\"    $NetBSD: ddb.4,v 1.162 2016/12/26 23:12:33 pgoyette Exp $
 .\"
 .\" Copyright (c) 1997 - 2009 The NetBSD Foundation, Inc.
 .\" All rights reserved.
@@ -749,6 +749,8 @@
 or
 .Cd options USB_DEBUG
 (or related options) or
+.Cd options BIOHIST
+or
 .Cd options UVMHIST .
 .It Ic show vnode Ns Oo Cm /f Oc Ar address
 Print the vnode at
diff -r 396ceeb6e86d -r 90700e101afe share/man/man4/options.4
--- a/share/man/man4/options.4  Mon Dec 26 23:10:46 2016 +0000
+++ b/share/man/man4/options.4  Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-.\"    $NetBSD: options.4,v 1.457 2016/12/13 11:00:20 wiz Exp $
+.\"    $NetBSD: options.4,v 1.458 2016/12/26 23:12:33 pgoyette Exp $
 .\"
 .\" Copyright (c) 1996
 .\"    Perry E. Metzger.  All rights reserved.
@@ -711,6 +711,32 @@
 This option depends upon the
 .Em UVMHIST
 option.
+.It Cd options BIOHIST
+Like
+.Em KERNHIST ,
+it enables the BIO history logs.
+These logs can be displayed by using
+.Cm show kernhist
+from DDB.
+See the kernel source file
+.Pa sys/kern/vfs_vio.c
+for details.
+.It Cd options BIOHIST_PRINT
+Like
+.Em BIOHIST ,
+it prints the BIO history logs on the system console as entries are added.
+Note that the output is
+.Em extremely
+voluminous, so this option is really only useful for debugging
+the very earliest parts of kernel initialization.
+.It Cd options BIOHIST_SIZE
+Set the size of the
+.Dq biohist
+kernel history.
+The default is 500.
+This option depends upon the
+.Em BIOHIST
+option.
 .El
 .Ss File Systems
 .Bl -ohang
diff -r 396ceeb6e86d -r 90700e101afe sys/conf/files
--- a/sys/conf/files    Mon Dec 26 23:10:46 2016 +0000
+++ b/sys/conf/files    Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-#      $NetBSD: files,v 1.1167 2016/12/13 20:20:34 christos Exp $
+#      $NetBSD: files,v 1.1168 2016/12/26 23:12:33 pgoyette Exp $
 #      @(#)files.newconf       7.5 (Berkeley) 5/10/93
 
 version        20150846
@@ -39,6 +39,7 @@
 
 defflag                                AIO
 defflag                                MQUEUE
+defflag                                SEMAPHORE
 
 defflag                                BUFQ_DISKSORT
 defflag                                BUFQ_FCFS
@@ -201,6 +202,13 @@
 defparam opt_usb.h                     USBHIST_SIZE
 
 #
+# Options for BIOHIST
+#
+defflag opt_biohist.h           BIOHIST: KERNHIST
+defflag opt_biohist.h           BIOHIST_PRINT: KERNHIST_PRINT
+defparam opt_biohist.h          BIOHIST_SIZE
+
+#
 # System monitoring framework
 #
 include "dev/sysmon/files.sysmon"
@@ -1507,6 +1515,7 @@
 include "miscfs/umapfs/files.umapfs"
 include "nfs/files.nfs"
 include "ufs/files.ufs"
+include "fs/nfs/files.newnfs"
 
 #
 # UVM (virtual memory)
diff -r 396ceeb6e86d -r 90700e101afe sys/kern/init_main.c
--- a/sys/kern/init_main.c      Mon Dec 26 23:10:46 2016 +0000
+++ b/sys/kern/init_main.c      Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-/*     $NetBSD: init_main.c,v 1.487 2016/11/16 12:31:33 pgoyette Exp $ */
+/*     $NetBSD: init_main.c,v 1.488 2016/12/26 23:12:33 pgoyette Exp $ */
 
 /*-
  * Copyright (c) 2008, 2009 The NetBSD Foundation, Inc.
@@ -97,7 +97,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.487 2016/11/16 12:31:33 pgoyette Exp $");
+__KERNEL_RCSID(0, "$NetBSD: init_main.c,v 1.488 2016/12/26 23:12:33 pgoyette Exp $");
 
 #include "opt_ddb.h"
 #include "opt_inet.h"
@@ -349,6 +349,7 @@
 
        /* Initialize the buffer cache */
        bufinit();
+       biohist_init();
 
 
 #if defined(SPLASHSCREEN) && defined(SPLASHSCREEN_IMAGE)
diff -r 396ceeb6e86d -r 90700e101afe sys/kern/kern_history.c
--- a/sys/kern/kern_history.c   Mon Dec 26 23:10:46 2016 +0000
+++ b/sys/kern/kern_history.c   Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-/*     $NetBSD: kern_history.c,v 1.6 2016/06/23 07:32:12 skrll Exp $    */
+/*     $NetBSD: kern_history.c,v 1.7 2016/12/26 23:12:33 pgoyette Exp $         */
 
 /*
  * Copyright (c) 1997 Charles D. Cranor and Washington University.
@@ -33,13 +33,14 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: kern_history.c,v 1.6 2016/06/23 07:32:12 skrll Exp $");
+__KERNEL_RCSID(0, "$NetBSD: kern_history.c,v 1.7 2016/12/26 23:12:33 pgoyette Exp $");
 
 #include "opt_ddb.h"
 #include "opt_kernhist.h"
 #include "opt_syscall_debug.h"
 #include "opt_usb.h"
 #include "opt_uvmhist.h"
+#include "opt_biohist.h"
 
 #include <sys/param.h>
 #include <sys/systm.h>
@@ -54,6 +55,10 @@
 #include <dev/usb/usbhist.h>
 #endif
 
+#ifdef BIOHIST
+#include <kern/biohist.h>
+#endif
+
 #ifdef SYSCALL_DEBUG
 KERNHIST_DECL(scdebughist);
 #endif
@@ -200,6 +205,11 @@
                hists[i++] = &scdebughist;
 #endif
 
+#ifdef BIOHIST
+       if ((bitmask & KERNHIST_BIOHIST) || bitmask == 0)
+               hists[i++] = &biohist;
+#endif
+
        hists[i] = NULL;
 
        kernhist_dump_histories(hists, printf);
@@ -234,6 +244,9 @@
 #ifdef SYSCALL_DEBUG
                hists[i++] = &scdebughist;
 #endif
+#ifdef BIOHIST
+               hists[i++] = &biohist;
+#endif
                hists[i] = NULL;
 
                kernhist_dump_histories(hists, pr);
diff -r 396ceeb6e86d -r 90700e101afe sys/kern/vfs_bio.c
--- a/sys/kern/vfs_bio.c        Mon Dec 26 23:10:46 2016 +0000
+++ b/sys/kern/vfs_bio.c        Mon Dec 26 23:12:33 2016 +0000
@@ -1,4 +1,4 @@
-/*     $NetBSD: vfs_bio.c,v 1.263 2016/12/18 05:43:20 dholland Exp $   */
+/*     $NetBSD: vfs_bio.c,v 1.264 2016/12/26 23:12:33 pgoyette Exp $   */
 
 /*-
  * Copyright (c) 2007, 2008, 2009 The NetBSD Foundation, Inc.
@@ -123,11 +123,12 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: vfs_bio.c,v 1.263 2016/12/18 05:43:20 dholland Exp $");
+__KERNEL_RCSID(0, "$NetBSD: vfs_bio.c,v 1.264 2016/12/26 23:12:33 pgoyette Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_bufcache.h"
 #include "opt_dtrace.h"
+#include "opt_biohist.h"
 #endif
 
 #include <sys/param.h>
@@ -196,6 +197,21 @@
 static void sysctl_kern_buf_setup(void);
 static void sysctl_vm_buf_setup(void);
 
+/* Initialization for biohist */
+
+#ifdef BIOHIST
+#include <sys/biohist.h>
+#endif /* BIOHIST */
+
+KERNHIST_DEFINE(biohist);
+
+void
+biohist_init(void)
+{
+ 
+       KERNHIST_INIT(biohist, BIOHIST_SIZE);
+}
+
 /*
  * Definitions for the buffer hash lists.
  */
@@ -726,6 +742,8 @@
        buf_t *bp;
        int error;
 
+       KERNHIST_FUNC(__func__); KERNHIST_CALLED(biohist);
+
        /* Get buffer for block. */
        bp = *bpp = bio_doread(vp, blkno, size, 0);
        if (bp == NULL)
@@ -754,6 +772,8 @@
        buf_t *bp;
        int error, i;
 
+       KERNHIST_FUNC(__func__); KERNHIST_CALLED(biohist);
+
        bp = *bpp = bio_doread(vp, blkno, size, 0);
        if (bp == NULL)
                return ENOMEM;
@@ -796,6 +816,9 @@
        struct vnode *vp;
        struct mount *mp;
 
+       KERNHIST_FUNC(__func__); KERNHIST_CALLARGS(biohist, "bp=%p",
+           bp, 0, 0, 0);
+
        KASSERT(ISSET(bp->b_cflags, BC_BUSY));
        KASSERT(!cv_has_waiters(&bp->b_done));
 
@@ -918,6 +941,9 @@
 bdwrite(buf_t *bp)
 {
 
+       KERNHIST_FUNC(__func__); KERNHIST_CALLARGS(biohist, "bp=%p",
+           bp, 0, 0, 0);
+
        KASSERT(bp->b_vp == NULL || bp->b_vp->v_tag != VT_UFS ||
            bp->b_vp->v_type == VBLK || ISSET(bp->b_flags, B_COWDONE));
        KASSERT(ISSET(bp->b_cflags, BC_BUSY));
@@ -1497,18 +1523,28 @@
 biowait(buf_t *bp)
 {
 
+       KERNHIST_FUNC(__func__);
+
        KASSERT(ISSET(bp->b_cflags, BC_BUSY));
        KASSERT(bp->b_refcnt > 0);
 
        SDT_PROBE1(io, kernel, , wait__start, bp);
 
        mutex_enter(bp->b_objlock);
-       while (!ISSET(bp->b_oflags, BO_DONE | BO_DELWRI))
+
+       KERNHIST_CALLARGS(biohist, "bp=%p, oflags=0x%x",
+           bp, bp->b_oflags, 0, 0);
+
+       while (!ISSET(bp->b_oflags, BO_DONE | BO_DELWRI)) {
+               KERNHIST_LOG(biohist, "waiting bp=%p", bp, 0, 0, 0);
                cv_wait(&bp->b_done, bp->b_objlock);
+       }
        mutex_exit(bp->b_objlock);
 
        SDT_PROBE1(io, kernel, , wait__done, bp);
 
+       KERNHIST_LOG(biohist, "  return %d", bp->b_error, 0, 0, 0);
+
        return bp->b_error;
 }
 
@@ -1533,12 +1569,17 @@
 {
        int s;