From owner-cvs-all Tue Apr 2 6:46:37 2002 Delivered-To: cvs-all@freebsd.org Received: from flood.ping.uio.no (flood.ping.uio.no [129.240.78.31]) by hub.freebsd.org (Postfix) with ESMTP id F41F037B41E; Tue, 2 Apr 2002 06:45:10 -0800 (PST) Received: by flood.ping.uio.no (Postfix, from userid 2602) id F3AF95346; Tue, 2 Apr 2002 16:45:06 +0200 (CEST) X-URL: http://www.ofug.org/~des/ X-Disclaimer: The views expressed in this message do not necessarily coincide with those of any organisation or company with which I am or have been affiliated. To: Poul-Henning Kamp Cc: Marcel Moolenaar , cvs-committers@FreeBSD.org, cvs-all@FreeBSD.org Subject: Re: cvs commit: src/sys/ia64/ia64 ia64dump.c References: <51854.1017754714@critter.freebsd.dk> From: Dag-Erling Smorgrav Date: 02 Apr 2002 16:45:05 +0200 In-Reply-To: <51854.1017754714@critter.freebsd.dk> Message-ID: Lines: 14 User-Agent: Gnus/5.0808 (Gnus v5.8.8) Emacs/21.1 MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" Sender: owner-cvs-all@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG --=-=-= Poul-Henning Kamp writes: > Sorry DES, I will NOT allow you to put down an exclusive lock on > this area until you have code to show for it. I *had* patches, but nuked them when you committed your code. Remnants can be found in the attached garbage file. I even blew a partition working on this (by setting dumplo too high). DES -- Dag-Erling Smorgrav - des@ofug.org --=-=-= Content-Type: text/x-patch Content-Disposition: attachment; filename=sys.diff Index: sys/alpha/alpha/machdep.c =================================================================== RCS file: /home/ncvs/src/sys/alpha/alpha/machdep.c,v retrieving revision 1.170 diff -u -r1.170 machdep.c --- sys/alpha/alpha/machdep.c 27 Mar 2002 09:23:37 -0000 1.170 +++ sys/alpha/alpha/machdep.c 30 Mar 2002 15:05:25 -0000 @@ -192,7 +192,6 @@ struct msgbuf *msgbufp=0; int Maxmem = 0; -long dumplo; int totalphysmem; /* total amount of physical memory in system */ int physmem; /* physical memory used by NetBSD + some rsvd */ Index: sys/conf/options.i386 =================================================================== RCS file: /home/ncvs/src/sys/conf/options.i386,v retrieving revision 1.169 diff -u -r1.169 options.i386 --- sys/conf/options.i386 27 Feb 2002 09:51:31 -0000 1.169 +++ sys/conf/options.i386 23 Mar 2002 18:04:45 -0000 @@ -188,6 +188,9 @@ # SMB/CIFS filesystem SMBFS +# Mutex profiling +TRACE_MUTEX_TIME opt_global.h + # ------------------------------- # EOF # ------------------------------- Index: sys/i386/i386/machdep.c =================================================================== RCS file: /home/ncvs/src/sys/i386/i386/machdep.c,v retrieving revision 1.507 diff -u -r1.507 machdep.c --- sys/i386/i386/machdep.c 27 Mar 2002 09:23:37 -0000 1.507 +++ sys/i386/i386/machdep.c 30 Mar 2002 15:06:12 -0000 @@ -196,7 +196,6 @@ 0, 0, sysctl_hw_availpages, "I", ""); int Maxmem = 0; -long dumplo; vm_offset_t phys_avail[10]; Index: sys/ia64/ia64/machdep.c =================================================================== RCS file: /home/ncvs/src/sys/ia64/ia64/machdep.c,v retrieving revision 1.85 diff -u -r1.85 machdep.c --- sys/ia64/ia64/machdep.c 30 Mar 2002 23:25:22 -0000 1.85 +++ sys/ia64/ia64/machdep.c 31 Mar 2002 00:36:27 -0000 @@ -142,7 +142,6 @@ struct msgbuf *msgbufp=0; int Maxmem = 0; -long dumplo; int totalphysmem; /* total amount of physical memory in system */ int physmem; /* physical memory used by NetBSD + some rsvd */ Index: sys/kern/kern_mutex.c =================================================================== RCS file: /home/ncvs/src/sys/kern/kern_mutex.c,v retrieving revision 1.83 diff -u -r1.83 kern_mutex.c --- sys/kern/kern_mutex.c 27 Mar 2002 09:23:38 -0000 1.83 +++ sys/kern/kern_mutex.c 30 Mar 2002 15:06:26 -0000 @@ -37,17 +37,19 @@ #include "opt_ddb.h" #include +#include #include +#include #include +#include #include #include #include #include #include +#include #include -#include #include -#include #include #include @@ -196,6 +198,104 @@ } } +#ifdef TRACE_MUTEX_TIME +#define TRACE_HASH_SIZE 1009 +SYSCTL_NODE(_kern, OID_AUTO, mtx, CTLFLAG_RD, NULL, "mutex manipulation"); +SYSCTL_NODE(_kern_mtx, OID_AUTO, trace, CTLFLAG_RD, NULL, "mutex tracing"); +static int kern_mtx_trace_enable = 0; +SYSCTL_INT(_kern_mtx_trace, OID_AUTO, enable, CTLFLAG_RW, + &kern_mtx_trace_enable, 0, "Enable tracing of mutex holdtime"); +static int kern_mtx_trace_hashsize = TRACE_HASH_SIZE; +SYSCTL_INT(_kern_mtx_trace, OID_AUTO, hashsize, CTLFLAG_RD, + &kern_mtx_trace_hashsize, 0, "Trace hash size"); +static int kern_mtx_trace_numtraced = 0; +SYSCTL_INT(_kern_mtx_trace, OID_AUTO, numtraced, CTLFLAG_RD, + &kern_mtx_trace_numtraced, 0, "Number of traced mutices"); +static int kern_mtx_trace_collisions = 0; +SYSCTL_INT(_kern_mtx_trace, OID_AUTO, collisions, CTLFLAG_RD, + &kern_mtx_trace_numtraced, 0, "Number of hash collisions"); + +static struct mutex_trace { + char name[64]; + u_int64_t count; + u_int64_t maxtsc; + u_int64_t totaltsc; + struct mutex_trace *next; +} *mutex_traces[TRACE_HASH_SIZE]; + +static struct mtx trace_mtx; + +/* + * tracebuf is the pool of trace records we have; + * we cannot (reliably) handle more than this number + * of places in the code where mutexes are aquired. + * + * We use a static allocation to avoid interacting + * with the rest of the system. + */ +#define NUM_TRACE_BUFFERS 1000 +static struct mutex_trace tracebuf[NUM_TRACE_BUFFERS]; +static int first_free_mutex_trace = 0; + +static const char *unknown = "(unknown)"; + +/* Number of locks to show in the sysctl. MUST BE AN EVEN NUMBER. */ +#define NUM_LOCKS_TO_DUMP 10 +#define mutex_trace_cmp(a, b) (tracebuf[a].maxtsc - tracebuf[b].maxtsc) + +/* + * Output statistics of mutex holders that keep the mutex the longest. + */ +static int +dump_mtx_trace(SYSCTL_HANDLER_ARGS) +{ + struct sbuf *sb; + struct mutex_trace *mtp; + int traces[NUM_LOCKS_TO_DUMP]; + int error, i, j, k; + + if (kern_mtx_trace_numtraced == 0) + return SYSCTL_OUT(req, "No locking recorded", + sizeof("No locking recorded")); + + /* + * Find the 10 largest + */ + mtx_lock_spin(&trace_mtx); + for (i = 0; i < NUM_LOCKS_TO_DUMP; ++i) + traces[i] = -1; + for (k = 0; k < first_free_mutex_trace; ++k) { + for (i = 0; i < NUM_LOCKS_TO_DUMP; ++i) { + if (traces[i] == -1) { + traces[i] = k; + break; + } + if (mutex_trace_cmp(k, traces[i]) < 0) + continue; + for (j = NUM_LOCKS_TO_DUMP - 1; j > i; --j) + traces[j] = traces[j - 1]; + traces[i] = k; + break; + } + } + + /* Now dump the garbage */ + sb = sbuf_new(NULL, NULL, 256, SBUF_AUTOEXTEND); + for (i = 0; i < NUM_LOCKS_TO_DUMP && traces[i] != -1; ++i) { + mtp = &tracebuf[traces[i]]; + sbuf_printf(sb, "%s: held %llu (%llu)\n", + mtp->name, mtp->maxtsc, mtp->totaltsc); + } + sbuf_finish(sb); + mtx_unlock_spin(&trace_mtx); + error = SYSCTL_OUT(req, sbuf_data(sb), sbuf_len(sb)); + sbuf_delete(sb); + return (error); +} +SYSCTL_PROC(_kern_mtx_trace, OID_AUTO, stats, CTLTYPE_STRING|CTLFLAG_RD, + NULL, 0, dump_mtx_trace, "A", "Statistics about how long mutexes are held"); +#endif /* TRACE_MUTEX_TIME */ + /* * Function versions of the inlined __mtx_* macros. These are used by * modules and can also be called from assembly language if needed. @@ -209,6 +309,22 @@ LOCK_LOG_LOCK("LOCK", &m->mtx_object, opts, m->mtx_recurse, file, line); WITNESS_LOCK(&m->mtx_object, opts | LOP_EXCLUSIVE, file, line); +#ifdef TRACE_MUTEX_TIME + if (!(trace_mtx.mtx_object.lo_flags & LO_INITIALIZED)) + mtx_init(&trace_mtx, "mutex trace lock", MTX_SPIN | MTX_QUIET); + mtx_lock_spin(&trace_mtx); + m->tsc = kern_mtx_trace_enable ? rdtsc() : 0; + if (m->name[0] == '\0') { + const char *p = file; + + while (p && strncmp(p, "../", 3) == 0) + p += 3; + if (p == NULL || *p == '\0') + p = unknown; + snprintf(m->name, sizeof m->name, "%s:%d", p, line); + } + mtx_unlock_spin(&trace_mtx); +#endif } void @@ -217,6 +333,54 @@ MPASS(curthread != NULL); mtx_assert(m, MA_OWNED); +#ifdef TRACE_MUTEX_TIME + if (m->tsc != 0 && m->name[0] != '\0') { + struct mutex_trace *trace; + u_int64_t tsc, mtsc; + u_int hash; + char *p; + + tsc = rdtsc(); + mtsc = m->tsc; + m->tsc = 0; + if (tsc <= mtsc) + goto out; + for (hash = 0, p = m->name; *p; p++) + hash += (unsigned char)*p; + hash %= TRACE_HASH_SIZE; + hash = line % TRACE_HASH_SIZE; + mtx_lock_spin(&trace_mtx); + for (trace = mutex_traces[hash]; trace; trace = trace->next) + if (strcmp(trace->name, m->name) == 0) + break; + if (trace == NULL) { + /* Just exit if we cannot get a trace buffer */ + if (first_free_mutex_trace >= NUM_TRACE_BUFFERS) + goto unlock_out; + trace = &tracebuf[first_free_mutex_trace++]; + /* Race protection */ + if (first_free_mutex_trace > NUM_TRACE_BUFFERS) + goto unlock_out; + strcpy(trace->name, m->name); + if (mutex_traces[hash] != NULL) + ++kern_mtx_trace_collisions; + trace->next = mutex_traces[hash]; + mutex_traces[hash] = trace; + ++kern_mtx_trace_numtraced; + } + /* + * Record if the mutex has been held longer now than ever + * before + */ + if ((tsc - mtsc) > trace->maxtsc) + trace->maxtsc = tsc - mtsc; + trace->totaltsc += tsc - mtsc; + trace->count += 1; + unlock_out: + mtx_unlock_spin(&trace_mtx); + } +out: +#endif WITNESS_UNLOCK(&m->mtx_object, opts | LOP_EXCLUSIVE, file, line); LOCK_LOG_LOCK("UNLOCK", &m->mtx_object, opts, m->mtx_recurse, file, line); Index: sys/kern/kern_shutdown.c =================================================================== RCS file: /home/ncvs/src/sys/kern/kern_shutdown.c,v retrieving revision 1.120 diff -u -r1.120 kern_shutdown.c --- sys/kern/kern_shutdown.c 7 Mar 2002 04:43:51 -0000 1.120 +++ sys/kern/kern_shutdown.c 13 Mar 2002 00:52:56 -0000 @@ -51,6 +51,7 @@ #include #include #include +#include #include #include #include @@ -59,9 +60,11 @@ #include #include #include +#include #include /* smp_active */ #include #include +#include #include #include @@ -116,7 +119,9 @@ */ const char *panicstr; -int dumping; /* system is dumping */ +int dumping; /* System is dumping */ +long dumplo; /* Dump offset */ +char dumpinfo[DUMPINFO_SIZE]; /* Dump metadata */ static void boot(int) __dead2; static void dumpsys(void); @@ -207,7 +212,7 @@ } /* - * Go through the rigmarole of shutting down.. + * Go through the rigmarole of shutting down.. * this used to be in machdep.c but I'll be dammned if I could see * anything machine dependant in it. */ @@ -444,9 +449,15 @@ if (psize == -1) return (ENXIO); /* XXX should be ENODEV ? */ /* - * XXX should clean up checking in dumpsys() to be more like this. + * Determine the dump offset. Place it as high as possible on the + * dump device, so it will survive a certain amount of swapping + * before savecore(1) runs, and reserve enough space for all + * physical memory, plus an extra page for metadata. */ - newdumplo = psize - Maxmem * (PAGE_SIZE / DEV_BSIZE); + /* + * XXX what happens if the device's sector size != DEV_BSIZE? + */ + newdumplo = psize - DUMP_SECS(DEV_BSIZE); if (newdumplo <= LABELSECTOR) return (ENOSPC); dumpdev = dev; @@ -490,6 +501,7 @@ SYSCTL_PROC(_kern, KERN_DUMPDEV, dumpdev, CTLTYPE_OPAQUE|CTLFLAG_RW, 0, sizeof dumpdev, sysctl_kern_dumpdev, "T,dev_t", ""); +extern void *kernbase; /* * Doadump comes here after turning off memory management and @@ -499,7 +511,22 @@ static void dumpsys(void) { - int error; + struct sbuf sb; + int error; + + sbuf_new(&sb, dumpinfo, DUMPINFO_SIZE, SBUF_FIXEDLEN); + /* magic + length of dump metadata */ + sbuf_printf(&sb, "DUMPINFO 0x%x\n", DUMPINFO_SIZE); + sbuf_printf(&sb, "dumpinfo_version=%d\n", DUMPINFO_VERSION); + sbuf_printf(&sb, "dumpinfo_size=0x%x\n", DUMPINFO_SIZE); + sbuf_printf(&sb, "page_size=0x%x\n", PAGE_SIZE); + sbuf_printf(&sb, "dev_bsize=0x%x\n", DEV_BSIZE); + sbuf_printf(&sb, "dumplo=0x%lx\n", dumplo); + sbuf_printf(&sb, "kernbase=0x%p\n", kernbase); + sbuf_printf(&sb, "dumptime=0x%lx\n", timecounter->tc_microtime.tv_sec); + sbuf_printf(&sb, "@0x0 0x%x\n", Maxmem); + sbuf_finish(&sb); + printf(dumpinfo); savectx(&dumppcb); if (!dodump) Index: sys/kern/subr_disk.c =================================================================== RCS file: /home/ncvs/src/sys/kern/subr_disk.c,v retrieving revision 1.52 diff -u -r1.52 subr_disk.c --- sys/kern/subr_disk.c 11 Mar 2002 08:08:02 -0000 1.52 +++ sys/kern/subr_disk.c 15 Mar 2002 20:35:43 -0000 @@ -15,6 +15,7 @@ #include #include +#include #include #include #include @@ -213,7 +214,7 @@ dl = dsgetlabel(dev, dp->d_slice); if (!dl) return (ENXIO); - *count = Maxmem * (PAGE_SIZE / dl->d_secsize); + *count = DUMP_SECS(dl->d_secsize); if (dumplo <= LABELSECTOR || (dumplo + *count > dl->d_partitions[dkpart(dev)].p_size)) return (EINVAL); Index: sys/kern/subr_witness.c =================================================================== RCS file: /home/ncvs/src/sys/kern/subr_witness.c,v retrieving revision 1.103 diff -u -r1.103 subr_witness.c --- sys/kern/subr_witness.c 27 Mar 2002 09:23:38 -0000 1.103 +++ sys/kern/subr_witness.c 30 Mar 2002 15:06:27 -0000 @@ -214,6 +214,7 @@ { "ithread table lock", &lock_class_mtx_spin }, { "sched lock", &lock_class_mtx_spin }, { "callout", &lock_class_mtx_spin }, + { "bio queue", &lock_class_mtx_spin }, /* * leaf locks */ Index: sys/pc98/i386/machdep.c =================================================================== RCS file: /home/ncvs/src/sys/pc98/i386/machdep.c,v retrieving revision 1.270 diff -u -r1.270 machdep.c --- sys/pc98/i386/machdep.c 30 Mar 2002 11:14:52 -0000 1.270 +++ sys/pc98/i386/machdep.c 30 Mar 2002 15:07:00 -0000 @@ -209,7 +209,6 @@ #ifdef PC98 int Maxmem_under16M = 0; #endif -long dumplo; vm_offset_t phys_avail[10]; Index: sys/sparc64/sparc64/machdep.c =================================================================== RCS file: /home/ncvs/src/sys/sparc64/sparc64/machdep.c,v retrieving revision 1.44 diff -u -r1.44 machdep.c --- sys/sparc64/sparc64/machdep.c 30 Mar 2002 20:58:08 -0000 1.44 +++ sys/sparc64/sparc64/machdep.c 31 Mar 2002 00:37:10 -0000 @@ -112,7 +112,6 @@ int physmem; int cold = 1; -long dumplo; int Maxmem; struct mtx Giant; Index: sys/sys/_mutex.h =================================================================== RCS file: /home/ncvs/src/sys/sys/_mutex.h,v retrieving revision 1.4 diff -u -r1.4 _mutex.h --- sys/sys/_mutex.h 18 Dec 2001 00:27:18 -0000 1.4 +++ sys/sys/_mutex.h 23 Mar 2002 17:41:05 -0000 @@ -41,6 +41,10 @@ volatile u_int mtx_recurse; /* number of recursive holds */ TAILQ_HEAD(, thread) mtx_blocked; /* threads blocked on this lock */ LIST_ENTRY(mtx) mtx_contested; /* list of all contested locks */ +#ifdef TRACE_MUTEX_TIME + u_int64_t tsc; + char name[64]; +#endif }; #endif /* !_SYS_MUTEX_TYPES_H_ */ Index: sys/sys/systm.h =================================================================== RCS file: /home/ncvs/src/sys/sys/systm.h,v retrieving revision 1.167 diff -u -r1.167 systm.h --- sys/sys/systm.h 30 Mar 2002 19:58:31 -0000 1.167 +++ sys/sys/systm.h 31 Mar 2002 00:37:12 -0000 @@ -62,9 +62,6 @@ extern int physmem; /* physical memory */ -extern dev_t dumpdev; /* dump device */ -extern long dumplo; /* offset into dumpdev */ - extern dev_t rootdev; /* root device */ extern dev_t rootdevs[2]; /* possible root devices */ extern char *rootdevnames[2]; /* names of possible root devices */ --=-=-=-- To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe cvs-all" in the body of the message