xref: /xnu-8796.101.5/tools/lldbmacros/ktrace.py (revision aca3beaa3dfbd42498b42c5e5ce20a938e6554e5)
1from __future__ import absolute_import, division, print_function
2
3from builtins import map
4from builtins import range
5from builtins import object
6
7from xnu import *
8from utils import *
9from core.lazytarget import *
10from misc import *
11from scheduler import *
12from kcdata import kcdata_item_iterator, KCObject, GetTypeForName, KCCompressedBufferObject
13from collections import namedtuple
14from future.utils import PY2
15import heapq
16import os
17import plistlib
18import struct
19import subprocess
20import sys
21import tempfile
22import time
23
24# From the defines in bsd/sys/kdebug.h:
25
26KdebugClassNames = {
27    1: "MACH",
28    2: "NETWORK",
29    3: "FSYSTEM",
30    4: "BSD",
31    5: "IOKIT",
32    6: "DRIVERS",
33    7: "TRACE",
34    8: "DLIL",
35    9: "WORKQUEUE",
36    10: "CORESTORAGE",
37    11: "CG",
38    20: "MISC",
39    30: "SECURITY",
40    31: "DYLD",
41    32: "QT",
42    33: "APPS",
43    34: "LAUNCHD",
44    36: "PPT",
45    37: "PERF",
46    38: "IMPORTANCE",
47    39: "PERFCTRL",
48    40: "BANK",
49    41: "XPC",
50    42: "ATM",
51    43: "ARIADNE",
52    44: "DAEMON",
53    45: "ENERGYTRACE",
54    49: "IMG",
55    50: "CLPC",
56    128: "ANS",
57    129: "SIO",
58    130: "SEP",
59    131: "ISP",
60    132: "OSCAR",
61    133: "EMBEDDEDGFX"
62}
63
64def GetKdebugClassName(class_num):
65    return (KdebugClassNames[class_num] + ' ({})'.format(class_num) if class_num in KdebugClassNames else 'unknown ({})'.format(class_num))
66
67@lldb_type_summary(['typefilter_t'])
68@header('{0: <20s}'.format("class") + ' '.join(map('{:02x}'.format, list(range(0, 255, 8)))))
69def GetKdebugTypefilter(typefilter):
70    """ Summarizes the provided typefilter.
71    """
72    classes = 256
73    subclasses_per_class = 256
74
75    # 8 bits at a time
76    subclasses_per_element = 64
77    cur_typefilter = cast(typefilter, 'uint64_t *')
78    subclasses_fmts = ' '.join(['{:02x}'] * 8)
79
80    elements_per_class = subclasses_per_class // subclasses_per_element
81
82    out_str = ''
83    for i in range(0, classes):
84        print_class = False
85        subclasses = [0] * elements_per_class
86
87        # check subclass ranges for set bits, remember those subclasses
88        for j in range(0, elements_per_class):
89            element = unsigned(cur_typefilter[i * elements_per_class + j])
90            if element != 0:
91                print_class = True
92            if print_class:
93                subclasses[j] = element
94
95        ## if any of the bits were set in a class, print the entire class
96        if print_class:
97            out_str += '{:<20s}'.format(GetKdebugClassName(i))
98            for element in subclasses:
99                # split up the 64-bit values into byte-sized pieces
100                bytes = [unsigned((element >> i) & 0xff) for i in (0, 8, 16, 24, 32, 40, 48, 56)]
101                out_str += subclasses_fmts.format(*bytes)
102                out_str += ' '
103
104            out_str += '\n'
105
106    return out_str
107
108@lldb_command('showkdebugtypefilter')
109def ShowKdebugTypefilter(cmd_args=None):
110    """ Show the current kdebug typefilter (or the typefilter at an address)
111
112        usage: showkdebugtypefilter [<address>]
113    """
114
115    if cmd_args:
116        typefilter = kern.GetValueFromAddress(cmd_args[0], 'typefilter_t')
117        if unsigned(typefilter) == 0:
118            raise ArgumentError('argument provided is NULL')
119
120        print(GetKdebugTypefilter.header)
121        print('-' * len(GetKdebugTypefilter.header))
122
123        print(GetKdebugTypefilter(typefilter))
124        return
125
126    typefilter = kern.globals.kdbg_typefilter
127    if unsigned(typefilter) == 0:
128        raise ArgumentError('no argument provided and active typefilter is not set')
129
130    print(GetKdebugTypefilter.header)
131    print('-' * len(GetKdebugTypefilter.header))
132    print(GetKdebugTypefilter(typefilter))
133
134def GetKdebugStatus():
135    """ Get a string summary of the kdebug subsystem.
136    """
137    out = ''
138
139    kdc_flags = kern.globals.kd_control_trace.kdc_flags
140    out += 'kdebug flags: {}\n'.format(xnudefines.GetStateString(xnudefines.kdebug_flags_strings, kdc_flags))
141    events = kern.globals.kd_buffer_trace.kdb_event_count
142    buf_mb = events * (64 if kern.arch == 'x86_64' or kern.arch.startswith('arm64') else 32) // 1000000
143    out += 'events allocated: {:<d} ({:<d} MB)\n'.format(events, buf_mb)
144    out += 'enabled: {}\n'.format('yes' if kern.globals.kdebug_enable != 0 else 'no')
145    if kdc_flags & xnudefines.KDBG_TYPEFILTER_CHECK:
146        out += 'typefilter:\n'
147        out += GetKdebugTypefilter.header + '\n'
148        out += '-' * len(GetKdebugTypefilter.header) + '\n'
149        typefilter = kern.globals.kdbg_typefilter
150        if unsigned(typefilter) != 0:
151            out += GetKdebugTypefilter(typefilter)
152
153    return out
154
155@lldb_command('showkdebug')
156def ShowKdebug(cmd_args=None):
157    """ Show the current kdebug state.
158
159        usage: showkdebug
160    """
161
162    print(GetKdebugStatus())
163
164@lldb_type_summary(['kperf_timer'])
165@header('{:<10s} {:<7s} {:<20s} {:<20s}'.format('period-ns', 'action', 'deadline', 'fire-time'))
166def GetKperfTimerSummary(timer):
167    """ Get a string summary of a kperf timer.
168
169        params:
170            timer: the kptimer object to get a summary of
171    """
172    try:
173        fire_time = timer.kt_fire_time
174    except:
175        fire_time = 0
176    return '{:<10d} {:<7d} {:<20d} {:<20d}\n'.format(
177        kern.GetNanotimeFromAbstime(timer.kt_period_abs), timer.kt_actionid,
178        timer.kt_cur_deadline, fire_time)
179
180@lldb_type_summary(['action'])
181@header('{:<10s} {:<20s} {:<20s}'.format('pid-filter', 'user-data', 'samplers'))
182def GetKperfActionSummary(action):
183    """ Get a string summary of a kperf action.
184
185        params:
186            action: the action object to get a summary of
187    """
188    samplers = xnudefines.GetStateString(xnudefines.kperf_samplers_strings, action.sample)
189    return '{:<10s} {:<20x} {:<20s}\n'.format(
190        '-' if action.pid_filter < 0 else str(action.pid_filter), action.userdata, samplers)
191
192def GetKperfKdebugFilterDescription():
193    kdebug_filter = kern.globals.kperf_kdebug_filter
194    desc = ''
195    for i in range(kdebug_filter.n_debugids):
196        filt_index = 1 if i >= 16 else 0
197        filt_type = (kdebug_filter.types[filt_index] >> ((i % 16) * 4)) & 0xf
198        debugid = kdebug_filter.debugids[i]
199        if filt_type < 2:
200            prefix = 'C'
201            width = 2
202            id = debugid >> 24
203        elif filt_type < 4:
204            prefix = 'S'
205            width = 4
206            id = debugid >> 16
207        else:
208            prefix = 'D'
209            width = 8
210            id = debugid
211
212        suffix = ''
213        if (filt_type % 2) == 1:
214            if debugid & xnudefines.DBG_FUNC_START:
215                suffix = 's'
216            elif debugid & xnudefines.DBG_FUNC_END:
217                suffix = 'r'
218            else:
219                suffix = 'n'
220
221        if i > 0:
222            desc += ','
223        desc += '{prefix}{id:0{width}x}{suffix}'.format(
224                prefix=prefix, id=id, width=width, suffix=suffix)
225
226    return desc
227
228def GetKperfStatus():
229    """ Get a string summary of the kperf subsystem.
230    """
231    out = ''
232
233    kperf_status = int(kern.globals.kperf_status)
234    out += 'sampling: '
235    if kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_OFF'):
236        out += 'off\n'
237    elif kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_SHUTDOWN'):
238        out += 'shutting down\n'
239    elif kperf_status == GetEnumValue('kperf_sampling::KPERF_SAMPLING_ON'):
240        out += 'on\n'
241    else:
242        out += 'unknown\n'
243
244    pet = kern.globals.kptimer.g_pet_active
245    pet_timer_id = kern.globals.kptimer.g_pet_active
246    if pet != 0:
247        pet_idle_rate = kern.globals.pet_idle_rate
248        out += 'legacy PET is active (timer = {:<d}, idle rate = {:<d})\n'.format(pet_timer_id, pet_idle_rate)
249    else:
250        out += 'legacy PET is off\n'
251
252    lw_pet = kern.globals.kppet.g_lightweight
253    if lw_pet != 0:
254        lw_pet_gen = kern.globals.kppet_gencount
255        out += 'lightweight PET is active (timer = {:<d}, generation count = {:<d})\n'.format(pet_timer_id, lw_pet_gen)
256    else:
257        out += 'lightweight PET is off\n'
258
259    actions = kern.globals.actionc
260    actions_arr = kern.globals.actionv
261
262    out += 'actions:\n'
263    out += '{:<5s} '.format('id') + GetKperfActionSummary.header + '\n'
264    for i in range(0, actions):
265        out += '{:<5d} '.format(i) + GetKperfActionSummary(actions_arr[i])
266
267    timers = kern.globals.kptimer.g_ntimers
268    timers_arr = kern.globals.kptimer.g_timers
269
270    out += 'timers:\n'
271    out += '{:<5s} '.format('id') + GetKperfTimerSummary.header + '\n'
272    for i in range(0, timers):
273        out += '{:<5d} '.format(i) + GetKperfTimerSummary(timers_arr[i])
274
275    return out
276
277
278def GetKtraceStatus():
279    """ Get a string summary of the ktrace subsystem.
280    """
281    out = ''
282
283    state = kern.globals.ktrace_state
284    if state == GetEnumValue('ktrace_state_t::KTRACE_STATE_OFF'):
285        out += 'ktrace is off\n'
286    else:
287        out += 'ktrace is active ('
288        if state == GetEnumValue('ktrace_state_t::KTRACE_STATE_FG'):
289            out += 'foreground)'
290        else:
291            out += 'background)'
292        out += '\n'
293        owner = kern.globals.ktrace_last_owner_execname
294        owner_pid = kern.globals.ktrace_owning_pid
295        out += 'owned by: {:<s} [{}]\n'.format(owner, unsigned(owner_pid))
296        active_mask = kern.globals.ktrace_active_mask
297        out += 'active systems: {:<#x}\n'.format(active_mask)
298
299    return out
300
301
302def GetKtraceConfig():
303    kdebug_state = 0
304    if (kern.globals.kd_control_trace.kdc_flags & xnudefines.KDBG_BUFINIT) != 0:
305        kdebug_state = 1
306    if kern.globals.kdebug_enable:
307        kdebug_state = 3
308    kdebug_wrapping = True
309    if (kern.globals.kd_control_trace.kdc_live_flags & xnudefines.KDBG_NOWRAP):
310        kdebug_wrapping = False
311
312    kperf_state = 3 if (
313            unsigned(kern.globals.kperf_status) ==
314            GetEnumValue('kperf_sampling::KPERF_SAMPLING_ON')) else 0
315
316    action_count = kern.globals.actionc
317    actions = kern.globals.actionv
318    action_samplers = []
319    action_user_datas = []
320    action_pid_filters = []
321    for i in range(action_count):
322        action = actions[i]
323        action_samplers.append(unsigned(action.sample))
324        action_user_datas.append(unsigned(action.userdata))
325        action_pid_filters.append(unsigned(action.pid_filter))
326
327    timer_count = kern.globals.kptimer.g_ntimers
328    timers = kern.globals.kptimer.g_timers
329    timer_actions = []
330    timer_periods_ns = []
331
332    for i in range(timer_count):
333        timer = timers[i]
334        timer_actions.append(unsigned(timer.kt_actionid))
335        timer_periods_ns.append(
336            kern.GetNanotimeFromAbstime(unsigned(timer.kt_period_abs)))
337
338    pet_mode = 0
339    if kern.globals.kppet.g_lightweight:
340        pet_mode = 2
341    elif kern.globals.kptimer.g_pet_active:
342        pet_mode = 1
343
344    return {
345        'owner_name': str(kern.globals.ktrace_last_owner_execname),
346        'owner_kind': unsigned(kern.globals.ktrace_state),
347        'owner_pid': int(kern.globals.ktrace_owning_pid),
348
349        'kdebug_state': kdebug_state,
350        'kdebug_buffer_size': unsigned(kern.globals.kd_buffer_trace.kdb_event_count),
351        'kdebug_typefilter': plist_data(struct.pack('B', 0xff) * 4096 * 2), # XXX
352        'kdebug_procfilt_mode': 0, # XXX
353        'kdebug_procfilt': [], # XXX
354        'kdebug_wrapping': kdebug_wrapping,
355
356        'kperf_state': kperf_state,
357        'kperf_actions_sampler': action_samplers,
358        'kperf_actions_user_data': action_user_datas,
359        'kperf_actions_pid_filter': action_pid_filters,
360        'kperf_timers_action_id': timer_actions,
361        'kperf_timers_period_ns': timer_periods_ns,
362        'kperf_pet_mode': pet_mode,
363        'kperf_pet_timer_id': unsigned(kern.globals.kptimer.g_pet_timerid),
364        'kperf_pet_idle_rate': unsigned(kern.globals.kppet.g_idle_rate),
365
366        'kperf_kdebug_action_id': unsigned(kern.globals.kperf_kdebug_action),
367        'kperf_kdebug_filter': GetKperfKdebugFilterDescription(),
368
369        # XXX
370        'kpc_state': 0,
371        'kpc_classes': 0,
372        'kpc_thread_classes': 0,
373        'kpc_periods': [],
374        'kpc_action_ids': [],
375        'kpc_config': [],
376
377        'context_kind': 2, # backwards-facing
378        'reason': 'core file debugging',
379        'command': '(lldb) savekdebugtrace',
380        'trigger_kind': 2, # diagnostics trigger
381    }
382
383
384@lldb_command('showktrace')
385def ShowKtrace(cmd_args=None):
386    """ Show the current ktrace state, including subsystems.
387
388        usage: showktrace
389    """
390
391    print(GetKtraceStatus())
392    print(' ')
393    print('kdebug:')
394    print(GetKdebugStatus())
395    print(' ')
396    print('kperf:')
397    print(GetKperfStatus())
398
399
400class KDEvent(object):
401    """
402    Wrapper around kevent pointer that handles sorting logic.
403    """
404    def __init__(self, timestamp, kevent, cpu):
405        self.kevent = kevent
406        self.timestamp = timestamp
407        self.cpu = cpu
408
409    def get_kevent(self):
410        return self.kevent
411
412    def __eq__(self, other):
413        return self.timestamp == other.timestamp
414
415    def __lt__(self, other):
416        return self.timestamp < other.timestamp
417
418    def __gt__(self, other):
419        return self.timestamp > other.timestamp
420
421    def __hash__(self):
422        return hash(self.timestamp)
423
424
425class KDCPU(object):
426    """
427    Represents all events from a single CPU.
428    """
429    def __init__(self, cpuid, k64, verbose, starting_timestamp=None):
430        self.cpuid = cpuid
431        self.iter_store = None
432        self.k64 = k64
433        self.verbose = verbose
434        self.disabled = False
435        self.timestamp_mask = ((1 << 48) - 1) if not self.k64 else ~0
436        self.last_timestamp = 0
437
438        kdstoreinfo = kern.globals.kd_buffer_trace.kdb_info[cpuid]
439        self.kdstorep = kdstoreinfo.kd_list_head
440
441        if self.kdstorep.raw == xnudefines.KDS_PTR_NULL:
442            # Return no events and stop at first call to __next__.
443            return
444
445        self.iter_store = self.get_kdstore(self.kdstorep)
446        skipped_storage_count = 0
447        if starting_timestamp:
448            while True:
449                newest_event = addressof(self.iter_store.kds_records[xnudefines.EVENTS_PER_STORAGE_UNIT - 1])
450                timestamp = unsigned(newest_event.timestamp) & self.timestamp_mask
451                if timestamp >= starting_timestamp:
452                    if verbose:
453                        print('done skipping events at time {}'.format(timestamp))
454                    break
455                next_store = self.iter_store.kds_next
456                if next_store.raw == xnudefines.KDS_PTR_NULL:
457                    if verbose:
458                        print('found no valid events from CPU {}'.format(cpuid))
459                    self.iter_store = None
460                    return
461                self.iter_store = self.get_kdstore(next_store)
462                skipped_storage_count += 1
463        if verbose and skipped_storage_count > 0:
464            print('CPU {} skipped {} storage units'.format(
465                    cpuid, skipped_storage_count))
466
467        # XXX Doesn't have the same logic to avoid un-mergeable events
468        #     (respecting barrier_min and bufindx) as the C code.
469
470        self.iter_idx = self.iter_store.kds_readlast
471
472    def get_kdstore(self, kdstorep):
473        """
474        See POINTER_FROM_KDSPTR.
475        """
476        buf = kern.globals.kd_buffer_trace.kd_bufs[kdstorep.buffer_index]
477        return addressof(buf.kdr_addr[kdstorep.offset])
478
479    # Event iterator implementation returns KDEvent instance
480
481    def __iter__(self):
482        return self
483
484    def __next__(self):
485        # This CPU is out of events.
486        if self.iter_store is None or self.disabled:
487            raise StopIteration
488
489        if self.iter_idx == self.iter_store.kds_bufindx:
490            self.iter_store = None
491            raise StopIteration
492
493        keventp = addressof(self.iter_store.kds_records[self.iter_idx])
494        timestamp = unsigned(keventp.timestamp) & self.timestamp_mask
495        if self.last_timestamp == 0 and self.verbose:
496            print('first event from CPU {} is at time {}'.format(
497                    self.cpuid, timestamp))
498        self.last_timestamp = timestamp
499
500        # Check for writer overrun.
501        if timestamp < self.iter_store.kds_timestamp:
502            raise StopIteration
503
504        self.iter_idx += 1
505
506        if self.iter_idx == xnudefines.EVENTS_PER_STORAGE_UNIT:
507            snext = self.iter_store.kds_next
508            if snext.raw == xnudefines.KDS_PTR_NULL:
509                # Terminate iteration in next loop. Current element is the
510                # last one in this CPU buffer.
511                self.iter_store = None
512            else:
513                self.iter_store = self.get_kdstore(snext)
514                self.iter_idx = self.iter_store.kds_readlast
515
516        return KDEvent(timestamp, keventp, self)
517
518    # Python 2 compatibility
519    # pragma pylint: disable=next-method-defined
520    def next(self):
521        return self.__next__()
522
523
524def GetKdebugCPUName(cpu_id):
525    current_iop = kern.globals.kd_control_trace.kdc_coprocs
526    while current_iop:
527        if current_iop.cpu_id == cpu_id:
528            return '{}({})'.format(cpu_id, str(current_iop.full_name))
529        current_iop = current_iop.next
530    return '{}(unknown)'.format(cpu_id)
531
532
533def IterateKdebugEvents(verbose=False, humanize=False, last=None,
534        include_coprocessors=True):
535    """
536    Yield events from the in-memory kdebug trace buffers.
537    """
538    ctrl = kern.globals.kd_control_trace
539
540    if (ctrl.kdc_flags & xnudefines.KDBG_BUFINIT) == 0:
541        return
542
543    barrier_min = ctrl.kdc_oldest_time
544
545    if (ctrl.kdc_live_flags & xnudefines.KDBG_WRAPPED) != 0:
546        # TODO Yield a wrap event with the barrier_min timestamp.
547        pass
548
549    k64 = kern.ptrsize == 8
550
551    cpu_count = kern.globals.machine_info.logical_cpu_max
552    if include_coprocessors:
553        cpu_count = ctrl.kdebug_cpus
554
555    start_timestamp = None
556    if last is not None:
557        (numer, denom) = GetTimebaseInfo()
558        duration = (last * 1e9) * denom / numer
559        now = GetRecentTimestamp()
560        start_timestamp = unsigned(now - duration)
561        if verbose:
562            print('starting at time {} ({} - {})'.format(
563                    start_timestamp, now, duration))
564
565    # Merge sort all events from all CPUs.
566    cpus = [KDCPU(cpuid, k64, verbose, starting_timestamp=start_timestamp)
567            for cpuid in range(cpu_count)]
568    last_timestamp = 0
569    last_kevent = None
570    warned = False
571    for event in heapq.merge(*cpus):
572        if event.timestamp < last_timestamp and not warned:
573            # Human-readable output might have garbage on the rest of the line.
574            # Use a CSI escape sequence to clear it out.
575            clear_line_csi = '\033[K'
576            print((
577                    'warning: events from CPU {} are out-of-order, ' +
578                    'last CPU = {}, last timestamp = {}, ' +
579                    'current timestamp = {}, disabling').format(
580                    GetKdebugCPUName(event.get_kevent().cpuid),
581                    GetKdebugCPUName(last_kevent.cpuid), last_timestamp,
582                    event.timestamp), end=(
583                    (clear_line_csi + '\n') if humanize else '\n'))
584            warned = True
585            event.cpu.disabled = True
586            continue
587        last_timestamp = event.timestamp
588        last_kevent = event.get_kevent()
589        yield event.get_kevent()
590
591
592@header('{:>12s} {:>10s} {:>18s} {:>18s} {:>18s} {:>18s} {:>5s} {:>8s}'.format(
593        'timestamp', 'debugid', 'arg1', 'arg2', 'arg3', 'arg4', 'cpuid',
594        'tid'))
595def GetKdebugEvent(event, k64, symbolicate=False, O=None):
596    """
597    Return a string representing a kdebug trace event.
598    """
599    if k64:
600        timestamp = event.timestamp & ((1 << 48) - 1)
601        cpuid = event.timestamp >> 48
602    else:
603        timestamp = event.timestamp
604        cpuid = event.cpuid
605    def fmt_arg(a):
606        return '0x{:016x}'.format(unsigned(a))
607    def sym_arg(a):
608        slid_addr = kern.globals.vm_kernel_slide + unsigned(a)
609        syms = kern.SymbolicateFromAddress(slid_addr)
610        return syms[0].GetName() if syms else fmt_arg(a)
611    args = list(map(
612            sym_arg if symbolicate else fmt_arg,
613            [event.arg1, event.arg2, event.arg3, event.arg4]))
614    return O.format(
615            '{:12d} 0x{:08x} {:18s} {:18s} {:18s} {:18s} {:5d} {:8d}',
616            unsigned(timestamp), unsigned(event.debugid),
617            args[0], args[1], args[2], args[3], unsigned(cpuid),
618            unsigned(event.arg5))
619
620
621@lldb_command('showkdebugtrace', 'L:S', fancy=True)
622def ShowKdebugTrace(cmd_args=None, cmd_options={}, O=None):
623    """
624    List the events present in the kdebug trace buffers.
625
626    (lldb) showkdebugtrace [-S] [-L <last-seconds>]
627
628        -L <last-seconds>: only show events from the last <last-seconds> seconds
629        -S: attempt to symbolicate arguments as kernel addresses
630
631    Caveats:
632        * Events from IOPs may be missing or cut-off -- they weren't informed
633          of this kind of buffer collection.
634    """
635    k64 = kern.ptrsize == 8
636    last = cmd_options.get('-L', None)
637    if last:
638        try:
639            last = float(last)
640        except ValueError:
641            raise ArgumentError(
642                    'error: -L argument must be a number, not {}'.format(last))
643    with O.table(GetKdebugEvent.header):
644        for event in IterateKdebugEvents(
645                config['verbosity'] > vHUMAN, humanize=True, last=last):
646            print(GetKdebugEvent(
647                    event, k64, symbolicate='-S' in cmd_options, O=O))
648
649
650def binary_plist(o):
651    if PY2:
652        # Python 2 lacks a convenient binary plist writer.
653        with tempfile.NamedTemporaryFile(delete=False) as f:
654            plistlib.writePlist(o, f)
655            name = f.name
656
657        subprocess.check_output(['plutil', '-convert', 'binary1', name])
658        with open(name, mode='rb') as f:
659            plist = f.read()
660
661        os.unlink(name)
662        return plist
663    else:
664        return plistlib.dumps(o, fmt=plistlib.FMT_BINARY)
665
666
667def plist_data(d):
668    if PY2:
669        return plistlib.Data(d)
670    else:
671        return d
672
673
674def align_next_chunk(f, offset, verbose):
675    trailing = offset % 8
676    padding = 0
677    if trailing != 0:
678        padding = 8 - trailing
679        f.write(b'\x00' * padding)
680        if verbose:
681            print('aligned next chunk with {} padding bytes'.format(padding))
682    return padding
683
684
685def GetKtraceMachine():
686    """
687    This is best effort -- several fields are only available to user space or
688    are difficult to determine from a core file.
689    """
690    master_cpu_data = GetCpuDataForCpuID(0)
691    if kern.arch == 'x86_64':
692        cpu_family = unsigned(kern.globals.cpuid_cpu_info.cpuid_cpufamily)
693    else:
694        cpu_family = 0 # XXX
695
696    k64 = kern.ptrsize == 8
697    page_size = 4 * 4096 if k64 else 4096
698
699    return {
700        'kern_version': str(kern.globals.version),
701        'boot_args': '', # XXX
702        'hw_memsize': unsigned(kern.globals.max_mem),
703        'hw_pagesize': page_size, # XXX
704        'vm_pagesize': page_size, # XXX
705        'os_name': 'Unknown', # XXX
706        'os_version': 'Unknown', # XXX
707        'os_build': str(kern.globals.osversion),
708        'arch': 'Unknown', # XXX
709        'hw_model': 'Unknown', # XXX
710        'cpu_type': unsigned(master_cpu_data.cpu_type),
711        'cpu_subtype': unsigned(master_cpu_data.cpu_subtype),
712        'cpu_family': cpu_family,
713        'active_cpus': unsigned(kern.globals.processor_avail_count),
714        'max_cpus': unsigned(kern.globals.machine_info.logical_cpu_max),
715        'apple_internal': True, # XXX
716    }
717
718
719CHUNKHDR_PACK = 'IHHQ'
720
721
722def append_chunk(f, file_offset, tag, major, minor, data, verbose):
723    f.write(struct.pack(CHUNKHDR_PACK, tag, major, minor, len(data)))
724    f.write(data)
725    offset = 16 + len(data)
726    return offset + align_next_chunk(f, file_offset + offset, verbose)
727
728
729@lldb_command('savekdebugtrace', 'IL:MN:')
730def SaveKdebugTrace(cmd_args=None, cmd_options={}):
731    """
732    Save any valid ktrace events to a file.
733
734    (lldb) savekdebugtrace [-IM] [-N <n-events> | -L <last-secs>] <output-path>
735
736        -I: ignore coprocessor (IOP) events entirely
737        -L <last-seconds>: only save events from the <last-seconds> seconds
738        -N <n-events>: only save the last <n-events> events
739        -M: ensure output is machine-friendly
740
741    Tips:
742        * To speed up the process, use the -I and -L options to avoid
743          processing events based on source or time.
744
745    Caveats:
746        * Fewer than the requested number of events may end up in the file.
747        * The machine and config chunks may be missing crucial information
748          required for tools to analyze them.
749        * Events from coprocessors may be missing or cut-off -- they weren't
750          informed of this kind of buffer collection.
751        * Chunks related to post-processing, like symbolication data or a
752          catalog will need to be added manually.
753    """
754
755    k64 = kern.ptrsize == 8
756
757    if len(cmd_args) != 1:
758        raise ArgumentError('error: path to trace file is required')
759
760    last = cmd_options.get('-L', None)
761    if last and '-N' in cmd_options:
762        raise ArgumentError('error: -L and -N are mutually exclusive')
763    if last:
764        try:
765            last = float(last)
766        except ValueError:
767            raise ArgumentError(
768                    'error: -L argument must be a number, not {}'.format(last))
769
770    nevents = unsigned(kern.globals.kd_buffer_trace.kdb_event_count)
771    if nevents == 0:
772        print('error: kdebug buffers are not set up')
773        return
774
775    limit_nevents = nevents
776    if '-N' in cmd_options:
777        limit_nevents = unsigned(cmd_options['-N'])
778        if limit_nevents > nevents:
779            limit_nevents = nevents
780    verbose = config['verbosity'] > vHUMAN
781    humanize = '-M' not in cmd_options
782
783    file_offset = 0
784    with open(cmd_args[0], 'w+b') as f:
785        FILE_MAGIC = 0x55aa0300
786        EVENTS_TAG = 0x00001e00
787        SSHOT_TAG = 0x8002
788        CONFIG_TAG = 0x8006
789        MACHINE_TAG = 0x8c00
790        CHUNKHDR_PACK = 'IHHQ'
791        FILEHDR_PACK = CHUNKHDR_PACK + 'IIQQIIII'
792        FILEHDR_SIZE = 40
793        FUTURE_SIZE = 8
794
795        numer, denom = GetTimebaseInfo()
796
797        # XXX The kernel doesn't have a solid concept of the wall time.
798        wall_abstime = 0
799        wall_secs = 0
800        wall_usecs = 0
801
802        event_size = 64 if k64 else 32
803
804        file_hdr = struct.pack(
805                FILEHDR_PACK, FILE_MAGIC, 0, 0, FILEHDR_SIZE,
806                numer, denom, wall_abstime, wall_secs, wall_usecs, 0, 0,
807                0x1 if k64 else 0)
808        f.write(file_hdr)
809        header_size_offset = file_offset + 8
810        file_offset += 16 + FILEHDR_SIZE # chunk header plus file header
811
812        if verbose:
813            print('writing machine chunk at offset 0x{:x}'.format(file_offset))
814        machine_data = GetKtraceMachine()
815        machine_bytes = binary_plist(machine_data)
816        file_offset += append_chunk(
817                f, file_offset, MACHINE_TAG, 0, 0, machine_bytes, verbose)
818
819        if verbose:
820            print('writing config chunk at offset 0x{:x}'.format(file_offset))
821        config_data = GetKtraceConfig()
822        config_bytes = binary_plist(config_data)
823        file_offset += append_chunk(
824                f, file_offset, CONFIG_TAG, 0, 0, config_bytes, verbose)
825
826        events_hdr = struct.pack(
827                CHUNKHDR_PACK, EVENTS_TAG, 0, 0, 0) # size will be filled in later
828        f.write(events_hdr)
829        file_offset += 16 # header size
830        event_size_offset = file_offset - FUTURE_SIZE
831        # Future events timestamp -- doesn't need to be set for merged events.
832        f.write(struct.pack('Q', 0))
833        file_offset += FUTURE_SIZE
834
835        if verbose:
836            print('events start at offset 0x{:x}'.format(file_offset))
837
838        process = LazyTarget().GetProcess()
839        error = lldb.SBError()
840
841        skip_nevents = nevents - limit_nevents if limit_nevents else 0
842        if skip_nevents > 0:
843            print('omitting {} events from the beginning'.format(skip_nevents))
844
845        written_nevents = 0
846        seen_nevents = 0
847        start_time = time.time()
848        update_every = 1000 if humanize else 25000
849        for event in IterateKdebugEvents(
850                verbose, include_coprocessors='-I' not in cmd_options,
851                humanize=humanize, last=last):
852            seen_nevents += 1
853            if skip_nevents >= seen_nevents:
854                if seen_nevents % update_every == 0:
855                    sys.stderr.write('skipped {}/{} ({:4.2f}%) events'.format(
856                            seen_nevents, skip_nevents,
857                            float(seen_nevents) / skip_nevents * 100.0))
858                    sys.stderr.write('\r')
859
860                continue
861
862            event = process.ReadMemory(
863                    unsigned(event), event_size, error)
864            file_offset += event_size
865            f.write(event)
866            written_nevents += 1
867            # Periodically update the CLI with progress.
868            if written_nevents % update_every == 0:
869                sys.stderr.write('{}: wrote {}/{} ({:4.2f}%) events'.format(
870                        time.strftime('%H:%M:%S'), written_nevents,
871                        limit_nevents,
872                        float(written_nevents) / nevents * 100.0))
873                if humanize:
874                    sys.stderr.write('\r')
875                else:
876                    sys.stderr.write('\n')
877        sys.stderr.write('\n')
878        elapsed = time.time() - start_time
879        print('wrote {} ({}MB) events in {:.3f}s'.format(
880                written_nevents, written_nevents * event_size >> 20, elapsed))
881        if verbose:
882            print('events end at offset 0x{:x}'.format(file_offset))
883
884        # Normally, the chunk would need to be padded to 8, but events are
885        # already aligned.
886
887        kcdata = kern.globals.kc_panic_data
888        kcdata_addr = unsigned(kcdata.kcd_addr_begin)
889        kcdata_length = unsigned(kcdata.kcd_length)
890        if kcdata_addr != 0 and kcdata_length != 0:
891            print('writing stackshot')
892            if verbose:
893                print('stackshot is 0x{:x} bytes at offset 0x{:x}'.format(
894                        kcdata_length, file_offset))
895            ssdata = process.ReadMemory(kcdata_addr, kcdata_length, error)
896            magic = struct.unpack('I', ssdata[:4])
897            if magic[0] == GetTypeForName('KCDATA_BUFFER_BEGIN_COMPRESSED'):
898                if verbose:
899                    print('found compressed stackshot')
900                iterator = kcdata_item_iterator(ssdata)
901                for item in iterator:
902                    kcdata_buffer = KCObject.FromKCItem(item)
903                    if isinstance(kcdata_buffer, KCCompressedBufferObject):
904                        kcdata_buffer.ReadItems(iterator)
905                        decompressed = kcdata_buffer.Decompress(ssdata)
906                        ssdata = decompressed
907                        kcdata_length = len(ssdata)
908                        if verbose:
909                            print(
910                                    'compressed stackshot is 0x{:x} bytes long'.
911                                    format(kcdata_length))
912
913            file_offset += append_chunk(
914                    f, file_offset, SSHOT_TAG, 1, 0, ssdata, verbose)
915            if verbose:
916                print('stackshot ends at offset 0x{:x}'.format(file_offset))
917        else:
918            print('warning: no stackshot; trace file may not be usable')
919
920        # After the number of events is known, fix up the events chunk size.
921        events_data_size = unsigned(written_nevents * event_size) + FUTURE_SIZE
922        f.seek(event_size_offset)
923        f.write(struct.pack('Q', events_data_size))
924        if verbose:
925            print('wrote {:x} bytes at offset 0x{:x} for event size'.format(
926                    events_data_size, event_size_offset))
927
928        # Fix up the size of the header chunks, too.
929        f.seek(header_size_offset)
930        f.write(struct.pack('Q', FILEHDR_SIZE + 16 + len(machine_bytes)))
931        if verbose:
932            print((
933                    'wrote 0x{:x} bytes at offset 0x{:x} for ' +
934                    'file header size').format(
935                    len(machine_bytes), header_size_offset))
936
937    return
938
939# Obsolete commands.
940
941@lldb_command('showkerneldebugbuffercpu')
942def ShowKernelDebugBufferCPU(cmd_args=None):
943    """ REMOVED: Use showkdebugtrace instead. """
944    raise NotImplementedError("Use showkdebugtrace instead")
945
946
947@lldb_command('showkerneldebugbuffer')
948def ShowKernelDebugBuffer(cmd_args=None):
949    """ REMOVED: Use showkdebugtrace instead. """
950    raise NotImplementedError("Use showkdebugtrace instead")
951
952
953@lldb_command('dumprawtracefile')
954def DumpRawTraceFile(cmd_args=[], cmd_options={}):
955    """ REMOVED: Use savekdebugtrace instead. """
956    raise NotImplementedError("Use savekdebugtrace instead")
957
958
959