1 // SPDX-License-Identifier: GPL-2.0
2 /*
3 * Copyright (C) 2021 Red Hat Inc, Daniel Bristot de Oliveira <bristot@kernel.org>
4 */
5
6 #define _GNU_SOURCE
7 #include <getopt.h>
8 #include <stdlib.h>
9 #include <string.h>
10 #include <signal.h>
11 #include <unistd.h>
12 #include <stdio.h>
13 #include <time.h>
14 #include <sched.h>
15 #include <pthread.h>
16
17 #include "timerlat.h"
18 #include "timerlat_aa.h"
19 #include "timerlat_bpf.h"
20
21 struct timerlat_hist_cpu {
22 int *irq;
23 int *thread;
24 int *user;
25
26 unsigned long long irq_count;
27 unsigned long long thread_count;
28 unsigned long long user_count;
29
30 unsigned long long min_irq;
31 unsigned long long sum_irq;
32 unsigned long long max_irq;
33
34 unsigned long long min_thread;
35 unsigned long long sum_thread;
36 unsigned long long max_thread;
37
38 unsigned long long min_user;
39 unsigned long long sum_user;
40 unsigned long long max_user;
41 };
42
43 struct timerlat_hist_data {
44 struct timerlat_hist_cpu *hist;
45 int entries;
46 int bucket_size;
47 int nr_cpus;
48 };
49
50 /*
51 * timerlat_free_histogram - free runtime data
52 */
53 static void
timerlat_free_histogram(struct timerlat_hist_data * data)54 timerlat_free_histogram(struct timerlat_hist_data *data)
55 {
56 int cpu;
57
58 /* one histogram for IRQ and one for thread, per CPU */
59 for (cpu = 0; cpu < data->nr_cpus; cpu++) {
60 if (data->hist[cpu].irq)
61 free(data->hist[cpu].irq);
62
63 if (data->hist[cpu].thread)
64 free(data->hist[cpu].thread);
65
66 if (data->hist[cpu].user)
67 free(data->hist[cpu].user);
68
69 }
70
71 /* one set of histograms per CPU */
72 if (data->hist)
73 free(data->hist);
74 }
75
timerlat_free_histogram_tool(struct osnoise_tool * tool)76 static void timerlat_free_histogram_tool(struct osnoise_tool *tool)
77 {
78 timerlat_free_histogram(tool->data);
79 timerlat_free(tool);
80 }
81
82 /*
83 * timerlat_alloc_histogram - alloc runtime data
84 */
85 static struct timerlat_hist_data
timerlat_alloc_histogram(int nr_cpus,int entries,int bucket_size)86 *timerlat_alloc_histogram(int nr_cpus, int entries, int bucket_size)
87 {
88 struct timerlat_hist_data *data;
89 int cpu;
90
91 data = calloc(1, sizeof(*data));
92 if (!data)
93 return NULL;
94
95 data->entries = entries;
96 data->bucket_size = bucket_size;
97 data->nr_cpus = nr_cpus;
98
99 /* one set of histograms per CPU */
100 data->hist = calloc(1, sizeof(*data->hist) * nr_cpus);
101 if (!data->hist)
102 goto cleanup;
103
104 /* one histogram for IRQ and one for thread, per cpu */
105 for (cpu = 0; cpu < nr_cpus; cpu++) {
106 data->hist[cpu].irq = calloc(1, sizeof(*data->hist->irq) * (entries + 1));
107 if (!data->hist[cpu].irq)
108 goto cleanup;
109
110 data->hist[cpu].thread = calloc(1, sizeof(*data->hist->thread) * (entries + 1));
111 if (!data->hist[cpu].thread)
112 goto cleanup;
113
114 data->hist[cpu].user = calloc(1, sizeof(*data->hist->user) * (entries + 1));
115 if (!data->hist[cpu].user)
116 goto cleanup;
117 }
118
119 /* set the min to max */
120 for (cpu = 0; cpu < nr_cpus; cpu++) {
121 data->hist[cpu].min_irq = ~0;
122 data->hist[cpu].min_thread = ~0;
123 data->hist[cpu].min_user = ~0;
124 }
125
126 return data;
127
128 cleanup:
129 timerlat_free_histogram(data);
130 return NULL;
131 }
132
133 /*
134 * timerlat_hist_update - record a new timerlat occurent on cpu, updating data
135 */
136 static void
timerlat_hist_update(struct osnoise_tool * tool,int cpu,unsigned long long context,unsigned long long latency)137 timerlat_hist_update(struct osnoise_tool *tool, int cpu,
138 unsigned long long context,
139 unsigned long long latency)
140 {
141 struct timerlat_params *params = to_timerlat_params(tool->params);
142 struct timerlat_hist_data *data = tool->data;
143 int entries = data->entries;
144 int bucket;
145 int *hist;
146
147 if (params->common.output_divisor)
148 latency = latency / params->common.output_divisor;
149
150 bucket = latency / data->bucket_size;
151
152 if (!context) {
153 hist = data->hist[cpu].irq;
154 data->hist[cpu].irq_count++;
155 update_min(&data->hist[cpu].min_irq, &latency);
156 update_sum(&data->hist[cpu].sum_irq, &latency);
157 update_max(&data->hist[cpu].max_irq, &latency);
158 } else if (context == 1) {
159 hist = data->hist[cpu].thread;
160 data->hist[cpu].thread_count++;
161 update_min(&data->hist[cpu].min_thread, &latency);
162 update_sum(&data->hist[cpu].sum_thread, &latency);
163 update_max(&data->hist[cpu].max_thread, &latency);
164 } else { /* user */
165 hist = data->hist[cpu].user;
166 data->hist[cpu].user_count++;
167 update_min(&data->hist[cpu].min_user, &latency);
168 update_sum(&data->hist[cpu].sum_user, &latency);
169 update_max(&data->hist[cpu].max_user, &latency);
170 }
171
172 if (bucket < entries)
173 hist[bucket]++;
174 else
175 hist[entries]++;
176 }
177
178 /*
179 * timerlat_hist_handler - this is the handler for timerlat tracer events
180 */
181 static int
timerlat_hist_handler(struct trace_seq * s,struct tep_record * record,struct tep_event * event,void * data)182 timerlat_hist_handler(struct trace_seq *s, struct tep_record *record,
183 struct tep_event *event, void *data)
184 {
185 struct trace_instance *trace = data;
186 unsigned long long context, latency;
187 struct osnoise_tool *tool;
188 int cpu = record->cpu;
189
190 tool = container_of(trace, struct osnoise_tool, trace);
191
192 tep_get_field_val(s, event, "context", record, &context, 1);
193 tep_get_field_val(s, event, "timer_latency", record, &latency, 1);
194
195 timerlat_hist_update(tool, cpu, context, latency);
196
197 return 0;
198 }
199
200 /*
201 * timerlat_hist_bpf_pull_data - copy data from BPF maps into userspace
202 */
timerlat_hist_bpf_pull_data(struct osnoise_tool * tool)203 static int timerlat_hist_bpf_pull_data(struct osnoise_tool *tool)
204 {
205 struct timerlat_hist_data *data = tool->data;
206 int i, j, err;
207 long long value_irq[data->nr_cpus],
208 value_thread[data->nr_cpus],
209 value_user[data->nr_cpus];
210
211 /* Pull histogram */
212 for (i = 0; i < data->entries; i++) {
213 err = timerlat_bpf_get_hist_value(i, value_irq, value_thread,
214 value_user, data->nr_cpus);
215 if (err)
216 return err;
217 for (j = 0; j < data->nr_cpus; j++) {
218 data->hist[j].irq[i] = value_irq[j];
219 data->hist[j].thread[i] = value_thread[j];
220 data->hist[j].user[i] = value_user[j];
221 }
222 }
223
224 /* Pull summary */
225 err = timerlat_bpf_get_summary_value(SUMMARY_COUNT,
226 value_irq, value_thread, value_user,
227 data->nr_cpus);
228 if (err)
229 return err;
230 for (i = 0; i < data->nr_cpus; i++) {
231 data->hist[i].irq_count = value_irq[i];
232 data->hist[i].thread_count = value_thread[i];
233 data->hist[i].user_count = value_user[i];
234 }
235
236 err = timerlat_bpf_get_summary_value(SUMMARY_MIN,
237 value_irq, value_thread, value_user,
238 data->nr_cpus);
239 if (err)
240 return err;
241 for (i = 0; i < data->nr_cpus; i++) {
242 data->hist[i].min_irq = value_irq[i];
243 data->hist[i].min_thread = value_thread[i];
244 data->hist[i].min_user = value_user[i];
245 }
246
247 err = timerlat_bpf_get_summary_value(SUMMARY_MAX,
248 value_irq, value_thread, value_user,
249 data->nr_cpus);
250 if (err)
251 return err;
252 for (i = 0; i < data->nr_cpus; i++) {
253 data->hist[i].max_irq = value_irq[i];
254 data->hist[i].max_thread = value_thread[i];
255 data->hist[i].max_user = value_user[i];
256 }
257
258 err = timerlat_bpf_get_summary_value(SUMMARY_SUM,
259 value_irq, value_thread, value_user,
260 data->nr_cpus);
261 if (err)
262 return err;
263 for (i = 0; i < data->nr_cpus; i++) {
264 data->hist[i].sum_irq = value_irq[i];
265 data->hist[i].sum_thread = value_thread[i];
266 data->hist[i].sum_user = value_user[i];
267 }
268
269 err = timerlat_bpf_get_summary_value(SUMMARY_OVERFLOW,
270 value_irq, value_thread, value_user,
271 data->nr_cpus);
272 if (err)
273 return err;
274 for (i = 0; i < data->nr_cpus; i++) {
275 data->hist[i].irq[data->entries] = value_irq[i];
276 data->hist[i].thread[data->entries] = value_thread[i];
277 data->hist[i].user[data->entries] = value_user[i];
278 }
279
280 return 0;
281 }
282
283 /*
284 * timerlat_hist_header - print the header of the tracer to the output
285 */
timerlat_hist_header(struct osnoise_tool * tool)286 static void timerlat_hist_header(struct osnoise_tool *tool)
287 {
288 struct timerlat_params *params = to_timerlat_params(tool->params);
289 struct timerlat_hist_data *data = tool->data;
290 struct trace_seq *s = tool->trace.seq;
291 char duration[26];
292 int cpu;
293
294 if (params->common.hist.no_header)
295 return;
296
297 get_duration(tool->start_time, duration, sizeof(duration));
298 trace_seq_printf(s, "# RTLA timerlat histogram\n");
299 trace_seq_printf(s, "# Time unit is %s (%s)\n",
300 params->common.output_divisor == 1 ? "nanoseconds" : "microseconds",
301 params->common.output_divisor == 1 ? "ns" : "us");
302
303 trace_seq_printf(s, "# Duration: %s\n", duration);
304
305 if (!params->common.hist.no_index)
306 trace_seq_printf(s, "Index");
307
308 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
309
310 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
311 continue;
312
313 if (!params->common.hist.no_irq)
314 trace_seq_printf(s, " IRQ-%03d", cpu);
315
316 if (!params->common.hist.no_thread)
317 trace_seq_printf(s, " Thr-%03d", cpu);
318
319 if (params->common.user_data)
320 trace_seq_printf(s, " Usr-%03d", cpu);
321 }
322 trace_seq_printf(s, "\n");
323
324
325 trace_seq_do_printf(s);
326 trace_seq_reset(s);
327 }
328
329 /*
330 * format_summary_value - format a line of summary value (min, max or avg)
331 * of hist data
332 */
format_summary_value(struct trace_seq * seq,int count,unsigned long long val,bool avg)333 static void format_summary_value(struct trace_seq *seq,
334 int count,
335 unsigned long long val,
336 bool avg)
337 {
338 if (count)
339 trace_seq_printf(seq, "%9llu ", avg ? val / count : val);
340 else
341 trace_seq_printf(seq, "%9c ", '-');
342 }
343
344 /*
345 * timerlat_print_summary - print the summary of the hist data to the output
346 */
347 static void
timerlat_print_summary(struct timerlat_params * params,struct trace_instance * trace,struct timerlat_hist_data * data)348 timerlat_print_summary(struct timerlat_params *params,
349 struct trace_instance *trace,
350 struct timerlat_hist_data *data)
351 {
352 int cpu;
353
354 if (params->common.hist.no_summary)
355 return;
356
357 if (!params->common.hist.no_index)
358 trace_seq_printf(trace->seq, "count:");
359
360 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
361
362 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
363 continue;
364
365 if (!params->common.hist.no_irq)
366 trace_seq_printf(trace->seq, "%9llu ",
367 data->hist[cpu].irq_count);
368
369 if (!params->common.hist.no_thread)
370 trace_seq_printf(trace->seq, "%9llu ",
371 data->hist[cpu].thread_count);
372
373 if (params->common.user_data)
374 trace_seq_printf(trace->seq, "%9llu ",
375 data->hist[cpu].user_count);
376 }
377 trace_seq_printf(trace->seq, "\n");
378
379 if (!params->common.hist.no_index)
380 trace_seq_printf(trace->seq, "min: ");
381
382 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
383
384 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
385 continue;
386
387 if (!params->common.hist.no_irq)
388 format_summary_value(trace->seq,
389 data->hist[cpu].irq_count,
390 data->hist[cpu].min_irq,
391 false);
392
393 if (!params->common.hist.no_thread)
394 format_summary_value(trace->seq,
395 data->hist[cpu].thread_count,
396 data->hist[cpu].min_thread,
397 false);
398
399 if (params->common.user_data)
400 format_summary_value(trace->seq,
401 data->hist[cpu].user_count,
402 data->hist[cpu].min_user,
403 false);
404 }
405 trace_seq_printf(trace->seq, "\n");
406
407 if (!params->common.hist.no_index)
408 trace_seq_printf(trace->seq, "avg: ");
409
410 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
411
412 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
413 continue;
414
415 if (!params->common.hist.no_irq)
416 format_summary_value(trace->seq,
417 data->hist[cpu].irq_count,
418 data->hist[cpu].sum_irq,
419 true);
420
421 if (!params->common.hist.no_thread)
422 format_summary_value(trace->seq,
423 data->hist[cpu].thread_count,
424 data->hist[cpu].sum_thread,
425 true);
426
427 if (params->common.user_data)
428 format_summary_value(trace->seq,
429 data->hist[cpu].user_count,
430 data->hist[cpu].sum_user,
431 true);
432 }
433 trace_seq_printf(trace->seq, "\n");
434
435 if (!params->common.hist.no_index)
436 trace_seq_printf(trace->seq, "max: ");
437
438 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
439
440 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
441 continue;
442
443 if (!params->common.hist.no_irq)
444 format_summary_value(trace->seq,
445 data->hist[cpu].irq_count,
446 data->hist[cpu].max_irq,
447 false);
448
449 if (!params->common.hist.no_thread)
450 format_summary_value(trace->seq,
451 data->hist[cpu].thread_count,
452 data->hist[cpu].max_thread,
453 false);
454
455 if (params->common.user_data)
456 format_summary_value(trace->seq,
457 data->hist[cpu].user_count,
458 data->hist[cpu].max_user,
459 false);
460 }
461 trace_seq_printf(trace->seq, "\n");
462 trace_seq_do_printf(trace->seq);
463 trace_seq_reset(trace->seq);
464 }
465
466 static void
timerlat_print_stats_all(struct timerlat_params * params,struct trace_instance * trace,struct timerlat_hist_data * data)467 timerlat_print_stats_all(struct timerlat_params *params,
468 struct trace_instance *trace,
469 struct timerlat_hist_data *data)
470 {
471 struct timerlat_hist_cpu *cpu_data;
472 struct timerlat_hist_cpu sum;
473 int cpu;
474
475 if (params->common.hist.no_summary)
476 return;
477
478 memset(&sum, 0, sizeof(sum));
479 sum.min_irq = ~0;
480 sum.min_thread = ~0;
481 sum.min_user = ~0;
482
483 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
484
485 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
486 continue;
487
488 cpu_data = &data->hist[cpu];
489
490 sum.irq_count += cpu_data->irq_count;
491 update_min(&sum.min_irq, &cpu_data->min_irq);
492 update_sum(&sum.sum_irq, &cpu_data->sum_irq);
493 update_max(&sum.max_irq, &cpu_data->max_irq);
494
495 sum.thread_count += cpu_data->thread_count;
496 update_min(&sum.min_thread, &cpu_data->min_thread);
497 update_sum(&sum.sum_thread, &cpu_data->sum_thread);
498 update_max(&sum.max_thread, &cpu_data->max_thread);
499
500 sum.user_count += cpu_data->user_count;
501 update_min(&sum.min_user, &cpu_data->min_user);
502 update_sum(&sum.sum_user, &cpu_data->sum_user);
503 update_max(&sum.max_user, &cpu_data->max_user);
504 }
505
506 if (!params->common.hist.no_index)
507 trace_seq_printf(trace->seq, "ALL: ");
508
509 if (!params->common.hist.no_irq)
510 trace_seq_printf(trace->seq, " IRQ");
511
512 if (!params->common.hist.no_thread)
513 trace_seq_printf(trace->seq, " Thr");
514
515 if (params->common.user_data)
516 trace_seq_printf(trace->seq, " Usr");
517
518 trace_seq_printf(trace->seq, "\n");
519
520 if (!params->common.hist.no_index)
521 trace_seq_printf(trace->seq, "count:");
522
523 if (!params->common.hist.no_irq)
524 trace_seq_printf(trace->seq, "%9llu ",
525 sum.irq_count);
526
527 if (!params->common.hist.no_thread)
528 trace_seq_printf(trace->seq, "%9llu ",
529 sum.thread_count);
530
531 if (params->common.user_data)
532 trace_seq_printf(trace->seq, "%9llu ",
533 sum.user_count);
534
535 trace_seq_printf(trace->seq, "\n");
536
537 if (!params->common.hist.no_index)
538 trace_seq_printf(trace->seq, "min: ");
539
540 if (!params->common.hist.no_irq)
541 format_summary_value(trace->seq,
542 sum.irq_count,
543 sum.min_irq,
544 false);
545
546 if (!params->common.hist.no_thread)
547 format_summary_value(trace->seq,
548 sum.thread_count,
549 sum.min_thread,
550 false);
551
552 if (params->common.user_data)
553 format_summary_value(trace->seq,
554 sum.user_count,
555 sum.min_user,
556 false);
557
558 trace_seq_printf(trace->seq, "\n");
559
560 if (!params->common.hist.no_index)
561 trace_seq_printf(trace->seq, "avg: ");
562
563 if (!params->common.hist.no_irq)
564 format_summary_value(trace->seq,
565 sum.irq_count,
566 sum.sum_irq,
567 true);
568
569 if (!params->common.hist.no_thread)
570 format_summary_value(trace->seq,
571 sum.thread_count,
572 sum.sum_thread,
573 true);
574
575 if (params->common.user_data)
576 format_summary_value(trace->seq,
577 sum.user_count,
578 sum.sum_user,
579 true);
580
581 trace_seq_printf(trace->seq, "\n");
582
583 if (!params->common.hist.no_index)
584 trace_seq_printf(trace->seq, "max: ");
585
586 if (!params->common.hist.no_irq)
587 format_summary_value(trace->seq,
588 sum.irq_count,
589 sum.max_irq,
590 false);
591
592 if (!params->common.hist.no_thread)
593 format_summary_value(trace->seq,
594 sum.thread_count,
595 sum.max_thread,
596 false);
597
598 if (params->common.user_data)
599 format_summary_value(trace->seq,
600 sum.user_count,
601 sum.max_user,
602 false);
603
604 trace_seq_printf(trace->seq, "\n");
605 trace_seq_do_printf(trace->seq);
606 trace_seq_reset(trace->seq);
607 }
608
609 /*
610 * timerlat_print_stats - print data for each CPUs
611 */
612 static void
timerlat_print_stats(struct osnoise_tool * tool)613 timerlat_print_stats(struct osnoise_tool *tool)
614 {
615 struct timerlat_params *params = to_timerlat_params(tool->params);
616 struct timerlat_hist_data *data = tool->data;
617 struct trace_instance *trace = &tool->trace;
618 int bucket, cpu;
619 int total;
620
621 timerlat_hist_header(tool);
622
623 for (bucket = 0; bucket < data->entries; bucket++) {
624 total = 0;
625
626 if (!params->common.hist.no_index)
627 trace_seq_printf(trace->seq, "%-6d",
628 bucket * data->bucket_size);
629
630 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
631
632 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
633 continue;
634
635 if (!params->common.hist.no_irq) {
636 total += data->hist[cpu].irq[bucket];
637 trace_seq_printf(trace->seq, "%9d ",
638 data->hist[cpu].irq[bucket]);
639 }
640
641 if (!params->common.hist.no_thread) {
642 total += data->hist[cpu].thread[bucket];
643 trace_seq_printf(trace->seq, "%9d ",
644 data->hist[cpu].thread[bucket]);
645 }
646
647 if (params->common.user_data) {
648 total += data->hist[cpu].user[bucket];
649 trace_seq_printf(trace->seq, "%9d ",
650 data->hist[cpu].user[bucket]);
651 }
652
653 }
654
655 if (total == 0 && !params->common.hist.with_zeros) {
656 trace_seq_reset(trace->seq);
657 continue;
658 }
659
660 trace_seq_printf(trace->seq, "\n");
661 trace_seq_do_printf(trace->seq);
662 trace_seq_reset(trace->seq);
663 }
664
665 if (!params->common.hist.no_index)
666 trace_seq_printf(trace->seq, "over: ");
667
668 for_each_monitored_cpu(cpu, data->nr_cpus, ¶ms->common) {
669
670 if (!data->hist[cpu].irq_count && !data->hist[cpu].thread_count)
671 continue;
672
673 if (!params->common.hist.no_irq)
674 trace_seq_printf(trace->seq, "%9d ",
675 data->hist[cpu].irq[data->entries]);
676
677 if (!params->common.hist.no_thread)
678 trace_seq_printf(trace->seq, "%9d ",
679 data->hist[cpu].thread[data->entries]);
680
681 if (params->common.user_data)
682 trace_seq_printf(trace->seq, "%9d ",
683 data->hist[cpu].user[data->entries]);
684 }
685 trace_seq_printf(trace->seq, "\n");
686 trace_seq_do_printf(trace->seq);
687 trace_seq_reset(trace->seq);
688
689 timerlat_print_summary(params, trace, data);
690 timerlat_print_stats_all(params, trace, data);
691 osnoise_report_missed_events(tool);
692 }
693
694 /*
695 * timerlat_hist_usage - prints timerlat top usage message
696 */
timerlat_hist_usage(void)697 static void timerlat_hist_usage(void)
698 {
699 int i;
700
701 char *msg[] = {
702 "",
703 " usage: [rtla] timerlat hist [-h] [-q] [-d s] [-D] [-n] [-a us] [-p us] [-i us] [-T us] [-s us] \\",
704 " [-t [file]] [-e sys[:event]] [--filter <filter>] [--trigger <trigger>] [-c cpu-list] [-H cpu-list]\\",
705 " [-P priority] [-E N] [-b N] [--no-irq] [--no-thread] [--no-header] [--no-summary] \\",
706 " [--no-index] [--with-zeros] [--dma-latency us] [-C [cgroup_name]] [--no-aa] [--dump-task] [-u|-k]",
707 " [--warm-up s] [--deepest-idle-state n]",
708 "",
709 " -h/--help: print this menu",
710 " -a/--auto: set automatic trace mode, stopping the session if argument in us latency is hit",
711 " -p/--period us: timerlat period in us",
712 " -i/--irq us: stop trace if the irq latency is higher than the argument in us",
713 " -T/--thread us: stop trace if the thread latency is higher than the argument in us",
714 " -s/--stack us: save the stack trace at the IRQ if a thread latency is higher than the argument in us",
715 " -c/--cpus cpus: run the tracer only on the given cpus",
716 " -H/--house-keeping cpus: run rtla control threads only on the given cpus",
717 " -C/--cgroup [cgroup_name]: set cgroup, if no cgroup_name is passed, the rtla's cgroup will be inherited",
718 " -d/--duration time[m|h|d]: duration of the session in seconds",
719 " --dump-tasks: prints the task running on all CPUs if stop conditions are met (depends on !--no-aa)",
720 " -D/--debug: print debug info",
721 " -t/--trace [file]: save the stopped trace to [file|timerlat_trace.txt]",
722 " -e/--event <sys:event>: enable the <sys:event> in the trace instance, multiple -e are allowed",
723 " --filter <filter>: enable a trace event filter to the previous -e event",
724 " --trigger <trigger>: enable a trace event trigger to the previous -e event",
725 " -n/--nano: display data in nanoseconds",
726 " --no-aa: disable auto-analysis, reducing rtla timerlat cpu usage",
727 " -b/--bucket-size N: set the histogram bucket size (default 1)",
728 " -E/--entries N: set the number of entries of the histogram (default 256)",
729 " --no-irq: ignore IRQ latencies",
730 " --no-thread: ignore thread latencies",
731 " --no-header: do not print header",
732 " --no-summary: do not print summary",
733 " --no-index: do not print index",
734 " --with-zeros: print zero only entries",
735 " --dma-latency us: set /dev/cpu_dma_latency latency <us> to reduce exit from idle latency",
736 " -P/--priority o:prio|r:prio|f:prio|d:runtime:period : set scheduling parameters",
737 " o:prio - use SCHED_OTHER with prio",
738 " r:prio - use SCHED_RR with prio",
739 " f:prio - use SCHED_FIFO with prio",
740 " d:runtime[us|ms|s]:period[us|ms|s] - use SCHED_DEADLINE with runtime and period",
741 " in nanoseconds",
742 " -u/--user-threads: use rtla user-space threads instead of kernel-space timerlat threads",
743 " -k/--kernel-threads: use timerlat kernel-space threads instead of rtla user-space threads",
744 " -U/--user-load: enable timerlat for user-defined user-space workload",
745 " --warm-up s: let the workload run for s seconds before collecting data",
746 " --trace-buffer-size kB: set the per-cpu trace buffer size in kB",
747 " --deepest-idle-state n: only go down to idle state n on cpus used by timerlat to reduce exit from idle latency",
748 " --on-threshold <action>: define action to be executed at latency threshold, multiple are allowed",
749 " --on-end <action>: define action to be executed at measurement end, multiple are allowed",
750 NULL,
751 };
752
753 fprintf(stderr, "rtla timerlat hist: a per-cpu histogram of the timer latency (version %s)\n",
754 VERSION);
755
756 for (i = 0; msg[i]; i++)
757 fprintf(stderr, "%s\n", msg[i]);
758
759 exit(EXIT_SUCCESS);
760 }
761
762 /*
763 * timerlat_hist_parse_args - allocs, parse and fill the cmd line parameters
764 */
765 static struct common_params
timerlat_hist_parse_args(int argc,char * argv[])766 *timerlat_hist_parse_args(int argc, char *argv[])
767 {
768 struct timerlat_params *params;
769 struct trace_events *tevent;
770 int auto_thresh;
771 int retval;
772 int c;
773 char *trace_output = NULL;
774
775 params = calloc(1, sizeof(*params));
776 if (!params)
777 exit(1);
778
779 actions_init(¶ms->common.threshold_actions);
780 actions_init(¶ms->common.end_actions);
781
782 /* disabled by default */
783 params->dma_latency = -1;
784
785 /* disabled by default */
786 params->deepest_idle_state = -2;
787
788 /* display data in microseconds */
789 params->common.output_divisor = 1000;
790 params->common.hist.bucket_size = 1;
791 params->common.hist.entries = 256;
792
793 /* default to BPF mode */
794 params->mode = TRACING_MODE_BPF;
795
796 while (1) {
797 static struct option long_options[] = {
798 {"auto", required_argument, 0, 'a'},
799 {"cpus", required_argument, 0, 'c'},
800 {"cgroup", optional_argument, 0, 'C'},
801 {"bucket-size", required_argument, 0, 'b'},
802 {"debug", no_argument, 0, 'D'},
803 {"entries", required_argument, 0, 'E'},
804 {"duration", required_argument, 0, 'd'},
805 {"house-keeping", required_argument, 0, 'H'},
806 {"help", no_argument, 0, 'h'},
807 {"irq", required_argument, 0, 'i'},
808 {"nano", no_argument, 0, 'n'},
809 {"period", required_argument, 0, 'p'},
810 {"priority", required_argument, 0, 'P'},
811 {"stack", required_argument, 0, 's'},
812 {"thread", required_argument, 0, 'T'},
813 {"trace", optional_argument, 0, 't'},
814 {"user-threads", no_argument, 0, 'u'},
815 {"kernel-threads", no_argument, 0, 'k'},
816 {"user-load", no_argument, 0, 'U'},
817 {"event", required_argument, 0, 'e'},
818 {"no-irq", no_argument, 0, '0'},
819 {"no-thread", no_argument, 0, '1'},
820 {"no-header", no_argument, 0, '2'},
821 {"no-summary", no_argument, 0, '3'},
822 {"no-index", no_argument, 0, '4'},
823 {"with-zeros", no_argument, 0, '5'},
824 {"trigger", required_argument, 0, '6'},
825 {"filter", required_argument, 0, '7'},
826 {"dma-latency", required_argument, 0, '8'},
827 {"no-aa", no_argument, 0, '9'},
828 {"dump-task", no_argument, 0, '\1'},
829 {"warm-up", required_argument, 0, '\2'},
830 {"trace-buffer-size", required_argument, 0, '\3'},
831 {"deepest-idle-state", required_argument, 0, '\4'},
832 {"on-threshold", required_argument, 0, '\5'},
833 {"on-end", required_argument, 0, '\6'},
834 {0, 0, 0, 0}
835 };
836
837 c = getopt_long(argc, argv, "a:c:C::b:d:e:E:DhH:i:knp:P:s:t::T:uU0123456:7:8:9\1\2:\3:",
838 long_options, NULL);
839
840 /* detect the end of the options. */
841 if (c == -1)
842 break;
843
844 switch (c) {
845 case 'a':
846 auto_thresh = get_llong_from_str(optarg);
847
848 /* set thread stop to auto_thresh */
849 params->common.stop_total_us = auto_thresh;
850 params->common.stop_us = auto_thresh;
851
852 /* get stack trace */
853 params->print_stack = auto_thresh;
854
855 /* set trace */
856 if (!trace_output)
857 trace_output = "timerlat_trace.txt";
858
859 break;
860 case 'c':
861 retval = parse_cpu_set(optarg, ¶ms->common.monitored_cpus);
862 if (retval)
863 fatal("Invalid -c cpu list");
864 params->common.cpus = optarg;
865 break;
866 case 'C':
867 params->common.cgroup = 1;
868 params->common.cgroup_name = parse_optional_arg(argc, argv);
869 break;
870 case 'b':
871 params->common.hist.bucket_size = get_llong_from_str(optarg);
872 if (params->common.hist.bucket_size == 0 ||
873 params->common.hist.bucket_size >= 1000000)
874 fatal("Bucket size needs to be > 0 and <= 1000000");
875 break;
876 case 'D':
877 config_debug = 1;
878 break;
879 case 'd':
880 params->common.duration = parse_seconds_duration(optarg);
881 if (!params->common.duration)
882 fatal("Invalid -D duration");
883 break;
884 case 'e':
885 tevent = trace_event_alloc(optarg);
886 if (!tevent)
887 fatal("Error alloc trace event");
888
889 if (params->common.events)
890 tevent->next = params->common.events;
891
892 params->common.events = tevent;
893 break;
894 case 'E':
895 params->common.hist.entries = get_llong_from_str(optarg);
896 if (params->common.hist.entries < 10 ||
897 params->common.hist.entries > 9999999)
898 fatal("Entries must be > 10 and < 9999999");
899 break;
900 case 'h':
901 case '?':
902 timerlat_hist_usage();
903 break;
904 case 'H':
905 params->common.hk_cpus = 1;
906 retval = parse_cpu_set(optarg, ¶ms->common.hk_cpu_set);
907 if (retval)
908 fatal("Error parsing house keeping CPUs");
909 break;
910 case 'i':
911 params->common.stop_us = get_llong_from_str(optarg);
912 break;
913 case 'k':
914 params->common.kernel_workload = 1;
915 break;
916 case 'n':
917 params->common.output_divisor = 1;
918 break;
919 case 'p':
920 params->timerlat_period_us = get_llong_from_str(optarg);
921 if (params->timerlat_period_us > 1000000)
922 fatal("Period longer than 1 s");
923 break;
924 case 'P':
925 retval = parse_prio(optarg, ¶ms->common.sched_param);
926 if (retval == -1)
927 fatal("Invalid -P priority");
928 params->common.set_sched = 1;
929 break;
930 case 's':
931 params->print_stack = get_llong_from_str(optarg);
932 break;
933 case 'T':
934 params->common.stop_total_us = get_llong_from_str(optarg);
935 break;
936 case 't':
937 trace_output = parse_optional_arg(argc, argv);
938 if (!trace_output)
939 trace_output = "timerlat_trace.txt";
940 break;
941 case 'u':
942 params->common.user_workload = 1;
943 /* fallback: -u implies in -U */
944 case 'U':
945 params->common.user_data = 1;
946 break;
947 case '0': /* no irq */
948 params->common.hist.no_irq = 1;
949 break;
950 case '1': /* no thread */
951 params->common.hist.no_thread = 1;
952 break;
953 case '2': /* no header */
954 params->common.hist.no_header = 1;
955 break;
956 case '3': /* no summary */
957 params->common.hist.no_summary = 1;
958 break;
959 case '4': /* no index */
960 params->common.hist.no_index = 1;
961 break;
962 case '5': /* with zeros */
963 params->common.hist.with_zeros = 1;
964 break;
965 case '6': /* trigger */
966 if (params->common.events) {
967 retval = trace_event_add_trigger(params->common.events, optarg);
968 if (retval)
969 fatal("Error adding trigger %s", optarg);
970 } else {
971 fatal("--trigger requires a previous -e");
972 }
973 break;
974 case '7': /* filter */
975 if (params->common.events) {
976 retval = trace_event_add_filter(params->common.events, optarg);
977 if (retval)
978 fatal("Error adding filter %s", optarg);
979 } else {
980 fatal("--filter requires a previous -e");
981 }
982 break;
983 case '8':
984 params->dma_latency = get_llong_from_str(optarg);
985 if (params->dma_latency < 0 || params->dma_latency > 10000)
986 fatal("--dma-latency needs to be >= 0 and < 10000");
987 break;
988 case '9':
989 params->no_aa = 1;
990 break;
991 case '\1':
992 params->dump_tasks = 1;
993 break;
994 case '\2':
995 params->common.warmup = get_llong_from_str(optarg);
996 break;
997 case '\3':
998 params->common.buffer_size = get_llong_from_str(optarg);
999 break;
1000 case '\4':
1001 params->deepest_idle_state = get_llong_from_str(optarg);
1002 break;
1003 case '\5':
1004 retval = actions_parse(¶ms->common.threshold_actions, optarg,
1005 "timerlat_trace.txt");
1006 if (retval)
1007 fatal("Invalid action %s", optarg);
1008 break;
1009 case '\6':
1010 retval = actions_parse(¶ms->common.end_actions, optarg,
1011 "timerlat_trace.txt");
1012 if (retval)
1013 fatal("Invalid action %s", optarg);
1014 break;
1015 default:
1016 fatal("Invalid option");
1017 }
1018 }
1019
1020 if (trace_output)
1021 actions_add_trace_output(¶ms->common.threshold_actions, trace_output);
1022
1023 if (geteuid())
1024 fatal("rtla needs root permission");
1025
1026 if (params->common.hist.no_irq && params->common.hist.no_thread)
1027 fatal("no-irq and no-thread set, there is nothing to do here");
1028
1029 if (params->common.hist.no_index && !params->common.hist.with_zeros)
1030 fatal("no-index set with with-zeros is not set - it does not make sense");
1031
1032 /*
1033 * Auto analysis only happens if stop tracing, thus:
1034 */
1035 if (!params->common.stop_us && !params->common.stop_total_us)
1036 params->no_aa = 1;
1037
1038 if (params->common.kernel_workload && params->common.user_workload)
1039 fatal("--kernel-threads and --user-threads are mutually exclusive!");
1040
1041 /*
1042 * If auto-analysis or trace output is enabled, switch from BPF mode to
1043 * mixed mode
1044 */
1045 if (params->mode == TRACING_MODE_BPF &&
1046 (params->common.threshold_actions.present[ACTION_TRACE_OUTPUT] ||
1047 params->common.end_actions.present[ACTION_TRACE_OUTPUT] ||
1048 !params->no_aa))
1049 params->mode = TRACING_MODE_MIXED;
1050
1051 return ¶ms->common;
1052 }
1053
1054 /*
1055 * timerlat_hist_apply_config - apply the hist configs to the initialized tool
1056 */
1057 static int
timerlat_hist_apply_config(struct osnoise_tool * tool)1058 timerlat_hist_apply_config(struct osnoise_tool *tool)
1059 {
1060 struct timerlat_params *params = to_timerlat_params(tool->params);
1061 int retval;
1062
1063 retval = timerlat_apply_config(tool, params);
1064 if (retval)
1065 goto out_err;
1066
1067 return 0;
1068
1069 out_err:
1070 return -1;
1071 }
1072
1073 /*
1074 * timerlat_init_hist - initialize a timerlat hist tool with parameters
1075 */
1076 static struct osnoise_tool
timerlat_init_hist(struct common_params * params)1077 *timerlat_init_hist(struct common_params *params)
1078 {
1079 struct osnoise_tool *tool;
1080 int nr_cpus;
1081
1082 nr_cpus = sysconf(_SC_NPROCESSORS_CONF);
1083
1084 tool = osnoise_init_tool("timerlat_hist");
1085 if (!tool)
1086 return NULL;
1087
1088 tool->data = timerlat_alloc_histogram(nr_cpus, params->hist.entries,
1089 params->hist.bucket_size);
1090 if (!tool->data)
1091 goto out_err;
1092
1093 tep_register_event_handler(tool->trace.tep, -1, "ftrace", "timerlat",
1094 timerlat_hist_handler, tool);
1095
1096 return tool;
1097
1098 out_err:
1099 osnoise_destroy_tool(tool);
1100 return NULL;
1101 }
1102
timerlat_hist_bpf_main_loop(struct osnoise_tool * tool)1103 static int timerlat_hist_bpf_main_loop(struct osnoise_tool *tool)
1104 {
1105 struct timerlat_params *params = to_timerlat_params(tool->params);
1106 int retval;
1107
1108 while (!stop_tracing) {
1109 timerlat_bpf_wait(-1);
1110
1111 if (!stop_tracing) {
1112 /* Threshold overflow, perform actions on threshold */
1113 actions_perform(¶ms->common.threshold_actions);
1114
1115 if (!params->common.threshold_actions.continue_flag)
1116 /* continue flag not set, break */
1117 break;
1118
1119 /* continue action reached, re-enable tracing */
1120 if (tool->record)
1121 trace_instance_start(&tool->record->trace);
1122 if (tool->aa)
1123 trace_instance_start(&tool->aa->trace);
1124 timerlat_bpf_restart_tracing();
1125 }
1126 }
1127 timerlat_bpf_detach();
1128
1129 retval = timerlat_hist_bpf_pull_data(tool);
1130 if (retval)
1131 err_msg("Error pulling BPF data\n");
1132
1133 return retval;
1134 }
1135
timerlat_hist_main(struct osnoise_tool * tool)1136 static int timerlat_hist_main(struct osnoise_tool *tool)
1137 {
1138 struct timerlat_params *params = to_timerlat_params(tool->params);
1139 int retval;
1140
1141 if (params->mode == TRACING_MODE_TRACEFS)
1142 retval = hist_main_loop(tool);
1143 else
1144 retval = timerlat_hist_bpf_main_loop(tool);
1145
1146 return retval;
1147 }
1148
1149 struct tool_ops timerlat_hist_ops = {
1150 .tracer = "timerlat",
1151 .comm_prefix = "timerlat/",
1152 .parse_args = timerlat_hist_parse_args,
1153 .init_tool = timerlat_init_hist,
1154 .apply_config = timerlat_hist_apply_config,
1155 .enable = timerlat_enable,
1156 .main = timerlat_hist_main,
1157 .print_stats = timerlat_print_stats,
1158 .analyze = timerlat_analyze,
1159 .free = timerlat_free_histogram_tool,
1160 };
1161