NetBSD-5.0.2/usr.sbin/lockstat/main.c
/* $NetBSD: main.c,v 1.14 2008/04/28 20:24:16 martin Exp $ */
/*-
* Copyright (c) 2006, 2007 The NetBSD Foundation, Inc.
* All rights reserved.
*
* This code is derived from software contributed to The NetBSD Foundation
* by Andrew Doran.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
* are met:
* 1. Redistributions of source code must retain the above copyright
* notice, this list of conditions and the following disclaimer.
* 2. Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
*
* THIS SOFTWARE IS PROVIDED BY THE NETBSD FOUNDATION, INC. AND CONTRIBUTORS
* ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED
* TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
* PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE FOUNDATION OR CONTRIBUTORS
* BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
* CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
* SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
* INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
* CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
* ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
* POSSIBILITY OF SUCH DAMAGE.
*/
/*
* TODO:
*
* - Tracking of times for sleep locks is broken.
* - Need better analysis and tracking of events.
* - Shouldn't have to parse the namelist here. We should use something like
* FreeBSD's libelf.
* - The way the namelist is searched sucks, is it worth doing something
* better?
*/
#include <sys/cdefs.h>
#ifndef lint
__RCSID("$NetBSD: main.c,v 1.14 2008/04/28 20:24:16 martin Exp $");
#endif /* not lint */
#include <sys/types.h>
#include <sys/param.h>
#include <sys/time.h>
#include <sys/fcntl.h>
#include <sys/ioctl.h>
#include <sys/wait.h>
#include <sys/signal.h>
#include <sys/sysctl.h>
#include <dev/lockstat.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <limits.h>
#include <unistd.h>
#include <err.h>
#include <paths.h>
#include <util.h>
#include <ctype.h>
#include <errno.h>
#include <stdbool.h>
#include "extern.h"
#define _PATH_DEV_LOCKSTAT "/dev/lockstat"
#define MILLI 1000.0
#define MICRO 1000000.0
#define NANO 1000000000.0
#define PICO 1000000000000.0
TAILQ_HEAD(lock_head, lockstruct);
typedef struct lock_head locklist_t;
TAILQ_HEAD(buf_head, lsbuf);
typedef struct buf_head buflist_t;
typedef struct lockstruct {
TAILQ_ENTRY(lockstruct) chain;
buflist_t bufs;
buflist_t tosort;
uintptr_t lock;
double time;
uint32_t count;
u_int flags;
u_int nbufs;
char name[NAME_SIZE];
} lock_t;
typedef struct name {
const char *name;
int mask;
} name_t;
const name_t locknames[] = {
{ "adaptive_mutex", LB_ADAPTIVE_MUTEX },
{ "spin_mutex", LB_SPIN_MUTEX },
{ "rwlock", LB_RWLOCK },
{ "kernel_lock", LB_KERNEL_LOCK },
{ "preemption", LB_NOPREEMPT },
{ NULL, 0 }
};
const name_t eventnames[] = {
{ "spin", LB_SPIN },
{ "sleep_exclusive", LB_SLEEP1 },
{ "sleep_shared", LB_SLEEP2 },
{ NULL, 0 },
};
const name_t alltypes[] = {
{ "Adaptive mutex spin", LB_ADAPTIVE_MUTEX | LB_SPIN },
{ "Adaptive mutex sleep", LB_ADAPTIVE_MUTEX | LB_SLEEP1 },
{ "Spin mutex spin", LB_SPIN_MUTEX | LB_SPIN },
{ "RW lock sleep (writer)", LB_RWLOCK | LB_SLEEP1 },
{ "RW lock sleep (reader)", LB_RWLOCK | LB_SLEEP2 },
{ "RW lock spin", LB_RWLOCK | LB_SPIN },
{ "Kernel lock spin", LB_KERNEL_LOCK | LB_SPIN },
{ "Kernel preemption defer", LB_NOPREEMPT | LB_SPIN },
{ NULL, 0 }
};
locklist_t locklist;
locklist_t freelist;
locklist_t sortlist;
lsbuf_t *bufs;
lsdisable_t ld;
bool lflag;
bool fflag;
int nbufs;
bool cflag;
int lsfd;
int displayed;
int bin64;
double tscale;
double cscale;
double cpuscale[sizeof(ld.ld_freq) / sizeof(ld.ld_freq[0])];
FILE *outfp;
void findsym(findsym_t, char *, uintptr_t *, uintptr_t *, bool);
void spawn(int, char **);
void display(int, const char *name);
void listnames(const name_t *);
void collapse(bool, bool);
int matchname(const name_t *, char *);
void makelists(int, int);
void nullsig(int);
void usage(void);
int ncpu(void);
lock_t *morelocks(void);
int
main(int argc, char **argv)
{
int eventtype, locktype, ch, nlfd, fd, i;
bool sflag, pflag, mflag, Mflag;
const char *nlistf, *outf;
char *lockname, *funcname;
const name_t *name;
lsenable_t le;
double ms;
char *p;
nlistf = NULL;
outf = NULL;
lockname = NULL;
funcname = NULL;
eventtype = -1;
locktype = -1;
nbufs = 0;
sflag = false;
pflag = false;
mflag = false;
Mflag = false;
while ((ch = getopt(argc, argv, "E:F:L:MN:T:b:ceflmo:pst")) != -1)
switch (ch) {
case 'E':
eventtype = matchname(eventnames, optarg);
break;
case 'F':
funcname = optarg;
break;
case 'L':
lockname = optarg;
break;
case 'N':
nlistf = optarg;
break;
case 'T':
locktype = matchname(locknames, optarg);
break;
case 'b':
nbufs = (int)strtol(optarg, &p, 0);
if (!isdigit((u_int)*optarg) || *p != '\0')
usage();
break;
case 'c':
cflag = true;
break;
case 'e':
listnames(eventnames);
break;
case 'f':
fflag = true;
break;
case 'l':
lflag = true;
break;
case 'm':
mflag = true;
break;
case 'M':
Mflag = true;
break;
case 'o':
outf = optarg;
break;
case 'p':
pflag = true;
break;
case 's':
sflag = true;
break;
case 't':
listnames(locknames);
break;
default:
usage();
}
argc -= optind;
argv += optind;
if (*argv == NULL)
usage();
if (outf) {
fd = open(outf, O_WRONLY | O_CREAT | O_TRUNC, 0600);
if (fd == -1)
err(EXIT_FAILURE, "opening %s", outf);
outfp = fdopen(fd, "w");
} else
outfp = stdout;
/*
* Find the name list for resolving symbol names, and load it into
* memory.
*/
if (nlistf == NULL) {
nlfd = open(_PATH_KSYMS, O_RDONLY);
nlistf = getbootfile();
} else
nlfd = -1;
if (nlfd == -1) {
if ((nlfd = open(nlistf, O_RDONLY)) < 0)
err(EXIT_FAILURE, "cannot open " _PATH_KSYMS " or %s",
nlistf);
}
if (loadsym32(nlfd) != 0) {
if (loadsym64(nlfd) != 0)
errx(EXIT_FAILURE, "unable to load symbol table");
bin64 = 1;
}
close(nlfd);
memset(&le, 0, sizeof(le));
le.le_nbufs = nbufs;
/*
* Set up initial filtering.
*/
if (lockname != NULL) {
findsym(LOCK_BYNAME, lockname, &le.le_lockstart,
&le.le_lockend, true);
le.le_flags |= LE_ONE_LOCK;
}
if (!lflag)
le.le_flags |= LE_CALLSITE;
if (!fflag)
le.le_flags |= LE_LOCK;
if (funcname != NULL) {
if (lflag)
usage();
findsym(FUNC_BYNAME, funcname, &le.le_csstart, &le.le_csend, true);
le.le_flags |= LE_ONE_CALLSITE;
}
le.le_mask = (eventtype & LB_EVENT_MASK) | (locktype & LB_LOCK_MASK);
/*
* Start tracing.
*/
if ((lsfd = open(_PATH_DEV_LOCKSTAT, O_RDONLY)) < 0)
err(EXIT_FAILURE, "cannot open " _PATH_DEV_LOCKSTAT);
if (ioctl(lsfd, IOC_LOCKSTAT_GVERSION, &ch) < 0)
err(EXIT_FAILURE, "ioctl");
if (ch != LS_VERSION)
errx(EXIT_FAILURE,
"incompatible lockstat interface version (%d, kernel %d)",
LS_VERSION, ch);
if (ioctl(lsfd, IOC_LOCKSTAT_ENABLE, &le))
err(EXIT_FAILURE, "cannot enable tracing");
/*
* Execute the traced program.
*/
spawn(argc, argv);
/*
* Stop tracing, and read the trace buffers from the kernel.
*/
if (ioctl(lsfd, IOC_LOCKSTAT_DISABLE, &ld) == -1) {
if (errno == EOVERFLOW) {
warnx("overflowed available kernel trace buffers");
exit(EXIT_FAILURE);
}
err(EXIT_FAILURE, "cannot disable tracing");
}
if ((bufs = malloc(ld.ld_size)) == NULL)
err(EXIT_FAILURE, "cannot allocate memory for user buffers");
if (read(lsfd, bufs, ld.ld_size) != ld.ld_size)
err(EXIT_FAILURE, "reading from " _PATH_DEV_LOCKSTAT);
if (close(lsfd))
err(EXIT_FAILURE, "close(" _PATH_DEV_LOCKSTAT ")");
/*
* Figure out how to scale the results. For internal use we convert
* all times from CPU frequency based to picoseconds, and values are
* eventually displayed in ms.
*/
for (i = 0; i < sizeof(ld.ld_freq) / sizeof(ld.ld_freq[0]); i++)
if (ld.ld_freq[i] != 0)
cpuscale[i] = PICO / ld.ld_freq[i];
ms = ld.ld_time.tv_sec * MILLI + ld.ld_time.tv_nsec / MICRO;
if (pflag)
cscale = 1.0 / ncpu();
else
cscale = 1.0;
cscale *= (sflag ? MILLI / ms : 1.0);
tscale = cscale / NANO;
nbufs = (int)(ld.ld_size / sizeof(lsbuf_t));
TAILQ_INIT(&locklist);
TAILQ_INIT(&sortlist);
TAILQ_INIT(&freelist);
if ((mflag | Mflag) != 0)
collapse(mflag, Mflag);
/*
* Display the results.
*/
fprintf(outfp, "Elapsed time: %.2f seconds.", ms / MILLI);
if (sflag || pflag) {
fprintf(outfp, " Displaying ");
if (pflag)
fprintf(outfp, "per-CPU ");
if (sflag)
fprintf(outfp, "per-second ");
fprintf(outfp, "averages.");
}
putc('\n', outfp);
for (name = alltypes; name->name != NULL; name++) {
if (eventtype != -1 &&
(name->mask & LB_EVENT_MASK) != eventtype)
continue;
if (locktype != -1 &&
(name->mask & LB_LOCK_MASK) != locktype)
continue;
display(name->mask, name->name);
}
if (displayed == 0)
fprintf(outfp, "None of the selected events were recorded.\n");
exit(EXIT_SUCCESS);
}
void
usage(void)
{
fprintf(stderr,
"%s: usage:\n"
"%s [options] <command>\n\n"
"-b nbuf\t\tset number of event buffers to allocate\n"
"-c\t\treport percentage of total events by count, not time\n"
"-E event\t\tdisplay only one type of event\n"
"-e\t\tlist event types\n"
"-F func\t\tlimit trace to one function\n"
"-f\t\ttrace only by function\n"
"-L lock\t\tlimit trace to one lock (name, or address)\n"
"-l\t\ttrace only by lock\n"
"-M\t\tmerge lock addresses within unique objects\n"
"-m\t\tmerge call sites within unique functions\n"
"-N nlist\tspecify name list file\n"
"-o file\t\tsend output to named file, not stdout\n"
"-p\t\tshow average count/time per CPU, not total\n"
"-s\t\tshow average count/time per second, not total\n"
"-T type\t\tdisplay only one type of lock\n"
"-t\t\tlist lock types\n",
getprogname(), getprogname());
exit(EXIT_FAILURE);
}
void
nullsig(int junk)
{
(void)junk;
}
void
listnames(const name_t *name)
{
for (; name->name != NULL; name++)
printf("%s\n", name->name);
exit(EXIT_SUCCESS);
}
int
matchname(const name_t *name, char *string)
{
int empty, mask;
char *sp;
empty = 1;
mask = 0;
while ((sp = strsep(&string, ",")) != NULL) {
if (*sp == '\0')
usage();
for (; name->name != NULL; name++) {
if (strcasecmp(name->name, sp) == 0) {
mask |= name->mask;
break;
}
}
if (name->name == NULL)
errx(EXIT_FAILURE, "unknown identifier `%s'", sp);
empty = 0;
}
if (empty)
usage();
return mask;
}
/*
* Return the number of CPUs in the running system.
*/
int
ncpu(void)
{
int rv, mib[2];
size_t varlen;
mib[0] = CTL_HW;
mib[1] = HW_NCPU;
varlen = sizeof(rv);
if (sysctl(mib, 2, &rv, &varlen, NULL, (size_t)0) < 0)
rv = 1;
return (rv);
}
/*
* Call into the ELF parser and look up a symbol by name or by address.
*/
void
findsym(findsym_t find, char *name, uintptr_t *start, uintptr_t *end, bool chg)
{
uintptr_t tend, sa, ea;
char *p;
int rv;
if (!chg) {
sa = *start;
start = &sa;
end = &ea;
}
if (end == NULL)
end = &tend;
if (find == LOCK_BYNAME) {
if (isdigit((u_int)name[0])) {
*start = (uintptr_t)strtoul(name, &p, 0);
if (*p == '\0')
return;
}
}
if (bin64)
rv = findsym64(find, name, start, end);
else
rv = findsym32(find, name, start, end);
if (find == FUNC_BYNAME || find == LOCK_BYNAME) {
if (rv == -1)
errx(EXIT_FAILURE, "unable to find symbol `%s'", name);
return;
}
if (rv == -1)
snprintf(name, NAME_SIZE, "%016lx", (long)*start);
}
/*
* Fork off the child process and wait for it to complete. We trap SIGINT
* so that the caller can use Ctrl-C to stop tracing early and still get
* useful results.
*/
void
spawn(int argc, char **argv)
{
pid_t pid;
switch (pid = fork()) {
case 0:
close(lsfd);
if (execvp(argv[0], argv) == -1)
err(EXIT_FAILURE, "cannot exec");
break;
case -1:
err(EXIT_FAILURE, "cannot fork to exec");
break;
default:
signal(SIGINT, nullsig);
wait(NULL);
signal(SIGINT, SIG_DFL);
break;
}
}
/*
* Allocate a new block of lock_t structures.
*/
lock_t *
morelocks(void)
{
const static int batch = 32;
lock_t *l, *lp, *max;
l = (lock_t *)malloc(sizeof(*l) * batch);
for (lp = l, max = l + batch; lp < max; lp++)
TAILQ_INSERT_TAIL(&freelist, lp, chain);
return l;
}
/*
* Collapse addresses from unique objects.
*/
void
collapse(bool func, bool lock)
{
lsbuf_t *lb, *max;
for (lb = bufs, max = bufs + nbufs; lb < max; lb++) {
if (func && lb->lb_callsite != 0) {
findsym(FUNC_BYADDR, NULL, &lb->lb_callsite, NULL,
true);
}
if (lock && lb->lb_lock != 0) {
findsym(LOCK_BYADDR, NULL, &lb->lb_lock, NULL,
true);
}
}
}
/*
* From the kernel supplied data, construct two dimensional lists of locks
* and event buffers, indexed by lock type and sorted by event type.
*/
void
makelists(int mask, int event)
{
lsbuf_t *lb, *lb2, *max;
lock_t *l, *l2;
int type;
/*
* Recycle lock_t structures from the last run.
*/
while ((l = TAILQ_FIRST(&locklist)) != NULL) {
TAILQ_REMOVE(&locklist, l, chain);
TAILQ_INSERT_HEAD(&freelist, l, chain);
}
type = mask & LB_LOCK_MASK;
for (lb = bufs, max = bufs + nbufs; lb < max; lb++) {
if ((lb->lb_flags & LB_LOCK_MASK) != type ||
lb->lb_counts[event] == 0)
continue;
/*
* Look for a record descibing this lock, and allocate a
* new one if needed.
*/
TAILQ_FOREACH(l, &sortlist, chain) {
if (l->lock == lb->lb_lock)
break;
}
if (l == NULL) {
if ((l = TAILQ_FIRST(&freelist)) == NULL)
l = morelocks();
TAILQ_REMOVE(&freelist, l, chain);
l->flags = lb->lb_flags;
l->lock = lb->lb_lock;
l->nbufs = 0;
l->name[0] = '\0';
l->count = 0;
l->time = 0;
TAILQ_INIT(&l->tosort);
TAILQ_INIT(&l->bufs);
TAILQ_INSERT_TAIL(&sortlist, l, chain);
}
/*
* Scale the time values per buffer and summarise
* times+counts per lock.
*/
lb->lb_times[event] *= cpuscale[lb->lb_cpu];
l->count += lb->lb_counts[event];
l->time += lb->lb_times[event];
/*
* Merge same lock+callsite pairs from multiple CPUs
* together.
*/
TAILQ_FOREACH(lb2, &l->tosort, lb_chain.tailq) {
if (lb->lb_callsite == lb2->lb_callsite)
break;
}
if (lb2 != NULL) {
lb2->lb_counts[event] += lb->lb_counts[event];
lb2->lb_times[event] += lb->lb_times[event];
} else {
TAILQ_INSERT_HEAD(&l->tosort, lb, lb_chain.tailq);
l->nbufs++;
}
}
/*
* Now sort the lists.
*/
while ((l = TAILQ_FIRST(&sortlist)) != NULL) {
TAILQ_REMOVE(&sortlist, l, chain);
/*
* Sort the buffers into the per-lock list.
*/
while ((lb = TAILQ_FIRST(&l->tosort)) != NULL) {
TAILQ_REMOVE(&l->tosort, lb, lb_chain.tailq);
lb2 = TAILQ_FIRST(&l->bufs);
while (lb2 != NULL) {
if (cflag) {
if (lb->lb_counts[event] >
lb2->lb_counts[event])
break;
} else if (lb->lb_times[event] >
lb2->lb_times[event])
break;
lb2 = TAILQ_NEXT(lb2, lb_chain.tailq);
}
if (lb2 == NULL)
TAILQ_INSERT_TAIL(&l->bufs, lb,
lb_chain.tailq);
else
TAILQ_INSERT_BEFORE(lb2, lb, lb_chain.tailq);
}
/*
* Sort this lock into the per-type list, based on the
* totals per lock.
*/
l2 = TAILQ_FIRST(&locklist);
while (l2 != NULL) {
if (cflag) {
if (l->count > l2->count)
break;
} else if (l->time > l2->time)
break;
l2 = TAILQ_NEXT(l2, chain);
}
if (l2 == NULL)
TAILQ_INSERT_TAIL(&locklist, l, chain);
else
TAILQ_INSERT_BEFORE(l2, l, chain);
}
}
/*
* Display a summary table for one lock type / event type pair.
*/
void
display(int mask, const char *name)
{
lock_t *l;
lsbuf_t *lb;
double pcscale, metric;
char fname[NAME_SIZE];
int event;
event = (mask & LB_EVENT_MASK) - 1;
makelists(mask, event);
if (TAILQ_EMPTY(&locklist))
return;
fprintf(outfp, "\n-- %s\n\n"
"Total%% Count Time/ms Lock Caller\n"
"------ ------- --------- ---------------------- ------------------------------\n",
name);
/*
* Sum up all events for this type of lock + event.
*/
pcscale = 0;
TAILQ_FOREACH(l, &locklist, chain) {
if (cflag)
pcscale += l->count;
else
pcscale += l->time;
displayed++;
}
if (pcscale == 0)
pcscale = 100;
else
pcscale = (100.0 / pcscale);
/*
* For each lock, print a summary total, followed by a breakdown by
* caller.
*/
TAILQ_FOREACH(l, &locklist, chain) {
if (cflag)
metric = l->count;
else
metric = l->time;
metric *= pcscale;
if (l->name[0] == '\0')
findsym(LOCK_BYADDR, l->name, &l->lock, NULL, false);
if (lflag || l->nbufs > 1)
fprintf(outfp, "%6.2f %7d %9.2f %-22s <all>\n",
metric, (int)(l->count * cscale),
l->time * tscale, l->name);
if (lflag)
continue;
TAILQ_FOREACH(lb, &l->bufs, lb_chain.tailq) {
if (cflag)
metric = lb->lb_counts[event];
else
metric = lb->lb_times[event];
metric *= pcscale;
findsym(FUNC_BYADDR, fname, &lb->lb_callsite, NULL,
false);
fprintf(outfp, "%6.2f %7d %9.2f %-22s %s\n",
metric, (int)(lb->lb_counts[event] * cscale),
lb->lb_times[event] * tscale, l->name, fname);
}
}
}