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 <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 22 struct 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 43 struct timerlat_top_data { 44 struct timerlat_top_cpu *cpu_data; 45 }; 46 47 /* 48 * timerlat_free_top - free runtime data 49 */ 50 static void timerlat_free_top(struct timerlat_top_data *data) 51 { 52 free(data->cpu_data); 53 free(data); 54 } 55 56 static 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 */ 65 static 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 88 cleanup: 89 timerlat_free_top(data); 90 return NULL; 91 } 92 93 static void 94 timerlat_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 102 static void 103 timerlat_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 */ 127 static void 128 timerlat_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 */ 163 static int 164 timerlat_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 */ 187 static 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 */ 252 static 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 293 static const char *no_value = " -"; 294 295 /* 296 * timerlat_top_print - prints the output of a given CPU 297 */ 298 static 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 */ 356 static void 357 timerlat_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 */ 423 static 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 */ 432 static void 433 timerlat_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, ¶ms->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 */ 465 static int 466 timerlat_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 480 out_err: 481 return -1; 482 } 483 484 /* 485 * timerlat_init_top - initialize a timerlat top tool with parameters 486 */ 487 static 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 505 out_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 */ 513 static int 514 timerlat_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 566 static 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 581 struct 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 }; 593