[Request for review] Profiling the FreeBSD kernel boot

Colin Percival cperciva at tarsnap.com
Sat Dec 23 03:39:05 UTC 2017

On 12/22/17 09:08, Mark Johnston wrote:
> On Fri, Dec 22, 2017 at 09:44:46AM +0000, Colin Percival wrote:
>> For the past few months I've been working on code for profiling the FreeBSD
>> "kernel boot", i.e., everything between when kernel code starts running and
>> when we first enter userland as init(8).  This is not trivial since it's
>> impossible to use tools like dtrace to monitor things prior to when said
>> tools are running.
> In the case of DTrace, this isn't quite true. We support so-called
> boot-time DTrace on x86. The caveat is that we can only start tracing
> after the SI_SUB_DTRACE_ANON sysinit has been executed. That sysinit
> can't come earlier than SI_SUB_SMP, since it needs to be able to measure
> TSC skew between CPUs in order to initialize DTrace's high-resolution
> timer.

Right.  Also, even aside from details like measuring the TSC skew between
CPUs, DTrace needs things like traps, memory allocation, and mutexes, none
of which exist when we enter hammer_time (or any of the other MD startup

What I meant is that it's impossible to use DTrace to monitor things which
happened prior to when the DTrace *kernel bits* are initialized.

> I don't think boot-time DTrace is quite what you want for this exercise,
> but it does come in handy sometimes.

Absolutely.  And for a long time I considered trying to splice together
a basic profiling mechanism for pre-DTrace-initialization with using DTrace
from when it's ready onwards... but I decided that it would be easier at
least to start with to simply use a single mechanism throughout.

> In case it's of interest: to use boot-time DTrace, invoke dtrace(1) as
> you normally would and add -A. Rather than starting to trace, dtrace(1)
> will save a representation of the D script to a file which gets read by
> the loader during the next boot. The results of the trace can be fetched
> with "dtrace -a". For instance, to print the amount of time elapsed in
> microseconds during each vprintf() call, along with a stack: [...]

Thanks for the example!  I think it's very likely that I'll make use of
boot-time DTrace for tracking down some of the performance warts I've found
-- the ones which happen after DTrace is initialized, that is.

Colin Percival
Security Officer Emeritus, FreeBSD | The power to serve
Founder, Tarsnap | www.tarsnap.com | Online backups for the truly paranoid

More information about the freebsd-current mailing list