]> git.saurik.com Git - apple/xnu.git/blame - tools/lldbmacros/ktrace.py
xnu-7195.81.3.tar.gz
[apple/xnu.git] / tools / lldbmacros / ktrace.py
CommitLineData
39037602
A
1from xnu import *
2from utils import *
f427ee49
A
3from core.lazytarget import *
4from misc import *
5from collections import namedtuple
39037602
A
6
7# From the defines in bsd/sys/kdebug.h:
8
9KdebugClassNames = {
10 1: "MACH",
11 2: "NETWORK",
12 3: "FSYSTEM",
13 4: "BSD",
14 5: "IOKIT",
15 6: "DRIVERS",
16 7: "TRACE",
17 8: "DLIL",
18 9: "WORKQUEUE",
19 10: "CORESTORAGE",
20 11: "CG",
21 20: "MISC",
22 30: "SECURITY",
23 31: "DYLD",
24 32: "QT",
25 33: "APPS",
26 34: "LAUNCHD",
27 36: "PPT",
28 37: "PERF",
29 38: "IMPORTANCE",
30 39: "PERFCTRL",
31 40: "BANK",
32 41: "XPC",
33 42: "ATM",
34 43: "ARIADNE",
35 44: "DAEMON",
36 45: "ENERGYTRACE",
37 49: "IMG",
38 50: "CLPC",
39 128: "ANS",
40 129: "SIO",
41 130: "SEP",
42 131: "ISP",
43 132: "OSCAR",
44 133: "EMBEDDEDGFX"
45}
46
47def GetKdebugClassName(class_num):
48 return (KdebugClassNames[class_num] + ' ({})'.format(class_num) if class_num in KdebugClassNames else 'unknown ({})'.format(class_num))
49
50@lldb_type_summary(['typefilter_t'])
51@header('{0: <20s}'.format("class") + ' '.join(map('{:02x}'.format, xrange(0, 255, 8))))
52def GetKdebugTypefilter(typefilter):
53 """ Summarizes the provided typefilter.
54 """
55 classes = 256
56 subclasses_per_class = 256
57
58 # 8 bits at a time
59 subclasses_per_element = 64
60 cur_typefilter = cast(typefilter, 'uint64_t *')
61 subclasses_fmts = ' '.join(['{:02x}'] * 8)
62
63 elements_per_class = subclasses_per_class / subclasses_per_element
64
65 out_str = ''
66 for i in xrange(0, classes):
67 print_class = False
68 subclasses = [0] * elements_per_class
69
70 # check subclass ranges for set bits, remember those subclasses
71 for j in xrange(0, elements_per_class):
72 element = unsigned(cur_typefilter[i * elements_per_class + j])
73 if element != 0:
74 print_class = True
75 if print_class:
76 subclasses[j] = element
77
5ba3f43e 78 ## if any of the bits were set in a class, print the entire class
39037602
A
79 if print_class:
80 out_str += '{:<20s}'.format(GetKdebugClassName(i))
81 for element in subclasses:
82 # split up the 64-bit values into byte-sized pieces
83 bytes = [unsigned((element >> i) & 0xff) for i in (0, 8, 16, 24, 32, 40, 48, 56)]
84 out_str += subclasses_fmts.format(*bytes)
85 out_str += ' '
86
87 out_str += '\n'
88
89 return out_str
90
91@lldb_command('showkdebugtypefilter')
92def ShowKdebugTypefilter(cmd_args=None):
93 """ Show the current kdebug typefilter (or the typefilter at an address)
94
95 usage: showkdebugtypefilter [<address>]
96 """
97
98 if cmd_args:
39037602
A
99 typefilter = kern.GetValueFromAddress(cmd_args[0], 'typefilter_t')
100 if unsigned(typefilter) == 0:
101 raise ArgumentError('argument provided is NULL')
102
813fb2f6
A
103 print GetKdebugTypefilter.header
104 print '-' * len(GetKdebugTypefilter.header)
105
106 print GetKdebugTypefilter(typefilter)
39037602
A
107 return
108
109 typefilter = kern.globals.kdbg_typefilter
110 if unsigned(typefilter) == 0:
111 raise ArgumentError('no argument provided and active typefilter is not set')
112
113 print GetKdebugTypefilter.header
114 print '-' * len(GetKdebugTypefilter.header)
115 print GetKdebugTypefilter(typefilter)
813fb2f6
A
116
117def GetKdebugStatus():
118 """ Get a string summary of the kdebug subsystem.
119 """
120 out = ''
121
122 kdebug_flags = kern.globals.kd_ctrl_page.kdebug_flags
123 out += 'kdebug flags: {}\n'.format(xnudefines.GetStateString(xnudefines.kdebug_flags_strings, kdebug_flags))
124 events = kern.globals.nkdbufs
5ba3f43e 125 buf_mb = events * (64 if kern.arch == 'x86_64' or kern.arch.startswith('arm64') else 32) / 1000000
813fb2f6
A
126 out += 'events allocated: {:<d} ({:<d} MB)\n'.format(events, buf_mb)
127 out += 'enabled: {}\n'.format('yes' if kern.globals.kdebug_enable != 0 else 'no')
128 if kdebug_flags & xnudefines.kdebug_typefilter_check:
129 out += 'typefilter:\n'
130 out += GetKdebugTypefilter.header + '\n'
131 out += '-' * len(GetKdebugTypefilter.header) + '\n'
132 typefilter = kern.globals.kdbg_typefilter
133 if unsigned(typefilter) != 0:
134 out += GetKdebugTypefilter(typefilter)
135
136 return out
137
138@lldb_command('showkdebug')
139def ShowKdebug(cmd_args=None):
140 """ Show the current kdebug state.
141
142 usage: showkdebug
143 """
144
5ba3f43e 145 print GetKdebugStatus()
813fb2f6
A
146
147@lldb_type_summary(['kperf_timer'])
f427ee49 148@header('{:<10s} {:<7s} {:<20s} {:<20s}'.format('period-ns', 'action', 'deadline', 'fire-time'))
813fb2f6
A
149def GetKperfTimerSummary(timer):
150 """ Get a string summary of a kperf timer.
151
152 params:
f427ee49 153 timer: the kptimer object to get a summary of
813fb2f6 154 """
f427ee49
A
155 try:
156 fire_time = timer.kt_fire_time
157 except:
158 fire_time = 0
159 return '{:<10d} {:<7d} {:<20d} {:<20d}\n'.format(
160 kern.GetNanotimeFromAbstime(timer.kt_period_abs), timer.kt_actionid,
161 timer.kt_cur_deadline, fire_time)
813fb2f6
A
162
163@lldb_type_summary(['action'])
164@header('{:<10s} {:<20s} {:<20s}'.format('pid-filter', 'user-data', 'samplers'))
165def GetKperfActionSummary(action):
166 """ Get a string summary of a kperf action.
167
168 params:
169 action: the action object to get a summary of
170 """
171 samplers = xnudefines.GetStateString(xnudefines.kperf_samplers_strings, action.sample)
172 return '{:<10s} {:<20x} {:<20s}\n'.format(
173 '-' if action.pid_filter < 0 else str(action.pid_filter), action.userdata, samplers)
174
175def GetKperfStatus():
176 """ Get a string summary of the kperf subsystem.
177 """
178 out = ''
179
f427ee49 180 kperf_status = int(kern.globals.kperf_status)
813fb2f6 181 out += 'sampling: '
f427ee49 182 if kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_OFF'):
813fb2f6 183 out += 'off\n'
f427ee49 184 elif kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_SHUTDOWN'):
813fb2f6 185 out += 'shutting down\n'
f427ee49
A
186 elif kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_ON'):
187 out += 'on\n'
813fb2f6
A
188 else:
189 out += 'unknown\n'
190
f427ee49
A
191 pet = kern.globals.kptimer.g_pet_active
192 pet_timer_id = kern.globals.kptimer.g_pet_active
813fb2f6
A
193 if pet != 0:
194 pet_idle_rate = kern.globals.pet_idle_rate
195 out += 'legacy PET is active (timer = {:<d}, idle rate = {:<d})\n'.format(pet_timer_id, pet_idle_rate)
196 else:
197 out += 'legacy PET is off\n'
198
f427ee49 199 lw_pet = kern.globals.kppet.g_lightweight
813fb2f6 200 if lw_pet != 0:
f427ee49 201 lw_pet_gen = kern.globals.kppet_gencount
813fb2f6
A
202 out += 'lightweight PET is active (timer = {:<d}, generation count = {:<d})\n'.format(pet_timer_id, lw_pet_gen)
203 else:
204 out += 'lightweight PET is off\n'
205
206 actions = kern.globals.actionc
207 actions_arr = kern.globals.actionv
208
209 out += 'actions:\n'
210 out += '{:<5s} '.format('id') + GetKperfActionSummary.header + '\n'
211 for i in xrange(0, actions):
212 out += '{:<5d} '.format(i) + GetKperfActionSummary(actions_arr[i])
213
f427ee49
A
214 timers = kern.globals.kptimer.g_ntimers
215 timers_arr = kern.globals.kptimer.g_timers
813fb2f6
A
216
217 out += 'timers:\n'
218 out += '{:<5s} '.format('id') + GetKperfTimerSummary.header + '\n'
219 for i in xrange(0, timers):
220 out += '{:<5d} '.format(i) + GetKperfTimerSummary(timers_arr[i])
221
222 return out
223
f427ee49 224
813fb2f6
A
225def GetKtraceStatus():
226 """ Get a string summary of the ktrace subsystem.
227 """
228 out = ''
229
230 state = kern.globals.ktrace_state
231 if state == GetEnumValue('ktrace_state::KTRACE_STATE_OFF'):
232 out += 'ktrace is off\n'
233 else:
234 out += 'ktrace is active ('
235 if state == GetEnumValue('ktrace_state::KTRACE_STATE_FG'):
236 out += 'foreground)'
237 else:
238 out += 'background)'
239 out += '\n'
240 owner = kern.globals.ktrace_last_owner_execname
241 out += 'owned by: {0: <s}\n'.format(owner)
242 active_mask = kern.globals.ktrace_active_mask
243 out += 'active systems: {:<#x}\n'.format(active_mask)
244
245 return out
246
f427ee49 247
813fb2f6
A
248@lldb_command('showktrace')
249def ShowKtrace(cmd_args=None):
250 """ Show the current ktrace state, including subsystems.
251
252 usage: showktrace
253 """
254
255 print GetKtraceStatus()
256 print ' '
257 print 'kdebug:'
258 print GetKdebugStatus()
259 print ' '
260 print 'kperf:'
261 print GetKperfStatus()
f427ee49
A
262
263
264class KDCPU(object):
265 def __init__(self, store, curidx):
266 self.store = store
267 self.curidx = curidx
268 self.oldest_time = None
269
270
271def IterateKdebugEvents():
272 """
273 Yield events from the in-memory kdebug trace buffers.
274 """
275 ctrl = kern.globals.kd_ctrl_page
276
277 def get_kdstore(kdstorep):
278 """
279 See POINTER_FROM_KDSPTR.
280 """
281 buf = kern.globals.kd_bufs[kdstorep.buffer_index]
282 return addressof(buf.kdsb_addr[kdstorep.offset])
283
284 def get_kdbuf_timestamp(kdbuf):
285 time_cpu = kdbuf.timestamp
286 return unsigned(time_cpu)
287
288 if (ctrl.kdebug_flags & xnudefines.KDBG_BFINIT) == 0:
289 return
290
291 barrier_min = ctrl.oldest_time
292
293 if (ctrl.kdebug_flags & xnudefines.KDBG_WRAPPED) != 0:
294 # TODO Yield a wrap event with the barrier_min timestamp.
295 pass
296
297 # Set up CPU state for merging events.
298 ncpus = ctrl.kdebug_cpus
299 cpus = []
300 for cpu in range(ncpus):
301 kdstoreinfo = kern.globals.kdbip[cpu]
302 storep = kdstoreinfo.kd_list_head
303 store = None
304 curidx = 0
305 if storep.raw != xnudefines.KDS_PTR_NULL:
306 store = get_kdstore(storep)
307 curidx = store.kds_readlast
308 # XXX Doesn't have the same logic to avoid un-mergeable events
309 # (respecting barrier_min and bufindx) as the C code.
310
311 cpus.append(KDCPU(store, curidx))
312
313 while True:
314 earliest_time = 0xffffffffffffffff
315 min_cpu = None
316 for cpu in cpus:
317 if not cpu.store:
318 continue
319
320 # Check for overrunning the writer, which also indicates the CPU is
321 # out of events.
322 if cpu.oldest_time:
323 timestamp = cpu.oldest_time
324 else:
325 timestamp = get_kdbuf_timestamp(
326 addressof(cpu.store.kds_records[cpu.curidx]))
327 cpu.oldest_time = timestamp
328
329 if timestamp < cpu.store.kds_timestamp:
330 cpu.store = None
331 continue
332
333 if timestamp < earliest_time:
334 earliest_time = timestamp
335 min_cpu = cpu
336
337 # Out of events.
338 if not min_cpu:
339 return
340
341 yield min_cpu.store.kds_records[min_cpu.curidx]
342 min_cpu.oldest_time = None
343
344 min_cpu.curidx += 1
345 if min_cpu.curidx == xnudefines.EVENTS_PER_STORAGE_UNIT:
346 next = min_cpu.store.kds_next
347 if next.raw == xnudefines.KDS_PTR_NULL:
348 min_cpu.store = None
349 min_cpu.curidx = None
350 else:
351 min_cpu.store = get_kdstore(next)
352 min_cpu.curidx = min_cpu.store.kds_readlast
353
354 # This CPU is out of events.
355 if min_cpu.curidx == min_cpu.store.kds_bufindx:
356 min_cpu.store = None
357 continue
358
359
360def GetKdebugEvent(event):
361 """
362 Return a string representing a kdebug trace event.
363 """
364 return '{:16} {:8} {:8x} {:16} {:16} {:16} {:16} {:4} {:8} {}'.format(
365 unsigned(event.timestamp), 0, unsigned(event.debugid),
366 unsigned(event.arg1), unsigned(event.arg2),
367 unsigned(event.arg3), unsigned(event.arg4), unsigned(event.cpuid),
368 unsigned(event.arg5), "")
369
370
371@lldb_command('showkdebugtrace')
372def ShowKdebugTrace(cmd_args=None):
373 """
374 List the events present in the kdebug trace buffers.
375
376 (lldb) showkdebugtrace
377
378 Caveats:
379 * Events from IOPs may be missing or cut-off -- they weren't informed
380 of this kind of buffer collection.
381 """
382 for event in IterateKdebugEvents():
383 print(GetKdebugEvent(event))
384
385
386@lldb_command('savekdebugtrace', 'N:')
387def SaveKdebugTrace(cmd_args=None, cmd_options={}):
388 """
389 Save any valid ktrace events to a file.
390
391 (lldb) savekdebugtrace [-N <n-events>] <file-to-write>
392
393 Caveats:
394 * 32-bit kernels are unsupported.
395 * The trace file will be missing machine and config chunks, which might
396 prevent tools from analyzing it.
397 """
398
399 if kern.arch not in ['x86_64', 'x86_64h', 'arm64', 'arm64e']:
400 print('32-bit kernels are unsupported')
401 return
402
403 if len(cmd_args) != 1:
404 raise ArgumentError('path to trace file is required')
405
406 nevents = unsigned(kern.globals.nkdbufs)
407 if nevents == 0:
408 print('kdebug buffers are not set up')
409 return
410
411 limit_nevents = nevents
412 if '-N' in cmd_options:
413 limit_nevents = unsigned(cmd_options['-N'])
414 if limit_nevents > nevents:
415 limit_nevents = nevents
416 verbose = config['verbosity'] > vHUMAN
417
418 file_offset = 0
419 with open(cmd_args[0], 'w+b') as f:
420 FILE_MAGIC = 0x55aa0300
421 EVENTS_TAG = 0x00001e00
422 SSHOT_TAG = 0x8002
423 CHUNKHDR_PACK = 'IHHQ'
424 FILEHDR_PACK = CHUNKHDR_PACK + 'IIQQIIII'
425 FILEHDR_SIZE = 40
426 FUTURE_SIZE = 8
427
428 numer, denom = GetTimebaseInfo()
429
430 # XXX The kernel doesn't have a solid concept of the wall time.
431 wall_abstime = 0
432 wall_secs = 0
433 wall_usecs = 0
434
435 # XXX 32-bit is NYI
436 k64 = True
437 event_size = unsigned(64)
438
439 file_hdr = struct.pack(
440 FILEHDR_PACK, FILE_MAGIC, 0, 0, FILEHDR_SIZE,
441 numer, denom, wall_abstime, wall_secs, wall_usecs, 0, 0,
442 0x1 if k64 else 0)
443 f.write(file_hdr)
444 file_offset += 16 + FILEHDR_SIZE # chunk header plus file header
445
446 skip_nevents = nevents - limit_nevents if limit_nevents else 0
447 if skip_nevents > 0:
448 print('omitting {} events from the beginning'.format(skip_nevents))
449
450 events_hdr = struct.pack(
451 CHUNKHDR_PACK, EVENTS_TAG, 0, 0, 0) # size will be filled in later
452 f.write(events_hdr)
453 file_offset += 16 # header size
454 event_size_offset = file_offset - FUTURE_SIZE
455 # Future events timestamp -- doesn't need to be set for merged events.
456 f.write(struct.pack('Q', 0))
457 file_offset += FUTURE_SIZE
458
459 if verbose:
460 print('events start at offset {}'.format(file_offset))
461
462 process = LazyTarget().GetProcess()
463 error = lldb.SBError()
464
465 written_nevents = 0
466 seen_nevents = 0
467 for event in IterateKdebugEvents():
468 seen_nevents += 1
469 if skip_nevents >= seen_nevents:
470 if seen_nevents % 1000 == 0:
471 sys.stderr.write('skipped {}/{} ({:4.2f}%) events'.format(
472 seen_nevents, skip_nevents,
473 float(seen_nevents) / skip_nevents * 100.0))
474 sys.stderr.write('\r')
475
476 continue
477
478 event = process.ReadMemory(
479 unsigned(addressof(event)), event_size, error)
480 file_offset += event_size
481 f.write(event)
482 written_nevents += 1
483 # Periodically update the CLI with progress.
484 if written_nevents % 1000 == 0:
485 sys.stderr.write('wrote {}/{} ({:4.2f}%) events'.format(
486 written_nevents, limit_nevents,
487 float(written_nevents) / nevents * 100.0))
488 sys.stderr.write('\r')
489 sys.stderr.write('\n')
490 print('wrote {} events'.format(written_nevents))
491 if verbose:
492 print('events end at offset {}'.format(file_offset))
493
494 # Normally, the chunk would need to be padded to 8, but events are
495 # already aligned.
496
497 kcdata = kern.globals.kc_panic_data
498 kcdata_addr = unsigned(kcdata.kcd_addr_begin)
499 kcdata_length = unsigned(kcdata.kcd_length)
500 if kcdata_addr != 0 and kcdata_length != 0:
501 print('writing stackshot')
502 f.write(struct.pack(CHUNKHDR_PACK, SSHOT_TAG, 1, 0, kcdata_length))
503 file_offset += 16
504 if verbose:
505 print('stackshot is {} bytes long'.format(kcdata_length))
506 print('stackshot starts at offset {}'.format(file_offset))
507 ssdata = process.ReadMemory(kcdata_addr, kcdata_length, error)
508 f.write(ssdata)
509 file_offset += kcdata_length
510 if verbose:
511 print('stackshot ends at offset {}'.format(file_offset))
512 else:
513 print('stackshot is not available, trace file may not be usable!')
514
515 # After the number of events is known, fix up the events chunk size.
516 events_data_size = unsigned(written_nevents * event_size) + FUTURE_SIZE
517 f.seek(event_size_offset)
518 f.write(struct.pack('Q', events_data_size))
519
520 return