| .. | .. |
|---|
| 1 | 1 | // SPDX-License-Identifier: GPL-2.0 |
|---|
| 2 | 2 | /* |
|---|
| 3 | | - * trace_hwlatdetect.c - A simple Hardware Latency detector. |
|---|
| 3 | + * trace_hwlat.c - A simple Hardware Latency detector. |
|---|
| 4 | 4 | * |
|---|
| 5 | 5 | * Use this tracer to detect large system latencies induced by the behavior of |
|---|
| 6 | 6 | * certain underlying system hardware or firmware, independent of Linux itself. |
|---|
| .. | .. |
|---|
| 83 | 83 | u64 nmi_total_ts; /* Total time spent in NMIs */ |
|---|
| 84 | 84 | struct timespec64 timestamp; /* wall time */ |
|---|
| 85 | 85 | int nmi_count; /* # NMIs during this sample */ |
|---|
| 86 | + int count; /* # of iteratons over threash */ |
|---|
| 86 | 87 | }; |
|---|
| 87 | 88 | |
|---|
| 88 | 89 | /* keep the global state somewhere. */ |
|---|
| .. | .. |
|---|
| 104 | 105 | { |
|---|
| 105 | 106 | struct trace_array *tr = hwlat_trace; |
|---|
| 106 | 107 | struct trace_event_call *call = &event_hwlat; |
|---|
| 107 | | - struct ring_buffer *buffer = tr->trace_buffer.buffer; |
|---|
| 108 | + struct trace_buffer *buffer = tr->array_buffer.buffer; |
|---|
| 108 | 109 | struct ring_buffer_event *event; |
|---|
| 109 | 110 | struct hwlat_entry *entry; |
|---|
| 110 | 111 | unsigned long flags; |
|---|
| .. | .. |
|---|
| 124 | 125 | entry->timestamp = sample->timestamp; |
|---|
| 125 | 126 | entry->nmi_total_ts = sample->nmi_total_ts; |
|---|
| 126 | 127 | entry->nmi_count = sample->nmi_count; |
|---|
| 128 | + entry->count = sample->count; |
|---|
| 127 | 129 | |
|---|
| 128 | 130 | if (!call_filter_check_discard(call, entry, buffer, event)) |
|---|
| 129 | 131 | trace_buffer_unlock_commit_nostack(buffer, event); |
|---|
| .. | .. |
|---|
| 167 | 169 | static int get_sample(void) |
|---|
| 168 | 170 | { |
|---|
| 169 | 171 | struct trace_array *tr = hwlat_trace; |
|---|
| 172 | + struct hwlat_sample s; |
|---|
| 170 | 173 | time_type start, t1, t2, last_t2; |
|---|
| 171 | | - s64 diff, total, last_total = 0; |
|---|
| 174 | + s64 diff, outer_diff, total, last_total = 0; |
|---|
| 172 | 175 | u64 sample = 0; |
|---|
| 173 | 176 | u64 thresh = tracing_thresh; |
|---|
| 174 | 177 | u64 outer_sample = 0; |
|---|
| 175 | 178 | int ret = -1; |
|---|
| 179 | + unsigned int count = 0; |
|---|
| 176 | 180 | |
|---|
| 177 | 181 | do_div(thresh, NSEC_PER_USEC); /* modifies interval value */ |
|---|
| 178 | 182 | |
|---|
| .. | .. |
|---|
| 186 | 190 | |
|---|
| 187 | 191 | init_time(last_t2, 0); |
|---|
| 188 | 192 | start = time_get(); /* start timestamp */ |
|---|
| 193 | + outer_diff = 0; |
|---|
| 189 | 194 | |
|---|
| 190 | 195 | do { |
|---|
| 191 | 196 | |
|---|
| .. | .. |
|---|
| 194 | 199 | |
|---|
| 195 | 200 | if (time_u64(last_t2)) { |
|---|
| 196 | 201 | /* Check the delta from outer loop (t2 to next t1) */ |
|---|
| 197 | | - diff = time_to_us(time_sub(t1, last_t2)); |
|---|
| 202 | + outer_diff = time_to_us(time_sub(t1, last_t2)); |
|---|
| 198 | 203 | /* This shouldn't happen */ |
|---|
| 199 | | - if (diff < 0) { |
|---|
| 204 | + if (outer_diff < 0) { |
|---|
| 200 | 205 | pr_err(BANNER "time running backwards\n"); |
|---|
| 201 | 206 | goto out; |
|---|
| 202 | 207 | } |
|---|
| 203 | | - if (diff > outer_sample) |
|---|
| 204 | | - outer_sample = diff; |
|---|
| 208 | + if (outer_diff > outer_sample) |
|---|
| 209 | + outer_sample = outer_diff; |
|---|
| 205 | 210 | } |
|---|
| 206 | 211 | last_t2 = t2; |
|---|
| 207 | 212 | |
|---|
| .. | .. |
|---|
| 216 | 221 | |
|---|
| 217 | 222 | /* This checks the inner loop (t1 to t2) */ |
|---|
| 218 | 223 | diff = time_to_us(time_sub(t2, t1)); /* current diff */ |
|---|
| 224 | + |
|---|
| 225 | + if (diff > thresh || outer_diff > thresh) { |
|---|
| 226 | + if (!count) |
|---|
| 227 | + ktime_get_real_ts64(&s.timestamp); |
|---|
| 228 | + count++; |
|---|
| 229 | + } |
|---|
| 219 | 230 | |
|---|
| 220 | 231 | /* This shouldn't happen */ |
|---|
| 221 | 232 | if (diff < 0) { |
|---|
| .. | .. |
|---|
| 236 | 247 | |
|---|
| 237 | 248 | /* If we exceed the threshold value, we have found a hardware latency */ |
|---|
| 238 | 249 | if (sample > thresh || outer_sample > thresh) { |
|---|
| 239 | | - struct hwlat_sample s; |
|---|
| 250 | + u64 latency; |
|---|
| 240 | 251 | |
|---|
| 241 | 252 | ret = 1; |
|---|
| 242 | 253 | |
|---|
| .. | .. |
|---|
| 248 | 259 | s.seqnum = hwlat_data.count; |
|---|
| 249 | 260 | s.duration = sample; |
|---|
| 250 | 261 | s.outer_duration = outer_sample; |
|---|
| 251 | | - ktime_get_real_ts64(&s.timestamp); |
|---|
| 252 | 262 | s.nmi_total_ts = nmi_total_ts; |
|---|
| 253 | 263 | s.nmi_count = nmi_count; |
|---|
| 264 | + s.count = count; |
|---|
| 254 | 265 | trace_hwlat_sample(&s); |
|---|
| 255 | 266 | |
|---|
| 267 | + latency = max(sample, outer_sample); |
|---|
| 268 | + |
|---|
| 256 | 269 | /* Keep a running maximum ever recorded hardware latency */ |
|---|
| 257 | | - if (sample > tr->max_latency) |
|---|
| 258 | | - tr->max_latency = sample; |
|---|
| 259 | | - if (outer_sample > tr->max_latency) |
|---|
| 260 | | - tr->max_latency = outer_sample; |
|---|
| 270 | + if (latency > tr->max_latency) { |
|---|
| 271 | + tr->max_latency = latency; |
|---|
| 272 | + latency_fsnotify(tr); |
|---|
| 273 | + } |
|---|
| 261 | 274 | } |
|---|
| 262 | 275 | |
|---|
| 263 | 276 | out: |
|---|
| .. | .. |
|---|
| 277 | 290 | return; |
|---|
| 278 | 291 | /* |
|---|
| 279 | 292 | * If for some reason the user modifies the CPU affinity |
|---|
| 280 | | - * of this thread, than stop migrating for the duration |
|---|
| 293 | + * of this thread, then stop migrating for the duration |
|---|
| 281 | 294 | * of the current test. |
|---|
| 282 | 295 | */ |
|---|
| 283 | 296 | if (!cpumask_equal(current_mask, current->cpus_ptr)) |
|---|
| .. | .. |
|---|
| 359 | 372 | return 0; |
|---|
| 360 | 373 | |
|---|
| 361 | 374 | /* Just pick the first CPU on first iteration */ |
|---|
| 362 | | - current_mask = &save_cpumask; |
|---|
| 363 | 375 | get_online_cpus(); |
|---|
| 364 | 376 | cpumask_and(current_mask, cpu_online_mask, tr->tracing_cpumask); |
|---|
| 365 | 377 | put_online_cpus(); |
|---|
| .. | .. |
|---|
| 526 | 538 | */ |
|---|
| 527 | 539 | static int init_tracefs(void) |
|---|
| 528 | 540 | { |
|---|
| 529 | | - struct dentry *d_tracer; |
|---|
| 541 | + int ret; |
|---|
| 530 | 542 | struct dentry *top_dir; |
|---|
| 531 | 543 | |
|---|
| 532 | | - d_tracer = tracing_init_dentry(); |
|---|
| 533 | | - if (IS_ERR(d_tracer)) |
|---|
| 544 | + ret = tracing_init_dentry(); |
|---|
| 545 | + if (ret) |
|---|
| 534 | 546 | return -ENOMEM; |
|---|
| 535 | 547 | |
|---|
| 536 | | - top_dir = tracefs_create_dir("hwlat_detector", d_tracer); |
|---|
| 548 | + top_dir = tracefs_create_dir("hwlat_detector", NULL); |
|---|
| 537 | 549 | if (!top_dir) |
|---|
| 538 | 550 | return -ENOMEM; |
|---|
| 539 | 551 | |
|---|
| .. | .. |
|---|
| 554 | 566 | return 0; |
|---|
| 555 | 567 | |
|---|
| 556 | 568 | err: |
|---|
| 557 | | - tracefs_remove_recursive(top_dir); |
|---|
| 569 | + tracefs_remove(top_dir); |
|---|
| 558 | 570 | return -ENOMEM; |
|---|
| 559 | 571 | } |
|---|
| 560 | 572 | |
|---|