Changeset View
Standalone View
share/man/man4/boottrace.4
- This file was added.
.\" SPDX-License-Identifier: BSD-2-Clause-FreeBSD | |||||||||||
.\" | |||||||||||
.\" Copyright (c) 2022 NetApp, Inc. | |||||||||||
.\" | |||||||||||
0mp: Note to myself: This needs to be fixed. | |||||||||||
.\" 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 AUTHOR 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 AUTHOR 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. | |||||||||||
.\" | |||||||||||
.Dd February 28, 2022 | |||||||||||
.Dt BOOTTRACE 4 | |||||||||||
.Os | |||||||||||
.Sh NAME | |||||||||||
.Nm boottrace | |||||||||||
.Nd Boot-time, run-time, and shutdown-time tracing facility | |||||||||||
.Sh SYNOPSIS | |||||||||||
.In sys/boottrace.h | |||||||||||
.Sh DESCRIPTION | |||||||||||
.Nm | |||||||||||
Done Inline ActionsMaybe "init-time" or "rc-time" instead of "run-time"? To me, the latter refers to the whole time between rc ending and shutdown. pauamma_gundo.com: Maybe "init-time" or "rc-time" instead of "run-time"? To me, the latter refers to the whole… | |||||||||||
Done Inline ActionsThis is the current intended semantic of 'run-time' events; everything logged after the completion of rc scripts (or to be precise, when init(8) transitions to multi-user) but before shutdown has begun. For example, loading a kmod on the command line will create an event in the run-time event buffer. We consider execution of rc scripts to be part of 'boot-time', but the choice is somewhat arbitrary. mhorne: This is the current intended semantic of 'run-time' events; everything logged after the… | |||||||||||
Done Inline ActionsI'm marking this discussion as resolved for now. The semantic seems to be good enough. 0mp: I'm marking this discussion as resolved for now. The semantic seems to be good enough. | |||||||||||
Done Inline ActionsThis seems like an unusual thing to state in the synopsis. Other pages simply list the relevant include file, sys/boottrace.h in this case. See watchdog(4), ng_split(4), tty(4) for other non-optional components that have this section. mhorne: This seems like an unusual thing to state in the synopsis. Other pages simply list the relevant… | |||||||||||
Done Inline ActionsGood idea. I'm moving this part to the description section and adding that include statement. 0mp: Good idea. I'm moving this part to the description section and adding that include statement. | |||||||||||
is a kernel-userspace interface for capturing trace events | |||||||||||
during system boot and shutdown. | |||||||||||
.Pp | |||||||||||
Done Inline Actionsmaybe write: ... during system boot and shutdown? bcr: maybe write: ... during system boot and shutdown? | |||||||||||
Done Inline Actions
In addition to bcr's comment. pauamma_gundo.com: In addition to bcr's comment. | |||||||||||
Event annotations are present in: | |||||||||||
.Bl -bullet -compact | |||||||||||
Done Inline Actions
Taste, concision pauamma_gundo.com: Taste, concision | |||||||||||
.It | |||||||||||
the boot and shutdown paths in the | |||||||||||
kernel | |||||||||||
.It | |||||||||||
some key system utilities | |||||||||||
.Po | |||||||||||
.Xr init 8 , | |||||||||||
.Xr shutdown 8 , | |||||||||||
.Xr reboot 8 | |||||||||||
.Pc | |||||||||||
Done Inline Actions
Taste, concision pauamma_gundo.com: Taste, concision | |||||||||||
.It | |||||||||||
Done Inline ActionsIt was mentioned a few lines above that rc(8) is covered by boottrace. mhorne: It was mentioned a few lines above that `rc(8)` is covered by boottrace. | |||||||||||
Done Inline ActionsI think that it is alright to add some more details here. We didn't mention the event annotations earlier. I thought about making it a bit concise for a moment but I didn't find a better way to express it. 0mp: I think that it is alright to add some more details here. We didn't mention the event… | |||||||||||
.Xr rc 8 | |||||||||||
scripts | |||||||||||
Done Inline Actions
"holistic" may confuse EFL readers (it sent me to MW to check its exact meaning). pauamma_gundo.com: "holistic" may confuse EFL readers (it sent me to MW to check its exact meaning). | |||||||||||
.El | |||||||||||
.Pp | |||||||||||
.Nm | |||||||||||
is unconditionally compiled into the kernel and | |||||||||||
disabled by default. | |||||||||||
.Sh EVENT TABLES | |||||||||||
Events are stored in three event tables: boot-time events, run-time events, | |||||||||||
and shutdown-time events. | |||||||||||
.Bl -column "shutdown-time events" "" | |||||||||||
.It Sy Table Name Ta Sy Event Description | |||||||||||
.It boot-time events Ta Boot, kernel initialization, and | |||||||||||
Done Inline ActionsTaste (minor): I'd use "fills up" or "gets full". pauamma_gundo.com: Taste (minor): I'd use "fills up" or "gets full". | |||||||||||
.Xr rc 8 | |||||||||||
Done Inline ActionsNitpick: I think panics happen more often than they're (user-)initiated. If you mean both, perhaps "Upon initiating a shutdown or reboot, or if a kernel panic occurs or is requested by the user, ..." pauamma_gundo.com: Nitpick: I think panics happen more often than they're (user-)initiated. If you mean both… | |||||||||||
Done Inline ActionsI'd not go into details of panics here. This should be covered in a separate document explaining what a kernel panic is and how it can be occur. I agree that "upon initialization" may sound like a user-initiated action. I cannot think of a better way to write this sentence, though. Please let me know if you have anything on your mind. 0mp: I'd not go into details of panics here. This should be covered in a separate document… | |||||||||||
execution; | |||||||||||
.Xo | |||||||||||
Done Inline ActionsAs the amateur sysadmin for my own computer, my vote is for "yes". pauamma_gundo.com: As the amateur sysadmin for my own computer, my vote is for "yes". | |||||||||||
Done Inline ActionsMakes sense. Also, many other many other manpages do that, eg. vte(4). 0mp: Makes sense. Also, many other many other manpages do that, eg. vte(4). | |||||||||||
until | |||||||||||
.Xr init 8 | |||||||||||
transitions into multi-user mode | |||||||||||
Done Inline ActionsIt actually takes over when the system has completed booting (including rc execution) and init(8) transitions to multi-user mode. mhorne: It actually takes over when the system has completed booting (including rc execution) and `init… | |||||||||||
Done Inline ActionsThanks. I'll include that in a patch shortly. 0mp: Thanks. I'll include that in a patch shortly. | |||||||||||
.Xc | |||||||||||
.It run-time events Ta Xo | |||||||||||
From when the system has completed booting (including | |||||||||||
.Xr rc 8 | |||||||||||
execution) and | |||||||||||
.Xr init 8 | |||||||||||
Done Inline ActionsThe format of which part was different? I can clarify any specific bits which there is confusion about. mhorne: The format of which part was different? I can clarify any specific bits which there is… | |||||||||||
Done Inline ActionsI cannot find that anymore. I think I was confusing the ${procname}: name format used by boottrace somewhere internally I suppose and the format of kern.boottrace.log. 0mp: I cannot find that anymore. I think I was confusing the `${procname}: name ` format used by… | |||||||||||
transitions to multi-user mode | |||||||||||
until the beginning of shutdown procedures | |||||||||||
.Xc | |||||||||||
.It shutdown-time events Ta Xo | |||||||||||
After initialization of a shutdown, a reboot, or a kernel panic | |||||||||||
Done Inline Actions
(Or whichever value(s) will enable tracing.) pauamma_gundo.com: (Or whichever value(s) will enable tracing.) | |||||||||||
.Xc | |||||||||||
.El | |||||||||||
.Sh LOADER TUNABLES | |||||||||||
Tunables can be set at the | |||||||||||
.Xr loader 8 | |||||||||||
Done Inline ActionsDo you mean "Return" (to userland) here? Or send to syslog? pauamma_gundo.com: Do you mean "Return" (to userland) here? Or send to syslog? | |||||||||||
prompt before booting the kernel or stored in | |||||||||||
.Xr loader.conf 5 . | |||||||||||
.Nm | |||||||||||
features the following loader tunables: | |||||||||||
.Bl -tag -width indent | |||||||||||
.It Va kern.boottrace.dotrace_kernel | |||||||||||
Set to | |||||||||||
.Ql 1 | |||||||||||
to enable tracing of kernel events. | |||||||||||
Default: | |||||||||||
.Ql 1 | |||||||||||
.Pq enabled . | |||||||||||
.It Va kern.boottrace.dotrace_user | |||||||||||
Set to | |||||||||||
.Ql 1 | |||||||||||
to enable tracing of userspace events. | |||||||||||
Default: | |||||||||||
Done Inline Actions
pauamma_gundo.com: | |||||||||||
.Ql 1 | |||||||||||
.Pq enabled . | |||||||||||
Done Inline ActionsNot an actual edit suggestion, but I'm curious: why does that only exist for shutdown? pauamma_gundo.com: Not an actual edit suggestion, but I'm curious: why does that only exist for shutdown? | |||||||||||
Done Inline ActionsThat's a good question. I'll ask @mhorne about it. 0mp: That's a good question. I'll ask @mhorne about it. | |||||||||||
.El | |||||||||||
.Sh SYSCTL VARIABLES | |||||||||||
Done Inline Actions
Something like this to describe the expected format. mhorne: Something like this to describe the expected format. | |||||||||||
Done Inline ActionsOh I get it now. I'll add this bit of information to the manual. 0mp: Oh I get it now. I'll add this bit of information to the manual. | |||||||||||
The following variables are available as both | |||||||||||
.Xr sysctl 8 | |||||||||||
variables and | |||||||||||
.Xr loader 8 | |||||||||||
tunables: | |||||||||||
.Bl -tag -width indent | |||||||||||
.It Va kern.boottrace.boottrace | |||||||||||
Done Inline ActionsThis variable is of no interest to end users, I suggest it be dropped from the man page. The only reason to use it is if one was working on the boottrace code, at which point they would find the tunable anyway. mhorne: This variable is of no interest to end users, I suggest it be dropped from the man page. The… | |||||||||||
Done Inline ActionsDone! 0mp: Done! | |||||||||||
Create a new trace event and write it to the boot-time table. | |||||||||||
.Pp | |||||||||||
A new trace event consists of a process name and an event description, | |||||||||||
separated by a colon | |||||||||||
.Pq Ql \&: . | |||||||||||
If the colon is missing or if the provided string for the process name is empty, | |||||||||||
the process name is inferred from the invoking process | |||||||||||
.Pq which most of the time is its executable name . | |||||||||||
Done Inline ActionsClarification request: is that the executable name, or the title set by setproctitle() or similar means? pauamma_gundo.com: Clarification request: is that the executable name, or the title set by setproctitle() or… | |||||||||||
Done Inline ActionsGood question, I'll look into that. 0mp: Good question, I'll look into that. | |||||||||||
Done Inline ActionsIt is the executable name. See getprogname(3) for details. 0mp: It is the executable name. See getprogname(3) for details. | |||||||||||
Done Inline ActionsIt is always the executable name, as neither setprogname() nor setproctitle() change the process's name from the kernel's POV. mhorne: It is always the executable name, as neither `setprogname()` nor `setproctitle()` change the… | |||||||||||
Done Inline ActionsAch, I didn't know about that. Thanks! 0mp: Ach, I didn't know about that. Thanks! | |||||||||||
pauamma_gundo.comUnsubmitted Done Inline Actions
Remove misleading qualifier following mhorne's comment. pauamma_gundo.com: Remove misleading qualifier following mhorne's comment. | |||||||||||
.It Va kern.boottrace.enabled | |||||||||||
Set to | |||||||||||
.Ql 1 | |||||||||||
to enable tracing. | |||||||||||
This is a read-only | |||||||||||
.Xr sysctl 8 | |||||||||||
variable. | |||||||||||
Done Inline ActionsDo you mean "userland" here, at any stage including shutdown? Or the "init+rc" stage only? pauamma_gundo.com: Do you mean "userland" here, at any stage including shutdown? Or the "init+rc" stage only? | |||||||||||
Done Inline ActionsI'll ask @mhorne about it. 0mp: I'll ask @mhorne about it. | |||||||||||
Done Inline ActionsIt logs everything that has been recorded in the boot-time and run-time event tables (whether the kernel or userspace generated the event). It doesn't include shutdown events, because this sysctl is not expected to be invoked at any point during shutdown. There is the kern.boottrace.shutdown_trace option to have those events printed before the system performs its final shutdown action(s). mhorne: It logs everything that has been recorded in the boot-time and run-time event tables (whether… | |||||||||||
Default: | |||||||||||
.Ql 0 | |||||||||||
.Pq disabled . | |||||||||||
.It Va kern.boottrace.log | |||||||||||
Show the events stored in boot-time and run-time | |||||||||||
tables. | |||||||||||
This | |||||||||||
is an opaque | |||||||||||
.Xr sysctl 8 | |||||||||||
variable. | |||||||||||
.It Va kern.boottrace.runtrace | |||||||||||
Same as | |||||||||||
.Va kern.boottrace.boottrace , | |||||||||||
but write to the run-time table. | |||||||||||
.It Va kern.boottrace.shuttrace | |||||||||||
Same as | |||||||||||
.Va kern.boottrace.boottrace , | |||||||||||
but write to the shutdown-time table. | |||||||||||
.It Va kern.boottrace.shutdown_trace | |||||||||||
Log shutdown-time events to the console before the system halts. | |||||||||||
.It Va kern.boottrace.shutdown_trace_threshold | |||||||||||
Set a time threshold for logging shutdown-time events in milliseconds. | |||||||||||
An event is ignored | |||||||||||
if the time difference to the previous event is less than | |||||||||||
the threshold value. | |||||||||||
Default: | |||||||||||
.Ql 0 | |||||||||||
.Pq logs all events . | |||||||||||
Done Inline Actionsmhorne: @debdrup raised the point in D31929 that we should not exceed 80 characters. I was able to… | |||||||||||
Done Inline Actionsdebdrup: > @debdrup raised the point in D31929 that we should not exceed 80 characters. I was able to… | |||||||||||
Done Inline ActionsI assume that this is the exact output format of that sysctl. I'd prefer to stay as close to the real output as possible. However, if @mhorne managed to make the output of this sysctl narrower, then we should definitely update this example to reflect those changes. 0mp: I assume that this is the exact output format of that sysctl. I'd prefer to stay as close to… | |||||||||||
.El | |||||||||||
.Sh EXAMPLES | |||||||||||
Create a new trace event with a process name | |||||||||||
.Dq foo | |||||||||||
and an event description | |||||||||||
.Dq bar | |||||||||||
using | |||||||||||
.Xr sysctl 8 : | |||||||||||
.Bd -literal -offset indent | |||||||||||
sysctl kern.boottrace.boottrace="foo:bar" | |||||||||||
.Ed | |||||||||||
.Pp | |||||||||||
Here is a sample output of | |||||||||||
.Va kern.boottrace.log | |||||||||||
.Po shortened with | |||||||||||
.Dq [...] | |||||||||||
for readability | |||||||||||
Done Inline ActionsThis looks out of place here to me. Am I missing something? pauamma_gundo.com: This looks out of place here to me. Am I missing something? | |||||||||||
Done Inline ActionsIt was a part of an old template. I removed it. 0mp: It was a part of an old template. I removed it. | |||||||||||
.Pc : | |||||||||||
.Bd -literal | |||||||||||
CPU msecs delta process event PID CPUtime IBlks OBlks | |||||||||||
0 44872811 0 kernel sysinit 0x2100001 0 0.00 0 0 | |||||||||||
0 44872812 1 kernel sysinit 0x2110000 0 0.00 0 0 | |||||||||||
0 44872812 0 kernel sysinit 0x2140000 0 0.00 0 0 | |||||||||||
[...] | |||||||||||
0 44872817 0 kernel sysinit 0x2800000 0 0.00 0 0 | |||||||||||
0 44873820 1003 kernel sysinit 0x2880000 0 0.00 0 0 | |||||||||||
0 44873820 0 kernel sysinit 0x2888000 0 0.00 0 0 | |||||||||||
[...] | |||||||||||
1 44875735 0 kernel sysinit 0xfffffff 0 0.00 0 0 | |||||||||||
1 44875735 0 swapper mi_startup done 0 0.00 0 0 | |||||||||||
0 44875750 15 init init(8) starting... 1 0.00 0 0 | |||||||||||
Done Inline ActionsI think this should reference sysctl(8) instead. Also add an xref for boottrace(1). mhorne: I think this should reference `sysctl(8)` instead. Also add an xref for `boottrace(1)`. | |||||||||||
Done Inline Actionsgood idea 0mp: good idea | |||||||||||
0 44875751 1 init /etc/rc starting... 1 0.00 0 0 | |||||||||||
0 44875831 80 boottrace /etc/rc.d/rctl start 26 0.00 0 0 | |||||||||||
Done Inline ActionsI don't think this section adds much, at least I would want to re-write the text comparing boottrace to tslog and I wouldn't classify it as a 'bug'. mhorne: I don't think this section adds much, at least I would want to re-write the text comparing… | |||||||||||
Done Inline ActionsI removed it. We should have a dedicated manual page for comparison of tracing facilities. Also, we need a tslog manual page. 0mp: I removed it. We should have a dedicated manual page for comparison of tracing facilities. Also… | |||||||||||
1 44875839 8 boottrace /etc/rc.d/rctl done 26 0.00 2 0 | |||||||||||
[...] | |||||||||||
0 44876446 0 boottrace /etc/rc.d/netif start 390 0.00 0 0 | |||||||||||
1 44881116 4670 boottrace /etc/rc.d/netif done 390 0.12 34 0 | |||||||||||
[...] | |||||||||||
0 44882866 1 boottrace /etc/rc.d/securelevel start 1679 0.00 0 0 | |||||||||||
0 44882872 6 boottrace /etc/rc.d/securelevel done 1679 0.00 0 0 | |||||||||||
1 44882879 7 init /etc/rc finished 1 2.22 743 15 | |||||||||||
Total measured time: 10068 msecs | |||||||||||
CPU msecs delta process event PID CPUtime IBlks OBlks | |||||||||||
Done Inline Actions
Or "for them". pauamma_gundo.com: Or "for them". | |||||||||||
1 44882880 0 init multi-user start 1 2.22 743 15 | |||||||||||
Done Inline ActionsMaybe "completely" or "mostly" instead depending on its amount of self-containedness? pauamma_gundo.com: Maybe "completely" or "mostly" instead depending on its amount of self-containedness? | |||||||||||
0 44918215 35335 kldload hwpmc.ko: sysinit 0xd800000 1698 0.00 0 0 | |||||||||||
Total measured time: 35335 msecs | |||||||||||
.Ed | |||||||||||
.Sh SEE ALSO | |||||||||||
.Xr boottrace 1 , | |||||||||||
mhorneUnsubmitted Done Inline ActionsIt is now boottrace(8) :) mhorne: It is now `boottrace(8)` :) | |||||||||||
pauamma_gundo.comUnsubmitted Done Inline Actions
pauamma_gundo.com: | |||||||||||
.Xr sysctl 8 | |||||||||||
.Sh HISTORY | |||||||||||
NetApp created | |||||||||||
.Nm | |||||||||||
to diagnose slow devices and subsystems. | |||||||||||
Once upstreamed, | |||||||||||
.Nm | |||||||||||
was first publicly released with | |||||||||||
.Fx 14.0 . | |||||||||||
.Sh AUTHORS | |||||||||||
This manual page was written by | |||||||||||
.An Mateusz Piotrowski Aq Mt 0mp@FreeBSD.org . |
Note to myself: This needs to be fixed.