| 1 | |
| 2 |
|
| 3 | |
| 4 | |
| 5 | |
| 6 |
|
| 7 | from tracecmd import *
|
| 8 |
|
| 9 | def load_kallsyms(file_path='/proc/kallsyms'):
|
| 10 | |
| 11 | Parses /proc/kallsyms into a dictionary.
|
| 12 | Returns: { address_int: symbol_name }
|
| 13 |
|
| 14 | kallsyms_map = {}
|
| 15 |
|
| 16 | try:
|
| 17 | with open(file_path, 'r') as f:
|
| 18 | for line in f:
|
| 19 | |
| 20 | parts = line.split()
|
| 21 | if len(parts) < 3:
|
| 22 | continue
|
| 23 |
|
| 24 | addr = int(parts[0], 16)
|
| 25 | name = parts[2]
|
| 26 |
|
| 27 | kallsyms_map[addr] = name
|
| 28 |
|
| 29 | except PermissionError:
|
| 30 | print(f"Error: Permission denied reading {file_path}. Try running with sudo.")
|
| 31 | except FileNotFoundError:
|
| 32 | print(f"Error: {file_path} not found.")
|
| 33 |
|
| 34 | return kallsyms_map
|
| 35 |
|
| 36 | ksyms = load_kallsyms()
|
| 37 |
|
| 38 | |
| 39 | pending = {}
|
| 40 |
|
| 41 | |
| 42 | histograms = {}
|
| 43 |
|
| 44 | class OnlineHarmonicMean:
|
| 45 | def __init__(self):
|
| 46 | self.n = 0 |
| 47 | self.S = 0.0 |
| 48 |
|
| 49 | def update(self, x):
|
| 50 | if x == 0:
|
| 51 | raise ValueError("Harmonic mean is undefined for zero.")
|
| 52 |
|
| 53 | self.n += 1
|
| 54 | self.S += 1.0 / x
|
| 55 | return self.n / self.S
|
| 56 |
|
| 57 | @property
|
| 58 | def mean(self):
|
| 59 | return self.n / self.S if self.n > 0 else 0
|
| 60 |
|
| 61 | ohms = {}
|
| 62 |
|
| 63 | def handle_start(record):
|
| 64 | func_name = ksyms[record.num_field("function")]
|
| 65 | if "rseq_slice_expired" in func_name:
|
| 66 | timer_ptr = record.num_field("hrtimer")
|
| 67 | pending[timer_ptr] = {
|
| 68 | 'ts': record.ts,
|
| 69 | 'comm': record.comm
|
| 70 | }
|
| 71 | return None
|
| 72 |
|
| 73 | def handle_cancel(record):
|
| 74 | timer_ptr = record.num_field("hrtimer")
|
| 75 |
|
| 76 | if timer_ptr in pending:
|
| 77 | start_data = pending.pop(timer_ptr)
|
| 78 | duration_ns = record.ts - start_data['ts']
|
| 79 | duration_us = duration_ns // 1000
|
| 80 |
|
| 81 | comm = start_data['comm']
|
| 82 |
|
| 83 | if comm not in ohms:
|
| 84 | ohms[comm] = OnlineHarmonicMean()
|
| 85 |
|
| 86 | ohms[comm].update(duration_ns)
|
| 87 |
|
| 88 | if comm not in histograms:
|
| 89 | histograms[comm] = {}
|
| 90 |
|
| 91 | histograms[comm][duration_us] = histograms[comm].get(duration_us, 0) + 1
|
| 92 | return None
|
| 93 |
|
| 94 | def handle_expire(record):
|
| 95 | timer_ptr = record.num_field("hrtimer")
|
| 96 |
|
| 97 | if timer_ptr in pending:
|
| 98 | start_data = pending.pop(timer_ptr)
|
| 99 | comm = start_data['comm']
|
| 100 |
|
| 101 | if comm not in histograms:
|
| 102 | histograms[comm] = {}
|
| 103 |
|
| 104 | |
| 105 | histograms[comm][-1] = histograms[comm].get(-1, 0) + 1
|
| 106 | return None
|
| 107 |
|
| 108 | if __name__ == "__main__":
|
| 109 | t = Trace("trace.dat")
|
| 110 | for cpu in range(0, t.cpus):
|
| 111 | ev = t.read_event(cpu)
|
| 112 | while ev:
|
| 113 | if "hrtimer_start" in ev.name:
|
| 114 | handle_start(ev)
|
| 115 | if "hrtimer_cancel" in ev.name:
|
| 116 | handle_cancel(ev)
|
| 117 | if "hrtimer_expire_entry" in ev.name:
|
| 118 | handle_expire(ev)
|
| 119 |
|
| 120 | ev = t.read_event(cpu)
|
| 121 |
|
| 122 | print("\n" + "="*40)
|
| 123 | print("RSEQ SLICE HISTOGRAM (us)")
|
| 124 | print("="*40)
|
| 125 | for comm, buckets in histograms.items():
|
| 126 | print(f"\nTask: {comm} Mean: {ohms[comm].mean:.3f} ns")
|
| 127 | print(f" {'Latency (us)':<15} | {'Count'}")
|
| 128 | print(f" {'-'*30}")
|
| 129 | |
| 130 | for bucket in sorted(buckets.keys()):
|
| 131 | label = "EXPIRED" if bucket == -1 else f"{bucket} us"
|
| 132 | print(f" {label:<15} | {buckets[bucket]}")
|