projects/linux·blob master · refs

592 lines · 15.0 KiB

1// SPDX-License-Identifier: GPL-2.0
2/*
3 * Copyright (C) 2021 Red Hat Inc, Daniel Bristot de Oliveira <[email protected]>
4 */
5
6#define _GNU_SOURCE
7#include <stdlib.h>
8#include <string.h>
9#include <signal.h>
10#include <unistd.h>
11#include <stdio.h>
12#include <time.h>
13#include <sched.h>
14#include <pthread.h>
15
16#include "timerlat.h"
17#include "timerlat_aa.h"
18#include "timerlat_bpf.h"
19#include "cli.h"
20#include "common.h"
21
22struct timerlat_top_cpu {
23 unsigned long long irq_count;
24 unsigned long long thread_count;
25 unsigned long long user_count;
26
27 unsigned long long cur_irq;
28 unsigned long long min_irq;
29 unsigned long long sum_irq;
30 unsigned long long max_irq;
31
32 unsigned long long cur_thread;
33 unsigned long long min_thread;
34 unsigned long long sum_thread;
35 unsigned long long max_thread;
36
37 unsigned long long cur_user;
38 unsigned long long min_user;
39 unsigned long long sum_user;
40 unsigned long long max_user;
41};
42
43struct timerlat_top_data {
44 struct timerlat_top_cpu *cpu_data;
45};
46
47/*
48 * timerlat_free_top - free runtime data
49 */
50static void timerlat_free_top(struct timerlat_top_data *data)
51{
52 free(data->cpu_data);
53 free(data);
54}
55
56static void timerlat_free_top_tool(struct osnoise_tool *tool)
57{
58 timerlat_free_top(tool->data);
59 timerlat_free(tool);
60}
61
62/*
63 * timerlat_alloc_histogram - alloc runtime data
64 */
65static struct timerlat_top_data *timerlat_alloc_top(void)
66{
67 struct timerlat_top_data *data;
68 int cpu;
69
70 data = calloc(1, sizeof(*data));
71 if (!data)
72 return NULL;
73
74 /* one set of histograms per CPU */
75 data->cpu_data = calloc(1, sizeof(*data->cpu_data) * nr_cpus);
76 if (!data->cpu_data)
77 goto cleanup;
78
79 /* set the min to max */
80 for (cpu = 0; cpu < nr_cpus; cpu++) {
81 data->cpu_data[cpu].min_irq = ~0;
82 data->cpu_data[cpu].min_thread = ~0;
83 data->cpu_data[cpu].min_user = ~0;
84 }
85
86 return data;
87
88cleanup:
89 timerlat_free_top(data);
90 return NULL;
91}
92
93static void
94timerlat_top_reset_sum(struct timerlat_top_cpu *summary)
95{
96 memset(summary, 0, sizeof(*summary));
97 summary->min_irq = ~0;
98 summary->min_thread = ~0;
99 summary->min_user = ~0;
100}
101
102static void
103timerlat_top_update_sum(struct osnoise_tool *tool, int cpu, struct timerlat_top_cpu *sum)
104{
105 struct timerlat_top_data *data = tool->data;
106 struct timerlat_top_cpu *cpu_data = &data->cpu_data[cpu];
107
108 sum->irq_count += cpu_data->irq_count;
109 update_min(&sum->min_irq, &cpu_data->min_irq);
110 update_sum(&sum->sum_irq, &cpu_data->sum_irq);
111 update_max(&sum->max_irq, &cpu_data->max_irq);
112
113 sum->thread_count += cpu_data->thread_count;
114 update_min(&sum->min_thread, &cpu_data->min_thread);
115 update_sum(&sum->sum_thread, &cpu_data->sum_thread);
116 update_max(&sum->max_thread, &cpu_data->max_thread);
117
118 sum->user_count += cpu_data->user_count;
119 update_min(&sum->min_user, &cpu_data->min_user);
120 update_sum(&sum->sum_user, &cpu_data->sum_user);
121 update_max(&sum->max_user, &cpu_data->max_user);
122}
123
124/*
125 * timerlat_hist_update - record a new timerlat occurent on cpu, updating data
126 */
127static void
128timerlat_top_update(struct osnoise_tool *tool, int cpu,
129 unsigned long long thread,
130 unsigned long long latency)
131{
132 struct timerlat_params *params = to_timerlat_params(tool->params);
133 struct timerlat_top_data *data = tool->data;
134 struct timerlat_top_cpu *cpu_data = &data->cpu_data[cpu];
135
136 if (params->common.output_divisor)
137 latency = latency / params->common.output_divisor;
138
139 if (!thread) {
140 cpu_data->irq_count++;
141 cpu_data->cur_irq = latency;
142 update_min(&cpu_data->min_irq, &latency);
143 update_sum(&cpu_data->sum_irq, &latency);
144 update_max(&cpu_data->max_irq, &latency);
145 } else if (thread == 1) {
146 cpu_data->thread_count++;
147 cpu_data->cur_thread = latency;
148 update_min(&cpu_data->min_thread, &latency);
149 update_sum(&cpu_data->sum_thread, &latency);
150 update_max(&cpu_data->max_thread, &latency);
151 } else {
152 cpu_data->user_count++;
153 cpu_data->cur_user = latency;
154 update_min(&cpu_data->min_user, &latency);
155 update_sum(&cpu_data->sum_user, &latency);
156 update_max(&cpu_data->max_user, &latency);
157 }
158}
159
160/*
161 * timerlat_top_handler - this is the handler for timerlat tracer events
162 */
163static int
164timerlat_top_handler(struct trace_seq *s, struct tep_record *record,
165 struct tep_event *event, void *context)
166{
167 struct trace_instance *trace = context;
168 unsigned long long latency, thread;
169 struct osnoise_tool *top;
170 int cpu = record->cpu;
171
172 top = container_of(trace, struct osnoise_tool, trace);
173
174 if (!top->params->aa_only) {
175 tep_get_field_val(s, event, "context", record, &thread, 1);
176 tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
177
178 timerlat_top_update(top, cpu, thread, latency);
179 }
180
181 return 0;
182}
183
184/*
185 * timerlat_top_bpf_pull_data - copy data from BPF maps into userspace
186 */
187static int timerlat_top_bpf_pull_data(struct osnoise_tool *tool)
188{
189 struct timerlat_top_data *data = tool->data;
190 int i, err;
191 long long value_irq[nr_cpus],
192 value_thread[nr_cpus],
193 value_user[nr_cpus];
194
195 /* Pull summary */
196 err = timerlat_bpf_get_summary_value(SUMMARY_CURRENT,
197 value_irq, value_thread, value_user);
198 if (err)
199 return err;
200 for (i = 0; i < nr_cpus; i++) {
201 data->cpu_data[i].cur_irq = value_irq[i];
202 data->cpu_data[i].cur_thread = value_thread[i];
203 data->cpu_data[i].cur_user = value_user[i];
204 }
205
206 err = timerlat_bpf_get_summary_value(SUMMARY_COUNT,
207 value_irq, value_thread, value_user);
208 if (err)
209 return err;
210 for (i = 0; i < nr_cpus; i++) {
211 data->cpu_data[i].irq_count = value_irq[i];
212 data->cpu_data[i].thread_count = value_thread[i];
213 data->cpu_data[i].user_count = value_user[i];
214 }
215
216 err = timerlat_bpf_get_summary_value(SUMMARY_MIN,
217 value_irq, value_thread, value_user);
218 if (err)
219 return err;
220 for (i = 0; i < nr_cpus; i++) {
221 data->cpu_data[i].min_irq = value_irq[i];
222 data->cpu_data[i].min_thread = value_thread[i];
223 data->cpu_data[i].min_user = value_user[i];
224 }
225
226 err = timerlat_bpf_get_summary_value(SUMMARY_MAX,
227 value_irq, value_thread, value_user);
228 if (err)
229 return err;
230 for (i = 0; i < nr_cpus; i++) {
231 data->cpu_data[i].max_irq = value_irq[i];
232 data->cpu_data[i].max_thread = value_thread[i];
233 data->cpu_data[i].max_user = value_user[i];
234 }
235
236 err = timerlat_bpf_get_summary_value(SUMMARY_SUM,
237 value_irq, value_thread, value_user);
238 if (err)
239 return err;
240 for (i = 0; i < nr_cpus; i++) {
241 data->cpu_data[i].sum_irq = value_irq[i];
242 data->cpu_data[i].sum_thread = value_thread[i];
243 data->cpu_data[i].sum_user = value_user[i];
244 }
245
246 return 0;
247}
248
249/*
250 * timerlat_top_header - print the header of the tool output
251 */
252static void timerlat_top_header(struct timerlat_params *params, struct osnoise_tool *top)
253{
254 struct trace_seq *s = top->trace.seq;
255 bool pretty = params->common.pretty_output;
256 char duration[26];
257
258 get_duration(top->start_time, duration, sizeof(duration));
259
260 if (pretty)
261 trace_seq_printf(s, "\033[2;37;40m");
262
263 trace_seq_printf(s, " Timer Latency ");
264 if (params->common.user_data)
265 trace_seq_printf(s, " ");
266
267 if (pretty)
268 trace_seq_printf(s, "\033[0;0;0m");
269 trace_seq_printf(s, "\n");
270
271 trace_seq_printf(s, "%-6s | IRQ Timer Latency (%s) | Thread Timer Latency (%s)", duration,
272 params->common.output_divisor == 1 ? "ns" : "us",
273 params->common.output_divisor == 1 ? "ns" : "us");
274
275 if (params->common.user_data) {
276 trace_seq_printf(s, " | Ret user Timer Latency (%s)",
277 params->common.output_divisor == 1 ? "ns" : "us");
278 }
279
280 trace_seq_printf(s, "\n");
281 if (pretty)
282 trace_seq_printf(s, "\033[2;30;47m");
283
284 trace_seq_printf(s, "CPU COUNT | cur min avg max | cur min avg max");
285 if (params->common.user_data)
286 trace_seq_printf(s, " | cur min avg max");
287
288 if (pretty)
289 trace_seq_printf(s, "\033[0;0;0m");
290 trace_seq_printf(s, "\n");
291}
292
293static const char *no_value = " -";
294
295/*
296 * timerlat_top_print - prints the output of a given CPU
297 */
298static void timerlat_top_print(struct osnoise_tool *top, int cpu)
299{
300 struct timerlat_params *params = to_timerlat_params(top->params);
301 struct timerlat_top_data *data = top->data;
302 struct timerlat_top_cpu *cpu_data = &data->cpu_data[cpu];
303 struct trace_seq *s = top->trace.seq;
304
305 /*
306 * Skip if no data is available: is this cpu offline?
307 */
308 if (!cpu_data->irq_count && !cpu_data->thread_count)
309 return;
310
311 /*
312 * Unless trace is being lost, IRQ counter is always the max.
313 */
314 trace_seq_printf(s, "%3d #%-9llu |", cpu, cpu_data->irq_count);
315
316 if (!cpu_data->irq_count) {
317 trace_seq_printf(s, "%s %s %s %s |", no_value, no_value, no_value, no_value);
318 } else {
319 trace_seq_printf(s, "%9llu ", cpu_data->cur_irq);
320 trace_seq_printf(s, "%9llu ", cpu_data->min_irq);
321 trace_seq_printf(s, "%9llu ", cpu_data->sum_irq / cpu_data->irq_count);
322 trace_seq_printf(s, "%9llu |", cpu_data->max_irq);
323 }
324
325 if (!cpu_data->thread_count) {
326 trace_seq_printf(s, "%s %s %s %s", no_value, no_value, no_value, no_value);
327 } else {
328 trace_seq_printf(s, "%9llu ", cpu_data->cur_thread);
329 trace_seq_printf(s, "%9llu ", cpu_data->min_thread);
330 trace_seq_printf(s, "%9llu ",
331 cpu_data->sum_thread / cpu_data->thread_count);
332 trace_seq_printf(s, "%9llu", cpu_data->max_thread);
333 }
334
335 if (!params->common.user_data) {
336 trace_seq_printf(s, "\n");
337 return;
338 }
339
340 trace_seq_printf(s, " |");
341
342 if (!cpu_data->user_count) {
343 trace_seq_printf(s, "%s %s %s %s\n", no_value, no_value, no_value, no_value);
344 } else {
345 trace_seq_printf(s, "%9llu ", cpu_data->cur_user);
346 trace_seq_printf(s, "%9llu ", cpu_data->min_user);
347 trace_seq_printf(s, "%9llu ",
348 cpu_data->sum_user / cpu_data->user_count);
349 trace_seq_printf(s, "%9llu\n", cpu_data->max_user);
350 }
351}
352
353/*
354 * timerlat_top_print_sum - prints the summary output
355 */
356static void
357timerlat_top_print_sum(struct osnoise_tool *top, struct timerlat_top_cpu *summary)
358{
359 const char *split = "----------------------------------------";
360 struct timerlat_params *params = to_timerlat_params(top->params);
361 unsigned long long count = summary->irq_count;
362 struct trace_seq *s = top->trace.seq;
363 int e = 0;
364
365 /*
366 * Skip if no data is available: is this cpu offline?
367 */
368 if (!summary->irq_count && !summary->thread_count)
369 return;
370
371 while (count > 999999) {
372 e++;
373 count /= 10;
374 }
375
376 trace_seq_printf(s, "%.*s|%.*s|%.*s", 15, split, 40, split, 39, split);
377 if (params->common.user_data)
378 trace_seq_printf(s, "-|%.*s", 39, split);
379 trace_seq_printf(s, "\n");
380
381 trace_seq_printf(s, "ALL #%-6llu e%d |", count, e);
382
383 if (!summary->irq_count) {
384 trace_seq_printf(s, " %s %s %s |", no_value, no_value, no_value);
385 } else {
386 trace_seq_printf(s, " ");
387 trace_seq_printf(s, "%9llu ", summary->min_irq);
388 trace_seq_printf(s, "%9llu ", summary->sum_irq / summary->irq_count);
389 trace_seq_printf(s, "%9llu |", summary->max_irq);
390 }
391
392 if (!summary->thread_count) {
393 trace_seq_printf(s, "%s %s %s %s", no_value, no_value, no_value, no_value);
394 } else {
395 trace_seq_printf(s, " ");
396 trace_seq_printf(s, "%9llu ", summary->min_thread);
397 trace_seq_printf(s, "%9llu ",
398 summary->sum_thread / summary->thread_count);
399 trace_seq_printf(s, "%9llu", summary->max_thread);
400 }
401
402 if (!params->common.user_data) {
403 trace_seq_printf(s, "\n");
404 return;
405 }
406
407 trace_seq_printf(s, " |");
408
409 if (!summary->user_count) {
410 trace_seq_printf(s, " %s %s %s |", no_value, no_value, no_value);
411 } else {
412 trace_seq_printf(s, " ");
413 trace_seq_printf(s, "%9llu ", summary->min_user);
414 trace_seq_printf(s, "%9llu ",
415 summary->sum_user / summary->user_count);
416 trace_seq_printf(s, "%9llu\n", summary->max_user);
417 }
418}
419
420/*
421 * clear_terminal - clears the output terminal
422 */
423static void clear_terminal(struct trace_seq *seq)
424{
425 if (!config_debug)
426 trace_seq_printf(seq, "\033c");
427}
428
429/*
430 * timerlat_print_stats - print data for all cpus
431 */
432static void
433timerlat_print_stats(struct osnoise_tool *top)
434{
435 struct timerlat_params *params = to_timerlat_params(top->params);
436 struct trace_instance *trace = &top->trace;
437 struct timerlat_top_cpu summary;
438 int i;
439
440 if (params->common.aa_only)
441 return;
442
443 if (!params->common.quiet)
444 clear_terminal(trace->seq);
445
446 timerlat_top_reset_sum(&summary);
447
448 timerlat_top_header(params, top);
449
450 for_each_monitored_cpu(i, &params->common) {
451 timerlat_top_print(top, i);
452 timerlat_top_update_sum(top, i, &summary);
453 }
454
455 timerlat_top_print_sum(top, &summary);
456
457 trace_seq_do_printf(trace->seq);
458 trace_seq_reset(trace->seq);
459 osnoise_report_missed_events(top);
460}
461
462/*
463 * timerlat_top_apply_config - apply the top configs to the initialized tool
464 */
465static int
466timerlat_top_apply_config(struct osnoise_tool *top)
467{
468 struct timerlat_params *params = to_timerlat_params(top->params);
469 int retval;
470
471 retval = timerlat_apply_config(top, params);
472 if (retval)
473 goto out_err;
474
475 if (isatty(STDOUT_FILENO) && !params->common.quiet)
476 params->common.pretty_output = 1;
477
478 return 0;
479
480out_err:
481 return -1;
482}
483
484/*
485 * timerlat_init_top - initialize a timerlat top tool with parameters
486 */
487static struct osnoise_tool
488*timerlat_init_top(struct common_params *params)
489{
490 struct osnoise_tool *top;
491
492 top = osnoise_init_tool("timerlat_top");
493 if (!top)
494 return NULL;
495
496 top->data = timerlat_alloc_top();
497 if (!top->data)
498 goto out_err;
499
500 tep_register_event_handler(top->trace.tep, -1, "ftrace", "timerlat",
501 timerlat_top_handler, top);
502
503 return top;
504
505out_err:
506 osnoise_destroy_tool(top);
507 return NULL;
508}
509
510/*
511 * timerlat_top_bpf_main_loop - main loop to process events (BPF variant)
512 */
513static int
514timerlat_top_bpf_main_loop(struct osnoise_tool *tool)
515{
516 const struct common_params *params = tool->params;
517 int retval, wait_retval;
518
519 if (params->aa_only) {
520 /* Auto-analysis only, just wait for stop tracing */
521 timerlat_bpf_wait(-1);
522 return 0;
523 }
524
525 /* Pull and display data in a loop */
526 while (!stop_tracing) {
527 wait_retval = timerlat_bpf_wait(params->quiet ? -1 :
528 params->sleep_time);
529
530 retval = timerlat_top_bpf_pull_data(tool);
531 if (retval) {
532 err_msg("Error pulling BPF data\n");
533 return retval;
534 }
535
536 if (!params->quiet)
537 timerlat_print_stats(tool);
538
539 if (wait_retval > 0) {
540 /* Stopping requested by tracer */
541 retval = common_threshold_handler(tool);
542 if (retval)
543 return retval;
544
545 if (!should_continue_tracing(tool->params))
546 break;
547
548 if (timerlat_bpf_restart_tracing()) {
549 err_msg("Error restarting BPF trace\n");
550 return -1;
551 }
552 }
553
554 /* is there still any user-threads ? */
555 if (params->user_workload) {
556 if (params->user.stopped_running) {
557 debug_msg("timerlat user space threads stopped!\n");
558 break;
559 }
560 }
561 }
562
563 return 0;
564}
565
566static int timerlat_top_main_loop(struct osnoise_tool *tool)
567{
568 struct timerlat_params *params = to_timerlat_params(tool->params);
569 int retval;
570
571 if (params->mode == TRACING_MODE_TRACEFS) {
572 retval = top_main_loop(tool);
573 } else {
574 retval = timerlat_top_bpf_main_loop(tool);
575 timerlat_bpf_detach();
576 }
577
578 return retval;
579}
580
581struct tool_ops timerlat_top_ops = {
582 .tracer = "timerlat",
583 .comm_prefix = "timerlat/",
584 .parse_args = timerlat_top_parse_args,
585 .init_tool = timerlat_init_top,
586 .apply_config = timerlat_top_apply_config,
587 .enable = timerlat_enable,
588 .main = timerlat_top_main_loop,
589 .print_stats = timerlat_print_stats,
590 .analyze = timerlat_analyze,
591 .free = timerlat_free_top_tool,
592};