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