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