kdv - KDebug Unleashed for OS X/iOS

What is this?

The OS X/iOS KDebug facility is an incredibly powerful tracing mechanism I touched on in the first edition of MOXiI. It is second only to DTrace, and - on iOS (where DTrace is unavailable) - is second to none. It has nonetheless gone unnoticed by many (not unlike other useful stuff I pointed out ;-).

Apple's own utilities - fs_usage(1), sc_usage(1), latency(1) and trace(1) - all part of the system_cmds package, use this facility. The Apple utilities impose filters on KDebug, and don't tap the full power of this amazing facility. The fabulous Instruments.app also uses kdebug, which it also invokes on the device with the help of iprofiler(1), present both in OS X and in iOS (in the DeveloperDiskImage)

You can compile the Apple tools for iOS as well, but to get rid of the filters (and customize my own) I concocted my own KDebug viewer tool, which I call KDebugView^*. The tool has actually been available for a while, released on the Website forum to answer a specific question, but that version was really unstable and rough. This one is more stable, though arguably still very basic. The tool follows the same pattern of Apple's own tools (with a snippet I lazily cut/pasted), and I am providing the full (short) source for it, along with a universal binary (OSX/iOS32/iOS64) here. If you want to compile it for iOS, you'll need to copy headers from the OS X SDK to the iOS SDK, because Apple tries to "hide" the APIs.

This tool traces EVERYTHING. And by EVERYTHING, I mean E-V-E-R-Y-T-H-I-N-G happening in both OS X AND iOS. The XNU kernel is laced with KERNEL_DEBUG macro calls, and quite a few user mode subsystems (notably my adversary, launchd, and libxpc.dylib) use it from user mode by invoking kdebug_trace (syscall #180). Apple seems committed to this facility, and has added syscall #179 and (recently) #178 - kdebug_trace_string. So this isn't going away. The bad news: Root access is required (alas), and I'm willing to bet good money that AAPL will further restrict this by slapping an entitlement on it as well^**. So use it while you can :-)

A sample of the tool is shown here:

bash-3.2# ./kdv all
Loaded 2471/2471 codes
Filtering myself (37686) out
excluding PID 37686
KDebug Enabled
NUM THREADS: 681 - size 21792
Allocated Threadmap of 21792 bytes, 0x7fa708805e00
Read Thread Map...
# Output: Timestamp  CPU  Code  Meaning  ProcName/PID/TID  ARGS
# The ">" means going into a func/interrupt,
# The "<" means coming out of a func/interrupt.
0 0 0x010c0175 > MSC_mk_timer_arm       Terminal/15598/0x517ed  Args:2603 899c42ff6989 2 899c42ff6800 
4368 0 0x010c0176 < MSC_mk_timer_arm            Terminal/15598/0x517ed  Args:0 0 0 0 
8409 0 0x010c0175 > MSC_mk_timer_arm            Terminal/15598/0x517ed  Args:3003 899c42ff6989 2 899c42ff6800 
8829 2 0x053100da < CPUPM_IDLE_MWAIT            kernel_task/0/0x87      Args:0 60 31412718 1 
9062 0 0x010c0176 < MSC_mk_timer_arm            Terminal/15598/0x517ed  Args:0 0 0 0 
10000 2 0x01400026 < MACH_IDLE                  kernel_task/0/0x87      Args:0 5 0 0 
10282 2 0x01400088   MACH_MULTIQ_DEQUEUE        kernel_task/0/0x87      Args:3 1f 0 0 
10757 2 0x01400008   MACH_STKHANDOFF            kernel_task/0/0x87      Args:0 51818 0 1f 
11875 2 0x01400055 > MACH_SCHED_URGENCY         Terminal/15598/0x51818  Args:2 2 1 0 
12427 2 0x05310208   CPUPM_PST_IDLE_EXIT        Terminal/15598/0x51818  Args:0 1f4d00001d00 3 2704a62 
12659 2 0x05310238   CPUPM_DVFS_TRANSIT         Terminal/15598/0x51818  Args:0 3 26e78cc 21 
12812 2 0x05310200   CPUPM_PST_RESOLVE          Terminal/15598/0x51818  Args:21 21 0 21 
13180 2 0x01090018   TMR_set_tsc_deadline       Terminal/15598/0x51818  Args:899c410337f8 899c4371ad00 18be2cf586fe8 18be2d4f016ad 
13296 2 0x01400056 < MACH_SCHED_URGENCY         Terminal/15598/0x51818  Args:2 2 1 0 
13473 2 0x0109001d > TMR_TimerCallEnter         Terminal/15598/0x51818  Args:ffffff811929e048 ffffff8029b35798 899c419bc52f 41 
13859 2 0x01090018   TMR_set_tsc_deadline       Terminal/15598/0x51818  Args:899c41033ad1 899c419bc52f 18be2cf587651 18be2d0b74e29 
13961 2 0x01090004   DecrSet                    Terminal/15598/0x51818  Args:988a5e 2 899c419bc52f 0 
14220 2 0x0109001e < TMR_TimerCallEnter         Terminal/15598/0x51818  Args:ffffff811929e048 0 899c419bc52f 1 
17876 2 0x040c0176 < BSC_select                 Terminal/15598/0x51818  Args:0 1 0 3cee 
18536 2 0x040c000d > BSC_read                   Terminal/15598/0x51818  Args:14 bd5bc60 1000 0

And, on iOS (filtering)

Pademonium-II:~ root# kdv.universal all  | grep Spring
Loaded 2473/2473 codes
Read Thread Map...
42782 0 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:3e9d4 5 4 5 
42864 0 0x01050001 > INTERRUPT           	SpringBoard/57/0x3a0	Args:0 ffffff8004103210 0 0 
42957 0 0x01050002 < INTERRUPT           	SpringBoard/57/0x3a0	Args:0 0 0 0 
42971 0 0x01400088   MACH_MULTIQ_DEQUEUE 	SpringBoard/57/0x3a0	Args:3 36 0 0 
43003 0 0x01400000   MACH_SCHED          	SpringBoard/57/0x3a0	Args:5 44f 2f 36 
44196 2 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:1d1 0 9 5 
44347 2 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:0 0 0 0 
44525 2 0x010c005d > MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:d07 2503 230f 0 
44655 2 0x010c005e < MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:0 0 0 0 
44959 2 0x31800100   49 (11,9)?          	SpringBoard/57/0x3a0	Args:15fa53c00 0 0 0 
45003 2 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd75818 3 2c 74 
45151 2 ff003245 MIG MSG: 3217 start	SpringBoard/57/0x3a0	Args:0 0 0 0
45151 2 0xff003245 > MSG_mach_port_get_attributes	SpringBoard/57/0x3a0	Args:0 0 0 0 
45189 2 ff003246 MIG MSG: 3217 end	SpringBoard/57/0x3a0	Args:0 0 0 0
45189 2 0xff003246 < MSG_mach_port_get_attributes	SpringBoard/57/0x3a0	Args:0 0 0 0 
45246 2 0x26120006 < imp_msg_send        	SpringBoard/57/0x3a0	Args:39 ffffffffffffffff ffffffffffffffff 0 
45319 2 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:0 0 0 0 
47243 2 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd76b58 7000906 0 c00 
47275 2 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:10004003 0 0 0 
47962 2 0x010c0059 > MSC_mach_port_insert_member_tr	SpringBoard/57/0x3a0	Args:d07 2503 230f 0 
48143 2 0x010c005a < MSC_mach_port_insert_member_tr	SpringBoard/57/0x3a0	Args:0 0 0 0 
48179 2 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd76b58 7000806 0 c00 
48218 2 0x0140003c   MACH_BLOCK          	SpringBoard/57/0x3a0	Args:0 ffffff800401b5c8 0 0 
48254 2 0x01400008   MACH_STKHANDOFF     	SpringBoard/57/0x3a0	Args:0 12d 2f 0 
Next iter (Used: 1059 , Flags: 0x801401c0
442546 2 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:3e9d4 5 4 6 
442601 2 0x01050001 > INTERRUPT           	SpringBoard/57/0x3a0	Args:0 ffffff8004103210 0 0 
442690 2 0x01050002 < INTERRUPT           	SpringBoard/57/0x3a0	Args:0 0 0 0 
442705 2 0x01400088   MACH_MULTIQ_DEQUEUE 	SpringBoard/57/0x3a0	Args:3 36 0 0 
442736 2 0x01400000   MACH_SCHED          	SpringBoard/57/0x3a0	Args:5 44f 2f 36 
444690 1 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:1e3 0 9 5 
444820 1 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:0 0 0 0 
444969 1 0x010c005d > MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:d07 2503 230f 0 
445069 1 0x010c005e < MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:0 0 0 0 
445331 1 0x31800100   49 (11,9)?          	SpringBoard/57/0x3a0	Args:15fa53c00 0 0 0 
445364 1 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd75818 3 2c 74 
445460 1 ff003245 MIG MSG: 3217 start	SpringBoard/57/0x3a0	Args:0 0 0 0
445460 1 0xff003245 > MSG_mach_port_get_attributes	SpringBoard/57/0x3a0	Args:0 0 0 0 
445492 1 ff003246 MIG MSG: 3217 end	SpringBoard/57/0x3a0	Args:0 0 0 0
445492 1 0xff003246 < MSG_mach_port_get_attributes	SpringBoard/57/0x3a0	Args:0 0 0 0 
445537 1 0x26120006 < imp_msg_send        	SpringBoard/57/0x3a0	Args:39 ffffffffffffffff ffffffffffffffff 0 
445587 1 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:0 0 0 0 
446040 1 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd76b58 7000906 0 c00 
446066 1 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:10004003 0 0 0 
446779 1 0x010c0059 > MSC_mach_port_insert_member_tr	SpringBoard/57/0x3a0	Args:d07 2503 230f 0 
446911 1 0x010c005a < MSC_mach_port_insert_member_tr	SpringBoard/57/0x3a0	Args:0 0 0 0 
446936 1 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd76b58 7000806 0 c00 
446962 1 0x0140003c   MACH_BLOCK          	SpringBoard/57/0x3a0	Args:0 ffffff800401b5c8 0 0 
446973 1 0x01400088   MACH_MULTIQ_DEQUEUE 	SpringBoard/57/0x3a0	Args:3 1f 0 0 
446993 1 0x01400008   MACH_STKHANDOFF     	SpringBoard/57/0x3a0	Args:0 498 2f 1f 
Next iter (Used: 1605 , Flags: 0x801401c0
841910 2 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:43b 0 1 6 
842058 2 0x010c007e < MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:0 0 0 0 
842192 2 0x010c005d > MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:d07 2503 230f 0 
842284 2 0x010c005e < MSC_mach_port_extract_member_t	SpringBoard/57/0x3a0	Args:0 0 0 0 
842562 2 0x01050001 > INTERRUPT           	SpringBoard/57/0x3a0	Args:0 ffffff80040fd34c 0 0 
842671 2 0x01050002 < INTERRUPT           	SpringBoard/57/0x3a0	Args:0 0 0 0 
842694 2 0x01400088   MACH_MULTIQ_DEQUEUE 	SpringBoard/57/0x3a0	Args:3 51 0 0 
842734 2 0x01400000   MACH_SCHED          	SpringBoard/57/0x3a0	Args:5 1d1 2f 51 
843154 2 0x01400080   MACH_DISPATCH       	SpringBoard/57/0x3a0	Args:1d1 0 9 6 
843212 2 0x31800100   49 (11,9)?          	SpringBoard/57/0x3a0	Args:15fa53c00 0 0 0 
843268 2 0x010c007d > MSC_mach_msg_trap   	SpringBoard/57/0x3a0	Args:16fd75818 3 2c 74 
843408 2 ff003245 MIG MSG: 3217 start	SpringBoard/57/0x3a0	Args:0 0 0 0
843408 2 0xff003245 > MSG_mach_port_get_attributes	SpringBoard/57/0x3a0	Args:0 0 0 0 
843444 2 ff003246 MIG MSG: 3217 end	SpringBoard/57/0x3a0	Args:0 0 0 0
..

Note, you get a TON of information - Scheduler events, interrupts(!!!), system calls, Mach traps, Mach Messages, and every little hiccup of the kernel. A plethora of information, maybe even TMI - You'll get tens of MB output per second. I'll add some of the filters in a later release, but for now I recommend grep(1) as your friend.

The version (and source) of the tool provided is very raw - I removed the filtering logic because the latest version is unstable. Expect a beefed up version soon.

How this works

The full detail of kdebug is in Chapter 5 of MOXiI's first edition, but do not buy that book. Seriously, it's paltry in comparison to the second edition, which provides a lot more detail (and yes, it's coming soon). The gist of it is, you use sysctl(2) to interface with the facility, set up filters (which I don't), provide a buffer, and gulp down tons of info. The kdebug messages are simple 32-bit constants, defined in sys/kdebug.h

/* The debug code consists of the following 
*
* ----------------------------------------------------------------------
*|              |               |                               |Func   |
*| Class (8)    | SubClass (8)  |          Code (14)            |Qual(2)|
* ----------------------------------------------------------------------
*/

Pre 10-10 the CoreProfile framework had a nice XML formatting of the codes in /System/Library/PrivateFrameworks/CorePorfile.framework/Resources/Devices/osx-13.0.0.xml. This has since been removed. Fortunately, Apple still provides /usr/share/misc/trace.codes to support their own tools. This is a pretty comprehensive file, though a lot of the really interesting codes have been "omitted". I wouldn't be surprised if this file, too, disappears, but rest assured I'm compiling a full list of all codes - both documented and undocumented - which will remain open. On iOS, this file is not present, so just use the one I've packaged with the tar file.

Each debug code has 5 arguments, depending on the caller, but in general arg5 is the thread ID, and args1-4 are the arguments to the event (usually a syscall, or Mach event). I make no attempt to parse or make sense of the arguments in this version of the tool, but I'll add support for that sometime soon, as well.

In other cases, kdebug can log strings (in place of the 4 args). That's handled.

I'm sure this - being powerful yet incomplete - will bring feature requests. Please use the Book's Forum to let me know - I'll be glad to oblige. The enclosed tar file also has the open source of the tool, so you can tweak/customize by yourself.

TG Annoucement - The upcoming MOXiI training in NYC (December 11^th, 2017) is open for registration! KDebug is only one of the many cool tracing/RE methods we demonstrate. You might want to follow @Technologeeks for announcements! You can drop i/n/f/o at TG an email if you want more details or to register.

Changelog

12/25/2015 - First public release. Merry XMas, everyone

* - Paying homage to SysInternals' DbgView, though hardly similar.
** - And considering the horrid info-leaks and KASLR snafu kdebug provides, I wouldn't blame them if/when they do..