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