1from __future__ import absolute_import, division, print_function 2 3from builtins import hex, range 4from future.utils import raise_ 5import six 6from xnu import * 7from utils import * 8from process import * 9from misc import * 10from memory import * 11from ipc import * 12 13# TODO: write scheduler related macros here 14 15# Macro: showallprocrunqcount 16 17@lldb_command('showallprocrunqcount') 18def ShowAllProcRunQCount(cmd_args=None): 19 """ Prints out the runq count for all processors 20 """ 21 out_str = "Processor\t# Runnable\n" 22 processor_itr = kern.globals.processor_list 23 while processor_itr: 24 out_str += "{:d}\t\t{:d}\n".format(processor_itr.cpu_id, processor_itr.runq.count) 25 processor_itr = processor_itr.processor_list 26 # out_str += "RT:\t\t{:d}\n".format(kern.globals.rt_runq.count) 27 print(out_str) 28 29# EndMacro: showallprocrunqcount 30 31# Macro: showinterrupts 32 33@lldb_command('showinterrupts') 34def ShowInterrupts(cmd_args=None): 35 """ Prints IRQ, IPI and TMR counts for each CPU 36 """ 37 38 if not kern.arch.startswith('arm'): 39 print("showinterrupts is only supported on arm/arm64") 40 return 41 42 base_address = kern.GetLoadAddressForSymbol('CpuDataEntries') 43 struct_size = 16 44 x = 0 45 y = 0 46 while x < unsigned(kern.globals.machine_info.physical_cpu): 47 element = kern.GetValueFromAddress(base_address + (y * struct_size), 'uintptr_t *')[1] 48 if element: 49 cpu_data_entry = Cast(element, 'cpu_data_t *') 50 print("CPU {} IRQ: {:d}\n".format(y, cpu_data_entry.cpu_stat.irq_ex_cnt)) 51 print("CPU {} IPI: {:d}\n".format(y, cpu_data_entry.cpu_stat.ipi_cnt)) 52 print("CPU {} PMI: {:d}\n".format(y, cpu_data_entry.cpu_monotonic.mtc_npmis)) 53 print("CPU {} TMR: {:d}\n".format(y, cpu_data_entry.cpu_stat.timer_cnt)) 54 x = x + 1 55 y = y + 1 56 57# EndMacro: showinterrupts 58 59# Macro: showactiveinterrupts 60 61@lldb_command('showactiveinterrupts') 62def ShowActiveInterrupts(cmd_args=None): 63 """ Prints the interrupts that are unmasked & active with the Interrupt Controller 64 Usage: showactiveinterrupts <address of Interrupt Controller object> 65 """ 66 if not cmd_args: 67 print("No arguments passed") 68 print(ShowActiveInterrupts.__doc__) 69 return False 70 aic = kern.GetValueFromAddress(cmd_args[0], 'AppleInterruptController *') 71 if not aic: 72 print("unknown arguments:", str(cmd_args)) 73 return False 74 75 aic_base = unsigned(aic._aicBaseAddress) 76 current_interrupt = 0 77 aic_imc_base = aic_base + 0x4180 78 aic_him_offset = 0x80 79 current_pointer = aic_imc_base 80 unmasked = dereference(kern.GetValueFromAddress(current_pointer, 'uintptr_t *')) 81 active = dereference(kern.GetValueFromAddress(current_pointer + aic_him_offset, 'uintptr_t *')) 82 group_count = 0 83 mask = 1 84 while current_interrupt < 192: 85 if (((unmasked & mask) == 0) and (active & mask)): 86 print("Interrupt {:d} unmasked and active\n".format(current_interrupt)) 87 current_interrupt = current_interrupt + 1 88 if (current_interrupt % 32 == 0): 89 mask = 1 90 group_count = group_count + 1 91 unmasked = dereference(kern.GetValueFromAddress(current_pointer + (4 * group_count), 'uintptr_t *')) 92 active = dereference(kern.GetValueFromAddress((current_pointer + aic_him_offset) + (4 * group_count), 'uintptr_t *')) 93 else: 94 mask = mask << 1 95# EndMacro: showactiveinterrupts 96 97# Macro: showirqbyipitimerratio 98@lldb_command('showirqbyipitimerratio') 99def ShowIrqByIpiTimerRatio(cmd_args=None): 100 """ Prints the ratio of IRQ by sum of IPI & TMR counts for each CPU 101 """ 102 if kern.arch == "x86_64": 103 print("This macro is not supported on x86_64 architecture") 104 return 105 106 out_str = "IRQ-IT Ratio: " 107 base_address = kern.GetLoadAddressForSymbol('CpuDataEntries') 108 struct_size = 16 109 x = 0 110 y = 0 111 while x < unsigned(kern.globals.machine_info.physical_cpu): 112 element = kern.GetValueFromAddress(base_address + (y * struct_size), 'uintptr_t *')[1] 113 if element: 114 cpu_data_entry = Cast(element, 'cpu_data_t *') 115 out_str += " CPU {} [{:.2f}]".format(y, float(cpu_data_entry.cpu_stat.irq_ex_cnt)/(cpu_data_entry.cpu_stat.ipi_cnt + cpu_data_entry.cpu_stat.timer_cnt)) 116 x = x + 1 117 y = y + 1 118 print(out_str) 119 120# EndMacro: showirqbyipitimerratio 121 122#Macro: showinterruptsourceinfo 123@lldb_command('showinterruptsourceinfo') 124def showinterruptsourceinfo(cmd_args = None): 125 """ Extract information of interrupt source causing interrupt storms. 126 """ 127 if not cmd_args: 128 print("No arguments passed") 129 return False 130 #Dump IOInterruptVector object 131 print("--- Dumping IOInterruptVector object ---\n") 132 object_info = lldb_run_command("dumpobject {:s} IOInterruptVector".format(cmd_args[0])) 133 print(object_info) 134 print("--- Dumping IOFilterInterruptEventSource object ---\n") 135 #Dump the IOFilterInterruptEventSource object. 136 target_info=re.search('target =\s+(.*)',object_info) 137 target= target_info.group() 138 target= target.split() 139 #Dump the Object pointer of the source who is triggering the Interrupts. 140 vector_info=lldb_run_command("dumpobject {:s} ".format(target[2])) 141 print(vector_info) 142 owner_info= re.search('owner =\s+(.*)',vector_info) 143 owner= owner_info.group() 144 owner= owner.split() 145 print("\n\n") 146 out=lldb_run_command(" dumpobject {:s}".format(owner[2])) 147 print(out) 148 149# EndMacro: showinterruptsourceinfo 150 151@lldb_command('showcurrentabstime') 152def ShowCurremtAbsTime(cmd_args=None): 153 """ Routine to print latest absolute time known to system before being stopped. 154 Usage: showcurrentabstime 155 """ 156 pset = addressof(kern.globals.pset0) 157 processor_array = kern.globals.processor_array 158 cur_abstime = 0 159 160 while unsigned(pset) != 0: 161 cpu_bitmap = int(pset.cpu_bitmask) 162 for cpuid in IterateBitmap(cpu_bitmap): 163 processor = processor_array[cpuid] 164 if unsigned(processor.last_dispatch) > cur_abstime: 165 cur_abstime = unsigned(processor.last_dispatch) 166 167 pset = pset.pset_list 168 169 print("Last dispatch time known: %d MATUs" % cur_abstime) 170 171bucketStr = ["FIXPRI (>UI)", "TIMESHARE_FG", "TIMESHARE_IN", "TIMESHARE_DF", "TIMESHARE_UT", "TIMESHARE_BG"] 172 173@header("{:<18s} | {:>20s} | {:>20s} | {:>10s} | {:>10s}".format('Thread Group', 'Pending (us)', 'Interactivity Score', 'TG Boost', 'Highest Thread Pri')) 174def GetSchedClutchBucketSummary(clutch_bucket): 175 tg_boost = kern.globals.sched_clutch_bucket_group_pri_boost[clutch_bucket.scb_group.scbg_clutch.sc_tg_priority] 176 pending_delta = kern.GetNanotimeFromAbstime(GetRecentTimestamp() - clutch_bucket.scb_group.scbg_pending_data.scct_timestamp) // 1000 177 if (int)(clutch_bucket.scb_group.scbg_pending_data.scct_timestamp) == 18446744073709551615: 178 pending_delta = 0 179 return "0x{:<16x} | {:>20d} | {:>20d} | {:>10d} | {:>10d}".format(clutch_bucket.scb_group.scbg_clutch.sc_tg, pending_delta, clutch_bucket.scb_group.scbg_interactivity_data.scct_count, tg_boost, SchedPriorityStableQueueRootPri(clutch_bucket.scb_thread_runq, 'struct thread', 'th_clutch_runq_link')) 180 181def ShowSchedClutchForPset(pset): 182 root_clutch = pset.pset_clutch_root 183 print("\n{:s} : {:d}\n\n".format("Current Timestamp", GetRecentTimestamp())) 184 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | {:<18s} | {:>10s} | {:>10s} | {:>15s} | ".format("Root", "Root Buckets", "Clutch Buckets", "Threads", "Address", "Pri (Base)", "Count", "Deadline (us)") + GetSchedClutchBucketSummary.header) 185 print("=" * 300) 186 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | 0x{:<16x} | {:>10d} | {:>10d} | {:>15s} | ".format("Root", "*", "*", "*", addressof(root_clutch), (root_clutch.scr_priority if root_clutch.scr_thr_count > 0 else -1), root_clutch.scr_thr_count, "*")) 187 print("-" * 300) 188 189 for i in range(0, 6): 190 root_bucket = root_clutch.scr_unbound_buckets[i] 191 root_bucket_deadline = 0 192 if root_bucket.scrb_clutch_buckets.scbrq_count != 0 and i != 0: 193 root_bucket_deadline = kern.GetNanotimeFromAbstime(root_bucket.scrb_pqlink.deadline - GetRecentTimestamp()) // 1000 194 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | 0x{:<16x} | {:>10s} | {:>10s} | {:>15d} | ".format("*", bucketStr[int(root_bucket.scrb_bucket)], "*", "*", addressof(root_bucket), "*", "*", root_bucket_deadline)) 195 clutch_bucket_runq = root_bucket.scrb_clutch_buckets 196 clutch_bucket_list = [] 197 for pri in range(0,128): 198 clutch_bucket_circleq = clutch_bucket_runq.scbrq_queues[pri] 199 for clutch_bucket in IterateCircleQueue(clutch_bucket_circleq, 'struct sched_clutch_bucket', 'scb_runqlink'): 200 clutch_bucket_list.append(clutch_bucket) 201 if len(clutch_bucket_list) > 0: 202 clutch_bucket_list.sort(key=lambda x: x.scb_priority, reverse=True) 203 for clutch_bucket in clutch_bucket_list: 204 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | {:<18s} | {:>10s} | {:>10s} | {:>15s} | ".format("", "", "", "", "", "", "", "")) 205 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | 0x{:<16x} | {:>10d} | {:>10d} | {:>15s} | ".format("*", "*", clutch_bucket.scb_group.scbg_clutch.sc_tg.tg_name, "*", clutch_bucket, clutch_bucket.scb_priority, clutch_bucket.scb_thr_count, "*") + GetSchedClutchBucketSummary(clutch_bucket)) 206 runq = clutch_bucket.scb_clutchpri_prioq 207 for thread in IterateSchedPriorityQueue(runq, 'struct thread', 'th_clutch_pri_link'): 208 thread_name = GetThreadName(thread)[-24:] 209 if len(thread_name) == 0: 210 thread_name = "<unnamed thread>" 211 print("{:>10s} | {:>20s} | {:>30s} | {:<25s} | 0x{:<16x} | {:>10d} | {:>10s} | {:>15s} | ".format("*", "*", "*", thread_name, thread, thread.base_pri, "*", "*")) 212 print("-" * 300) 213 root_bucket = root_clutch.scr_bound_buckets[i] 214 root_bucket_deadline = 0 215 if root_bucket.scrb_bound_thread_runq.count != 0: 216 root_bucket_deadline = kern.GetNanotimeFromAbstime(root_bucket.scrb_pqlink.deadline - GetRecentTimestamp()) // 1000 217 print("{:>10s} | {:>20s} | {:>30s} | {:>25s} | 0x{:<16x} | {:>10s} | {:>10d} | {:>15d} | ".format("*", bucketStr[int(root_bucket.scrb_bucket)] + " [Bound]", "*", "*", addressof(root_bucket), "*", root_bucket.scrb_bound_thread_runq.count, root_bucket_deadline)) 218 if root_bucket.scrb_bound_thread_runq.count == 0: 219 print("-" * 300) 220 continue 221 thread_runq = root_bucket.scrb_bound_thread_runq 222 for pri in range(0, 128): 223 thread_circleq = thread_runq.queues[pri] 224 for thread in IterateCircleQueue(thread_circleq, 'struct thread', 'runq_links'): 225 thread_name = GetThreadName(thread)[-24:] 226 if len(thread_name) == 0: 227 thread_name = "<unnamed thread>" 228 print("{:>10s} | {:>20s} | {:>30s} | {:<25s} | 0x{:<16x} | {:>10d} | {:>10s} | {:>15s} | ".format("*", "*", "*", thread_name, thread, thread.base_pri, "*", "*")) 229 print("-" * 300) 230 231@lldb_command('showschedclutch') 232def ShowSchedClutch(cmd_args=[]): 233 """ Routine to print the clutch scheduler hierarchy. 234 Usage: showschedclutch <pset> 235 """ 236 if not cmd_args: 237 raise ArgumentError("Invalid argument") 238 pset = kern.GetValueFromAddress(cmd_args[0], "processor_set_t") 239 ShowSchedClutchForPset(pset) 240 241@lldb_command('showschedclutchroot') 242def ShowSchedClutchRoot(cmd_args=[]): 243 """ show information about the root of the sched clutch hierarchy 244 Usage: showschedclutchroot <root> 245 """ 246 if not cmd_args: 247 raise ArgumentError("Invalid argument") 248 root = kern.GetValueFromAddress(cmd_args[0], "struct sched_clutch_root *") 249 if not root: 250 print("unknown arguments:", str(cmd_args)) 251 return False 252 print("{:>30s} : 0x{:<16x}".format("Root", root)) 253 print("{:>30s} : 0x{:<16x}".format("Pset", root.scr_pset)) 254 print("{:>30s} : {:d}".format("Priority", (root.scr_priority if root.scr_thr_count > 0 else -1))) 255 print("{:>30s} : {:d}".format("Urgency", root.scr_urgency)) 256 print("{:>30s} : {:d}".format("Threads", root.scr_thr_count)) 257 print("{:>30s} : {:d}".format("Current Timestamp", GetRecentTimestamp())) 258 print("{:>30s} : {:b} (BG/UT/DF/IN/FG/FIX/NULL)".format("Runnable Root Buckets Bitmap", int(root.scr_runnable_bitmap[0]))) 259 260@lldb_command('showschedclutchrootbucket') 261def ShowSchedClutchRootBucket(cmd_args=[]): 262 """ show information about a root bucket in the sched clutch hierarchy 263 Usage: showschedclutchrootbucket <root_bucket> 264 """ 265 if not cmd_args: 266 raise ArgumentError("Invalid argument") 267 root_bucket = kern.GetValueFromAddress(cmd_args[0], "struct sched_clutch_root_bucket *") 268 if not root_bucket: 269 print("unknown arguments:", str(cmd_args)) 270 return False 271 print("{:<30s} : 0x{:<16x}".format("Root Bucket", root_bucket)) 272 print("{:<30s} : {:s}".format("Bucket Name", bucketStr[int(root_bucket.scrb_bucket)])) 273 print("{:<30s} : {:d}".format("Deadline", (root_bucket.scrb_pqlink.deadline if root_bucket.scrb_clutch_buckets.scbrq_count != 0 else 0))) 274 print("{:<30s} : {:d}".format("Current Timestamp", GetRecentTimestamp())) 275 print("\n") 276 clutch_bucket_runq = root_bucket.scrb_clutch_buckets 277 clutch_bucket_list = [] 278 for pri in range(0,128): 279 clutch_bucket_circleq = clutch_bucket_runq.scbrq_queues[pri] 280 for clutch_bucket in IterateCircleQueue(clutch_bucket_circleq, 'struct sched_clutch_bucket', 'scb_runqlink'): 281 clutch_bucket_list.append(clutch_bucket) 282 if len(clutch_bucket_list) > 0: 283 print("=" * 240) 284 print("{:>30s} | {:>18s} | {:>20s} | {:>20s} | ".format("Name", "Clutch Bucket", "Priority", "Count") + GetSchedClutchBucketSummary.header) 285 print("=" * 240) 286 clutch_bucket_list.sort(key=lambda x: x.scb_priority, reverse=True) 287 for clutch_bucket in clutch_bucket_list: 288 print("{:>30s} | 0x{:<16x} | {:>20d} | {:>20d} | ".format(clutch_bucket.scb_group.scbg_clutch.sc_tg.tg_name, clutch_bucket, clutch_bucket.scb_priority, clutch_bucket.scb_thr_count) + GetSchedClutchBucketSummary(clutch_bucket)) 289 290def SchedClutchBucketDetails(clutch_bucket): 291 print("{:<30s} : 0x{:<16x}".format("Clutch Bucket", clutch_bucket)) 292 print("{:<30s} : {:s}".format("Scheduling Bucket", bucketStr[(int)(clutch_bucket.scb_bucket)])) 293 print("{:<30s} : 0x{:<16x}".format("Clutch Bucket Group", clutch_bucket.scb_group)) 294 print("{:<30s} : {:s}".format("TG Name", clutch_bucket.scb_group.scbg_clutch.sc_tg.tg_name)) 295 print("{:<30s} : {:d}".format("Priority", clutch_bucket.scb_priority)) 296 print("{:<30s} : {:d}".format("Thread Count", clutch_bucket.scb_thr_count)) 297 print("{:<30s} : 0x{:<16x}".format("Thread Group", clutch_bucket.scb_group.scbg_clutch.sc_tg)) 298 print("{:<30s} : {:6d} (inherited from clutch bucket group)".format("Interactivity Score", clutch_bucket.scb_group.scbg_interactivity_data.scct_count)) 299 print("{:<30s} : {:6d} (inherited from clutch bucket group)".format("Last Timeshare Update Tick", clutch_bucket.scb_group.scbg_timeshare_tick)) 300 print("{:<30s} : {:6d} (inherited from clutch bucket group)".format("Priority Shift", clutch_bucket.scb_group.scbg_pri_shift)) 301 print("\n") 302 runq = clutch_bucket.scb_clutchpri_prioq 303 thread_list = [] 304 for thread in IterateSchedPriorityQueue(runq, 'struct thread', 'th_clutch_pri_link'): 305 thread_list.append(thread) 306 if len(thread_list) > 0: 307 print("=" * 240) 308 print(GetThreadSummary.header + "{:s}".format("Process Name")) 309 print("=" * 240) 310 for thread in thread_list: 311 proc = thread.t_tro.tro_proc 312 print(GetThreadSummary(thread) + "{:s}".format(GetProcName(proc))) 313 314@lldb_command('showschedclutchbucket') 315def ShowSchedClutchBucket(cmd_args=[]): 316 """ show information about a clutch bucket in the sched clutch hierarchy 317 Usage: showschedclutchbucket <clutch_bucket> 318 """ 319 if not cmd_args: 320 raise ArgumentError("Invalid argument") 321 clutch_bucket = kern.GetValueFromAddress(cmd_args[0], "struct sched_clutch_bucket *") 322 if not clutch_bucket: 323 print("unknown arguments:", str(cmd_args)) 324 return False 325 SchedClutchBucketDetails(clutch_bucket) 326 327@lldb_command('abs2nano') 328def ShowAbstimeToNanoTime(cmd_args=[]): 329 """ convert mach_absolute_time units to nano seconds 330 Usage: (lldb) abs2nano <timestamp in MATUs> 331 """ 332 if not cmd_args: 333 raise ArgumentError("Invalid argument") 334 timedata = ArgumentStringToInt(cmd_args[0]) 335 ns = kern.GetNanotimeFromAbstime(timedata) 336 us = float(ns) / 1000 337 ms = us / 1000 338 s = ms / 1000 339 340 if s > 60 : 341 m = s // 60 342 h = m // 60 343 d = h // 24 344 345 print("{:d} ns, {:f} us, {:f} ms, {:f} s, {:f} m, {:f} h, {:f} d".format(ns, us, ms, s, m, h, d)) 346 else: 347 print("{:d} ns, {:f} us, {:f} ms, {:f} s".format(ns, us, ms, s)) 348 349 # Macro: showschedhistory 350 351def GetRecentTimestamp(): 352 """ 353 Return a recent timestamp. 354 TODO: on x86, if not in the debugger, then look at the scheduler 355 """ 356 if kern.arch == 'x86_64': 357 most_recent_dispatch = GetSchedMostRecentDispatch(False) 358 if most_recent_dispatch > kern.globals.debugger_entry_time : 359 return most_recent_dispatch 360 else : 361 return kern.globals.debugger_entry_time 362 else : 363 return GetSchedMostRecentDispatch(False) 364 365def GetSchedMostRecentDispatch(show_processor_details=False): 366 """ Return the most recent dispatch on the system, printing processor 367 details if argument is true. 368 """ 369 processor_list = kern.globals.processor_list 370 371 most_recent_dispatch = 0 372 current_processor = processor_list 373 374 while unsigned(current_processor) > 0: 375 active_thread = current_processor.active_thread 376 if unsigned(active_thread) != 0 : 377 task_val = active_thread.t_tro.tro_task 378 proc_val = active_thread.t_tro.tro_proc 379 proc_name = "<unknown>" if unsigned(proc_val) == 0 else GetProcName(proc_val) 380 381 last_dispatch = unsigned(current_processor.last_dispatch) 382 383 if kern.arch == 'x86_64': 384 cpu_data = kern.globals.cpu_data_ptr[current_processor.cpu_id] 385 if (cpu_data != 0) : 386 cpu_debugger_time = max(cpu_data.debugger_entry_time, cpu_data.debugger_ipi_time) 387 time_since_dispatch = unsigned(cpu_debugger_time - last_dispatch) 388 time_since_dispatch_us = kern.GetNanotimeFromAbstime(time_since_dispatch) / 1000.0 389 time_since_debugger = unsigned(cpu_debugger_time - kern.globals.debugger_entry_time) 390 time_since_debugger_us = kern.GetNanotimeFromAbstime(time_since_debugger) / 1000.0 391 392 if show_processor_details: 393 print("Processor last dispatch: {:16d} Entered debugger: {:16d} ({:8.3f} us after dispatch, {:8.3f} us after debugger) Active thread: 0x{t:<16x} 0x{t.thread_id:<8x} {proc_name:s}".format(last_dispatch, cpu_debugger_time, 394 time_since_dispatch_us, time_since_debugger_us, t=active_thread, proc_name=proc_name)) 395 else: 396 if show_processor_details: 397 print("Processor last dispatch: {:16d} Active thread: 0x{t:<16x} 0x{t.thread_id:<8x} {proc_name:s}".format(last_dispatch, t=active_thread, proc_name=proc_name)) 398 399 if last_dispatch > most_recent_dispatch: 400 most_recent_dispatch = last_dispatch 401 402 current_processor = current_processor.processor_list 403 404 return most_recent_dispatch 405 406@header("{:<18s} {:<10s} {:>16s} {:>16s} {:>16s} {:>16s} {:>18s} {:>16s} {:>16s} {:>16s} {:>16s} {:2s} {:2s} {:2s} {:>2s} {:<19s} {:<9s} {:>10s} {:>10s} {:>10s} {:>10s} {:>10s} {:>11s} {:>8s}".format("thread", "id", "on-core", "off-core", "runnable", "prichange", "last-duration (us)", "since-off (us)", "since-on (us)", "pending (us)", "pri-change (us)", "BP", "SP", "TP", "MP", "sched-mode", "state", "cpu-usage", "delta", "sch-usage", "stamp", "shift", "task", "thread-name")) 407def ShowThreadSchedHistory(thread, most_recent_dispatch): 408 """ Given a thread and the most recent dispatch time of a thread on the 409 system, print out details about scheduler history for the thread. 410 """ 411 412 thread_name = "" 413 414 uthread = GetBSDThread(thread) 415 # Doing the straightforward thing blows up weirdly, so use some indirections to get back on track 416 if unsigned(uthread.pth_name) != 0 : 417 thread_name = str(kern.GetValueFromAddress(unsigned(uthread.pth_name), 'char*')) 418 419 task = thread.t_tro.tro_task 420 task_name = "unknown" 421 if task and unsigned(task.bsd_info): 422 p = Cast(task.bsd_info, 'proc *') 423 task_name = GetProcName(p) 424 425 sched_mode = "" 426 427 mode = str(thread.sched_mode) 428 if "TIMESHARE" in mode: 429 sched_mode+="timeshare" 430 elif "FIXED" in mode: 431 sched_mode+="fixed" 432 elif "REALTIME" in mode: 433 sched_mode+="realtime" 434 435 if (unsigned(thread.bound_processor) != 0): 436 sched_mode+="-bound" 437 438 # TH_SFLAG_THROTTLED 439 if (unsigned(thread.sched_flags) & 0x0004): 440 sched_mode+="-BG" 441 442 state = thread.state 443 444 thread_state_chars = {0x0:'', 0x1:'W', 0x2:'S', 0x4:'R', 0x8:'U', 0x10:'H', 0x20:'A', 0x40:'P', 0x80:'I'} 445 state_str = '' 446 mask = 0x1 447 while mask <= 0x80 : 448 state_str += thread_state_chars[int(state & mask)] 449 mask = mask << 1 450 451 last_on = thread.computation_epoch 452 last_off = thread.last_run_time 453 last_runnable = thread.last_made_runnable_time 454 last_prichange = thread.last_basepri_change_time 455 456 if int(last_runnable) == 18446744073709551615 : 457 last_runnable = 0 458 459 if int(last_prichange) == 18446744073709551615 : 460 last_prichange = 0 461 462 time_on_abs = unsigned(last_off - last_on) 463 time_on_us = kern.GetNanotimeFromAbstime(time_on_abs) / 1000.0 464 465 time_pending_abs = unsigned(most_recent_dispatch - last_runnable) 466 time_pending_us = kern.GetNanotimeFromAbstime(time_pending_abs) / 1000.0 467 468 if int(last_runnable) == 0 : 469 time_pending_us = 0 470 471 last_prichange_abs = unsigned(most_recent_dispatch - last_prichange) 472 last_prichange_us = kern.GetNanotimeFromAbstime(last_prichange_abs) / 1000.0 473 474 if int(last_prichange) == 0 : 475 last_prichange_us = 0 476 477 time_since_off_abs = unsigned(most_recent_dispatch - last_off) 478 time_since_off_us = kern.GetNanotimeFromAbstime(time_since_off_abs) / 1000.0 479 time_since_on_abs = unsigned(most_recent_dispatch - last_on) 480 time_since_on_us = kern.GetNanotimeFromAbstime(time_since_on_abs) / 1000.0 481 482 fmt = "0x{t:<16x} 0x{t.thread_id:<8x} {t.computation_epoch:16d} {t.last_run_time:16d} {last_runnable:16d} {last_prichange:16d} {time_on_us:18.3f} {time_since_off_us:16.3f} {time_since_on_us:16.3f} {time_pending_us:16.3f} {last_prichange_us:16.3f}" 483 fmt2 = " {t.base_pri:2d} {t.sched_pri:2d} {t.task_priority:2d} {t.max_priority:2d} {sched_mode:19s}" 484 fmt3 = " {state:9s} {t.cpu_usage:10d} {t.cpu_delta:10d} {t.sched_usage:10d} {t.sched_stamp:10d} {t.pri_shift:10d} {name:s} {thread_name:s}" 485 486 out_str = fmt.format(t=thread, time_on_us=time_on_us, time_since_off_us=time_since_off_us, time_since_on_us=time_since_on_us, last_runnable=last_runnable, time_pending_us=time_pending_us, last_prichange=last_prichange, last_prichange_us=last_prichange_us) 487 out_str += fmt2.format(t=thread, sched_mode=sched_mode) 488 out_str += fmt3.format(t=thread, state=state_str, name=task_name, thread_name=thread_name) 489 490 print(out_str) 491 492def SortThreads(threads, column): 493 if column != 'on-core' and column != 'off-core' and column != 'last-duration': 494 raise ArgumentError("unsupported sort column") 495 if column == 'on-core': 496 threads.sort(key=lambda t: t.computation_epoch) 497 elif column == 'off-core': 498 threads.sort(key=lambda t: t.last_run_time) 499 else: 500 threads.sort(key=lambda t: t.last_run_time - t.computation_epoch) 501 502@lldb_command('showschedhistory', 'S:') 503def ShowSchedHistory(cmd_args=None, cmd_options=None): 504 """ Routine to print out thread scheduling history, optionally sorted by a 505 column. 506 507 Usage: showschedhistory [-S on-core|off-core|last-duration] [<thread-ptr> ...] 508 """ 509 510 sort_column = None 511 if '-S' in cmd_options: 512 sort_column = cmd_options['-S'] 513 514 if cmd_args: 515 most_recent_dispatch = GetSchedMostRecentDispatch(False) 516 517 print(ShowThreadSchedHistory.header) 518 519 if sort_column: 520 threads = [] 521 for thread_ptr in cmd_args: 522 threads.append(kern.GetValueFromAddress(ArgumentStringToInt(thread_ptr), 'thread *')) 523 524 SortThreads(threads, sort_column) 525 526 for thread in threads: 527 ShowThreadSchedHistory(thread, most_recent_dispatch) 528 else: 529 for thread_ptr in cmd_args: 530 thread = kern.GetValueFromAddress(ArgumentStringToInt(thread_ptr), 'thread *') 531 ShowThreadSchedHistory(thread, most_recent_dispatch) 532 533 return 534 535 run_buckets = kern.globals.sched_run_buckets 536 537 run_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_RUN')] 538 fixpri_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_FIXPRI')] 539 share_fg_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_FG')] 540 share_df_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_DF')] 541 share_ut_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_UT')] 542 share_bg_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_BG')] 543 544 sched_pri_shifts = kern.globals.sched_run_buckets 545 546 share_fg_shift = sched_pri_shifts[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_FG')] 547 share_df_shift = sched_pri_shifts[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_DF')] 548 share_ut_shift = sched_pri_shifts[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_UT')] 549 share_bg_shift = sched_pri_shifts[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_BG')] 550 551 552 print("Processors: {g.processor_avail_count:d} Runnable threads: {:d} Fixpri threads: {:d}\n".format(run_count, fixpri_count, g=kern.globals)) 553 print("FG Timeshare threads: {:d} DF Timeshare threads: {:d} UT Timeshare threads: {:d} BG Timeshare threads: {:d}\n".format(share_fg_count, share_df_count, share_ut_count, share_bg_count)) 554 print("Mach factor: {g.sched_mach_factor:d} Load factor: {g.sched_load_average:d} Sched tick: {g.sched_tick:d} timestamp: {g.sched_tick_last_abstime:d} interval:{g.sched_tick_interval:d}\n".format(g=kern.globals)) 555 print("Fixed shift: {g.sched_fixed_shift:d} FG shift: {:d} DF shift: {:d} UT shift: {:d} BG shift: {:d}\n".format(share_fg_shift, share_df_shift, share_ut_shift, share_bg_shift, g=kern.globals)) 556 print("sched_pri_decay_band_limit: {g.sched_pri_decay_band_limit:d} sched_decay_usage_age_factor: {g.sched_decay_usage_age_factor:d}\n".format(g=kern.globals)) 557 558 if kern.arch == 'x86_64': 559 print("debugger_entry_time: {g.debugger_entry_time:d}\n".format(g=kern.globals)) 560 561 most_recent_dispatch = GetSchedMostRecentDispatch(True) 562 print("Most recent dispatch: " + str(most_recent_dispatch)) 563 564 print(ShowThreadSchedHistory.header) 565 566 if sort_column: 567 threads = [t for t in IterateQueue(kern.globals.threads, 'thread *', 'threads')] 568 569 SortThreads(threads, sort_column) 570 571 for thread in threads: 572 ShowThreadSchedHistory(thread, most_recent_dispatch) 573 else: 574 for thread in IterateQueue(kern.globals.threads, 'thread *', 'threads'): 575 ShowThreadSchedHistory(thread, most_recent_dispatch) 576 577 578# EndMacro: showschedhistory 579 580def int32(n): 581 n = n & 0xffffffff 582 return (n ^ 0x80000000) - 0x80000000 583 584# Macro: showallprocessors 585 586def ShowGroupSetSummary(runq, task_map): 587 """ Internal function to print summary of group run queue 588 params: runq - value representing struct run_queue * 589 """ 590 591 print(" runq: count {: <10d} highq: {: <10d} urgency {: <10d}\n".format(runq.count, int32(runq.highq), runq.urgency)) 592 593 runq_queue_i = 0 594 runq_queue_count = sizeof(runq.queues) // sizeof(runq.queues[0]) 595 596 for runq_queue_i in range(runq_queue_count) : 597 runq_queue_head = addressof(runq.queues[runq_queue_i]) 598 runq_queue_p = runq_queue_head.next 599 600 if unsigned(runq_queue_p) != unsigned(runq_queue_head): 601 runq_queue_this_count = 0 602 603 for entry in ParanoidIterateLinkageChain(runq_queue_head, "sched_entry_t", "entry_links", circleQueue=True): 604 runq_queue_this_count += 1 605 606 print(" Queue [{: <#012x}] Priority {: <3d} count {:d}\n".format(runq_queue_head, runq_queue_i, runq_queue_this_count)) 607 for entry in ParanoidIterateLinkageChain(runq_queue_head, "sched_entry_t", "entry_links", circleQueue=True): 608 group_addr = unsigned(entry) - (sizeof(dereference(entry)) * unsigned(entry.sched_pri)) 609 group = kern.GetValueFromAddress(unsigned(group_addr), 'sched_group_t') 610 task = task_map.get(unsigned(group), 0x0) 611 if task == 0x0 : 612 print("Cannot find task for group: {: <#012x}".format(group)) 613 print("\tEntry [{: <#012x}] Priority {: <3d} Group {: <#012x} Task {: <#012x}\n".format(unsigned(entry), entry.sched_pri, unsigned(group), unsigned(task))) 614 615@lldb_command('showrunq') 616def ShowRunq(cmd_args=None): 617 """ Routine to print information of a runq 618 Usage: showrunq <runq> 619 """ 620 621 if not cmd_args: 622 print("No arguments passed") 623 print(ShowRunq.__doc__) 624 return False 625 626 runq = kern.GetValueFromAddress(cmd_args[0], 'struct run_queue *') 627 ShowRunQSummary(runq) 628 629def ShowRunQSummary(runq): 630 """ Internal function to print summary of run_queue 631 params: runq - value representing struct run_queue * 632 """ 633 634 print(" runq: count {: <10d} highq: {: <10d} urgency {: <10d}\n".format(runq.count, int32(runq.highq), runq.urgency)) 635 636 runq_queue_i = 0 637 runq_queue_count = sizeof(runq.queues) // sizeof(runq.queues[0]) 638 639 for runq_queue_i in range(runq_queue_count) : 640 runq_queue_head = addressof(runq.queues[runq_queue_i]) 641 runq_queue_p = runq_queue_head.head 642 643 if unsigned(runq_queue_p): 644 runq_queue_this_count = 0 645 646 for thread in ParanoidIterateLinkageChain(runq_queue_head, "thread_t", "runq_links", circleQueue=True): 647 runq_queue_this_count += 1 648 649 print(" Queue [{: <#012x}] Priority {: <3d} count {:d}\n".format(runq_queue_head, runq_queue_i, runq_queue_this_count)) 650 print("\t" + GetThreadSummary.header + "\n") 651 for thread in ParanoidIterateLinkageChain(runq_queue_head, "thread_t", "runq_links", circleQueue=True): 652 print("\t" + GetThreadSummary(thread) + "\n") 653 if config['verbosity'] > vHUMAN : 654 print("\t" + GetThreadBackTrace(thread, prefix="\t\t") + "\n") 655 656def ShowRTRunQSummary(rt_runq): 657 if (hex(rt_runq.count) == hex(0xfdfdfdfd)) : 658 print(" Realtime Queue ({:<#012x}) uninitialized\n".format(rt_runq)) 659 return 660 print(" Realtime Queue ({:<#012x}) Count {:d}\n".format(rt_runq, rt_runq.count)) 661 if rt_runq.count != 0: 662 rt_pri_bitmap = int(rt_runq.bitmap[0]) 663 for rt_index in IterateBitmap(rt_pri_bitmap): 664 rt_pri_rq = addressof(rt_runq.rt_queue_pri[rt_index]) 665 print(" Realtime Queue Index {:d} ({:<#012x}) Count {:d}\n".format(rt_index, rt_pri_rq, rt_pri_rq.pri_count)) 666 print("\t" + GetThreadSummary.header + "\n") 667 for rt_runq_thread in ParanoidIterateLinkageChain(rt_pri_rq.pri_queue, "thread_t", "runq_links", circleQueue=False): 668 print("\t" + GetThreadSummary(rt_runq_thread) + "\n") 669 670def ShowGrrrSummary(grrr_runq): 671 """ Internal function to print summary of grrr_run_queue 672 params: grrr_runq - value representing struct grrr_run_queue * 673 """ 674 print(" GRRR Info: Count {: <10d} Weight {: <10d} Current Group {: <#012x}\n".format(grrr_runq.count, 675 grrr_runq.weight, grrr_runq.current_group)) 676 grrr_group_i = 0 677 grrr_group_count = sizeof(grrr_runq.groups) // sizeof(grrr_runq.groups[0]) 678 for grrr_group_i in range(grrr_group_count) : 679 grrr_group = addressof(grrr_runq.groups[grrr_group_i]) 680 if grrr_group.count > 0: 681 print(" Group {: <3d} [{: <#012x}] ".format(grrr_group.index, grrr_group)) 682 print("Count {:d} Weight {:d}\n".format(grrr_group.count, grrr_group.weight)) 683 grrr_group_client_head = addressof(grrr_group.clients) 684 print(GetThreadSummary.header) 685 for thread in ParanoidIterateLinkageChain(grrr_group_client_head, "thread_t", "runq_links", circleQueue=True): 686 print("\t" + GetThreadSummary(thread) + "\n") 687 if config['verbosity'] > vHUMAN : 688 print("\t" + GetThreadBackTrace(thread, prefix="\t\t") + "\n") 689 690def ShowActiveThread(processor): 691 if (processor.active_thread != 0) : 692 print("\t" + GetThreadSummary.header + "\n") 693 print("\t" + GetThreadSummary(processor.active_thread) + "\n") 694 695@lldb_command('showallprocessors') 696@lldb_command('showscheduler') 697def ShowScheduler(cmd_args=None): 698 """ Routine to print information of all psets and processors 699 Usage: showscheduler 700 """ 701 node = addressof(kern.globals.pset_node0) 702 show_grrr = 0 703 show_priority_runq = 0 704 show_priority_pset_runq = 0 705 show_group_pset_runq = 0 706 show_clutch = 0 707 show_edge = 0 708 sched_string = str(kern.globals.sched_string) 709 710 if sched_string == "traditional": 711 show_priority_runq = 1 712 elif sched_string == "traditional_with_pset_runqueue": 713 show_priority_pset_runq = 1 714 elif sched_string == "grrr": 715 show_grrr = 1 716 elif sched_string == "multiq": 717 show_priority_runq = 1 718 show_group_pset_runq = 1 719 elif sched_string == "dualq": 720 show_priority_pset_runq = 1 721 show_priority_runq = 1 722 elif sched_string == "amp": 723 show_priority_pset_runq = 1 724 show_priority_runq = 1 725 elif sched_string == "clutch": 726 show_clutch = 1 727 elif sched_string == "edge": 728 show_edge = 1 729 else : 730 print("Unknown sched_string {:s}".format(sched_string)) 731 732 print("Scheduler: {:s}\n".format(sched_string)) 733 734 if show_clutch == 0 and show_edge == 0: 735 run_buckets = kern.globals.sched_run_buckets 736 run_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_RUN')] 737 fixpri_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_FIXPRI')] 738 share_fg_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_FG')] 739 share_df_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_DF')] 740 share_ut_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_UT')] 741 share_bg_count = run_buckets[GetEnumValue('sched_bucket_t::TH_BUCKET_SHARE_BG')] 742 print("Processors: {g.processor_avail_count:d} Runnable threads: {:d} Fixpri threads: {:d}\n".format(run_count, fixpri_count, g=kern.globals)) 743 print("FG Timeshare threads: {:d} DF Timeshare threads: {:d} UT Timeshare threads: {:d} BG Timeshare threads: {:d}\n".format(share_fg_count, share_df_count, share_ut_count, share_bg_count)) 744 745 processor_offline = GetEnumValue('processor_state_t::PROCESSOR_OFF_LINE') 746 processor_idle = GetEnumValue('processor_state_t::PROCESSOR_IDLE') 747 processor_dispatching = GetEnumValue('processor_state_t::PROCESSOR_DISPATCHING') 748 processor_running = GetEnumValue('processor_state_t::PROCESSOR_RUNNING') 749 750 if show_group_pset_runq: 751 if hasattr(kern.globals, "multiq_sanity_check"): 752 print("multiq scheduler config: deep-drain {g.deep_drain:d}, ceiling {g.drain_ceiling:d}, depth limit {g.drain_depth_limit:d}, band limit {g.drain_band_limit:d}, sanity check {g.multiq_sanity_check:d}\n".format(g=kern.globals)) 753 else: 754 print("multiq scheduler config: deep-drain {g.deep_drain:d}, ceiling {g.drain_ceiling:d}, depth limit {g.drain_depth_limit:d}, band limit {g.drain_band_limit:d}\n".format(g=kern.globals)) 755 756 # Create a group->task mapping 757 task_map = {} 758 for task in kern.tasks: 759 task_map[unsigned(task.sched_group)] = task 760 for task in kern.terminated_tasks: 761 task_map[unsigned(task.sched_group)] = task 762 763 print(" \n") 764 765 while node != 0: 766 pset = node.psets 767 pset = kern.GetValueFromAddress(unsigned(pset), 'struct processor_set *') 768 769 while pset != 0: 770 print("Processor Set {: <#012x} Count {:d} (cpu_id {:<#x}-{:<#x})\n".format(pset, 771 unsigned(pset.cpu_set_count), pset.cpu_set_low, pset.cpu_set_hi)) 772 773 rt_runq = kern.GetValueFromAddress(unsigned(addressof(pset.rt_runq)), 'struct rt_queue *') 774 ShowRTRunQSummary(rt_runq) 775 776 if show_priority_pset_runq: 777 runq = kern.GetValueFromAddress(unsigned(addressof(pset.pset_runq)), 'struct run_queue *') 778 ShowRunQSummary(runq) 779 780 if show_group_pset_runq: 781 print("Main Runq:\n") 782 runq = kern.GetValueFromAddress(unsigned(addressof(pset.pset_runq)), 'struct run_queue *') 783 ShowGroupSetSummary(runq, task_map) 784 print("All Groups:\n") 785 # TODO: Possibly output task header for each group 786 for group in IterateQueue(kern.globals.sched_groups, "sched_group_t", "sched_groups"): 787 if (group.runq.count != 0) : 788 task = task_map.get(unsigned(group), "Unknown task!") 789 print("Group {: <#012x} Task {: <#012x}\n".format(unsigned(group), unsigned(task))) 790 ShowRunQSummary(group.runq) 791 print(" \n") 792 793 processor_array = kern.globals.processor_array 794 795 print("Active Processors:\n") 796 active_bitmap = int(pset.cpu_state_map[processor_dispatching]) | int(pset.cpu_state_map[processor_running]) 797 for cpuid in IterateBitmap(active_bitmap): 798 processor = processor_array[cpuid] 799 if processor != 0: 800 print(" " + GetProcessorSummary(processor)) 801 ShowActiveThread(processor) 802 803 if show_priority_runq: 804 runq = processor.runq 805 ShowRunQSummary(runq) 806 if show_grrr: 807 grrr_runq = processor.grrr_runq 808 ShowGrrrSummary(grrr_runq) 809 print(" \n") 810 811 812 print("Idle Processors:\n") 813 idle_bitmap = int(pset.cpu_state_map[processor_idle]) & int(pset.primary_map) 814 for cpuid in IterateBitmap(idle_bitmap): 815 processor = processor_array[cpuid] 816 if processor != 0: 817 print(" " + GetProcessorSummary(processor)) 818 ShowActiveThread(processor) 819 820 if show_priority_runq: 821 ShowRunQSummary(processor.runq) 822 print(" \n") 823 824 825 print("Idle Secondary Processors:\n") 826 idle_bitmap = int(pset.cpu_state_map[processor_idle]) & ~(int(pset.primary_map)) 827 for cpuid in IterateBitmap(idle_bitmap): 828 processor = processor_array[cpuid] 829 if processor != 0: 830 print(" " + GetProcessorSummary(processor)) 831 ShowActiveThread(processor) 832 833 if show_priority_runq: 834 print(ShowRunQSummary(processor.runq)) 835 print(" \n") 836 837 838 print("Other Processors:\n") 839 other_bitmap = 0 840 for i in range(processor_offline, processor_idle): 841 other_bitmap |= int(pset.cpu_state_map[i]) 842 other_bitmap &= int(pset.cpu_bitmask) 843 for cpuid in IterateBitmap(other_bitmap): 844 processor = processor_array[cpuid] 845 if processor != 0: 846 print(" " + GetProcessorSummary(processor)) 847 ShowActiveThread(processor) 848 849 if show_priority_runq: 850 ShowRunQSummary(processor.runq) 851 print(" \n") 852 853 if show_clutch or show_edge: 854 cluster_type = "SMP" 855 if pset.pset_type == 1: 856 cluster_type = "E" 857 elif pset.pset_type == 2: 858 cluster_type = "P" 859 print("=== Clutch Scheduler Hierarchy Pset{:d} (Type: {:s}) ] ===\n\n".format(pset.pset_cluster_id, cluster_type)) 860 ShowSchedClutchForPset(pset) 861 862 pset = pset.pset_list 863 864 node = node.node_list 865 866 print("\nCrashed Threads Queue: ({:<#012x})\n".format(addressof(kern.globals.crashed_threads_queue))) 867 first = True 868 for thread in ParanoidIterateLinkageChain(kern.globals.crashed_threads_queue, "thread_t", "runq_links"): 869 if first: 870 print("\t" + GetThreadSummary.header) 871 first = False 872 print("\t" + GetThreadSummary(thread)) 873 874 def dump_mpsc_thread_queue(name, head): 875 head = addressof(head) 876 print("\n{:s}: ({:<#012x})\n".format(name, head)) 877 first = True 878 for thread in IterateMPSCQueue(head.mpd_queue, 'struct thread', 'mpsc_links'): 879 if first: 880 print("\t" + GetThreadSummary.header) 881 first = False 882 print("\t" + GetThreadSummary(thread)) 883 884 dump_mpsc_thread_queue("Terminate Queue", kern.globals.thread_terminate_queue) 885 dump_mpsc_thread_queue("Waiting For Kernel Stacks Queue", kern.globals.thread_stack_queue) 886 dump_mpsc_thread_queue("Thread Exception Queue", kern.globals.thread_exception_queue) 887 dump_mpsc_thread_queue("Thread Deallocate Queue", kern.globals.thread_deallocate_queue) 888 889 print("\n") 890 891 print("\n") 892 893# EndMacro: showallprocessors 894 895 896def ParanoidIterateLinkageChain(queue_head, element_type, field_name, field_ofst=0, circleQueue=False): 897 """ Iterate over a Linkage Chain queue in kernel of type queue_head_t or circle_queue_head_t. (osfmk/kern/queue.h method 1 or circle_queue.h) 898 This is equivalent to the qe_foreach_element() macro 899 Blows up aggressively and descriptively when something goes wrong iterating a queue. 900 Prints correctness errors, and throws exceptions on 'cannot proceed' errors 901 If this is annoying, set the global 'enable_paranoia' to false. 902 903 params: 904 queue_head - value : Value object for queue_head. 905 element_type - lldb.SBType : pointer type of the element which contains the queue_chain_t. Typically its structs like thread, task etc.. 906 - str : OR a string describing the type. ex. 'task *' 907 field_name - str : Name of the field (in element) which holds a queue_chain_t 908 field_ofst - int : offset from the 'field_name' (in element) which holds a queue_chain_t 909 This is mostly useful if a particular element contains an array of queue_chain_t 910 returns: 911 A generator does not return. It is used for iterating. 912 value : An object thats of type (element_type). Always a pointer object 913 example usage: 914 for thread in IterateQueue(kern.globals.threads, 'thread *', 'threads'): 915 print thread.thread_id 916 """ 917 918 if isinstance(element_type, six.string_types): 919 element_type = gettype(element_type) 920 921 # Some ways of constructing a queue head seem to end up with the 922 # struct object as the value and not a pointer to the struct head 923 # In that case, addressof will give us a pointer to the struct, which is what we need 924 if not queue_head.GetSBValue().GetType().IsPointerType() : 925 queue_head = addressof(queue_head) 926 927 if circleQueue: 928 # Mosh the value into a brand new value, to really get rid of its old cvalue history 929 queue_head = kern.GetValueFromAddress(unsigned(queue_head), 'struct circle_queue_head *').head 930 else: 931 # Mosh the value into a brand new value, to really get rid of its old cvalue history 932 queue_head = kern.GetValueFromAddress(unsigned(queue_head), 'struct queue_entry *') 933 934 if unsigned(queue_head) == 0: 935 if not circleQueue and ParanoidIterateLinkageChain.enable_paranoia: 936 print("bad queue_head_t: {:s}".format(queue_head)) 937 return 938 939 if element_type.IsPointerType(): 940 struct_type = element_type.GetPointeeType() 941 else: 942 struct_type = element_type 943 944 elem_ofst = getfieldoffset(struct_type, field_name) + field_ofst 945 946 try: 947 link = queue_head.next 948 last_link = queue_head 949 try_read_next = unsigned(queue_head.next) 950 except: 951 print("Exception while looking at queue_head: {:>#18x}".format(unsigned(queue_head))) 952 raise 953 954 if ParanoidIterateLinkageChain.enable_paranoia: 955 if unsigned(queue_head.next) == 0: 956 raise ValueError("NULL next pointer on head: queue_head {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, queue_head.next, queue_head.prev)) 957 if unsigned(queue_head.prev) == 0: 958 print("NULL prev pointer on head: queue_head {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, queue_head.next, queue_head.prev)) 959 if unsigned(queue_head.next) == unsigned(queue_head) and unsigned(queue_head.prev) != unsigned(queue_head): 960 print("corrupt queue_head {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, queue_head.next, queue_head.prev)) 961 962 if ParanoidIterateLinkageChain.enable_debug : 963 print("starting at queue_head {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, queue_head.next, queue_head.prev)) 964 965 addr = 0 966 obj = 0 967 968 try: 969 while True: 970 if not circleQueue and unsigned(queue_head) == unsigned(link): 971 break; 972 if ParanoidIterateLinkageChain.enable_paranoia: 973 if unsigned(link.next) == 0: 974 raise ValueError("NULL next pointer: queue_head {:>#18x} link: {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, link, link.next, link.prev)) 975 if unsigned(link.prev) == 0: 976 print("NULL prev pointer: queue_head {:>#18x} link: {:>#18x} next: {:>#18x} prev: {:>#18x}".format(queue_head, link, link.next, link.prev)) 977 if unsigned(last_link) != unsigned(link.prev): 978 print("Corrupt prev pointer: queue_head {:>#18x} link: {:>#18x} next: {:>#18x} prev: {:>#18x} prev link: {:>#18x} ".format( 979 queue_head, link, link.next, link.prev, last_link)) 980 981 addr = unsigned(link) - unsigned(elem_ofst); 982 obj = kern.GetValueFromAddress(addr, element_type) 983 if ParanoidIterateLinkageChain.enable_debug : 984 print("yielding link: {:>#18x} next: {:>#18x} prev: {:>#18x} addr: {:>#18x} obj: {:>#18x}".format(link, link.next, link.prev, addr, obj)) 985 yield obj 986 last_link = link 987 link = link.next 988 if circleQueue and unsigned(queue_head) == unsigned(link): 989 break; 990 except: 991 exc_info = sys.exc_info() 992 try: 993 print("Exception while iterating queue: {:>#18x} link: {:>#18x} addr: {:>#18x} obj: {:>#18x} last link: {:>#18x}".format(queue_head, link, addr, obj, last_link)) 994 except: 995 import traceback 996 traceback.print_exc() 997 raise_(exc_info[0], exc_info[1], exc_info[2]) 998 999ParanoidIterateLinkageChain.enable_paranoia = True 1000ParanoidIterateLinkageChain.enable_debug = False 1001 1002def LinkageChainEmpty(queue_head): 1003 if not queue_head.GetSBValue().GetType().IsPointerType() : 1004 queue_head = addressof(queue_head) 1005 1006 # Mosh the value into a brand new value, to really get rid of its old cvalue history 1007 # avoid using GetValueFromAddress 1008 queue_head = value(queue_head.GetSBValue().CreateValueFromExpression(None,'(void *)'+str(unsigned(queue_head)))) 1009 queue_head = cast(queue_head, 'struct queue_entry *') 1010 1011 link = queue_head.next 1012 1013 return unsigned(queue_head) == unsigned(link) 1014 1015def bit_first(bitmap): 1016 return bitmap.bit_length() - 1 1017 1018def lsb_first(bitmap): 1019 bitmap = bitmap & -bitmap 1020 return bit_first(bitmap) 1021 1022def IterateBitmap(bitmap): 1023 """ Iterate over a bitmap, returning the index of set bits starting from 0 1024 1025 params: 1026 bitmap - value : bitmap 1027 returns: 1028 A generator does not return. It is used for iterating. 1029 value : index of a set bit 1030 example usage: 1031 for cpuid in IterateBitmap(running_bitmap): 1032 print processor_array[cpuid] 1033 """ 1034 i = lsb_first(bitmap) 1035 while (i >= 0): 1036 yield i 1037 bitmap = bitmap & ~((1 << (i + 1)) - 1) 1038 i = lsb_first(bitmap) 1039 1040 1041# Macro: showallcallouts 1042 1043from kevent import GetKnoteKqueue 1044 1045def ShowThreadCall(prefix, call, recent_timestamp, is_pending=False): 1046 """ 1047 Print a description of a thread_call_t and its relationship to its expected fire time 1048 """ 1049 func = call.tc_func 1050 param0 = call.tc_param0 1051 param1 = call.tc_param1 1052 1053 is_iotes = False 1054 1055 func_name = kern.Symbolicate(func) 1056 1057 extra_string = "" 1058 1059 strip_func = kern.StripKernelPAC(unsigned(func)) 1060 1061 func_syms = kern.SymbolicateFromAddress(strip_func) 1062 # returns an array of SBSymbol 1063 1064 if func_syms and func_syms[0] : 1065 func_name = func_syms[0].GetName() 1066 1067 try : 1068 if ("IOTimerEventSource::timeoutAndRelease" in func_name or 1069 "IOTimerEventSource::timeoutSignaled" in func_name) : 1070 iotes = Cast(call.tc_param0, 'IOTimerEventSource*') 1071 try: 1072 func = iotes.action 1073 param0 = iotes.owner 1074 param1 = unsigned(iotes) 1075 except AttributeError: 1076 # This is horrible, horrible, horrible. But it works. Needed because IOEventSource hides the action member in an 1077 # anonymous union when XNU_PRIVATE_SOURCE is set. To grab it, we work backwards from the enabled member. 1078 func = dereference(kern.GetValueFromAddress(addressof(iotes.enabled) - sizeof('IOEventSource::Action'), 'uint64_t *')) 1079 param0 = iotes.owner 1080 param1 = unsigned(iotes) 1081 1082 workloop = iotes.workLoop 1083 thread = workloop.workThread 1084 1085 is_iotes = True 1086 1087 # re-symbolicate the func we found inside the IOTES 1088 strip_func = kern.StripKernelPAC(unsigned(func)) 1089 func_syms = kern.SymbolicateFromAddress(strip_func) 1090 if func_syms and func_syms[0] : 1091 func_name = func_syms[0].GetName() 1092 else : 1093 func_name = str(FindKmodNameForAddr(func)) 1094 1095 # cast from IOThread to thread_t, because IOThread is sometimes opaque 1096 thread = Cast(thread, 'thread_t') 1097 thread_id = thread.thread_id 1098 thread_name = GetThreadName(thread) 1099 1100 extra_string += "workloop thread: {:#x} ({:#x}) {:s}".format(thread, thread_id, thread_name) 1101 1102 if "filt_timerexpire" in func_name : 1103 knote = Cast(call.tc_param0, 'struct knote *') 1104 kqueue = GetKnoteKqueue(knote) 1105 proc = kqueue.kq_p 1106 proc_name = GetProcName(proc) 1107 proc_pid = GetProcPID(proc) 1108 1109 extra_string += "kq: {:#018x} {:s}[{:d}]".format(kqueue, proc_name, proc_pid) 1110 1111 if "mk_timer_expire" in func_name : 1112 timer = Cast(call.tc_param0, 'struct mk_timer *') 1113 port = timer.port 1114 1115 extra_string += "port: {:#018x} {:s}".format(port, GetPortDestinationSummary(port)) 1116 1117 if "workq_kill_old_threads_call" in func_name : 1118 workq = Cast(call.tc_param0, 'struct workqueue *') 1119 proc = workq.wq_proc 1120 proc_name = GetProcName(proc) 1121 proc_pid = GetProcPID(proc) 1122 1123 extra_string += "{:s}[{:d}]".format(proc_name, proc_pid) 1124 1125 if ("workq_add_new_threads_call" in func_name or 1126 "realitexpire" in func_name): 1127 proc = Cast(call.tc_param0, 'struct proc *') 1128 proc_name = GetProcName(proc) 1129 proc_pid = GetProcPID(proc) 1130 1131 extra_string += "{:s}[{:d}]".format(proc_name, proc_pid) 1132 1133 except: 1134 print("exception generating extra_string for call: {:#018x}".format(call)) 1135 if ShowThreadCall.enable_debug : 1136 raise 1137 1138 if (func_name == "") : 1139 func_name = FindKmodNameForAddr(func) 1140 1141 if (call.tc_flags & GetEnumValue('thread_call_flags_t::THREAD_CALL_FLAG_CONTINUOUS')) : 1142 timer_fire = call.tc_pqlink.deadline - (recent_timestamp + kern.globals.mach_absolutetime_asleep) 1143 else : 1144 timer_fire = call.tc_pqlink.deadline - recent_timestamp 1145 1146 timer_fire_s = kern.GetNanotimeFromAbstime(timer_fire) / 1000000000.0 1147 1148 ttd_s = kern.GetNanotimeFromAbstime(call.tc_ttd) / 1000000000.0 1149 1150 if (is_pending) : 1151 pending_time = call.tc_pending_timestamp - recent_timestamp 1152 pending_time = kern.GetNanotimeFromAbstime(pending_time) / 1000000000.0 1153 1154 flags = int(call.tc_flags) 1155 # TODO: extract this out of the thread_call_flags_t enum 1156 thread_call_flags = {0x0:'', 0x1:'A', 0x2:'W', 0x4:'D', 0x8:'R', 0x10:'S', 0x20:'O', 1157 0x40:'P', 0x80:'L', 0x100:'C'} 1158 1159 flags_str = '' 1160 mask = 0x1 1161 while mask <= 0x100 : 1162 flags_str += thread_call_flags[int(flags & mask)] 1163 mask = mask << 1 1164 1165 if is_iotes : 1166 flags_str += 'I' 1167 1168 if (is_pending) : 1169 print(("{:s}{:#018x}: {:18d} {:18d} {:16.06f} {:16.06f} {:16.06f} {:9s} " + 1170 "{:#018x} ({:#018x}, {:#018x}) ({:s}) {:s}").format(prefix, 1171 unsigned(call), call.tc_pqlink.deadline, call.tc_soft_deadline, ttd_s, 1172 timer_fire_s, pending_time, flags_str, 1173 func, param0, param1, func_name, extra_string)) 1174 else : 1175 print(("{:s}{:#018x}: {:18d} {:18d} {:16.06f} {:16.06f} {:9s} " + 1176 "{:#018x} ({:#018x}, {:#018x}) ({:s}) {:s}").format(prefix, 1177 unsigned(call), call.tc_pqlink.deadline, call.tc_soft_deadline, ttd_s, 1178 timer_fire_s, flags_str, 1179 func, param0, param1, func_name, extra_string)) 1180 1181ShowThreadCall.enable_debug = False 1182 1183@header("{:>18s} {:>18s} {:>18s} {:>16s} {:>16s} {:9s} {:>18s}".format( 1184 "entry", "deadline", "soft_deadline", 1185 "duration (s)", "to go (s)", "flags", "(*func) (param0, param1)")) 1186def PrintThreadGroup(group): 1187 header = PrintThreadGroup.header 1188 pending_header = "{:>18s} {:>18s} {:>18s} {:>16s} {:>16s} {:>16s} {:9s} {:>18s}".format( 1189 "entry", "deadline", "soft_deadline", 1190 "duration (s)", "to go (s)", "pending", "flags", "(*func) (param0, param1)") 1191 1192 recent_timestamp = GetRecentTimestamp() 1193 1194 idle_timestamp_distance = group.idle_timestamp - recent_timestamp 1195 idle_timestamp_distance_s = kern.GetNanotimeFromAbstime(idle_timestamp_distance) / 1000000000.0 1196 1197 is_parallel = "" 1198 1199 if (group.tcg_flags & GetEnumValue('thread_call_group_flags_t::TCG_PARALLEL')) : 1200 is_parallel = " (parallel)" 1201 1202 print("Group: {g.tcg_name:s} ({:#18x}){:s}".format(unsigned(group), is_parallel, g=group)) 1203 print("\t" +"Thread Priority: {g.tcg_thread_pri:d}\n".format(g=group)) 1204 print(("\t" +"Active: {g.active_count:<3d} Idle: {g.idle_count:<3d}" + 1205 "Blocked: {g.blocked_count:<3d} Pending: {g.pending_count:<3d}" + 1206 "Target: {g.target_thread_count:<3d}\n").format(g=group)) 1207 1208 if unsigned(group.idle_timestamp) != 0 : 1209 print("\t" +"Idle Timestamp: {g.idle_timestamp:d} ({:03.06f})\n".format(idle_timestamp_distance_s, 1210 g=group)) 1211 1212 print("\t" +"Pending Queue: ({:>#18x})\n".format(addressof(group.pending_queue))) 1213 if not LinkageChainEmpty(group.pending_queue) : 1214 print("\t\t" + pending_header) 1215 for call in ParanoidIterateLinkageChain(group.pending_queue, "thread_call_t", "tc_qlink"): 1216 ShowThreadCall("\t\t", call, recent_timestamp, is_pending=True) 1217 1218 print("\t" +"Delayed Queue (Absolute Time): ({:>#18x}) timer: ({:>#18x})\n".format( 1219 addressof(group.delayed_queues[0]), addressof(group.delayed_timers[0]))) 1220 if not LinkageChainEmpty(group.delayed_queues[0]) : 1221 print("\t\t" + header) 1222 for call in ParanoidIterateLinkageChain(group.delayed_queues[0], "thread_call_t", "tc_qlink"): 1223 ShowThreadCall("\t\t", call, recent_timestamp) 1224 1225 print("\t" +"Delayed Queue (Continuous Time): ({:>#18x}) timer: ({:>#18x})\n".format( 1226 addressof(group.delayed_queues[1]), addressof(group.delayed_timers[1]))) 1227 if not LinkageChainEmpty(group.delayed_queues[1]) : 1228 print("\t\t" + header) 1229 for call in ParanoidIterateLinkageChain(group.delayed_queues[1], "thread_call_t", "tc_qlink"): 1230 ShowThreadCall("\t\t", call, recent_timestamp) 1231 1232def PrintThreadCallThreads() : 1233 callout_flag = GetEnumValue('thread_tag_t::THREAD_TAG_CALLOUT') 1234 recent_timestamp = GetRecentTimestamp() 1235 1236 for thread in IterateQueue(kern.globals.kernel_task.threads, 'thread *', 'task_threads'): 1237 if (thread.thread_tag & callout_flag) : 1238 print(" {:#20x} {:#12x} {:s}".format(thread, thread.thread_id, GetThreadName(thread))) 1239 state = thread.thc_state 1240 if state and state.thc_call : 1241 print("\t" + PrintThreadGroup.header) 1242 ShowThreadCall("\t", state.thc_call, recent_timestamp) 1243 soft_deadline = state.thc_call_soft_deadline 1244 slop_time = state.thc_call_hard_deadline - soft_deadline 1245 slop_time = kern.GetNanotimeFromAbstime(slop_time) / 1000000000.0 1246 print("\t original soft deadline {:d}, hard deadline {:d} (leeway {:.06f}s)".format( 1247 soft_deadline, state.thc_call_hard_deadline, slop_time)) 1248 enqueue_time = state.thc_call_pending_timestamp - soft_deadline 1249 enqueue_time = kern.GetNanotimeFromAbstime(enqueue_time) / 1000000000.0 1250 print("\t time to enqueue after deadline: {:.06f}s (enqueued at: {:d})".format( 1251 enqueue_time, state.thc_call_pending_timestamp)) 1252 wait_time = state.thc_call_start - state.thc_call_pending_timestamp 1253 wait_time = kern.GetNanotimeFromAbstime(wait_time) / 1000000000.0 1254 print("\t time to start executing after enqueue: {:.06f}s (executing at: {:d})".format( 1255 wait_time, state.thc_call_start)) 1256 1257 if (state.thc_IOTES_invocation_timestamp) : 1258 iotes_acquire_time = state.thc_IOTES_invocation_timestamp - state.thc_call_start 1259 iotes_acquire_time = kern.GetNanotimeFromAbstime(iotes_acquire_time) / 1000000000.0 1260 print("\t IOTES acquire time: {:.06f}s (acquired at: {:d})".format( 1261 iotes_acquire_time, state.thc_IOTES_invocation_timestamp)) 1262 1263 1264@lldb_command('showcalloutgroup') 1265def ShowCalloutGroup(cmd_args=None): 1266 """ Prints out the pending and delayed thread calls for a specific group 1267 1268 Pass 'threads' to show the thread call threads themselves. 1269 1270 Callout flags: 1271 1272 A - Allocated memory owned by thread_call.c 1273 W - Wait - thread waiting for call to finish running 1274 D - Delayed - deadline based 1275 R - Running - currently executing on a thread 1276 S - Signal - call from timer interrupt instead of thread 1277 O - Once - pend the enqueue if re-armed while running 1278 P - Reschedule pending - enqueue is pending due to re-arm while running 1279 L - Rate-limited - (App Nap) 1280 C - Continuous time - Timeout is in mach_continuous_time 1281 I - Callout is an IOTimerEventSource 1282 """ 1283 if not cmd_args: 1284 print("No arguments passed") 1285 print(ShowCalloutGroup.__doc__) 1286 return False 1287 1288 if "threads" in cmd_args[0] : 1289 PrintThreadCallThreads() 1290 return 1291 1292 group = kern.GetValueFromAddress(cmd_args[0], 'struct thread_call_group *') 1293 if not group: 1294 print("unknown arguments:", str(cmd_args)) 1295 return False 1296 1297 PrintThreadGroup(group) 1298 1299@lldb_command('showallcallouts') 1300def ShowAllCallouts(cmd_args=None): 1301 """ Prints out the pending and delayed thread calls for the thread call groups 1302 1303 Callout flags: 1304 1305 A - Allocated memory owned by thread_call.c 1306 W - Wait - thread waiting for call to finish running 1307 D - Delayed - deadline based 1308 R - Running - currently executing on a thread 1309 S - Signal - call from timer interrupt instead of thread 1310 O - Once - pend the enqueue if re-armed while running 1311 P - Reschedule pending - enqueue is pending due to re-arm while running 1312 L - Rate-limited - (App Nap) 1313 C - Continuous time - Timeout is in mach_continuous_time 1314 I - Callout is an IOTimerEventSource 1315 """ 1316 index_max = GetEnumValue('thread_call_index_t::THREAD_CALL_INDEX_MAX') 1317 1318 for i in range (0, index_max) : 1319 group = addressof(kern.globals.thread_call_groups[i]) 1320 PrintThreadGroup(group) 1321 1322 print("Thread Call Threads:") 1323 PrintThreadCallThreads() 1324 1325# EndMacro: showallcallouts 1326 1327