1from __future__ import absolute_import, division, print_function 2 3from xnu import * 4 5 6def validate_args(opts, valid_flags): 7 valid_flags = set(valid_flags) 8 for k in opts.keys(): 9 if k[1:] not in valid_flags: 10 raise ArgumentError('-{} not supported in subcommand'.format(k)) 11 12 13@lldb_command('recount', 'AF:MT', fancy=True) 14def Recount(cmd_args=None, cmd_options={}, O=None): # noqa: E741 15 """ Inspect counters maintained by the Recount subsystem on various resource 16 aggregators, like tasks or threads. 17 18 recount task [-TM] <task_t> [...] | -F <task_name> 19 recount thread [-M] <thread_t> [...] 20 recount coalition [-M] <coalition_t> [...] 21 recount processor [-ATM] [<processor_t-or-cpu-id>] [...] 22 23 Options: 24 -T : break out active threads for a task or processor 25 -M : show times in the Mach timebase 26 -A : show all processors 27 28 Diagnostic macros: 29 recount diagnose task <task_t> 30 - Ensure resource accounting consistency in a task. 31 recount triage 32 - Print out statistics useful for general panic triage. 33 34 """ 35 if not cmd_args: 36 raise ArgumentError('subcommand required') 37 38 if cmd_args[0] == 'coalition': 39 validate_args(cmd_options, ['M']) 40 RecountCoalition(cmd_args[1:], cmd_options=cmd_options, O=O) 41 elif cmd_args[0] == 'task': 42 validate_args(cmd_options, ['F', 'M', 'T']) 43 RecountTask(cmd_args[1:], cmd_options=cmd_options, O=O) 44 elif cmd_args[0] == 'thread': 45 validate_args(cmd_options, ['M']) 46 RecountThread(cmd_args[1:], cmd_options=cmd_options, O=O) 47 elif cmd_args[0] == 'processor': 48 validate_args(cmd_options, ['A', 'M', 'T']) 49 RecountProcessor(cmd_args[1:], cmd_options=cmd_options, O=O) 50 elif cmd_args[0] == 'diagnose': 51 RecountDiagnose(cmd_args[1:], cmd_options=cmd_options, O=O) 52 elif cmd_args[0] == 'triage': 53 validate_args(cmd_options, []) 54 RecountTriage(cmd_options=cmd_options, O=O) 55 else: 56 raise ArgumentError('{}: invalid subcommand'.format(cmd_args[0])) 57 58 59def scale_suffix(val, unit=''): 60 si_units = [ 61 (1e21, 'Z'), (1e18, 'E'), (1e15, 'P'), (1e12, 'T'), (1e9, 'B'), 62 (1e6, 'M'), (1e3, 'k'), (1, ' '), (1e-3, 'm'), (1e-6, 'u'), 63 (1e-9, 'n')] 64 scale, sfx = (1, '') 65 for (si_scale, si_sfx) in si_units: 66 if val >= si_scale: 67 scale, sfx = (si_scale, si_sfx) 68 break 69 return '{:>7.3f}{:<1s}{}'.format(val / scale, sfx, unit) 70 71 72class RecountSum(object): 73 """ 74 Accumulate usage counters. 75 """ 76 77 def __init__(self, mach_times=False): 78 self._mach_times = mach_times 79 self._user_time_mach = 0 80 self._system_time_mach = 0 81 self._instructions = 0 82 self._cycles = 0 83 self._energy_nj = 0 84 self._valid_count = 0 85 86 def add_usage(self, usage): 87 self._user_time_mach += unsigned(usage.ru_user_time_mach) 88 self._system_time_mach += unsigned(usage.ru_system_time_mach) 89 if hasattr(usage, 'ru_cycles'): 90 self._instructions += unsigned(usage.ru_instructions) 91 self._cycles += unsigned(usage.ru_cycles) 92 if unsigned(usage.ru_cycles) != 0: 93 self._valid_count += 1 94 if hasattr(usage, 'ru_energy_nj'): 95 self._energy_nj += unsigned(usage.ru_energy_nj) 96 97 def user_sys_times(self): 98 return (self._user_time_mach, self._system_time_mach) 99 100 def div_valid(self, numer, denom): 101 if self._valid_count == 0 or denom == 0: 102 return 0 103 return numer / denom 104 105 def _convert_time(self, time): 106 if self._mach_times: 107 return time 108 return kern.GetNanotimeFromAbstime(time) / 1e9 109 110 def fmt_args(self): 111 time_ns = kern.GetNanotimeFromAbstime( 112 self._system_time_mach + self._user_time_mach) 113 power_w = self._energy_nj / time_ns if time_ns != 0 else 0 114 return [ 115 self._convert_time(self._system_time_mach), 116 self._convert_time(self._user_time_mach), 117 scale_suffix(self._cycles), 118 self.div_valid(self._cycles, time_ns), 119 scale_suffix(self._instructions), 120 self.div_valid(self._cycles, self._instructions), 121 scale_suffix(self._energy_nj / 1e9, 'J'), 122 scale_suffix(power_w, 'W')] 123 124 def fmt_basic_args(self): 125 return [ 126 self._convert_time(self._system_time_mach), 127 self._convert_time(self._user_time_mach), 128 self._cycles, 129 self._instructions, 130 self._energy_nj / 1e9] 131 132 133 134class RecountPlan(object): 135 """ 136 Format tracks and usage according to a plan. 137 """ 138 139 def __init__(self, name, mach_times=False): 140 self._mach_times = mach_times 141 self._group_names = [] 142 self._group_column = None 143 144 plan = kern.GetGlobalVariable('recount_' + name + '_plan') 145 topo = plan.rpl_topo 146 if topo == GetEnumValue('recount_topo_t::RCT_TOPO_CPU'): 147 self._group_column = 'cpu' 148 self._group_count = unsigned(kern.globals.real_ncpus) 149 self._group_names = [ 150 'cpu-{}'.format(i) for i in range(self._group_count)] 151 elif topo == GetEnumValue('recount_topo_t::RCT_TOPO_CPU_KIND'): 152 if kern.arch.startswith('arm64'): 153 self._group_column = 'cpu-kind' 154 cluster_mask = int(kern.globals.topology_info.cluster_types) 155 self._group_count = bin(cluster_mask).count('1') 156 self._group_names = [ 157 GetEnumName('recount_cpu_kind_t', i)[8:][:4] 158 for i in range(self._group_count)] 159 else: 160 self._group_count = 1 161 elif topo == GetEnumValue('recount_topo_t::RCT_TOPO_SYSTEM'): 162 self._group_count = 1 163 else: 164 raise RuntimeError('{}: Unexpected recount topography', topo) 165 166 def time_fmt(self): 167 return '{:>12d}' if self._mach_times else '{:>12.05f}' 168 169 def _usage_fmt(self): 170 prefix = '{n}{t} {t}'.format( 171 t=self.time_fmt(), n='{:>8s} ' if self._group_column else '') 172 return prefix + ' {:>8s} {:>7.3g} {:>8s} {:>5.03f} {:>9s} {:>9s}' 173 174 def usages(self, usages): 175 for i in range(self._group_count): 176 yield usages[i] 177 178 def track_usages(self, tracks): 179 for i in range(self._group_count): 180 yield tracks[i].rt_usage 181 182 def usage_header(self): 183 fmt = '{:>12s} {:>12s} {:>8s} {:>7s} {:>8s} {:>5s} {:>9s} {:>9s}'.format( 184 'sys-time', 'user-time', 'cycles', 'GHz', 'insns', 'CPI', 185 'energy', 'power',) 186 if self._group_column: 187 fmt = '{:>8s} '.format(self._group_column) + fmt 188 return fmt 189 190 def format_usage(self, usage, name=None, sum=None, O=None): 191 usr_time = unsigned(usage.ru_user_time_mach) 192 usr_time_ns = kern.GetNanotimeFromAbstime(usr_time) 193 sys_time = unsigned(usage.ru_system_time_mach) 194 sys_time_ns = kern.GetNanotimeFromAbstime(sys_time) 195 all_time_ns = usr_time_ns + sys_time_ns 196 if not self._mach_times: 197 usr_time = usr_time_ns / 1e9 198 if not self._mach_times: 199 sys_time = sys_time_ns / 1e9 200 if hasattr(usage, 'ru_cycles'): 201 cycles = unsigned(usage.ru_cycles) 202 freq = cycles / all_time_ns if all_time_ns != 0 else 0 203 insns = unsigned(usage.ru_instructions) 204 cpi = cycles / insns if insns != 0 else 0 205 else: 206 cycles = 0 207 freq = 0 208 insns = 0 209 cpi = 0 210 if hasattr(usage, 'ru_energy_nj'): 211 energy_nj = unsigned(usage.ru_energy_nj) 212 time_ns = usr_time_ns + sys_time_ns 213 if time_ns != 0: 214 power_w = energy_nj / time_ns 215 else: 216 power_w = 0 217 else: 218 energy_nj = 0 219 power_w = 0 220 if sum: 221 sum.add_usage(usage) 222 223 args = [ 224 sys_time, usr_time, scale_suffix(cycles), freq, 225 scale_suffix(insns), cpi, scale_suffix(energy_nj / 1e9, 'J'), 226 scale_suffix(power_w, 'W')] 227 if self._group_column: 228 args.insert(0, name) 229 230 return O.format(self._usage_fmt(), *args) 231 232 def format_sum(self, sum, O=None): 233 return O.format(self._usage_fmt(), '*', *sum.fmt_args()) 234 235 def format_usages(self, usages, O=None): # noqa: E741 236 sum = RecountSum(self._mach_times) if self._group_count > 1 else None 237 str = '' 238 for (i, usage) in enumerate(self.usages(usages)): 239 name = self._group_names[i] if i < len(self._group_names) else None 240 str += self.format_usage(usage, name=name, sum=sum, O=O) + '\n' 241 if sum: 242 str += self.format_sum(sum, O=O) 243 return str 244 245 def format_tracks(self, tracks, newlines=True, O=None): # noqa: E741 246 sum = RecountSum(self._mach_times) if self._group_count > 1 else None 247 str = '' 248 nl = '\n' if newlines else '' 249 for (i, usage) in enumerate(self.track_usages(tracks)): 250 name = self._group_names[i] if i < len(self._group_names) else None 251 str += self.format_usage(usage, name=name, sum=sum, O=O) + nl 252 if sum: 253 str += self.format_sum(sum, O=O) 254 return str 255 256 def sum_usages(self, usages, sum=None): 257 if sum is None: 258 sum = RecountSum(mach_times=self._mach_times) 259 for usage in self.usages(usages): 260 sum.add_usage(usage) 261 return sum 262 263 def sum_tracks(self, tracks, sum=None): 264 if sum is None: 265 sum = RecountSum(mach_times=self._mach_times) 266 for usage in self.track_usages(tracks): 267 sum.add_usage(usage) 268 return sum 269 270 271def GetTaskTerminatedUserSysTime(task): 272 plan = RecountPlan('task_terminated') 273 sum = RecountSum() 274 for usage in plan.usages(task.tk_recount.rtk_terminated): 275 sum.add_usage(usage) 276 return sum.user_sys_times() 277 278 279def GetThreadUserSysTime(thread): 280 plan = RecountPlan('thread') 281 sum = RecountSum() 282 for usage in plan.track_usages(thread.th_recount.rth_lifetime): 283 sum.add_usage(usage) 284 return sum.user_sys_times() 285 286 287def print_threads(plan, thread_ptrs, indent=False, O=None): # noqa: E741 288 for thread_ptr in thread_ptrs: 289 thread = kern.GetValueFromAddress(thread_ptr, 'thread_t') 290 print('{}thread 0x{:x} 0x{:x} {}'.format( 291 ' ' if indent else '', unsigned(thread.thread_id), 292 unsigned(thread), GetThreadName(thread))) 293 with O.table(plan.usage_header(), indent=indent): 294 print(plan.format_tracks(thread.th_recount.rth_lifetime, O=O)) 295 296 297def RecountThread( 298 thread_ptrs, cmd_options={}, indent=False, O=None): # noqa: E741 299 plan = RecountPlan('thread', mach_times='-M' in cmd_options) 300 print_threads(plan, thread_ptrs, indent=indent, O=O) 301 302 303def get_task_age_ns(task): 304 start_abs = GetProcStartAbsTimeForTask(task) 305 if start_abs is not None: 306 return kern.GetNanotimeFromAbstime(GetRecentTimestamp() - start_abs) 307 return None 308 309 310def print_task_description(task): 311 task_name = GetProcNameForTask(task) 312 task_age_ns = get_task_age_ns(task) 313 if task_age_ns is not None: 314 duration_desc = '{:.3f}s'.format(task_age_ns / 1e9) 315 else: 316 duration_desc = '-s' 317 print('task 0x{:x} {} ({} old)'.format( 318 unsigned(task), task_name, duration_desc)) 319 return task_name 320 321 322def RecountTask(task_ptrs, cmd_options={}, O=None): # noqa: E741 323 if '-F' in cmd_options: 324 tasks = FindTasksByName(cmd_options['-F']) 325 else: 326 tasks = [kern.GetValueFromAddress(t, 'task_t') for t in task_ptrs] 327 mach_times = '-M' in cmd_options 328 plan = RecountPlan('task', mach_times=mach_times) 329 terminated_plan = RecountPlan('task_terminated', mach_times=mach_times) 330 active_threads = '-T' in cmd_options 331 if active_threads: 332 thread_plan = RecountPlan('thread', mach_times=mach_times) 333 for task in tasks: 334 task_name = print_task_description(task) 335 with O.table(plan.usage_header()): 336 print(plan.format_tracks(task.tk_recount.rtk_lifetime, O=O)) 337 if active_threads: 338 threads = [unsigned(t) for t in IterateQueue( 339 task.threads, 'thread *', 'task_threads')] 340 print_threads(thread_plan, threads, indent=True, O=O) 341 print('task (terminated threads) 0x{:x} {}'.format( 342 unsigned(task), task_name)) 343 with O.table(terminated_plan.usage_header()): 344 print(terminated_plan.format_usages( 345 task.tk_recount.rtk_terminated, O=O)) 346 347 348def RecountCoalition(coal_ptrs, cmd_options={}, O=None): # noqa: E741 349 plan = RecountPlan('coalition', mach_times='-M' in cmd_options) 350 coals = [kern.GetValueFromAddress(c, 'coalition_t') for c in coal_ptrs] 351 for coal in coals: 352 print('coalition 0x{:x} {}'.format(unsigned(coal), unsigned(coal.id))) 353 with O.table(plan.usage_header()): 354 print(plan.format_usages(coal.r.co_recount.rco_exited, O=O)) 355 356 357def get_processor(ptr_or_id): 358 ptr_or_id = unsigned(ptr_or_id) 359 if ptr_or_id < 1024: 360 processor_list = kern.GetGlobalVariable('processor_list') 361 current_processor = processor_list 362 while unsigned(current_processor) > 0: 363 if unsigned(current_processor.cpu_id) == ptr_or_id: 364 return current_processor 365 current_processor = current_processor.processor_list 366 raise ArgumentError('no processor found with CPU ID {}'.format( 367 ptr_or_id)) 368 else: 369 return kern.GetValueFromAddress(ptr_or_id, 'processor_t') 370 371 372def get_all_processors(): 373 processors = [] 374 processor_list = kern.GetGlobalVariable('processor_list') 375 current_processor = processor_list 376 while unsigned(current_processor) > 0: 377 processors.append(current_processor) 378 current_processor = current_processor.processor_list 379 return sorted(processors, key=lambda p: p.cpu_id) 380 381 382def RecountProcessor(pr_ptrs_or_ids, cmd_options={}, O=None): # noqa: E741 383 mach_times = '-M' in cmd_options 384 plan = RecountPlan('processor', mach_times=mach_times) 385 if '-A' in cmd_options: 386 prs = get_all_processors() 387 else: 388 prs = [get_processor(p) for p in pr_ptrs_or_ids] 389 active_threads = '-T' in cmd_options 390 if active_threads: 391 thread_plan = RecountPlan('thread', mach_times=mach_times) 392 hdr_prefix = '{:>18s} {:>4s} {:>4s} '.format('processor', 'cpu', 'kind',) 393 hdr_suffix = ' {:>12s} {:>12s} {:>8s}'.format( 394 'idle-time', 'total-time', 'idle-pct') 395 with O.table(hdr_prefix + plan.usage_header() + hdr_suffix): 396 for pr in prs: 397 usage = pr.pr_recount.rpr_active.rt_usage 398 idle_time = pr.pr_recount.rpr_idle_time_mach 399 total_time = ( 400 usage.ru_system_time_mach + usage.ru_user_time_mach + 401 idle_time) 402 if not mach_times: 403 idle_time = kern.GetNanotimeFromAbstime(idle_time) / 1e9 404 total_time = kern.GetNanotimeFromAbstime(total_time) / 1e9 405 kind = 'SMP' 406 pset = pr.processor_set 407 if unsigned(pset.pset_cluster_type) == 1: 408 kind = 'E' 409 elif unsigned(pset.pset_cluster_type) == 2: 410 kind = 'P' 411 412 prefix = '{:<#018x} {:>4d} {:>4s} '.format( 413 unsigned(pr), pr.cpu_id, kind) 414 suffix = ( 415 ' ' + plan.time_fmt().format(idle_time) + ' ' + 416 plan.time_fmt().format(total_time) + 417 ' {:>7.2f}%'.format(idle_time / total_time * 100)) 418 O.write(prefix + plan.format_usage(usage, O=O) + suffix + '\n') 419 if active_threads: 420 active_thread = unsigned(pr.active_thread) 421 if active_thread != 0: 422 print_threads( 423 thread_plan, [active_thread], indent=True, O=O) 424 425 426@header('{:>4s} {:>20s} {:>20s} {:>20s}'.format( 427 'cpu', 'time-mach', 'cycles', 'insns')) 428def GetRecountSnapshot(cpu, snap, O=None): 429 (insns, cycles) = (0, 0) 430 if hasattr(snap, 'rsn_cycles'): 431 (insns, cycles) = (snap.rsn_insns, snap.rsn_cycles) 432 return O.format( 433 '{:4d} {:20d} {:20d} {:20d}', cpu, snap.rsn_time_mach, 434 cycles, insns) 435 436 437def GetRecountProcessorState(pr): 438 state_time = pr.pr_recount.rpr_state_last_abs_time 439 state = state_time >> 63 440 return ( 441 pr.pr_recount.rpr_snap, 442 'I' if state == 1 else 'A', 443 state_time & ~(0x1 << 63)) 444 445 446@header('{:>20s} {:>4s} {:>6s} {:>18s} {:>18s} {:>18s} {:>18s} {:>18s}'.format( 447 'processor', 'cpu', 'state', 'last-idle-change', 'last-user-change', 448 'last-disp', 'since-idle-change', 'since-user-change')) 449def GetRecountProcessorDiagnostics(pr, cur_time, O=None): 450 (snap, state, time) = GetRecountProcessorState(pr) 451 cpu_id = unsigned(pr.cpu_id) 452 last_usrchg = snap.rsn_time_mach 453 since_usrchg = cur_time - last_usrchg 454 last_disp = '{}{:>d}'.format( 455 '*' if cur_time == unsigned(pr.last_dispatch) else '', 456 pr.last_dispatch) 457 return O.format( 458 '{:>#20x} {:4d} {:>6s} {:>18d} {:>18d} {:>18s} {:>18d} {:>18d}', 459 unsigned(pr), cpu_id, state, time, last_usrchg, last_disp, 460 cur_time - time, since_usrchg) 461 462 463@header('{:>12s} {:>12s} {:>12s} {:>20s} {:>20s} {:>12s}'.format( 464 'group', 'sys-time', 'user-time', 'cycles', 'insns', 'energy')) 465def RecountDiagnoseTask(task_ptrs, cmd_options={}, O=None): # noqa: E74 466 if '-F' in cmd_options: 467 tasks = FindTasksByName(cmd_options['-F']) 468 else: 469 tasks = [kern.GetValueFromAddress(t, 'task_t') for t in task_ptrs] 470 471 line_fmt = '{:12s} = {:10.3f}' 472 row_fmt = '{:>12s} {:>12.3f} {:>12.3f} {:>20d} {:20d} {:12.3f}' 473 474 task_plan = RecountPlan('task', mach_times=False) 475 term_plan = RecountPlan('task_terminated', mach_times=False) 476 thread_plan = RecountPlan('thread', mach_times=False) 477 for task in tasks: 478 print_task_description(task) 479 with O.table(RecountDiagnoseTask.header): 480 task_sum = task_plan.sum_tracks(task.tk_recount.rtk_lifetime) 481 print(O.format(row_fmt, 'task', *task_sum.fmt_basic_args())) 482 483 term_sum = term_plan.sum_usages(task.tk_recount.rtk_terminated) 484 print(O.format(row_fmt, 'terminated', *term_sum.fmt_basic_args())) 485 486 threads_sum = RecountSum(mach_times=False) 487 for thread in IterateQueue(task.threads, 'thread *', 'task_threads'): 488 usr_time, sys_time = GetThreadUserSysTime(thread) 489 threads_sum_mach += usr_time + sys_time 490 491 threads_sum_ns = kern.GetNanotimeFromAbstime(threads_sum_mach) 492 print(line_fmt.format('threads CPU', threads_sum_ns / 1e9)) 493 494 all_threads_sum_ns = threads_sum_ns + terminated_threads_sum_ns 495 print(line_fmt.format('all threads CPU', all_threads_sum_ns / 1e9)) 496 497 print(line_fmt.format('discrepancy', task_sum_ns - all_threads_sum_ns)) 498 499 500def RecountDiagnose(cmd_args=[], cmd_options={}, O=None): # noqa: E741 501 if not cmd_args: 502 raise ArgumentError('diagnose subcommand required') 503 504 if cmd_args[0] == 'task': 505 validate_args(cmd_options, ['F']) 506 RecountDiagnoseTask(cmd_args[0], cmd_options=cmd_options, O=O) 507 else: 508 raise ArgumentError('{}: invalid diagnose subcommand'.format( 509 cmd_args[0])) 510 511 512def RecountTriage(cmd_options={}, O=None): # noqa: E741 513 prs = get_all_processors() 514 print('processors') 515 with O.table(GetRecountProcessorDiagnostics.header, indent=True): 516 max_dispatch = max([unsigned(pr.last_dispatch) for pr in prs]) 517 for pr in prs: 518 print(GetRecountProcessorDiagnostics( 519 pr, cur_time=max_dispatch, O=O)) 520 521 print('snapshots') 522 with O.table(GetRecountSnapshot.header, indent=True): 523 for (i, pr) in enumerate(prs): 524 print(GetRecountSnapshot(i, pr.pr_recount.rpr_snap, O=O)) 525