svn commit: r294471 - head/sys/dev/usb/wlan

[Mark Johnston]

On Wed, Jan 20, 2016 at 04:15:54PM -0800, Ravi Pokala wrote:
> -----Original Message-----
> 
> 
> From: <owner-src-committers at freebsd.org> on behalf of Adrian Chadd <adrian.chadd at gmail.com>
> Date: 2016-01-20, Wednesday at 16:02
> To: Andriy Voskoboinyk <avos at freebsd.org>
> Cc: "src-committers at freebsd.org" <src-committers at freebsd.org>, "svn-src-all at freebsd.org" <svn-src-all at freebsd.org>, "svn-src-head at freebsd.org" <svn-src-head at freebsd.org>
> Subject: Re: svn commit: r294471 - head/sys/dev/usb/wlan
> 
> >Hi,
> >
> >So yeah, I think it's time we just bit the bullet and wrote a
> >generic-ish debug/ktr framework for drivers to use so drivers and
> >infrastructure doesn't keep spinning its own damned debugging stuff.
> >
> >(I know people keep saying "dtrace", but ...)
> >
> >Let's have a think about it.
> 
> One issue I have with DTrace (and KTR, though I'm even less familiar with it than I am with DTrace) is that you only get a stream of what's happening right now - there's no way to see *what just happened*. For example, I wrote an ATA command tracing infrastructure for Panasas which keeps the last several thousand commands in a trace buffer, and a tool that extracts the buffer and saves it to a file.

What you describe sounds like it could be accomplished with KTR. All KTR
does is maintain a ring of buffers, each containing a static format
string with optional arguments, as well as some metadata (CPU, thread,
timecounter value).

One feature that would be nice would be a way to associate KTR rings
with arbitrary objects rather than having a single global ring (or
per-CPU rings). For example, KTR_BUF lets one trace operations on
filesystem buffers, but there's no good way to find all trace records
corresponding to a given buf. At the moment one has to always include a
pointer to the buf, and then scan *all* KTR entries for the pointer of
interest while hoping that the relevant entries haven't already been
overwritten. With per-object rings, one can in effect see a "history" of
the object, whether it's a buf or a driver softc or whatever.

Isilon has done ad-hoc implementations of this for bufs and mbufs, and
they're quite handy for debugging. With BUF_TRACKING enabled in our
kernel config, each buf contains a const char *b_records[32], and one
adds

	buf_track(bp, __func__);

or so to various functions to record an entry in the buf when the
function is invoked. This is really similar to what KTR does already,
and I've needed to further hack up our buf tracking to include metadata
(thread IDs) that KTR already provides. And, KTR records can be
retrieved from vmcores by ktrdump -M.

> We can then feed that file into various analysis tools, which can show us exactly what we sent to the drive, and exactly what the drive sent back to us. (The nice thing is, the buffer is also in the vmcore, so we can easily extract it after a panic, and it's identical to what you get from the live system, so the same analysis tools can be used in both instances.) This has come in very handy when we want to see, for example, what new and stupid thing a drive did that caused an error, slowdown or panic.