NAME
ffwwkkppffvv - FireWire kprintf viewer
SYNOPSIS
ffwwkkppffvv [--aappppeennddlloogg] [--ooppeennlloogg] [--nneewwlloogg] [--pprreeffiixx] [--ppuubblliisshh]
[--ssiinnggllee] [--bbuuffffeerr=boot-args] [--sseettaarrggss[=boot-args]] [--hheellpp]
DESCRIPTION
Use fwkpfv to receive FireWire kprintf logging. FireWireKPrintf redirects
"kprintf()" logging to FireWire. Kernel printfs or "kprintfs" are used by many kernel services as a low level logging mechanism. They can also be used in third party kernel extensions. FireWire kprintfs are available very early in the kernel's startup and right until the cpu is powered down at sleep, restarted, or shutdown. Similarly, they are available almost as soon as the cpu is powered when waking. They can be useful for debugging kernel code (including KEXTs), particularly sleep/wake issues where the display and/or ethernet is unavailable. OOPPTTIIOONNSS The available options are as follows:--aappppeennddlloogg, -aa
Append output logging to /Library/Logs/FireWireKPrintf.log.--ooppeennlloogg, -oo
Open log file with Console.app. Only valid with -aa.
--nneewwlloogg, -nn
Create a new log file, rather than append. Only valid with -aa.
--pprreeffiixx, -pp
Prefix logger machine's ID to each log.--ppuubblliisshh, -kk
Do not publish FireWire unit directory keys.--ssiinnggllee, -ss
Use a single window even if multiple loggers are present.--bbuuffffeerr=size, -bbsize
Sets the host's psuedo address space queue buffer to size in bytes. Increasing this value may help avoid potential packet loss. The default buffer size is 204,800 bytes.--sseettaarrggss[=boot-args], -rr[boot-args]
Sets the nvram boot-args on the current machine to boot-args. This
flag should only be used on the target machine (which is contrary to all other usage cases, when it is used on the host). Ifboot-args is not passed, the tool will prompt the user as to which
boot-args are to be set.
--hheellpp, -hh
Displays usage info for fwkpfv.
CCOOMMPPAATTAABBIILLIITTYYUnlike in the past, Mac OS X 10.5 has integrated FireWireKPrintf func-
tionality, so it is not necessary to install a separate kext to enable kprintf logging over FireWire. While the symbol for kprintf() is available at all times, the calls are essentially ignored unless activated with a boot argument (see below). While the new FireWireKPrintf is integrated with the normal FireWire stack, once the machine begins logging kprintfs via FireWire, normalFireWire services will stop until the machine is restarted. Once in log-
ging mode, all typical FireWire services (like FireWire hard disk access) will be unavailable. It is expected that any devices connected before logging will be forcefully removed. If you need to log while also using the FireWire stack, please use FireLog (see the FireWireSDK).The new integrated FireWireKPrintf cannot be used while the old Apple-
FireWireKPrintf.kext is installed. Remove it to use the integrated ver-
sion.The new viewer will be able to capture kprintf logs from the old-style
AppleFireWireKPrintf.kext, however, the old-style viewer will not work
with the integrated FireWireKPrintf services. Currently, the FireWireGDB functionality should be integrated as well. Hence, it is unnecessary to install AppleFireWireGDB.kext. The same FireWireGDB plugins will work. Additionally, FireWireKDP can be installed while using the integrated FireWireKPrintf (interlaced breaks may not yet be supported; for this use the old version, AppleFireWireKPrintf.kext). UUSSAAGGEE To use the FireWireKPrintf, two machines must be setup as such:- On the Target machine (to be debugged):
1. Boot the Mac from the partition you wish to use. 2. Set kernel boot arguments to enable kernel printfs:% sudo nvram boot-args="debug=0x8"
While only the debug bit equivalent to '0x8' is required for kprintf logging, you may want to set the debug variable to '0x14e' to enable other debugging services. For more information on the debug flags, please see Technical Note TN2118. For more logging options, please see. 3. Restart the target Mac. 4. Disconnect any FireWire device. - On the debugger machine with Mac OS X and Developer Tools
installed, run from Terminal.app:% fwkpfv
(If the machine is running Tiger: Run the FireWireKPrintf viewer tool included in the FireWireSDK available at http://developer.apple.com/sdk/.)- Connect the two machines together using a FireWire cable.
- After 5 seconds, you should see output in the viewer and kprintf
logging is flowing. Note: At this point, normal FireWire ser-
vices will cease to exist on the target until the machine is restarted.TTAARRGGEETT-SSIIDDEE OOPPTTIIOONNSS
FireWireKPrintf implements a few options that can be set as a "boot-arg,"
much like the "debug" variable. The "fwkpf" variable specifies the time-
stamp format (calculated on the target, before transmission), timestamp padding, verbose kprintf printing, and synchronous mode. To set the "fwkpf" variable, choose a timestamp unit and add any of the "additive" options. The default timestamp is 0x4 (microseconds). Timestamp Formats (not additive):0x0 Converted FW Cycle Time Units (c) - Classic time format shown as
"Seconds.Microseconds". The Second unit rolls over every 128 seconds. Driven by the FireWire clock.0x1 Absolute Time Units (a) - "Absolute" time units derived directly
from the kernel's uptime clock.0x2 FireWire Time Units (w) - Shown as "Seconds:Cycles:Offset".
Driven by the FireWire clock. Seconds rollover every 128 sec-
onds. 8000 cycles per second. 3072 offset counts per cycle. Equivalent to FireBug's time format.0x3 Nanoseconds Time Units (n) - The kernel's uptime clock converted
to nanoseconds.0x4 Microseconds Time Units (u) - The kernel's uptime clock con-
verted to microseconds.0x5 Milliseconds Time Units (m) - The kernel's uptime clock con-
verted to milliseconds.0x6 Seconds Time Units (s) - Shown as "Seconds:Millisec-
onds:Microseconds". Converted from kernel's uptime clock.0x7 Day Time Units (d) - "Days:Hours:Minutes:Seconds:Millisec-
onds:Microseconds". Converted from kernel's uptime clock.0xF No Time Units (-) - No time units, displayed as "-".
Additive Options: 0x10 Append output logging to /Library/Logs/FireWireKPrintf.log.0x100 Open log file with Console.app. Only valid with "-o".
0x800 Create a new log file, rather than append. Only valid with "-o".
0x8000 Prefix logger machine's ID to each log. For example, if you wish to display microsecond time units with padding, synchronous mode enabled, and verbose printing disabled, the target'sboot-args would be as follows: "debug=0x14e fwkpf=0x114". On the target,
run the following in Terminal.app: % sudo nvram boot-args="debug=0x14e
fwkpf=0x114" If not defined, the "fwkpf" variable defaults to "0x004." DDEECCIIPPHHEERRIINNGG TTHHEE OOUUTTPPUUTT Once the viewer is running, he target machine is logging, and both machines are connected with a FireWire cable, you will see output similar to the following:% fwkpfv
Welcome to FireWireKPrintf (viewer x.x.x). c>50.097255 AppleFWOHCIKPF version x.x.x c>55.110783 AppleFWOHCIKPF (re)initialized c>55.110793 Log saver c>55.129614 in.c: warning can't plumb proto if=fw0 type 144 error=17 'Welcome to FireWireKPrintf (viewer x.x.x)' signifies viewer tool start correctly. If multiple interfaces are present on the debugger machine, it will give an interface count. 'AppleFWOHCIKPF version x.x.x' signifies the AppleFireWireKPrintf kext has (re)initialized the FireWire hardware for use in a FireWIreKPrintf manner.'FWKPF: Time Format->...'
displays the time format declared in the target's boot-args. See the
"Options" section of this document to select a different time for-
mat. 'c>13.481567' displays the time at which the kprintf call was logged. Prefixed with the letter that corresponds to the time formats listed above. The format of this time log is displayed upon start and can bechanged in the target's boot-args. See above.
'... in.c: warning can't...' the const char * string from the kprintf() call; the log. (This is a normal log.) TTRROOUUBBLLEESSHHOOOOTTIINNGG If you are seeing the following symptoms:There is no output from the fwkpfv tool on the second machine:
- Make sure the two machines are connected with a good FireWire
cable.- Run "nvram boot-args" and verify that the boot-args are set
correctly.- Be sure you're using the new fwkpfv utility, version 2.1 or
newer. The machine hangs at boot:- Sometimes the console will hang at boot when there is a high
volume of logging to screen. Try booting in non-verbose mode or
limiting the volume of logging. Remove the "-v" from your
machine's boot-args. Or remove "io=0x80".
DDIISSAABBLLIINNGGTo disable the FireWireKPrintf, delete the target machine's boot-args.
Within Terminal.app run the following:- % sudo nvram -d boot-args
- OR set the boot-args variable to your previous setting.
- Restart to target Mac.
NNOOTTEESSOOtthheerr ddeebbuugg//bboooott-aarrgg ooppttiioonnss::
For more information on the debug flags, please see Technical NoteTN2118. Setting the boot-arg variable "io" to "0x80" will turn on a sig-
nificant volume of power management logging, which may be useful whiledebugging sleep/wake issues. Similarly, adding the "-v" argument to the
boot-args will enable Mac OS X's verbose mode. This may be useful for
watching local logging during boot or shutdown. For example, to add power management logging and verbose mode:% sudo nvram boot-args="debug=0x8 io=0x80 -v"
The timestamps for very early boot logs are inconsistent:FireWireKPrintf tries to catch kprintf calls as soon as its start() rou-
tine is called. All kprintf calls after this point will be saved until the FireWire hardware has been initialized completely (which is also early in the boot process), however, the timestamps for these very early logs will reference the time they were sent via FireWire, not when kprintf() was called. All timestamps can be assumed accurate after the log from FireWireKPrintf that reads something similar to:FWKPF: Time Format->...
The timestamps for very early wake logs are inconsistent: Similar to very early boot logs, kprintf() calls by the kernel very early upon wake will be saved and sent after the FireWire hardware has had time to initialize. Likewise, the timestamps for these early logs may reflecta yet-to-be-initialized cpu time. These timestamps will be extremely
large and clearly recognizable.SSyynncchhrroonnoouuss oorr NNoonn-SSyynncchhrroonnoouuss??::
With exception to the two cases above (very early boot and very early sleep) when the FireWire hardware cannot be initialized without stopping kernel progression, all FireWireKPrintf logs are sent synchronously. This means that if the log is sent successfully, it is guaranteed to be on the wire before the call returns. If the log cannot be sent, an error will be written to system.log. HHooww ddoo II kknnooww iiff II hhaavvee eennaabblleedd FFiirreeWWiirreeKKPPrriinnttff aanndd hhaavvee ''nnoorrmmaall'' FFiirreeWWiirree ddiissaabblleedd??:: The "FireWire" tab of "/Applications/Utilities/System Profiler.app" willallow you to see if FireWireKPrintf has disabled normal FireWire ser-
vices. To this end, if FireWire is disabled, unplug any FireWire cables and restart the Mac to restore normal FireWire services. Additionally, be mindful to restart machines that have dropped into logging mode as soon as you have finished using FireWireKPrintf logging.MMyy bboooott-aarrggss ddiissaappppeeaarreedd uunneexxppeecctteeddllyy::
Some applications, such as the Startup Disk preference pane, set theboot-args themselves. Therefore, it is always best to boot to the parti-
tion you wish to debug, set the boot-args, and then restart.
MMyy FFiirreeWWiirree ddrriivvee mmoouunnttss oonn aa sseeccoonndd mmaacchhiinnee aanndd tthheenn ddiissaappppeeaarrss ooffff tthhee ffiirrsstt:: When a viewer Mac is connected to a logging (target) Mac, all normal FireWire services stop, including FireWire disk access. It may take a few moments for the disk to disappear on the logging Mac, but once you have connected a viewer Mac, it will be impossible to use a FireWire hard disk without restarting. II sseeee aann eerrrroorr wwhheenn II ffiirrsstt ccoonnnneecctt:: The following log is often shown when you first connect: in.c: warning can't plumb proto if=fw0 type 144 error=17 It is a normal log from a different part of the system and should not be of any concern. CCoommppaattiibbiilliittyy wwiitthh IInntteell aanndd PPPPCC::FireWireKPrintf works on both Intel and PowerPC based Macs. The inte-
grated FireWireKPrintf and fwkpfv is new for Leopard and is not included
in any previous OS release. OOtthheerr FFiirreeWWiirree DDeevviicceess:: To avoid conflicts it is best not to have other FireWire devices plugged into the host or target machines while using FireWireKPrintf. Having more than 2 nodes total (i.e. the two CPUs) may cause unexpected results. LLooggggiinngg ffrroomm mmuullttiippllee mmaacchhiinneess::The fwkpfv utility is able to receive logging from multiple machines.
Connecting more than one logging target machine to a viewer will result in individual Terminal windows showing machine specific logs. A full, unparsed log is saved to "/Library/Logs/fwkpf.log". You may also forcemachine ID prefixation to each log by specifying the "-i" flags to
fwkpfv.
UUssiinngg FFiirreeWWiirreeKKPPrriinnttff wwiitthh FFiirreeWWiirreeKKDDPP::FireWireKPrintf is compatible with FireWireKDP. To use both, it is recom-
mended to set the boot-args using the following command: % sudo nvram
boot-args="debug=0x14e kdpmatchname=bogus" Of course, you may modify or
add boot-args to suit your needs (see note above).
HHooww ddoo II cclleeaarr tthhee vviieewweerr??::Remember, you can clear the scrollback buffer of Terminal.app by select-
ing "Clear Scrollback" (or Cmd-K) from the "Scrollback" menu.
WWhhyy ddoo II sseeee ddiiffffeerreenntt llooggggiinngg wwiitthh ddiiffffeerreenntt mmaacchhiinneess??::The "built-in" kprintf output is target machine specific. This is due to
special casing of hardware and other states. It may also vary with oper-
ating system version and even kext versions. Remember, a developer can change their kprintf() calls at any time. CCaann II sseeee mmoorree llooggggiinngg??::Most Macs have the ability to output a significant volume of power man-
agement logging, which may be useful while debugging sleep/wake issues. Many options are defined in. WWhhaatt aabboouutt FFiirreeLLoogg??:: FireLog and FireWireKPrintf are different, both in theory and practice. FireLog is a high speed logging system which requires a framework. Most importantly, FireLog uses a buffering system (in a pull manner) to pre-
vent the loss of logs during high logging volume or low processing time. Conversely, FireWireKPrintf employs a push method of sending each log onto the wire as soon as it is available. Furthermore, FireWireKPrintf isavailable sooner in the kernel's startup. FireLog is an excellent solu-
tion if you need high speed logging. FILES/usr/bin/fwkpfv
is installed as part of the Mac OS X Developer Tools.SEE ALSO
fwkdp(1) Mac OS X August 13, 2007 Mac OS X