1 // SPDX-License-Identifier: GPL-2.0 2 #include "builtin.h" 3 #include "perf.h" 4 #include "perf-sys.h" 5 6 #include "util/cpumap.h" 7 #include "util/evlist.h" 8 #include "util/evsel.h" 9 #include "util/evsel_fprintf.h" 10 #include "util/mutex.h" 11 #include "util/symbol.h" 12 #include "util/thread.h" 13 #include "util/header.h" 14 #include "util/session.h" 15 #include "util/tool.h" 16 #include "util/cloexec.h" 17 #include "util/thread_map.h" 18 #include "util/color.h" 19 #include "util/stat.h" 20 #include "util/string2.h" 21 #include "util/callchain.h" 22 #include "util/time-utils.h" 23 24 #include <subcmd/pager.h> 25 #include <subcmd/parse-options.h> 26 #include "util/trace-event.h" 27 28 #include "util/debug.h" 29 #include "util/event.h" 30 #include "util/util.h" 31 #include "util/synthetic-events.h" 32 #include "util/target.h" 33 34 #include <linux/kernel.h> 35 #include <linux/log2.h> 36 #include <linux/zalloc.h> 37 #include <sys/prctl.h> 38 #include <sys/resource.h> 39 #include <sys/wait.h> 40 #include <inttypes.h> 41 42 #include <errno.h> 43 #include <semaphore.h> 44 #include <pthread.h> 45 #include <math.h> 46 #include <api/fs/fs.h> 47 #include <perf/cpumap.h> 48 #include <linux/time64.h> 49 #include <linux/err.h> 50 51 #include <linux/ctype.h> 52 53 #define PR_SET_NAME 15 /* Set process name */ 54 #define MAX_CPUS 4096 55 #define COMM_LEN 20 56 #define SYM_LEN 129 57 #define MAX_PID 1024000 58 #define PID_MAX_LIMIT 4194304 /* kernel limit on 64-bit */ 59 #define MAX_PRIO 140 60 #define SEP_LEN 100 61 62 #define NUM_LAT_BUCKETS 22 63 64 enum hist_mode { 65 HIST_MODE_LOG = 0, 66 HIST_MODE_LINEAR, 67 }; 68 69 static const char *lat_bucket_names[NUM_LAT_BUCKETS] = { 70 "< 1 us", 71 "1 - 2 us", 72 "2 - 4 us", 73 "4 - 8 us", 74 "8 - 16 us", 75 "16 - 32 us", 76 "32 - 64 us", 77 "64 - 128 us", 78 "128 - 256 us", 79 "256 - 512 us", 80 "512 - 1024 us", 81 "1 - 2 ms", 82 "2 - 4 ms", 83 "4 - 8 ms", 84 "8 - 16 ms", 85 "16 - 32 ms", 86 "32 - 64 ms", 87 "64 - 128 ms", 88 "128 - 256 ms", 89 "256 - 512 ms", 90 "512 - 1024 ms", 91 ">= 1.05 s" 92 }; 93 94 static const char *linear_bucket_names[NUM_LAT_BUCKETS] = { 95 "< 100 us", 96 "100 - 200 us", 97 "200 - 300 us", 98 "300 - 400 us", 99 "400 - 500 us", 100 "500 - 600 us", 101 "600 - 700 us", 102 "700 - 800 us", 103 "800 - 900 us", 104 "900 - 1000 us", 105 "1.0 - 1.1 ms", 106 "1.1 - 1.2 ms", 107 "1.2 - 1.3 ms", 108 "1.3 - 1.4 ms", 109 "1.4 - 1.5 ms", 110 "1.5 - 1.6 ms", 111 "1.6 - 1.7 ms", 112 "1.7 - 1.8 ms", 113 "1.8 - 1.9 ms", 114 "1.9 - 2.0 ms", 115 "2.0 - 2.1 ms", 116 ">= 2.1 ms" 117 }; 118 119 struct perf_sched; 120 static int latency_bucket(struct perf_sched *sched, u64 delta_ns); 121 static void print_latency_histogram(struct perf_sched *sched, u64 *hist, 122 u64 total_count, const char *title); 123 124 static const char *cpu_list; 125 static struct perf_cpu_map *user_requested_cpus; 126 static DECLARE_BITMAP(cpu_bitmap, MAX_NR_CPUS); 127 128 struct sched_atom; 129 130 struct task_desc { 131 unsigned long nr; 132 unsigned long pid; 133 char comm[COMM_LEN]; 134 135 unsigned long nr_events; 136 unsigned long curr_event; 137 struct sched_atom **atoms; 138 139 pthread_t thread; 140 141 sem_t ready_for_work; 142 sem_t work_done_sem; 143 144 u64 cpu_usage; 145 }; 146 147 enum sched_event_type { 148 SCHED_EVENT_RUN, 149 SCHED_EVENT_SLEEP, 150 SCHED_EVENT_WAKEUP, 151 }; 152 153 struct sched_atom { 154 enum sched_event_type type; 155 u64 timestamp; 156 u64 duration; 157 unsigned long nr; 158 sem_t *wait_sem; 159 struct task_desc *wakee; 160 }; 161 162 enum thread_state { 163 THREAD_SLEEPING = 0, 164 THREAD_WAIT_CPU, 165 THREAD_SCHED_IN, 166 THREAD_IGNORE 167 }; 168 169 struct work_atom { 170 struct list_head list; 171 enum thread_state state; 172 u64 sched_out_time; 173 u64 wake_up_time; 174 u64 sched_in_time; 175 u64 runtime; 176 }; 177 178 struct work_atoms { 179 struct list_head work_list; 180 struct thread *thread; 181 struct rb_node node; 182 u64 max_lat; 183 u64 max_lat_start; 184 u64 max_lat_end; 185 u64 total_lat; 186 u64 nb_atoms; 187 u64 total_runtime; 188 int num_merged; 189 u64 hist[NUM_LAT_BUCKETS]; 190 }; 191 192 typedef int (*sort_fn_t)(struct work_atoms *, struct work_atoms *); 193 194 struct perf_sched; 195 196 struct trace_sched_handler { 197 int (*switch_event)(struct perf_sched *sched, struct perf_sample *sample, 198 struct machine *machine); 199 200 int (*runtime_event)(struct perf_sched *sched, struct perf_sample *sample, 201 struct machine *machine); 202 203 int (*wakeup_event)(struct perf_sched *sched, struct perf_sample *sample, 204 struct machine *machine); 205 206 /* PERF_RECORD_FORK event, not sched_process_fork tracepoint */ 207 int (*fork_event)(struct perf_sched *sched, union perf_event *event, 208 struct machine *machine); 209 210 int (*migrate_task_event)(struct perf_sched *sched, 211 struct perf_sample *sample, 212 struct machine *machine); 213 }; 214 215 #define COLOR_PIDS PERF_COLOR_BLUE 216 #define COLOR_CPUS PERF_COLOR_BG_RED 217 218 struct perf_sched_map { 219 DECLARE_BITMAP(comp_cpus_mask, MAX_CPUS); 220 struct perf_cpu *comp_cpus; 221 bool comp; 222 struct perf_thread_map *color_pids; 223 const char *color_pids_str; 224 struct perf_cpu_map *color_cpus; 225 const char *color_cpus_str; 226 const char *task_name; 227 struct strlist *task_names; 228 bool fuzzy; 229 struct perf_cpu_map *cpus; 230 const char *cpus_str; 231 }; 232 233 struct perf_sched { 234 struct perf_tool tool; 235 const char *sort_order; 236 unsigned long nr_tasks; 237 struct task_desc **pid_to_task; 238 struct task_desc **tasks; 239 const struct trace_sched_handler *tp_handler; 240 struct mutex start_work_mutex; 241 struct mutex work_done_wait_mutex; 242 int profile_cpu; 243 /* 244 * Track the current task - that way we can know whether there's any 245 * weird events, such as a task being switched away that is not current. 246 */ 247 struct perf_cpu max_cpu; 248 u32 *curr_pid; 249 struct thread **curr_thread; 250 struct thread **curr_out_thread; 251 char next_shortname1; 252 char next_shortname2; 253 unsigned int replay_repeat; 254 unsigned long nr_run_events; 255 unsigned long nr_sleep_events; 256 unsigned long nr_wakeup_events; 257 unsigned long nr_sleep_corrections; 258 unsigned long nr_run_events_optimized; 259 unsigned long targetless_wakeups; 260 unsigned long multitarget_wakeups; 261 unsigned long nr_runs; 262 unsigned long nr_timestamps; 263 unsigned long nr_unordered_timestamps; 264 unsigned long nr_context_switch_bugs; 265 unsigned long nr_events; 266 unsigned long nr_lost_chunks; 267 unsigned long nr_lost_events; 268 u64 run_measurement_overhead; 269 u64 sleep_measurement_overhead; 270 u64 start_time; 271 u64 cpu_usage; 272 u64 runavg_cpu_usage; 273 u64 parent_cpu_usage; 274 u64 runavg_parent_cpu_usage; 275 u64 sum_runtime; 276 u64 sum_fluct; 277 u64 run_avg; 278 u64 all_runtime; 279 u64 all_count; 280 u64 *cpu_last_switched; 281 struct rb_root_cached atom_root, sorted_atom_root, merged_atom_root; 282 struct list_head sort_list, cmp_pid; 283 bool force; 284 bool skip_merge; 285 bool show_histogram; 286 enum hist_mode hist_mode; 287 const char *hist_mode_str; 288 u64 global_hist[NUM_LAT_BUCKETS]; 289 struct perf_sched_map map; 290 291 /* options for timehist command */ 292 bool summary; 293 bool summary_only; 294 bool idle_hist; 295 bool show_callchain; 296 unsigned int max_stack; 297 bool show_cpu_visual; 298 bool show_wakeups; 299 bool show_next; 300 bool show_migrations; 301 bool pre_migrations; 302 bool show_state; 303 bool show_prio; 304 u64 skipped_samples; 305 const char *time_str; 306 struct perf_time_interval ptime; 307 struct perf_time_interval hist_time; 308 volatile bool thread_funcs_exit; 309 const char *prio_str; 310 DECLARE_BITMAP(prio_bitmap, MAX_PRIO); 311 312 struct perf_session *session; 313 struct perf_data *data; 314 }; 315 316 static int scnprintf_latency_unit(char *buf, size_t size, u64 nsecs) 317 { 318 if (nsecs < 1000) 319 return scnprintf(buf, size, "%6" PRIu64 " ns", nsecs); 320 if (nsecs < NSEC_PER_MSEC) 321 return scnprintf(buf, size, "%6.3f us", (double)nsecs / NSEC_PER_USEC); 322 if (nsecs < NSEC_PER_SEC) 323 return scnprintf(buf, size, "%6.3f ms", (double)nsecs / NSEC_PER_MSEC); 324 return scnprintf(buf, size, "%6.3f s ", (double)nsecs / NSEC_PER_SEC); 325 } 326 327 static int latency_bucket(struct perf_sched *sched, u64 delta_ns) 328 { 329 u64 delta_us = delta_ns / NSEC_PER_USEC; 330 u64 b; 331 332 if (sched->hist_mode == HIST_MODE_LINEAR) { 333 b = delta_us / 100; 334 } else { 335 if (delta_us == 0) 336 return 0; 337 b = 64 - __builtin_clzll(delta_us); 338 } 339 340 if (b >= NUM_LAT_BUCKETS - 1) 341 return NUM_LAT_BUCKETS - 1; 342 return b; 343 } 344 345 static void print_latency_histogram(struct perf_sched *sched, u64 *hist, 346 u64 total_count, const char *title) 347 { 348 const char **bucket_names = (sched->hist_mode == HIST_MODE_LINEAR) ? 349 linear_bucket_names : lat_bucket_names; 350 int bar_total = 40; 351 char bar[] = "########################################"; 352 int i; 353 354 if (total_count == 0) 355 return; 356 357 printf("\n %s (total samples: %" PRIu64 ")\n", title, total_count); 358 printf(" -------------------------------------------------------------------\n"); 359 printf(" %-16s | %10s | %6s | %s\n", 360 "Latency Range", "Count", "Pct", "Histogram Graph"); 361 printf(" -------------------------------------------------------------------\n"); 362 363 for (i = 0; i < NUM_LAT_BUCKETS; i++) { 364 double pct; 365 int bar_len; 366 367 if (hist[i] == 0) 368 continue; 369 pct = (double)hist[i] * 100.0 / total_count; 370 bar_len = (hist[i] * bar_total) / total_count; 371 if (bar_len == 0 && hist[i] > 0) 372 bar_len = 1; 373 printf(" %-16s | %10" PRIu64 " | %5.1f%% | %.*s\n", 374 bucket_names[i], hist[i], pct, 375 bar_len, bar); 376 } 377 printf(" -------------------------------------------------------------------\n"); 378 } 379 380 /* per thread run time data */ 381 struct thread_runtime { 382 u64 last_time; /* time of previous sched in/out event */ 383 u64 dt_run; /* run time */ 384 u64 dt_sleep; /* time between CPU access by sleep (off cpu) */ 385 u64 dt_iowait; /* time between CPU access by iowait (off cpu) */ 386 u64 dt_preempt; /* time between CPU access by preempt (off cpu) */ 387 u64 dt_delay; /* time between wakeup and sched-in */ 388 u64 dt_pre_mig; /* time between migration and wakeup */ 389 u64 ready_to_run; /* time of wakeup */ 390 u64 migrated; /* time when a thread is migrated */ 391 392 struct stats run_stats; 393 u64 total_run_time; 394 u64 total_sleep_time; 395 u64 total_iowait_time; 396 u64 total_preempt_time; 397 u64 total_delay_time; 398 u64 total_pre_mig_time; 399 400 char last_state; 401 402 char shortname[3]; 403 bool comm_changed; 404 405 u64 migrations; 406 407 int prio; 408 bool color; 409 }; 410 411 /* per event run time data */ 412 struct evsel_runtime { 413 u64 *last_time; /* time this event was last seen per cpu */ 414 u32 ncpu; /* highest cpu slot allocated */ 415 }; 416 417 /* per cpu idle time data */ 418 struct idle_thread_runtime { 419 struct thread_runtime tr; 420 struct thread *last_thread; 421 struct rb_root_cached sorted_root; 422 struct callchain_root callchain; 423 struct callchain_cursor cursor; 424 }; 425 426 /* track idle times per cpu */ 427 static struct thread **idle_threads; 428 static int idle_max_cpu; 429 static char idle_comm[] = "<idle>"; 430 431 static u64 get_nsecs(void) 432 { 433 struct timespec ts; 434 435 clock_gettime(CLOCK_MONOTONIC, &ts); 436 437 return ts.tv_sec * NSEC_PER_SEC + ts.tv_nsec; 438 } 439 440 static void burn_nsecs(struct perf_sched *sched, u64 nsecs) 441 { 442 u64 T0 = get_nsecs(), T1; 443 444 do { 445 T1 = get_nsecs(); 446 } while (T1 + sched->run_measurement_overhead < T0 + nsecs); 447 } 448 449 static void sleep_nsecs(u64 nsecs) 450 { 451 struct timespec ts; 452 453 ts.tv_nsec = nsecs % 999999999; 454 ts.tv_sec = nsecs / 999999999; 455 456 nanosleep(&ts, NULL); 457 } 458 459 static void calibrate_run_measurement_overhead(struct perf_sched *sched) 460 { 461 u64 T0, T1, delta, min_delta = NSEC_PER_SEC; 462 int i; 463 464 for (i = 0; i < 10; i++) { 465 T0 = get_nsecs(); 466 burn_nsecs(sched, 0); 467 T1 = get_nsecs(); 468 delta = T1-T0; 469 min_delta = min(min_delta, delta); 470 } 471 sched->run_measurement_overhead = min_delta; 472 473 printf("run measurement overhead: %" PRIu64 " nsecs\n", min_delta); 474 } 475 476 static void calibrate_sleep_measurement_overhead(struct perf_sched *sched) 477 { 478 u64 T0, T1, delta, min_delta = NSEC_PER_SEC; 479 int i; 480 481 for (i = 0; i < 10; i++) { 482 T0 = get_nsecs(); 483 sleep_nsecs(10000); 484 T1 = get_nsecs(); 485 delta = T1-T0; 486 min_delta = min(min_delta, delta); 487 } 488 min_delta -= 10000; 489 sched->sleep_measurement_overhead = min_delta; 490 491 printf("sleep measurement overhead: %" PRIu64 " nsecs\n", min_delta); 492 } 493 494 static struct sched_atom * 495 get_new_event(struct task_desc *task, u64 timestamp) 496 { 497 struct sched_atom *event = zalloc(sizeof(*event)); 498 unsigned long idx = task->nr_events; 499 size_t size; 500 struct sched_atom **atoms_p; 501 502 if (event == NULL) { 503 pr_err("ERROR: sched: failed to allocate event\n"); 504 return NULL; 505 } 506 507 event->timestamp = timestamp; 508 event->nr = idx; 509 510 size = sizeof(struct sched_atom *) * (task->nr_events + 1); 511 atoms_p = realloc(task->atoms, size); 512 if (!atoms_p) { 513 pr_err("ERROR: sched: failed to grow atoms array\n"); 514 free(event); 515 return NULL; 516 } 517 task->atoms = atoms_p; 518 task->nr_events++; 519 520 task->atoms[idx] = event; 521 522 return event; 523 } 524 525 static struct sched_atom *last_event(struct task_desc *task) 526 { 527 if (!task->nr_events) 528 return NULL; 529 530 return task->atoms[task->nr_events - 1]; 531 } 532 533 static void add_sched_event_run(struct perf_sched *sched, struct task_desc *task, 534 u64 timestamp, u64 duration) 535 { 536 struct sched_atom *event, *curr_event = last_event(task); 537 538 /* 539 * optimize an existing RUN event by merging this one 540 * to it: 541 */ 542 if (curr_event && curr_event->type == SCHED_EVENT_RUN) { 543 sched->nr_run_events_optimized++; 544 curr_event->duration += duration; 545 return; 546 } 547 548 event = get_new_event(task, timestamp); 549 if (event == NULL) 550 return; 551 552 event->type = SCHED_EVENT_RUN; 553 event->duration = duration; 554 555 sched->nr_run_events++; 556 } 557 558 static void add_sched_event_wakeup(struct perf_sched *sched, struct task_desc *task, 559 u64 timestamp, struct task_desc *wakee) 560 { 561 struct sched_atom *event, *wakee_event; 562 563 event = get_new_event(task, timestamp); 564 if (event == NULL) 565 return; 566 event->type = SCHED_EVENT_WAKEUP; 567 event->wakee = wakee; 568 569 wakee_event = last_event(wakee); 570 if (!wakee_event || wakee_event->type != SCHED_EVENT_SLEEP) { 571 sched->targetless_wakeups++; 572 return; 573 } 574 if (wakee_event->wait_sem) { 575 sched->multitarget_wakeups++; 576 return; 577 } 578 579 wakee_event->wait_sem = zalloc(sizeof(*wakee_event->wait_sem)); 580 if (!wakee_event->wait_sem) { 581 pr_err("ERROR: sched: failed to allocate semaphore\n"); 582 return; 583 } 584 sem_init(wakee_event->wait_sem, 0, 0); 585 event->wait_sem = wakee_event->wait_sem; 586 587 sched->nr_wakeup_events++; 588 } 589 590 static void add_sched_event_sleep(struct perf_sched *sched, struct task_desc *task, 591 u64 timestamp) 592 { 593 struct sched_atom *event = get_new_event(task, timestamp); 594 595 if (event == NULL) 596 return; 597 598 event->type = SCHED_EVENT_SLEEP; 599 600 sched->nr_sleep_events++; 601 } 602 603 static struct task_desc *register_pid(struct perf_sched *sched, 604 unsigned long pid, const char *comm) 605 { 606 struct task_desc *task, **tasks_p; 607 static int pid_max; 608 609 /* perf.data is untrusted — cap pid to prevent overflow in size calculations */ 610 if (pid >= PID_MAX_LIMIT) { 611 pr_err("pid %lu exceeds limit %d, skipping\n", pid, PID_MAX_LIMIT); 612 return NULL; 613 } 614 615 if (sched->pid_to_task == NULL) { 616 if (sysctl__read_int("kernel/pid_max", &pid_max) < 0) 617 pid_max = MAX_PID; 618 sched->pid_to_task = calloc(pid_max, sizeof(struct task_desc *)); 619 if (sched->pid_to_task == NULL) 620 return NULL; 621 } 622 if (pid >= (unsigned long)pid_max) { 623 void *p = realloc(sched->pid_to_task, (pid + 1) * sizeof(struct task_desc *)); 624 625 if (p == NULL) 626 return NULL; 627 sched->pid_to_task = p; 628 while (pid >= (unsigned long)pid_max) 629 sched->pid_to_task[pid_max++] = NULL; 630 } 631 632 task = sched->pid_to_task[pid]; 633 634 if (task) 635 return task; 636 637 task = zalloc(sizeof(*task)); 638 if (task == NULL) 639 return NULL; 640 task->pid = pid; 641 if (comm) 642 strlcpy(task->comm, comm, sizeof(task->comm)); 643 /* 644 * every task starts in sleeping state - this gets ignored 645 * if there's no wakeup pointing to this sleep state: 646 */ 647 add_sched_event_sleep(sched, task, 0); 648 649 sched->pid_to_task[pid] = task; 650 tasks_p = realloc(sched->tasks, (sched->nr_tasks + 1) * sizeof(struct task_desc *)); 651 if (!tasks_p) 652 return NULL; 653 sched->tasks = tasks_p; 654 sched->tasks[sched->nr_tasks] = task; 655 task->nr = sched->nr_tasks++; 656 657 if (verbose > 0) 658 printf("registered task #%ld, PID %ld (%s)\n", sched->nr_tasks, pid, comm); 659 660 return task; 661 } 662 663 664 static void print_task_traces(struct perf_sched *sched) 665 { 666 struct task_desc *task; 667 unsigned long i; 668 669 for (i = 0; i < sched->nr_tasks; i++) { 670 task = sched->tasks[i]; 671 printf("task %6ld (%20s:%10ld), nr_events: %ld\n", 672 task->nr, task->comm, task->pid, task->nr_events); 673 } 674 } 675 676 static void add_cross_task_wakeups(struct perf_sched *sched) 677 { 678 struct task_desc *task1, *task2; 679 unsigned long i, j; 680 681 for (i = 0; i < sched->nr_tasks; i++) { 682 task1 = sched->tasks[i]; 683 j = i + 1; 684 if (j == sched->nr_tasks) 685 j = 0; 686 task2 = sched->tasks[j]; 687 add_sched_event_wakeup(sched, task1, 0, task2); 688 } 689 } 690 691 static void perf_sched__process_event(struct perf_sched *sched, 692 struct sched_atom *atom) 693 { 694 int ret = 0; 695 696 switch (atom->type) { 697 case SCHED_EVENT_RUN: 698 burn_nsecs(sched, atom->duration); 699 break; 700 case SCHED_EVENT_SLEEP: 701 if (atom->wait_sem) 702 ret = sem_wait(atom->wait_sem); 703 BUG_ON(ret); 704 break; 705 case SCHED_EVENT_WAKEUP: 706 if (atom->wait_sem) 707 ret = sem_post(atom->wait_sem); 708 BUG_ON(ret); 709 break; 710 default: 711 BUG_ON(1); 712 } 713 } 714 715 static u64 get_cpu_usage_nsec_parent(void) 716 { 717 struct rusage ru; 718 u64 sum; 719 int err; 720 721 err = getrusage(RUSAGE_SELF, &ru); 722 BUG_ON(err); 723 724 sum = ru.ru_utime.tv_sec * NSEC_PER_SEC + ru.ru_utime.tv_usec * NSEC_PER_USEC; 725 sum += ru.ru_stime.tv_sec * NSEC_PER_SEC + ru.ru_stime.tv_usec * NSEC_PER_USEC; 726 727 return sum; 728 } 729 730 static int self_open_counters(struct perf_sched *sched, unsigned long cur_task) 731 { 732 struct perf_event_attr attr; 733 char sbuf[STRERR_BUFSIZE], info[STRERR_BUFSIZE]; 734 int fd; 735 struct rlimit limit; 736 bool need_privilege = false; 737 738 memset(&attr, 0, sizeof(attr)); 739 740 attr.type = PERF_TYPE_SOFTWARE; 741 attr.config = PERF_COUNT_SW_TASK_CLOCK; 742 743 force_again: 744 fd = sys_perf_event_open(&attr, 0, -1, -1, 745 perf_event_open_cloexec_flag()); 746 747 if (fd < 0) { 748 if (errno == EMFILE) { 749 if (sched->force) { 750 BUG_ON(getrlimit(RLIMIT_NOFILE, &limit) == -1); 751 limit.rlim_cur += sched->nr_tasks - cur_task; 752 if (limit.rlim_cur > limit.rlim_max) { 753 limit.rlim_max = limit.rlim_cur; 754 need_privilege = true; 755 } 756 if (setrlimit(RLIMIT_NOFILE, &limit) == -1) { 757 if (need_privilege && errno == EPERM) 758 strcpy(info, "Need privilege\n"); 759 } else 760 goto force_again; 761 } else 762 strcpy(info, "Have a try with -f option\n"); 763 } 764 pr_err("Error: sys_perf_event_open() syscall returned " 765 "with %d (%s)\n%s", fd, 766 str_error_r(errno, sbuf, sizeof(sbuf)), info); 767 exit(EXIT_FAILURE); 768 } 769 return fd; 770 } 771 772 static u64 get_cpu_usage_nsec_self(int fd) 773 { 774 u64 runtime; 775 int ret; 776 777 ret = read(fd, &runtime, sizeof(runtime)); 778 BUG_ON(ret != sizeof(runtime)); 779 780 return runtime; 781 } 782 783 struct sched_thread_parms { 784 struct task_desc *task; 785 struct perf_sched *sched; 786 int fd; 787 }; 788 789 static void *thread_func(void *ctx) 790 { 791 struct sched_thread_parms *parms = ctx; 792 struct task_desc *this_task = parms->task; 793 struct perf_sched *sched = parms->sched; 794 u64 cpu_usage_0, cpu_usage_1; 795 unsigned long i, ret; 796 char comm2[22]; 797 int fd = parms->fd; 798 799 zfree(&parms); 800 801 sprintf(comm2, ":%s", this_task->comm); 802 prctl(PR_SET_NAME, comm2); 803 if (fd < 0) 804 return NULL; 805 806 while (!sched->thread_funcs_exit) { 807 ret = sem_post(&this_task->ready_for_work); 808 BUG_ON(ret); 809 mutex_lock(&sched->start_work_mutex); 810 mutex_unlock(&sched->start_work_mutex); 811 812 cpu_usage_0 = get_cpu_usage_nsec_self(fd); 813 814 for (i = 0; i < this_task->nr_events; i++) { 815 this_task->curr_event = i; 816 perf_sched__process_event(sched, this_task->atoms[i]); 817 } 818 819 cpu_usage_1 = get_cpu_usage_nsec_self(fd); 820 this_task->cpu_usage = cpu_usage_1 - cpu_usage_0; 821 ret = sem_post(&this_task->work_done_sem); 822 BUG_ON(ret); 823 824 mutex_lock(&sched->work_done_wait_mutex); 825 mutex_unlock(&sched->work_done_wait_mutex); 826 } 827 return NULL; 828 } 829 830 static void create_tasks(struct perf_sched *sched) 831 EXCLUSIVE_LOCK_FUNCTION(sched->start_work_mutex) 832 EXCLUSIVE_LOCK_FUNCTION(sched->work_done_wait_mutex) 833 { 834 struct task_desc *task; 835 pthread_attr_t attr; 836 unsigned long i; 837 int err; 838 839 err = pthread_attr_init(&attr); 840 BUG_ON(err); 841 err = pthread_attr_setstacksize(&attr, 842 (size_t) max(16 * 1024, (int)PTHREAD_STACK_MIN)); 843 BUG_ON(err); 844 mutex_lock(&sched->start_work_mutex); 845 mutex_lock(&sched->work_done_wait_mutex); 846 for (i = 0; i < sched->nr_tasks; i++) { 847 struct sched_thread_parms *parms = malloc(sizeof(*parms)); 848 BUG_ON(parms == NULL); 849 parms->task = task = sched->tasks[i]; 850 parms->sched = sched; 851 parms->fd = self_open_counters(sched, i); 852 sem_init(&task->ready_for_work, 0, 0); 853 sem_init(&task->work_done_sem, 0, 0); 854 task->curr_event = 0; 855 err = pthread_create(&task->thread, &attr, thread_func, parms); 856 BUG_ON(err); 857 } 858 } 859 860 static void destroy_tasks(struct perf_sched *sched) 861 UNLOCK_FUNCTION(sched->start_work_mutex) 862 UNLOCK_FUNCTION(sched->work_done_wait_mutex) 863 { 864 struct task_desc *task; 865 unsigned long i; 866 int err; 867 868 mutex_unlock(&sched->start_work_mutex); 869 mutex_unlock(&sched->work_done_wait_mutex); 870 /* Get rid of threads so they won't be upset by mutex destrunction */ 871 for (i = 0; i < sched->nr_tasks; i++) { 872 task = sched->tasks[i]; 873 err = pthread_join(task->thread, NULL); 874 BUG_ON(err); 875 sem_destroy(&task->ready_for_work); 876 sem_destroy(&task->work_done_sem); 877 } 878 } 879 880 static void wait_for_tasks(struct perf_sched *sched) 881 EXCLUSIVE_LOCKS_REQUIRED(sched->work_done_wait_mutex) 882 EXCLUSIVE_LOCKS_REQUIRED(sched->start_work_mutex) 883 { 884 u64 cpu_usage_0, cpu_usage_1; 885 struct task_desc *task; 886 unsigned long i, ret; 887 888 sched->start_time = get_nsecs(); 889 sched->cpu_usage = 0; 890 mutex_unlock(&sched->work_done_wait_mutex); 891 892 for (i = 0; i < sched->nr_tasks; i++) { 893 task = sched->tasks[i]; 894 ret = sem_wait(&task->ready_for_work); 895 BUG_ON(ret); 896 sem_init(&task->ready_for_work, 0, 0); 897 } 898 mutex_lock(&sched->work_done_wait_mutex); 899 900 cpu_usage_0 = get_cpu_usage_nsec_parent(); 901 902 mutex_unlock(&sched->start_work_mutex); 903 904 for (i = 0; i < sched->nr_tasks; i++) { 905 task = sched->tasks[i]; 906 ret = sem_wait(&task->work_done_sem); 907 BUG_ON(ret); 908 sem_init(&task->work_done_sem, 0, 0); 909 sched->cpu_usage += task->cpu_usage; 910 task->cpu_usage = 0; 911 } 912 913 cpu_usage_1 = get_cpu_usage_nsec_parent(); 914 if (!sched->runavg_cpu_usage) 915 sched->runavg_cpu_usage = sched->cpu_usage; 916 sched->runavg_cpu_usage = (sched->runavg_cpu_usage * (sched->replay_repeat - 1) + sched->cpu_usage) / sched->replay_repeat; 917 918 sched->parent_cpu_usage = cpu_usage_1 - cpu_usage_0; 919 if (!sched->runavg_parent_cpu_usage) 920 sched->runavg_parent_cpu_usage = sched->parent_cpu_usage; 921 sched->runavg_parent_cpu_usage = (sched->runavg_parent_cpu_usage * (sched->replay_repeat - 1) + 922 sched->parent_cpu_usage)/sched->replay_repeat; 923 924 mutex_lock(&sched->start_work_mutex); 925 926 for (i = 0; i < sched->nr_tasks; i++) { 927 task = sched->tasks[i]; 928 task->curr_event = 0; 929 } 930 } 931 932 static void run_one_test(struct perf_sched *sched) 933 EXCLUSIVE_LOCKS_REQUIRED(sched->work_done_wait_mutex) 934 EXCLUSIVE_LOCKS_REQUIRED(sched->start_work_mutex) 935 { 936 u64 T0, T1, delta, avg_delta, fluct; 937 938 T0 = get_nsecs(); 939 wait_for_tasks(sched); 940 T1 = get_nsecs(); 941 942 delta = T1 - T0; 943 sched->sum_runtime += delta; 944 sched->nr_runs++; 945 946 avg_delta = sched->sum_runtime / sched->nr_runs; 947 if (delta < avg_delta) 948 fluct = avg_delta - delta; 949 else 950 fluct = delta - avg_delta; 951 sched->sum_fluct += fluct; 952 if (!sched->run_avg) 953 sched->run_avg = delta; 954 sched->run_avg = (sched->run_avg * (sched->replay_repeat - 1) + delta) / sched->replay_repeat; 955 956 printf("#%-3ld: %0.3f, ", sched->nr_runs, (double)delta / NSEC_PER_MSEC); 957 958 printf("ravg: %0.2f, ", (double)sched->run_avg / NSEC_PER_MSEC); 959 960 printf("cpu: %0.2f / %0.2f", 961 (double)sched->cpu_usage / NSEC_PER_MSEC, (double)sched->runavg_cpu_usage / NSEC_PER_MSEC); 962 963 #if 0 964 /* 965 * rusage statistics done by the parent, these are less 966 * accurate than the sched->sum_exec_runtime based statistics: 967 */ 968 printf(" [%0.2f / %0.2f]", 969 (double)sched->parent_cpu_usage / NSEC_PER_MSEC, 970 (double)sched->runavg_parent_cpu_usage / NSEC_PER_MSEC); 971 #endif 972 973 printf("\n"); 974 975 if (sched->nr_sleep_corrections) 976 printf(" (%ld sleep corrections)\n", sched->nr_sleep_corrections); 977 sched->nr_sleep_corrections = 0; 978 } 979 980 static void test_calibrations(struct perf_sched *sched) 981 { 982 u64 T0, T1; 983 984 T0 = get_nsecs(); 985 burn_nsecs(sched, NSEC_PER_MSEC); 986 T1 = get_nsecs(); 987 988 printf("the run test took %" PRIu64 " nsecs\n", T1 - T0); 989 990 T0 = get_nsecs(); 991 sleep_nsecs(NSEC_PER_MSEC); 992 T1 = get_nsecs(); 993 994 printf("the sleep test took %" PRIu64 " nsecs\n", T1 - T0); 995 } 996 997 static int 998 replay_wakeup_event(struct perf_sched *sched, 999 struct perf_sample *sample, 1000 struct machine *machine __maybe_unused) 1001 { 1002 const char *comm = perf_sample__strval(sample, "comm"); 1003 const u32 pid = perf_sample__intval(sample, "pid"); 1004 struct task_desc *waker, *wakee; 1005 1006 if (verbose > 0) { 1007 printf("sched_wakeup event %p\n", sample->evsel); 1008 1009 printf(" ... pid %d woke up %s/%d\n", sample->tid, comm, pid); 1010 } 1011 1012 waker = register_pid(sched, sample->tid, "<unknown>"); 1013 wakee = register_pid(sched, pid, comm); 1014 if (waker == NULL || wakee == NULL) 1015 return -1; 1016 1017 add_sched_event_wakeup(sched, waker, sample->time, wakee); 1018 return 0; 1019 } 1020 1021 static int replay_switch_event(struct perf_sched *sched, 1022 struct perf_sample *sample, 1023 struct machine *machine __maybe_unused) 1024 { 1025 const char *prev_comm = perf_sample__strval(sample, "prev_comm"), 1026 *next_comm = perf_sample__strval(sample, "next_comm"); 1027 const u32 prev_pid = perf_sample__intval(sample, "prev_pid"), 1028 next_pid = perf_sample__intval(sample, "next_pid"); 1029 struct task_desc *prev, __maybe_unused *next; 1030 u64 timestamp0, timestamp = sample->time; 1031 int cpu = sample->cpu; 1032 s64 delta; 1033 1034 if (verbose > 0) 1035 printf("sched_switch event %p\n", sample->evsel); 1036 1037 if (cpu >= MAX_CPUS || cpu < 0) 1038 return 0; 1039 1040 timestamp0 = sched->cpu_last_switched[cpu]; 1041 if (timestamp0) 1042 delta = timestamp - timestamp0; 1043 else 1044 delta = 0; 1045 1046 if (delta < 0) { 1047 pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta); 1048 return -1; 1049 } 1050 1051 pr_debug(" ... switch from %s/%d to %s/%d [ran %" PRIu64 " nsecs]\n", 1052 prev_comm, prev_pid, next_comm, next_pid, delta); 1053 1054 prev = register_pid(sched, prev_pid, prev_comm); 1055 next = register_pid(sched, next_pid, next_comm); 1056 if (prev == NULL || next == NULL) 1057 return -1; 1058 1059 sched->cpu_last_switched[cpu] = timestamp; 1060 1061 add_sched_event_run(sched, prev, timestamp, delta); 1062 add_sched_event_sleep(sched, prev, timestamp); 1063 1064 return 0; 1065 } 1066 1067 static int replay_fork_event(struct perf_sched *sched, 1068 union perf_event *event, 1069 struct machine *machine) 1070 { 1071 struct thread *child, *parent; 1072 1073 child = machine__findnew_thread(machine, event->fork.pid, 1074 event->fork.tid); 1075 parent = machine__findnew_thread(machine, event->fork.ppid, 1076 event->fork.ptid); 1077 1078 if (child == NULL || parent == NULL) { 1079 pr_debug("thread does not exist on fork event: child %p, parent %p\n", 1080 child, parent); 1081 goto out_put; 1082 } 1083 1084 if (verbose > 0) { 1085 printf("fork event\n"); 1086 printf("... parent: %s/%d\n", thread__comm_str(parent), thread__tid(parent)); 1087 printf("... child: %s/%d\n", thread__comm_str(child), thread__tid(child)); 1088 } 1089 1090 register_pid(sched, thread__tid(parent), thread__comm_str(parent)); 1091 register_pid(sched, thread__tid(child), thread__comm_str(child)); 1092 out_put: 1093 thread__put(child); 1094 thread__put(parent); 1095 return 0; 1096 } 1097 1098 struct sort_dimension { 1099 const char *name; 1100 sort_fn_t cmp; 1101 struct list_head list; 1102 }; 1103 1104 static inline void init_prio(struct thread_runtime *r) 1105 { 1106 r->prio = -1; 1107 } 1108 1109 /* 1110 * handle runtime stats saved per thread 1111 */ 1112 static struct thread_runtime *thread__init_runtime(struct thread *thread) 1113 { 1114 struct thread_runtime *r; 1115 1116 r = zalloc(sizeof(struct thread_runtime)); 1117 if (!r) 1118 return NULL; 1119 1120 init_stats(&r->run_stats); 1121 init_prio(r); 1122 thread__set_priv(thread, r); 1123 1124 return r; 1125 } 1126 1127 static struct thread_runtime *thread__get_runtime(struct thread *thread) 1128 { 1129 struct thread_runtime *tr; 1130 1131 tr = thread__priv(thread); 1132 if (tr == NULL) { 1133 tr = thread__init_runtime(thread); 1134 if (tr == NULL) 1135 pr_debug("Failed to malloc memory for runtime data.\n"); 1136 } 1137 1138 return tr; 1139 } 1140 1141 static int 1142 thread_lat_cmp(struct list_head *list, struct work_atoms *l, struct work_atoms *r) 1143 { 1144 struct sort_dimension *sort; 1145 int ret = 0; 1146 1147 BUG_ON(list_empty(list)); 1148 1149 list_for_each_entry(sort, list, list) { 1150 ret = sort->cmp(l, r); 1151 if (ret) 1152 return ret; 1153 } 1154 1155 return ret; 1156 } 1157 1158 static struct work_atoms * 1159 thread_atoms_search(struct rb_root_cached *root, struct thread *thread, 1160 struct list_head *sort_list) 1161 { 1162 struct rb_node *node = root->rb_root.rb_node; 1163 struct work_atoms key = { .thread = thread }; 1164 1165 while (node) { 1166 struct work_atoms *atoms; 1167 int cmp; 1168 1169 atoms = container_of(node, struct work_atoms, node); 1170 1171 cmp = thread_lat_cmp(sort_list, &key, atoms); 1172 if (cmp > 0) 1173 node = node->rb_left; 1174 else if (cmp < 0) 1175 node = node->rb_right; 1176 else { 1177 BUG_ON(!RC_CHK_EQUAL(thread, atoms->thread)); 1178 return atoms; 1179 } 1180 } 1181 return NULL; 1182 } 1183 1184 static void 1185 __thread_latency_insert(struct rb_root_cached *root, struct work_atoms *data, 1186 struct list_head *sort_list) 1187 { 1188 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 1189 bool leftmost = true; 1190 1191 while (*new) { 1192 struct work_atoms *this; 1193 int cmp; 1194 1195 this = container_of(*new, struct work_atoms, node); 1196 parent = *new; 1197 1198 cmp = thread_lat_cmp(sort_list, data, this); 1199 1200 if (cmp > 0) 1201 new = &((*new)->rb_left); 1202 else { 1203 new = &((*new)->rb_right); 1204 leftmost = false; 1205 } 1206 } 1207 1208 rb_link_node(&data->node, parent, new); 1209 rb_insert_color_cached(&data->node, root, leftmost); 1210 } 1211 1212 static int thread_atoms_insert(struct perf_sched *sched, struct thread *thread) 1213 { 1214 struct work_atoms *atoms = zalloc(sizeof(*atoms)); 1215 if (!atoms) { 1216 pr_err("No memory at %s\n", __func__); 1217 return -1; 1218 } 1219 1220 atoms->thread = thread__get(thread); 1221 INIT_LIST_HEAD(&atoms->work_list); 1222 __thread_latency_insert(&sched->atom_root, atoms, &sched->cmp_pid); 1223 return 0; 1224 } 1225 1226 static int 1227 add_sched_out_event(struct work_atoms *atoms, 1228 char run_state, 1229 u64 timestamp) 1230 { 1231 struct work_atom *atom = NULL; 1232 1233 if (!list_empty(&atoms->work_list)) { 1234 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1235 if (atom->state != THREAD_SCHED_IN) 1236 goto reuse; 1237 } 1238 1239 atom = zalloc(sizeof(*atom)); 1240 if (!atom) { 1241 pr_err("Non memory at %s", __func__); 1242 return -1; 1243 } 1244 1245 list_add_tail(&atom->list, &atoms->work_list); 1246 1247 reuse: 1248 atom->sched_out_time = timestamp; 1249 1250 if (run_state == 'R') { 1251 atom->state = THREAD_WAIT_CPU; 1252 atom->wake_up_time = atom->sched_out_time; 1253 } else { 1254 atom->state = THREAD_SLEEPING; 1255 atom->wake_up_time = 0; 1256 } 1257 1258 return 0; 1259 } 1260 1261 static void 1262 add_runtime_event(struct work_atoms *atoms, u64 delta, 1263 u64 timestamp __maybe_unused) 1264 { 1265 struct work_atom *atom; 1266 1267 BUG_ON(list_empty(&atoms->work_list)); 1268 1269 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1270 1271 atom->runtime += delta; 1272 atoms->total_runtime += delta; 1273 } 1274 1275 static void 1276 add_sched_in_event(struct perf_sched *sched, struct work_atoms *atoms, 1277 u64 timestamp) 1278 { 1279 struct work_atom *atom; 1280 u64 delta; 1281 int b; 1282 1283 if (list_empty(&atoms->work_list)) 1284 return; 1285 1286 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1287 1288 if (atom->state != THREAD_WAIT_CPU) 1289 return; 1290 1291 if (timestamp < atom->wake_up_time) { 1292 atom->state = THREAD_IGNORE; 1293 return; 1294 } 1295 1296 if (perf_time__skip_sample(&sched->ptime, timestamp)) 1297 return; 1298 1299 atom->state = THREAD_SCHED_IN; 1300 atom->sched_in_time = timestamp; 1301 1302 delta = atom->sched_in_time - atom->wake_up_time; 1303 atoms->total_lat += delta; 1304 if (delta > atoms->max_lat) { 1305 atoms->max_lat = delta; 1306 atoms->max_lat_start = atom->wake_up_time; 1307 atoms->max_lat_end = timestamp; 1308 } 1309 1310 atoms->nb_atoms++; 1311 1312 b = latency_bucket(sched, delta); 1313 atoms->hist[b]++; 1314 if (thread__tid(atoms->thread) != 0) 1315 sched->global_hist[b]++; 1316 } 1317 1318 static void free_work_atoms(struct work_atoms *atoms) 1319 { 1320 struct work_atom *atom, *tmp; 1321 1322 if (atoms == NULL) 1323 return; 1324 1325 list_for_each_entry_safe(atom, tmp, &atoms->work_list, list) { 1326 list_del(&atom->list); 1327 free(atom); 1328 } 1329 thread__zput(atoms->thread); 1330 free(atoms); 1331 } 1332 1333 static int latency_switch_event(struct perf_sched *sched, 1334 struct perf_sample *sample, 1335 struct machine *machine) 1336 { 1337 const u32 prev_pid = perf_sample__intval(sample, "prev_pid"), 1338 next_pid = perf_sample__intval(sample, "next_pid"); 1339 const char prev_state = perf_sample__taskstate(sample, "prev_state"); 1340 struct work_atoms *out_events, *in_events; 1341 struct thread *sched_out, *sched_in; 1342 u64 timestamp0, timestamp = sample->time; 1343 int cpu = sample->cpu, err = -1; 1344 s64 delta; 1345 1346 /* perf.data is untrusted input — CPU may be absent or corrupted */ 1347 if (cpu >= MAX_CPUS || cpu < 0) { 1348 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %d, skipping sample\n", 1349 sample->file_offset, cpu); 1350 return 0; 1351 } 1352 1353 timestamp0 = sched->cpu_last_switched[cpu]; 1354 sched->cpu_last_switched[cpu] = timestamp; 1355 if (timestamp0) 1356 delta = timestamp - timestamp0; 1357 else 1358 delta = 0; 1359 1360 if (delta < 0) { 1361 pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta); 1362 return -1; 1363 } 1364 1365 sched_out = machine__findnew_thread(machine, -1, prev_pid); 1366 sched_in = machine__findnew_thread(machine, -1, next_pid); 1367 if (sched_out == NULL || sched_in == NULL) 1368 goto out_put; 1369 1370 out_events = thread_atoms_search(&sched->atom_root, sched_out, &sched->cmp_pid); 1371 if (!out_events) { 1372 if (thread_atoms_insert(sched, sched_out)) 1373 goto out_put; 1374 out_events = thread_atoms_search(&sched->atom_root, sched_out, &sched->cmp_pid); 1375 if (!out_events) { 1376 pr_err("out-event: Internal tree error"); 1377 goto out_put; 1378 } 1379 } 1380 if (add_sched_out_event(out_events, prev_state, timestamp)) 1381 goto out_put; 1382 1383 in_events = thread_atoms_search(&sched->atom_root, sched_in, &sched->cmp_pid); 1384 if (!in_events) { 1385 if (thread_atoms_insert(sched, sched_in)) 1386 goto out_put; 1387 in_events = thread_atoms_search(&sched->atom_root, sched_in, &sched->cmp_pid); 1388 if (!in_events) { 1389 pr_err("in-event: Internal tree error"); 1390 goto out_put; 1391 } 1392 /* 1393 * Take came in we have not heard about yet, 1394 * add in an initial atom in runnable state: 1395 */ 1396 if (add_sched_out_event(in_events, 'R', timestamp)) 1397 goto out_put; 1398 } 1399 add_sched_in_event(sched, in_events, timestamp); 1400 err = 0; 1401 out_put: 1402 thread__put(sched_out); 1403 thread__put(sched_in); 1404 return err; 1405 } 1406 1407 static int latency_runtime_event(struct perf_sched *sched, 1408 struct perf_sample *sample, 1409 struct machine *machine) 1410 { 1411 const u32 pid = perf_sample__intval(sample, "pid"); 1412 const u64 runtime = perf_sample__intval(sample, "runtime"); 1413 struct thread *thread; 1414 struct work_atoms *atoms; 1415 u64 timestamp = sample->time; 1416 int cpu = sample->cpu, err = -1; 1417 1418 if (perf_time__skip_sample(&sched->ptime, timestamp)) 1419 return 0; 1420 1421 thread = machine__findnew_thread(machine, -1, pid); 1422 if (thread == NULL) 1423 return -1; 1424 1425 atoms = thread_atoms_search(&sched->atom_root, thread, &sched->cmp_pid); 1426 1427 /* perf.data is untrusted input — CPU may be absent or corrupted */ 1428 if (cpu >= MAX_CPUS || cpu < 0) { 1429 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %d, skipping sample\n", 1430 sample->file_offset, cpu); 1431 err = 0; 1432 goto out_put; 1433 } 1434 if (!atoms) { 1435 if (thread_atoms_insert(sched, thread)) 1436 goto out_put; 1437 atoms = thread_atoms_search(&sched->atom_root, thread, &sched->cmp_pid); 1438 if (!atoms) { 1439 pr_err("in-event: Internal tree error"); 1440 goto out_put; 1441 } 1442 if (add_sched_out_event(atoms, 'R', timestamp)) 1443 goto out_put; 1444 } 1445 1446 add_runtime_event(atoms, runtime, timestamp); 1447 err = 0; 1448 out_put: 1449 thread__put(thread); 1450 return err; 1451 } 1452 1453 static int latency_wakeup_event(struct perf_sched *sched, 1454 struct perf_sample *sample, 1455 struct machine *machine) 1456 { 1457 const u32 pid = perf_sample__intval(sample, "pid"); 1458 struct work_atoms *atoms; 1459 struct work_atom *atom; 1460 struct thread *wakee; 1461 u64 timestamp = sample->time; 1462 int err = -1; 1463 1464 wakee = machine__findnew_thread(machine, -1, pid); 1465 if (wakee == NULL) 1466 return -1; 1467 atoms = thread_atoms_search(&sched->atom_root, wakee, &sched->cmp_pid); 1468 if (!atoms) { 1469 if (thread_atoms_insert(sched, wakee)) 1470 goto out_put; 1471 atoms = thread_atoms_search(&sched->atom_root, wakee, &sched->cmp_pid); 1472 if (!atoms) { 1473 pr_err("wakeup-event: Internal tree error"); 1474 goto out_put; 1475 } 1476 if (add_sched_out_event(atoms, 'S', timestamp)) 1477 goto out_put; 1478 } 1479 1480 BUG_ON(list_empty(&atoms->work_list)); 1481 1482 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1483 1484 /* 1485 * As we do not guarantee the wakeup event happens when 1486 * task is out of run queue, also may happen when task is 1487 * on run queue and wakeup only change ->state to TASK_RUNNING, 1488 * then we should not set the ->wake_up_time when wake up a 1489 * task which is on run queue. 1490 * 1491 * You WILL be missing events if you've recorded only 1492 * one CPU, or are only looking at only one, so don't 1493 * skip in this case. 1494 */ 1495 if (sched->profile_cpu == -1 && atom->state != THREAD_SLEEPING) 1496 goto out_ok; 1497 1498 sched->nr_timestamps++; 1499 if (atom->sched_out_time > timestamp) { 1500 sched->nr_unordered_timestamps++; 1501 goto out_ok; 1502 } 1503 1504 atom->state = THREAD_WAIT_CPU; 1505 atom->wake_up_time = timestamp; 1506 out_ok: 1507 err = 0; 1508 out_put: 1509 thread__put(wakee); 1510 return err; 1511 } 1512 1513 static int latency_migrate_task_event(struct perf_sched *sched, 1514 struct perf_sample *sample, 1515 struct machine *machine) 1516 { 1517 const u32 pid = perf_sample__intval(sample, "pid"); 1518 u64 timestamp = sample->time; 1519 struct work_atoms *atoms; 1520 struct work_atom *atom; 1521 struct thread *migrant; 1522 int err = -1; 1523 1524 /* 1525 * Only need to worry about migration when profiling one CPU. 1526 */ 1527 if (sched->profile_cpu == -1) 1528 return 0; 1529 1530 migrant = machine__findnew_thread(machine, -1, pid); 1531 if (migrant == NULL) 1532 return -1; 1533 atoms = thread_atoms_search(&sched->atom_root, migrant, &sched->cmp_pid); 1534 if (!atoms) { 1535 if (thread_atoms_insert(sched, migrant)) 1536 goto out_put; 1537 register_pid(sched, thread__tid(migrant), thread__comm_str(migrant)); 1538 atoms = thread_atoms_search(&sched->atom_root, migrant, &sched->cmp_pid); 1539 if (!atoms) { 1540 pr_err("migration-event: Internal tree error"); 1541 goto out_put; 1542 } 1543 if (add_sched_out_event(atoms, 'R', timestamp)) 1544 goto out_put; 1545 } 1546 1547 BUG_ON(list_empty(&atoms->work_list)); 1548 1549 atom = list_entry(atoms->work_list.prev, struct work_atom, list); 1550 atom->sched_in_time = atom->sched_out_time = atom->wake_up_time = timestamp; 1551 1552 sched->nr_timestamps++; 1553 1554 if (atom->sched_out_time > timestamp) 1555 sched->nr_unordered_timestamps++; 1556 err = 0; 1557 out_put: 1558 thread__put(migrant); 1559 return err; 1560 } 1561 1562 static void output_lat_thread(struct perf_sched *sched, struct work_atoms *work_list) 1563 { 1564 int i; 1565 int ret; 1566 u64 avg; 1567 char runtime_lat[32]; 1568 char avg_lat[32], max_lat[32]; 1569 char max_lat_start[32], max_lat_end[32]; 1570 1571 if (!work_list->nb_atoms) 1572 return; 1573 /* 1574 * Ignore idle threads: 1575 */ 1576 if (thread__tid(work_list->thread) == 0) 1577 return; 1578 1579 sched->all_runtime += work_list->total_runtime; 1580 sched->all_count += work_list->nb_atoms; 1581 1582 if (work_list->num_merged > 1) { 1583 ret = printf(" %s:(%d)", thread__comm_str(work_list->thread), 1584 work_list->num_merged); 1585 } else { 1586 ret = printf(" %s:%d", thread__comm_str(work_list->thread), 1587 thread__tid(work_list->thread)); 1588 } 1589 1590 for (i = 0; i < 24 - ret; i++) 1591 printf(" "); 1592 1593 avg = work_list->total_lat / work_list->nb_atoms; 1594 scnprintf_latency_unit(runtime_lat, sizeof(runtime_lat), work_list->total_runtime); 1595 scnprintf_latency_unit(avg_lat, sizeof(avg_lat), avg); 1596 scnprintf_latency_unit(max_lat, sizeof(max_lat), work_list->max_lat); 1597 timestamp__scnprintf_usec(work_list->max_lat_start, max_lat_start, sizeof(max_lat_start)); 1598 timestamp__scnprintf_usec(work_list->max_lat_end, max_lat_end, sizeof(max_lat_end)); 1599 1600 printf(" |%15s |%9" PRIu64 " |%16s |%16s |%20s s |%20s s |\n", 1601 runtime_lat, 1602 work_list->nb_atoms, avg_lat, max_lat, 1603 max_lat_start, max_lat_end); 1604 1605 if (sched->show_histogram && verbose > 0) 1606 print_latency_histogram(sched, work_list->hist, 1607 work_list->nb_atoms, 1608 "Task Latency Histogram"); 1609 } 1610 1611 static int pid_cmp(struct work_atoms *l, struct work_atoms *r) 1612 { 1613 pid_t l_tid, r_tid; 1614 1615 if (RC_CHK_EQUAL(l->thread, r->thread)) 1616 return 0; 1617 l_tid = thread__tid(l->thread); 1618 r_tid = thread__tid(r->thread); 1619 if (l_tid < r_tid) 1620 return -1; 1621 if (l_tid > r_tid) 1622 return 1; 1623 return (int)(RC_CHK_ACCESS(l->thread) - RC_CHK_ACCESS(r->thread)); 1624 } 1625 1626 static int avg_cmp(struct work_atoms *l, struct work_atoms *r) 1627 { 1628 u64 avgl, avgr; 1629 1630 if (!l->nb_atoms) 1631 return -1; 1632 1633 if (!r->nb_atoms) 1634 return 1; 1635 1636 avgl = l->total_lat / l->nb_atoms; 1637 avgr = r->total_lat / r->nb_atoms; 1638 1639 if (avgl < avgr) 1640 return -1; 1641 if (avgl > avgr) 1642 return 1; 1643 1644 return 0; 1645 } 1646 1647 static int max_cmp(struct work_atoms *l, struct work_atoms *r) 1648 { 1649 if (l->max_lat < r->max_lat) 1650 return -1; 1651 if (l->max_lat > r->max_lat) 1652 return 1; 1653 1654 return 0; 1655 } 1656 1657 static int switch_cmp(struct work_atoms *l, struct work_atoms *r) 1658 { 1659 if (l->nb_atoms < r->nb_atoms) 1660 return -1; 1661 if (l->nb_atoms > r->nb_atoms) 1662 return 1; 1663 1664 return 0; 1665 } 1666 1667 static int runtime_cmp(struct work_atoms *l, struct work_atoms *r) 1668 { 1669 if (l->total_runtime < r->total_runtime) 1670 return -1; 1671 if (l->total_runtime > r->total_runtime) 1672 return 1; 1673 1674 return 0; 1675 } 1676 1677 static int sort_dimension__add(const char *tok, struct list_head *list) 1678 { 1679 size_t i; 1680 static struct sort_dimension avg_sort_dimension = { 1681 .name = "avg", 1682 .cmp = avg_cmp, 1683 }; 1684 static struct sort_dimension max_sort_dimension = { 1685 .name = "max", 1686 .cmp = max_cmp, 1687 }; 1688 static struct sort_dimension pid_sort_dimension = { 1689 .name = "pid", 1690 .cmp = pid_cmp, 1691 }; 1692 static struct sort_dimension runtime_sort_dimension = { 1693 .name = "runtime", 1694 .cmp = runtime_cmp, 1695 }; 1696 static struct sort_dimension switch_sort_dimension = { 1697 .name = "switch", 1698 .cmp = switch_cmp, 1699 }; 1700 struct sort_dimension *available_sorts[] = { 1701 &pid_sort_dimension, 1702 &avg_sort_dimension, 1703 &max_sort_dimension, 1704 &switch_sort_dimension, 1705 &runtime_sort_dimension, 1706 }; 1707 1708 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) { 1709 if (!strcmp(available_sorts[i]->name, tok)) { 1710 list_add_tail(&available_sorts[i]->list, list); 1711 1712 return 0; 1713 } 1714 } 1715 1716 return -1; 1717 } 1718 1719 static void perf_sched__sort_lat(struct perf_sched *sched) 1720 { 1721 struct rb_node *node; 1722 struct rb_root_cached *root = &sched->atom_root; 1723 again: 1724 for (;;) { 1725 struct work_atoms *data; 1726 node = rb_first_cached(root); 1727 if (!node) 1728 break; 1729 1730 rb_erase_cached(node, root); 1731 data = rb_entry(node, struct work_atoms, node); 1732 __thread_latency_insert(&sched->sorted_atom_root, data, &sched->sort_list); 1733 } 1734 if (root == &sched->atom_root) { 1735 root = &sched->merged_atom_root; 1736 goto again; 1737 } 1738 } 1739 1740 static int process_sched_wakeup_event(const struct perf_tool *tool, 1741 struct perf_sample *sample, 1742 struct machine *machine) 1743 { 1744 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 1745 1746 if (sched->tp_handler->wakeup_event) 1747 return sched->tp_handler->wakeup_event(sched, sample, machine); 1748 1749 return 0; 1750 } 1751 1752 1753 static bool thread__has_color(struct thread *thread) 1754 { 1755 struct thread_runtime *tr = thread__priv(thread); 1756 1757 return tr != NULL && tr->color; 1758 } 1759 1760 static struct thread* 1761 map__findnew_thread(struct perf_sched *sched, struct machine *machine, pid_t pid, pid_t tid) 1762 { 1763 struct thread *thread = machine__findnew_thread(machine, pid, tid); 1764 1765 if (!sched->map.color_pids || !thread) 1766 return thread; 1767 1768 /* 1769 * Always check the color-pids map, even if thread__priv() is 1770 * already set. COMM events processed before the first sched_switch 1771 * allocate a thread_runtime via thread__get_runtime(), so priv is 1772 * non-NULL before we ever get here. Skipping the check on non-NULL 1773 * priv would prevent those threads from being colored. 1774 */ 1775 if (thread_map__has(sched->map.color_pids, tid)) { 1776 struct thread_runtime *tr = thread__get_runtime(thread); 1777 1778 if (tr) 1779 tr->color = true; 1780 } 1781 return thread; 1782 } 1783 1784 static bool sched_match_task(struct perf_sched *sched, const char *comm_str) 1785 { 1786 bool fuzzy_match = sched->map.fuzzy; 1787 struct strlist *task_names = sched->map.task_names; 1788 struct str_node *node; 1789 1790 strlist__for_each_entry(node, task_names) { 1791 bool match_found = fuzzy_match ? !!strstr(comm_str, node->s) : 1792 !strcmp(comm_str, node->s); 1793 if (match_found) 1794 return true; 1795 } 1796 1797 return false; 1798 } 1799 1800 static void print_sched_map(struct perf_sched *sched, struct perf_cpu this_cpu, int cpus_nr, 1801 const char *color, bool sched_out) 1802 { 1803 for (int i = 0; i < cpus_nr; i++) { 1804 struct perf_cpu cpu = { 1805 .cpu = sched->map.comp ? sched->map.comp_cpus[i].cpu : i, 1806 }; 1807 struct thread *curr_thread = sched->curr_thread[cpu.cpu]; 1808 struct thread *curr_out_thread = sched->curr_out_thread[cpu.cpu]; 1809 struct thread_runtime *curr_tr; 1810 const char *pid_color = color; 1811 const char *cpu_color = color; 1812 char symbol = ' '; 1813 struct thread *thread_to_check = sched_out ? curr_out_thread : curr_thread; 1814 1815 if (thread_to_check && thread__has_color(thread_to_check)) 1816 pid_color = COLOR_PIDS; 1817 1818 if (sched->map.color_cpus && perf_cpu_map__has(sched->map.color_cpus, cpu)) 1819 cpu_color = COLOR_CPUS; 1820 1821 if (cpu.cpu == this_cpu.cpu) 1822 symbol = '*'; 1823 1824 color_fprintf(stdout, cpu.cpu != this_cpu.cpu ? color : cpu_color, "%c", symbol); 1825 1826 thread_to_check = sched_out ? sched->curr_out_thread[cpu.cpu] : 1827 sched->curr_thread[cpu.cpu]; 1828 1829 if (thread_to_check) { 1830 curr_tr = thread__get_runtime(thread_to_check); 1831 if (curr_tr == NULL) 1832 return; 1833 1834 if (sched_out) { 1835 if (cpu.cpu == this_cpu.cpu) 1836 color_fprintf(stdout, color, "- "); 1837 else { 1838 curr_tr = thread__get_runtime(sched->curr_thread[cpu.cpu]); 1839 if (curr_tr != NULL) 1840 color_fprintf(stdout, pid_color, "%2s ", 1841 curr_tr->shortname); 1842 } 1843 } else 1844 color_fprintf(stdout, pid_color, "%2s ", curr_tr->shortname); 1845 } else 1846 color_fprintf(stdout, color, " "); 1847 } 1848 } 1849 1850 static int map_switch_event(struct perf_sched *sched, struct perf_sample *sample, 1851 struct machine *machine) 1852 { 1853 const u32 next_pid = perf_sample__intval(sample, "next_pid"); 1854 const u32 prev_pid = perf_sample__intval(sample, "prev_pid"); 1855 struct thread *sched_in, *sched_out; 1856 struct thread_runtime *tr; 1857 int new_shortname; 1858 u64 timestamp0, timestamp = sample->time; 1859 s64 delta; 1860 struct perf_cpu this_cpu = { 1861 .cpu = sample->cpu, 1862 }; 1863 int cpus_nr; 1864 int proceed; 1865 bool new_cpu = false; 1866 const char *color = PERF_COLOR_NORMAL; 1867 char stimestamp[32]; 1868 const char *str; 1869 int ret = -1; 1870 1871 /* perf.data is untrusted input — CPU may be absent or corrupted */ 1872 if (this_cpu.cpu >= MAX_CPUS || this_cpu.cpu < 0) { 1873 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %d, skipping sample\n", 1874 sample->file_offset, this_cpu.cpu); 1875 return 0; 1876 } 1877 1878 if (this_cpu.cpu > sched->max_cpu.cpu) 1879 sched->max_cpu = this_cpu; 1880 1881 if (sched->map.comp) { 1882 cpus_nr = bitmap_weight(sched->map.comp_cpus_mask, MAX_CPUS); 1883 if (!__test_and_set_bit(this_cpu.cpu, sched->map.comp_cpus_mask)) { 1884 sched->map.comp_cpus[cpus_nr++] = this_cpu; 1885 new_cpu = true; 1886 } 1887 } else 1888 cpus_nr = sched->max_cpu.cpu + 1; 1889 1890 timestamp0 = sched->cpu_last_switched[this_cpu.cpu]; 1891 sched->cpu_last_switched[this_cpu.cpu] = timestamp; 1892 if (timestamp0) 1893 delta = timestamp - timestamp0; 1894 else 1895 delta = 0; 1896 1897 if (delta < 0) { 1898 pr_err("hm, delta: %" PRIu64 " < 0 ?\n", delta); 1899 return -1; 1900 } 1901 1902 sched_in = map__findnew_thread(sched, machine, -1, next_pid); 1903 sched_out = map__findnew_thread(sched, machine, -1, prev_pid); 1904 if (sched_in == NULL || sched_out == NULL) 1905 goto out; 1906 1907 tr = thread__get_runtime(sched_in); 1908 if (tr == NULL) 1909 goto out; 1910 1911 thread__put(sched->curr_thread[this_cpu.cpu]); 1912 thread__put(sched->curr_out_thread[this_cpu.cpu]); 1913 1914 sched->curr_thread[this_cpu.cpu] = thread__get(sched_in); 1915 sched->curr_out_thread[this_cpu.cpu] = thread__get(sched_out); 1916 1917 ret = 0; 1918 1919 str = thread__comm_str(sched_in); 1920 new_shortname = 0; 1921 if (!tr->shortname[0]) { 1922 if (!strcmp(thread__comm_str(sched_in), "swapper")) { 1923 /* 1924 * Don't allocate a letter-number for swapper:0 1925 * as a shortname. Instead, we use '.' for it. 1926 */ 1927 tr->shortname[0] = '.'; 1928 tr->shortname[1] = ' '; 1929 } else if (!sched->map.task_name || sched_match_task(sched, str)) { 1930 tr->shortname[0] = sched->next_shortname1; 1931 tr->shortname[1] = sched->next_shortname2; 1932 1933 if (sched->next_shortname1 < 'Z') { 1934 sched->next_shortname1++; 1935 } else { 1936 sched->next_shortname1 = 'A'; 1937 if (sched->next_shortname2 < '9') 1938 sched->next_shortname2++; 1939 else 1940 sched->next_shortname2 = '0'; 1941 } 1942 } else { 1943 tr->shortname[0] = '-'; 1944 tr->shortname[1] = ' '; 1945 } 1946 new_shortname = 1; 1947 } 1948 1949 if (sched->map.cpus && !perf_cpu_map__has(sched->map.cpus, this_cpu)) 1950 goto out; 1951 1952 proceed = 0; 1953 str = thread__comm_str(sched_in); 1954 /* 1955 * Check which of sched_in and sched_out matches the passed --task-name 1956 * arguments and call the corresponding print_sched_map. 1957 */ 1958 if (sched->map.task_name && !sched_match_task(sched, str)) { 1959 if (!sched_match_task(sched, thread__comm_str(sched_out))) 1960 goto out; 1961 else 1962 goto sched_out; 1963 1964 } else { 1965 str = thread__comm_str(sched_out); 1966 if (!(sched->map.task_name && !sched_match_task(sched, str))) 1967 proceed = 1; 1968 } 1969 1970 printf(" "); 1971 1972 print_sched_map(sched, this_cpu, cpus_nr, color, false); 1973 1974 timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp)); 1975 color_fprintf(stdout, color, " %12s secs ", stimestamp); 1976 if (new_shortname || tr->comm_changed || (verbose > 0 && thread__tid(sched_in))) { 1977 const char *pid_color = color; 1978 1979 if (thread__has_color(sched_in)) 1980 pid_color = COLOR_PIDS; 1981 1982 color_fprintf(stdout, pid_color, "%s => %s:%d", 1983 tr->shortname, thread__comm_str(sched_in), thread__tid(sched_in)); 1984 tr->comm_changed = false; 1985 } 1986 1987 if (sched->map.comp && new_cpu) 1988 color_fprintf(stdout, color, " (CPU %d)", this_cpu.cpu); 1989 1990 if (proceed != 1) { 1991 color_fprintf(stdout, color, "\n"); 1992 goto out; 1993 } 1994 1995 sched_out: 1996 if (sched->map.task_name) { 1997 tr = thread__get_runtime(sched->curr_out_thread[this_cpu.cpu]); 1998 if (tr == NULL || strcmp(tr->shortname, "") == 0) 1999 goto out; 2000 2001 if (proceed == 1) 2002 color_fprintf(stdout, color, "\n"); 2003 2004 printf(" "); 2005 print_sched_map(sched, this_cpu, cpus_nr, color, true); 2006 timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp)); 2007 color_fprintf(stdout, color, " %12s secs ", stimestamp); 2008 } 2009 2010 color_fprintf(stdout, color, "\n"); 2011 2012 out: 2013 thread__put(sched_out); 2014 thread__put(sched_in); 2015 2016 return ret; 2017 } 2018 2019 static int process_sched_switch_event(const struct perf_tool *tool, 2020 struct perf_sample *sample, 2021 struct machine *machine) 2022 { 2023 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 2024 int this_cpu = sample->cpu, err = 0; 2025 u32 prev_pid = perf_sample__intval(sample, "prev_pid"), 2026 next_pid = perf_sample__intval(sample, "next_pid"); 2027 2028 /* perf.data is untrusted input — CPU may be absent or corrupted */ 2029 if (this_cpu < 0 || this_cpu >= MAX_CPUS) { 2030 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %d, skipping sample\n", 2031 sample->file_offset, this_cpu); 2032 return 0; 2033 } 2034 2035 if (sched->curr_pid[this_cpu] != (u32)-1) { 2036 /* 2037 * Are we trying to switch away a PID that is 2038 * not current? 2039 */ 2040 if (sched->curr_pid[this_cpu] != prev_pid) 2041 sched->nr_context_switch_bugs++; 2042 } 2043 2044 if (sched->tp_handler->switch_event) 2045 err = sched->tp_handler->switch_event(sched, sample, machine); 2046 2047 sched->curr_pid[this_cpu] = next_pid; 2048 return err; 2049 } 2050 2051 static int process_sched_runtime_event(const struct perf_tool *tool, 2052 struct perf_sample *sample, 2053 struct machine *machine) 2054 { 2055 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 2056 2057 /* perf.data is untrusted input — CPU may be absent or corrupted */ 2058 if (sample->cpu >= MAX_CPUS) { 2059 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %u, skipping sample\n", 2060 sample->file_offset, sample->cpu); 2061 return 0; 2062 } 2063 2064 if (sched->tp_handler->runtime_event) 2065 return sched->tp_handler->runtime_event(sched, sample, machine); 2066 2067 return 0; 2068 } 2069 2070 static int perf_sched__process_fork_event(const struct perf_tool *tool, 2071 union perf_event *event, 2072 struct perf_sample *sample, 2073 struct machine *machine) 2074 { 2075 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 2076 2077 /* run the fork event through the perf machinery */ 2078 perf_event__process_fork(tool, event, sample, machine); 2079 2080 /* and then run additional processing needed for this command */ 2081 if (sched->tp_handler->fork_event) 2082 return sched->tp_handler->fork_event(sched, event, machine); 2083 2084 return 0; 2085 } 2086 2087 static int process_sched_migrate_task_event(const struct perf_tool *tool, 2088 struct perf_sample *sample, 2089 struct machine *machine) 2090 { 2091 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 2092 2093 if (sched->tp_handler->migrate_task_event) 2094 return sched->tp_handler->migrate_task_event(sched, sample, machine); 2095 2096 return 0; 2097 } 2098 2099 typedef int (*tracepoint_handler)(const struct perf_tool *tool, 2100 struct perf_sample *sample, 2101 struct machine *machine); 2102 2103 static struct evsel_str_handler latency_handlers[] = { 2104 { "sched:sched_switch", process_sched_switch_event, }, 2105 { "sched:sched_stat_runtime", process_sched_runtime_event, }, 2106 { "sched:sched_wakeup", process_sched_wakeup_event, }, 2107 { "sched:sched_waking", process_sched_wakeup_event, }, 2108 { "sched:sched_wakeup_new", process_sched_wakeup_event, }, 2109 { "sched:sched_migrate_task", process_sched_migrate_task_event, }, 2110 }; 2111 2112 static int process_sched_ignore(const struct perf_tool *tool __maybe_unused, 2113 struct perf_sample *sample __maybe_unused, 2114 struct machine *machine __maybe_unused) 2115 { 2116 return 0; 2117 } 2118 2119 static int perf_sched__process_tracepoint_sample(const struct perf_tool *tool __maybe_unused, 2120 union perf_event *event __maybe_unused, 2121 struct perf_sample *sample, 2122 struct machine *machine) 2123 { 2124 struct evsel *evsel = sample->evsel; 2125 int err = 0; 2126 2127 if (evsel->handler == NULL) { 2128 evsel->handler = process_sched_ignore; 2129 for (size_t i = 0; i < ARRAY_SIZE(latency_handlers); i++) { 2130 if (!evsel__name_is(evsel, latency_handlers[i].name)) 2131 continue; 2132 2133 if (!strcmp(latency_handlers[i].name, "sched:sched_wakeup") && 2134 sample->evsel->evlist && 2135 evlist__find_tracepoint_by_name(sample->evsel->evlist, "sched:sched_waking")) 2136 break; 2137 2138 evsel->handler = latency_handlers[i].handler; 2139 break; 2140 } 2141 } 2142 2143 if (evsel->handler != process_sched_ignore) { 2144 tracepoint_handler f = evsel->handler; 2145 err = f(tool, sample, machine); 2146 } 2147 2148 return err; 2149 } 2150 2151 static int perf_sched__process_comm(const struct perf_tool *tool __maybe_unused, 2152 union perf_event *event, 2153 struct perf_sample *sample, 2154 struct machine *machine) 2155 { 2156 struct thread *thread; 2157 struct thread_runtime *tr; 2158 int err; 2159 2160 err = perf_event__process_comm(tool, event, sample, machine); 2161 if (err) 2162 return err; 2163 2164 thread = machine__find_thread(machine, sample->pid, sample->tid); 2165 if (!thread) { 2166 pr_err("Internal error: can't find thread\n"); 2167 return -1; 2168 } 2169 2170 tr = thread__get_runtime(thread); 2171 if (tr == NULL) { 2172 thread__put(thread); 2173 return -1; 2174 } 2175 2176 tr->comm_changed = true; 2177 thread__put(thread); 2178 2179 return 0; 2180 } 2181 2182 static int perf_sched__read_events(struct perf_sched *sched) 2183 { 2184 struct perf_session *session; 2185 struct perf_data data = { 2186 .path = input_name, 2187 .mode = PERF_DATA_MODE_READ, 2188 .force = sched->force, 2189 }; 2190 int rc = -1, err; 2191 2192 session = perf_session__new(&data, &sched->tool); 2193 if (IS_ERR(session)) { 2194 pr_debug("Error creating perf session"); 2195 return PTR_ERR(session); 2196 } 2197 2198 symbol__init(perf_session__env(session)); 2199 2200 if (!perf_data__is_pipe(session->data)) { 2201 /* prefer sched_waking if it is captured */ 2202 if (evlist__find_tracepoint_by_name(session->evlist, "sched:sched_waking")) 2203 latency_handlers[2].handler = process_sched_ignore; 2204 2205 if (perf_session__set_tracepoints_handlers(session, latency_handlers)) 2206 goto out_delete; 2207 } 2208 2209 if (!perf_data__is_pipe(session->data) && 2210 !perf_session__has_traces(session, "record -R")) 2211 goto out_delete; 2212 2213 err = perf_session__process_events(session); 2214 if (err) { 2215 pr_err("Failed to process events, error %d", err); 2216 goto out_delete; 2217 } 2218 2219 if (perf_data__is_pipe(session->data) && 2220 !perf_session__has_traces(session, "record -R")) { 2221 goto out_delete; 2222 } 2223 2224 sched->nr_events = evlist__stats(session->evlist)->nr_events[0]; 2225 sched->nr_lost_events = evlist__stats(session->evlist)->total_lost; 2226 sched->nr_lost_chunks = evlist__stats(session->evlist)->nr_events[PERF_RECORD_LOST]; 2227 2228 rc = 0; 2229 out_delete: 2230 perf_session__delete(session); 2231 return rc; 2232 } 2233 2234 /* 2235 * scheduling times are printed as msec.usec 2236 */ 2237 static inline void print_sched_time(unsigned long long nsecs, int width) 2238 { 2239 unsigned long msecs; 2240 unsigned long usecs; 2241 2242 msecs = nsecs / NSEC_PER_MSEC; 2243 nsecs -= msecs * NSEC_PER_MSEC; 2244 usecs = nsecs / NSEC_PER_USEC; 2245 printf("%*lu.%03lu ", width, msecs, usecs); 2246 } 2247 2248 /* 2249 * returns runtime data for event, allocating memory for it the 2250 * first time it is used. 2251 */ 2252 static struct evsel_runtime *evsel__get_runtime(struct evsel *evsel) 2253 { 2254 struct evsel_runtime *r = evsel->priv; 2255 2256 if (r == NULL) { 2257 r = zalloc(sizeof(struct evsel_runtime)); 2258 evsel->priv = r; 2259 } 2260 2261 return r; 2262 } 2263 2264 /* 2265 * save last time event was seen per cpu 2266 */ 2267 static void evsel__save_time(struct evsel *evsel, u64 timestamp, u32 cpu) 2268 { 2269 struct evsel_runtime *r = evsel__get_runtime(evsel); 2270 2271 if (r == NULL) 2272 return; 2273 2274 if ((cpu >= r->ncpu) || (r->last_time == NULL)) { 2275 int i, n = __roundup_pow_of_two(cpu+1); 2276 void *p = r->last_time; 2277 2278 p = realloc(r->last_time, n * sizeof(u64)); 2279 if (!p) 2280 return; 2281 2282 r->last_time = p; 2283 for (i = r->ncpu; i < n; ++i) 2284 r->last_time[i] = (u64) 0; 2285 2286 r->ncpu = n; 2287 } 2288 2289 r->last_time[cpu] = timestamp; 2290 } 2291 2292 /* returns last time this event was seen on the given cpu */ 2293 static u64 evsel__get_time(struct evsel *evsel, u32 cpu) 2294 { 2295 struct evsel_runtime *r = evsel__get_runtime(evsel); 2296 2297 if ((r == NULL) || (r->last_time == NULL) || (cpu >= r->ncpu)) 2298 return 0; 2299 2300 return r->last_time[cpu]; 2301 } 2302 2303 static void timehist__evsel_priv_destructor(void *priv) 2304 { 2305 struct evsel_runtime *r = priv; 2306 2307 if (r) { 2308 free(r->last_time); 2309 free(r); 2310 } 2311 } 2312 2313 static int comm_width = 30; 2314 2315 static char *timehist_get_commstr(struct thread *thread) 2316 { 2317 static char str[32]; 2318 const char *comm = thread__comm_str(thread); 2319 pid_t tid = thread__tid(thread); 2320 pid_t pid = thread__pid(thread); 2321 int n; 2322 2323 if (pid == 0) 2324 n = scnprintf(str, sizeof(str), "%s", comm); 2325 2326 else if (tid != pid) 2327 n = scnprintf(str, sizeof(str), "%s[%d/%d]", comm, tid, pid); 2328 2329 else 2330 n = scnprintf(str, sizeof(str), "%s[%d]", comm, tid); 2331 2332 if (n > comm_width) 2333 comm_width = n; 2334 2335 return str; 2336 } 2337 2338 /* prio field format: xxx or xxx->yyy */ 2339 #define MAX_PRIO_STR_LEN 8 2340 static char *timehist_get_priostr(struct thread *thread, 2341 struct perf_sample *sample) 2342 { 2343 static char prio_str[16]; 2344 int prev_prio = (int)perf_sample__intval(sample, "prev_prio"); 2345 struct thread_runtime *tr = thread__priv(thread); 2346 2347 if (tr->prio != prev_prio && tr->prio != -1) 2348 scnprintf(prio_str, sizeof(prio_str), "%d->%d", tr->prio, prev_prio); 2349 else 2350 scnprintf(prio_str, sizeof(prio_str), "%d", prev_prio); 2351 2352 return prio_str; 2353 } 2354 2355 static void timehist_header(struct perf_sched *sched) 2356 { 2357 u32 ncpus = sched->max_cpu.cpu + 1; 2358 u32 i, j; 2359 2360 printf("%15s %6s ", "time", "cpu"); 2361 2362 if (sched->show_cpu_visual) { 2363 printf(" "); 2364 for (i = 0, j = 0; i < ncpus; ++i) { 2365 printf("%x", j++); 2366 if (j > 15) 2367 j = 0; 2368 } 2369 printf(" "); 2370 } 2371 2372 printf(" %-*s", comm_width, "task name"); 2373 2374 if (sched->show_prio) 2375 printf(" %-*s", MAX_PRIO_STR_LEN, "prio"); 2376 2377 printf(" %9s %9s %9s", "wait time", "sch delay", "run time"); 2378 2379 if (sched->pre_migrations) 2380 printf(" %9s", "pre-mig time"); 2381 2382 if (sched->show_state) 2383 printf(" %s", "state"); 2384 2385 printf("\n"); 2386 2387 /* 2388 * units row 2389 */ 2390 printf("%15s %-6s ", "", ""); 2391 2392 if (sched->show_cpu_visual) 2393 printf(" %*s ", ncpus, ""); 2394 2395 printf(" %-*s", comm_width, "[tid/pid]"); 2396 2397 if (sched->show_prio) 2398 printf(" %-*s", MAX_PRIO_STR_LEN, ""); 2399 2400 printf(" %9s %9s %9s", "(msec)", "(msec)", "(msec)"); 2401 2402 if (sched->pre_migrations) 2403 printf(" %9s", "(msec)"); 2404 2405 printf("\n"); 2406 2407 /* 2408 * separator 2409 */ 2410 printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line); 2411 2412 if (sched->show_cpu_visual) 2413 printf(" %.*s ", ncpus, graph_dotted_line); 2414 2415 printf(" %.*s", comm_width, graph_dotted_line); 2416 2417 if (sched->show_prio) 2418 printf(" %.*s", MAX_PRIO_STR_LEN, graph_dotted_line); 2419 2420 printf(" %.9s %.9s %.9s", graph_dotted_line, graph_dotted_line, graph_dotted_line); 2421 2422 if (sched->pre_migrations) 2423 printf(" %.9s", graph_dotted_line); 2424 2425 if (sched->show_state) 2426 printf(" %.5s", graph_dotted_line); 2427 2428 printf("\n"); 2429 } 2430 2431 static void timehist_print_sample(struct perf_sched *sched, 2432 struct perf_sample *sample, 2433 struct addr_location *al, 2434 struct thread *thread, 2435 u64 t, const char state) 2436 { 2437 struct thread_runtime *tr = thread__priv(thread); 2438 const char *next_comm = perf_sample__strval(sample, "next_comm"); 2439 const u32 next_pid = perf_sample__intval(sample, "next_pid"); 2440 u32 max_cpus = sched->max_cpu.cpu + 1; 2441 char tstr[64]; 2442 char nstr[30]; 2443 u64 wait_time; 2444 2445 if (cpu_list && (sample->cpu >= MAX_NR_CPUS || 2446 !test_bit(sample->cpu, cpu_bitmap))) 2447 return; 2448 2449 timestamp__scnprintf_usec(t, tstr, sizeof(tstr)); 2450 printf("%15s [%04d] ", tstr, sample->cpu); 2451 2452 if (sched->show_cpu_visual) { 2453 u32 i; 2454 char c; 2455 2456 printf(" "); 2457 for (i = 0; i < max_cpus; ++i) { 2458 /* flag idle times with 'i'; others are sched events */ 2459 if (i == sample->cpu) 2460 c = (thread__tid(thread) == 0) ? 'i' : 's'; 2461 else 2462 c = ' '; 2463 printf("%c", c); 2464 } 2465 printf(" "); 2466 } 2467 2468 printf(" %-*s ", comm_width, timehist_get_commstr(thread)); 2469 2470 if (sched->show_prio) 2471 printf(" %-*s ", MAX_PRIO_STR_LEN, timehist_get_priostr(thread, sample)); 2472 2473 wait_time = tr->dt_sleep + tr->dt_iowait + tr->dt_preempt; 2474 print_sched_time(wait_time, 6); 2475 2476 print_sched_time(tr->dt_delay, 6); 2477 print_sched_time(tr->dt_run, 6); 2478 if (sched->pre_migrations) 2479 print_sched_time(tr->dt_pre_mig, 6); 2480 2481 if (sched->show_state) 2482 printf(" %5c ", thread__tid(thread) == 0 ? 'I' : state); 2483 2484 if (sched->show_next) { 2485 snprintf(nstr, sizeof(nstr), "next: %s[%d]", next_comm, next_pid); 2486 printf(" %-*s", comm_width, nstr); 2487 } 2488 2489 if (sched->show_wakeups && !sched->show_next) 2490 printf(" %-*s", comm_width, ""); 2491 2492 if (thread__tid(thread) == 0) 2493 goto out; 2494 2495 if (sched->show_callchain) 2496 printf(" "); 2497 2498 sample__fprintf_sym(sample, al, 0, 2499 EVSEL__PRINT_SYM | EVSEL__PRINT_ONELINE | 2500 EVSEL__PRINT_CALLCHAIN_ARROW | 2501 EVSEL__PRINT_SKIP_IGNORED, 2502 get_tls_callchain_cursor(), symbol_conf.bt_stop_list, stdout); 2503 2504 out: 2505 printf("\n"); 2506 } 2507 2508 /* 2509 * Explanation of delta-time stats: 2510 * 2511 * t = time of current schedule out event 2512 * tprev = time of previous sched out event 2513 * also time of schedule-in event for current task 2514 * last_time = time of last sched change event for current task 2515 * (i.e, time process was last scheduled out) 2516 * ready_to_run = time of wakeup for current task 2517 * migrated = time of task migration to another CPU 2518 * 2519 * -----|-------------|-------------|-------------|-------------|----- 2520 * last ready migrated tprev t 2521 * time to run 2522 * 2523 * |---------------- dt_wait ----------------| 2524 * |--------- dt_delay ---------|-- dt_run --| 2525 * |- dt_pre_mig -| 2526 * 2527 * dt_run = run time of current task 2528 * dt_wait = time between last schedule out event for task and tprev 2529 * represents time spent off the cpu 2530 * dt_delay = time between wakeup and schedule-in of task 2531 * dt_pre_mig = time between wakeup and migration to another CPU 2532 */ 2533 2534 static void timehist_update_runtime_stats(struct thread_runtime *r, 2535 u64 t, u64 tprev) 2536 { 2537 r->dt_delay = 0; 2538 r->dt_sleep = 0; 2539 r->dt_iowait = 0; 2540 r->dt_preempt = 0; 2541 r->dt_run = 0; 2542 r->dt_pre_mig = 0; 2543 2544 if (tprev) { 2545 r->dt_run = t - tprev; 2546 if (r->ready_to_run) { 2547 if (r->ready_to_run > tprev) 2548 pr_debug("time travel: wakeup time for task > previous sched_switch event\n"); 2549 else 2550 r->dt_delay = tprev - r->ready_to_run; 2551 2552 if ((r->migrated > r->ready_to_run) && (r->migrated < tprev)) 2553 r->dt_pre_mig = r->migrated - r->ready_to_run; 2554 } 2555 2556 if (r->last_time > tprev) 2557 pr_debug("time travel: last sched out time for task > previous sched_switch event\n"); 2558 else if (r->last_time) { 2559 u64 dt_wait = tprev - r->last_time; 2560 2561 if (r->last_state == 'R') 2562 r->dt_preempt = dt_wait; 2563 else if (r->last_state == 'D') 2564 r->dt_iowait = dt_wait; 2565 else 2566 r->dt_sleep = dt_wait; 2567 } 2568 } 2569 2570 update_stats(&r->run_stats, r->dt_run); 2571 2572 r->total_run_time += r->dt_run; 2573 r->total_delay_time += r->dt_delay; 2574 r->total_sleep_time += r->dt_sleep; 2575 r->total_iowait_time += r->dt_iowait; 2576 r->total_preempt_time += r->dt_preempt; 2577 r->total_pre_mig_time += r->dt_pre_mig; 2578 } 2579 2580 static bool is_idle_sample(struct perf_sample *sample) 2581 { 2582 /* pid 0 == swapper == idle task */ 2583 if (evsel__name_is(sample->evsel, "sched:sched_switch")) 2584 return perf_sample__intval(sample, "prev_pid") == 0; 2585 2586 return sample->pid == 0; 2587 } 2588 2589 static void save_task_callchain(struct perf_sched *sched, 2590 struct perf_sample *sample, 2591 struct machine *machine) 2592 { 2593 struct callchain_cursor *cursor; 2594 struct thread *thread; 2595 2596 /* want main thread for process - has maps */ 2597 thread = machine__findnew_thread(machine, sample->pid, sample->pid); 2598 if (thread == NULL) { 2599 pr_debug("Failed to get thread for pid %d.\n", sample->pid); 2600 return; 2601 } 2602 2603 if (!sched->show_callchain || sample->callchain == NULL) { 2604 thread__put(thread); 2605 return; 2606 } 2607 2608 cursor = get_tls_callchain_cursor(); 2609 2610 if (thread__resolve_callchain(thread, cursor, sample, 2611 NULL, NULL, sched->max_stack + 2) != 0) { 2612 if (verbose > 0) 2613 pr_err("Failed to resolve callchain. Skipping\n"); 2614 2615 thread__put(thread); 2616 return; 2617 } 2618 2619 callchain_cursor_commit(cursor); 2620 thread__put(thread); 2621 2622 while (true) { 2623 struct callchain_cursor_node *node; 2624 struct symbol *sym; 2625 2626 node = callchain_cursor_current(cursor); 2627 if (node == NULL) 2628 break; 2629 2630 sym = node->ms.sym; 2631 if (sym) { 2632 if (!strcmp(sym->name, "schedule") || 2633 !strcmp(sym->name, "__schedule") || 2634 !strcmp(sym->name, "preempt_schedule")) 2635 symbol__set_ignore(sym, true); 2636 } 2637 2638 callchain_cursor_advance(cursor); 2639 } 2640 } 2641 2642 static int init_idle_thread(struct thread *thread) 2643 { 2644 struct idle_thread_runtime *itr; 2645 2646 thread__set_comm(thread, idle_comm, 0); 2647 2648 itr = zalloc(sizeof(*itr)); 2649 if (itr == NULL) 2650 return -ENOMEM; 2651 2652 init_prio(&itr->tr); 2653 init_stats(&itr->tr.run_stats); 2654 callchain_init(&itr->callchain); 2655 callchain_cursor_reset(&itr->cursor); 2656 thread__set_priv(thread, itr); 2657 2658 return 0; 2659 } 2660 2661 /* 2662 * Track idle stats per cpu by maintaining a local thread 2663 * struct for the idle task on each cpu. 2664 */ 2665 static int init_idle_threads(int ncpu) 2666 { 2667 int i, ret; 2668 2669 idle_threads = calloc(ncpu, sizeof(struct thread *)); 2670 if (!idle_threads) 2671 return -ENOMEM; 2672 2673 idle_max_cpu = ncpu; 2674 2675 /* allocate the actual thread struct if needed */ 2676 for (i = 0; i < ncpu; ++i) { 2677 idle_threads[i] = thread__new(0, 0); 2678 if (idle_threads[i] == NULL) 2679 return -ENOMEM; 2680 2681 ret = init_idle_thread(idle_threads[i]); 2682 if (ret < 0) 2683 return ret; 2684 } 2685 2686 return 0; 2687 } 2688 2689 static void free_idle_threads(void) 2690 { 2691 int i; 2692 2693 if (idle_threads == NULL) 2694 return; 2695 2696 for (i = 0; i < idle_max_cpu; ++i) { 2697 struct thread *idle = idle_threads[i]; 2698 2699 if (idle) { 2700 struct idle_thread_runtime *itr; 2701 2702 itr = thread__priv(idle); 2703 if (itr) { 2704 thread__put(itr->last_thread); 2705 free_callchain(&itr->callchain); 2706 callchain_cursor_cleanup(&itr->cursor); 2707 } 2708 2709 thread__put(idle); 2710 } 2711 } 2712 2713 free(idle_threads); 2714 } 2715 2716 static struct thread *get_idle_thread(int cpu) 2717 { 2718 /* 2719 * expand/allocate array of pointers to local thread 2720 * structs if needed 2721 */ 2722 if ((cpu >= idle_max_cpu) || (idle_threads == NULL)) { 2723 int i, j = __roundup_pow_of_two(cpu+1); 2724 void *p; 2725 2726 p = realloc(idle_threads, j * sizeof(struct thread *)); 2727 if (!p) 2728 return NULL; 2729 2730 idle_threads = (struct thread **) p; 2731 for (i = idle_max_cpu; i < j; ++i) 2732 idle_threads[i] = NULL; 2733 2734 idle_max_cpu = j; 2735 } 2736 2737 /* allocate a new thread struct if needed */ 2738 if (idle_threads[cpu] == NULL) { 2739 idle_threads[cpu] = thread__new(0, 0); 2740 2741 if (idle_threads[cpu]) { 2742 if (init_idle_thread(idle_threads[cpu]) < 0) { 2743 /* clean up so next call doesn't find a half-initialized thread */ 2744 thread__zput(idle_threads[cpu]); 2745 return NULL; 2746 } 2747 } 2748 } 2749 2750 return thread__get(idle_threads[cpu]); 2751 } 2752 2753 static void save_idle_callchain(struct perf_sched *sched, 2754 struct idle_thread_runtime *itr, 2755 struct perf_sample *sample) 2756 { 2757 struct callchain_cursor *cursor; 2758 2759 if (!sched->show_callchain || sample->callchain == NULL) 2760 return; 2761 2762 cursor = get_tls_callchain_cursor(); 2763 if (cursor == NULL) 2764 return; 2765 2766 callchain_cursor__copy(&itr->cursor, cursor); 2767 } 2768 2769 static struct thread *timehist_get_thread(struct perf_sched *sched, 2770 struct perf_sample *sample, 2771 struct machine *machine) 2772 { 2773 struct thread *thread; 2774 2775 if (is_idle_sample(sample)) { 2776 thread = get_idle_thread(sample->cpu); 2777 if (thread == NULL) 2778 pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu); 2779 2780 } else { 2781 /* there were samples with tid 0 but non-zero pid */ 2782 thread = machine__findnew_thread(machine, sample->pid, 2783 sample->tid ?: sample->pid); 2784 if (thread == NULL) { 2785 pr_debug("Failed to get thread for tid %d. skipping sample.\n", 2786 sample->tid); 2787 } 2788 2789 save_task_callchain(sched, sample, machine); 2790 if (sched->idle_hist) { 2791 struct thread *idle; 2792 struct idle_thread_runtime *itr; 2793 2794 idle = get_idle_thread(sample->cpu); 2795 if (idle == NULL) { 2796 pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu); 2797 thread__put(thread); 2798 return NULL; 2799 } 2800 2801 itr = thread__priv(idle); 2802 if (itr == NULL) { 2803 thread__put(idle); 2804 thread__put(thread); 2805 return NULL; 2806 } 2807 2808 thread__put(itr->last_thread); 2809 itr->last_thread = thread__get(thread); 2810 2811 /* copy task callchain when entering to idle */ 2812 if (perf_sample__intval(sample, "next_pid") == 0) 2813 save_idle_callchain(sched, itr, sample); 2814 2815 thread__put(idle); 2816 } 2817 } 2818 2819 return thread; 2820 } 2821 2822 static bool timehist_skip_sample(struct perf_sched *sched, 2823 struct thread *thread, 2824 struct perf_sample *sample) 2825 { 2826 bool rc = false; 2827 int prio = -1; 2828 struct thread_runtime *tr = NULL; 2829 2830 if (thread__is_filtered(thread)) { 2831 rc = true; 2832 sched->skipped_samples++; 2833 } 2834 2835 if (sched->prio_str) { 2836 /* 2837 * Because priority may be changed during task execution, 2838 * first read priority from prev sched_in event for current task. 2839 * If prev sched_in event is not saved, then read priority from 2840 * current task sched_out event. 2841 */ 2842 tr = thread__get_runtime(thread); 2843 if (tr && tr->prio != -1) 2844 prio = tr->prio; 2845 else if (evsel__name_is(sample->evsel, "sched:sched_switch")) 2846 prio = perf_sample__intval(sample, "prev_prio"); 2847 2848 /* negative prio means no info; out-of-range prio can't match the filter */ 2849 if (prio >= 0 && 2850 (prio >= MAX_PRIO || !test_bit(prio, sched->prio_bitmap))) { 2851 rc = true; 2852 sched->skipped_samples++; 2853 } 2854 } 2855 2856 if (sched->idle_hist) { 2857 if (!evsel__name_is(sample->evsel, "sched:sched_switch")) 2858 rc = true; 2859 else if (perf_sample__intval(sample, "prev_pid") != 0 && 2860 perf_sample__intval(sample, "next_pid") != 0) 2861 rc = true; 2862 } 2863 2864 return rc; 2865 } 2866 2867 static void timehist_print_wakeup_event(struct perf_sched *sched, 2868 struct perf_sample *sample, 2869 struct machine *machine, 2870 struct thread *awakened) 2871 { 2872 struct thread *thread; 2873 char tstr[64]; 2874 2875 thread = machine__findnew_thread(machine, sample->pid, sample->tid); 2876 if (thread == NULL) 2877 return; 2878 2879 /* show wakeup unless both awakee and awaker are filtered */ 2880 if (timehist_skip_sample(sched, thread, sample) && 2881 timehist_skip_sample(sched, awakened, sample)) { 2882 thread__put(thread); 2883 return; 2884 } 2885 2886 timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); 2887 printf("%15s [%04d] ", tstr, sample->cpu); 2888 if (sched->show_cpu_visual) 2889 printf(" %*s ", sched->max_cpu.cpu + 1, ""); 2890 2891 printf(" %-*s ", comm_width, timehist_get_commstr(thread)); 2892 2893 /* dt spacer */ 2894 printf(" %9s %9s %9s ", "", "", ""); 2895 2896 printf("awakened: %s", timehist_get_commstr(awakened)); 2897 2898 printf("\n"); 2899 2900 thread__put(thread); 2901 } 2902 2903 static int timehist_sched_wakeup_ignore(const struct perf_tool *tool __maybe_unused, 2904 union perf_event *event __maybe_unused, 2905 struct perf_sample *sample __maybe_unused, 2906 struct machine *machine __maybe_unused) 2907 { 2908 return 0; 2909 } 2910 2911 static int timehist_sched_wakeup_event(const struct perf_tool *tool, 2912 union perf_event *event __maybe_unused, 2913 struct perf_sample *sample, 2914 struct machine *machine) 2915 { 2916 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 2917 struct thread *thread; 2918 struct thread_runtime *tr = NULL; 2919 /* want pid of awakened task not pid in sample */ 2920 const u32 pid = perf_sample__intval(sample, "pid"); 2921 2922 thread = machine__findnew_thread(machine, 0, pid); 2923 if (thread == NULL) 2924 return -1; 2925 2926 tr = thread__get_runtime(thread); 2927 if (tr == NULL) { 2928 thread__put(thread); 2929 return -1; 2930 } 2931 2932 if (tr->ready_to_run == 0) 2933 tr->ready_to_run = sample->time; 2934 2935 /* show wakeups if requested */ 2936 if (sched->show_wakeups && 2937 !perf_time__skip_sample(&sched->ptime, sample->time)) 2938 timehist_print_wakeup_event(sched, sample, machine, thread); 2939 2940 thread__put(thread); 2941 return 0; 2942 } 2943 2944 static void timehist_print_migration_event(struct perf_sched *sched, 2945 struct perf_sample *sample, 2946 struct machine *machine, 2947 struct thread *migrated) 2948 { 2949 struct thread *thread; 2950 char tstr[64]; 2951 u32 max_cpus; 2952 u32 ocpu, dcpu; 2953 2954 if (sched->summary_only) 2955 return; 2956 2957 max_cpus = sched->max_cpu.cpu + 1; 2958 ocpu = perf_sample__intval(sample, "orig_cpu"); 2959 dcpu = perf_sample__intval(sample, "dest_cpu"); 2960 2961 thread = machine__findnew_thread(machine, sample->pid, sample->tid); 2962 if (thread == NULL) 2963 return; 2964 2965 if (timehist_skip_sample(sched, thread, sample) && 2966 timehist_skip_sample(sched, migrated, sample)) { 2967 thread__put(thread); 2968 return; 2969 } 2970 2971 timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); 2972 printf("%15s [%04d] ", tstr, sample->cpu); 2973 2974 if (sched->show_cpu_visual) { 2975 u32 i; 2976 char c; 2977 2978 printf(" "); 2979 for (i = 0; i < max_cpus; ++i) { 2980 c = (i == sample->cpu) ? 'm' : ' '; 2981 printf("%c", c); 2982 } 2983 printf(" "); 2984 } 2985 2986 printf(" %-*s ", comm_width, timehist_get_commstr(thread)); 2987 2988 /* dt spacer */ 2989 printf(" %9s %9s %9s ", "", "", ""); 2990 2991 printf("migrated: %s", timehist_get_commstr(migrated)); 2992 printf(" cpu %d => %d", ocpu, dcpu); 2993 2994 printf("\n"); 2995 thread__put(thread); 2996 } 2997 2998 static int timehist_migrate_task_event(const struct perf_tool *tool, 2999 union perf_event *event __maybe_unused, 3000 struct perf_sample *sample, 3001 struct machine *machine) 3002 { 3003 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 3004 struct thread *thread; 3005 struct thread_runtime *tr = NULL; 3006 /* want pid of migrated task not pid in sample */ 3007 const u32 pid = perf_sample__intval(sample, "pid"); 3008 3009 thread = machine__findnew_thread(machine, 0, pid); 3010 if (thread == NULL) 3011 return -1; 3012 3013 tr = thread__get_runtime(thread); 3014 if (tr == NULL) { 3015 thread__put(thread); 3016 return -1; 3017 } 3018 3019 tr->migrations++; 3020 tr->migrated = sample->time; 3021 3022 /* show migrations if requested */ 3023 if (sched->show_migrations) { 3024 timehist_print_migration_event(sched, sample, machine, thread); 3025 } 3026 thread__put(thread); 3027 3028 return 0; 3029 } 3030 3031 static void timehist_update_task_prio(struct perf_sample *sample, 3032 struct machine *machine) 3033 { 3034 struct thread *thread; 3035 struct thread_runtime *tr = NULL; 3036 const u32 next_pid = perf_sample__intval(sample, "next_pid"); 3037 const u32 next_prio = perf_sample__intval(sample, "next_prio"); 3038 3039 if (next_pid == 0) 3040 thread = get_idle_thread(sample->cpu); 3041 else 3042 thread = machine__findnew_thread(machine, -1, next_pid); 3043 3044 if (thread == NULL) 3045 return; 3046 3047 tr = thread__get_runtime(thread); 3048 if (tr != NULL) 3049 tr->prio = next_prio; 3050 3051 thread__put(thread); 3052 } 3053 3054 static int timehist_sched_change_event(const struct perf_tool *tool, 3055 union perf_event *event, 3056 struct perf_sample *sample, 3057 struct machine *machine) 3058 { 3059 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 3060 struct perf_time_interval *ptime = &sched->ptime; 3061 struct addr_location al; 3062 struct thread *thread = NULL; 3063 struct thread_runtime *tr = NULL; 3064 u64 tprev, t = sample->time; 3065 int rc = 0; 3066 const char state = perf_sample__taskstate(sample, "prev_state"); 3067 3068 /* perf.data is untrusted input — CPU may be absent or corrupted */ 3069 if (sample->cpu >= MAX_CPUS) { 3070 pr_warning("WARNING: at offset %#" PRIx64 ": out-of-bound sample CPU %d, skipping sample\n", 3071 sample->file_offset, sample->cpu); 3072 return 0; 3073 } 3074 3075 addr_location__init(&al); 3076 if (machine__resolve(machine, &al, sample) < 0) { 3077 pr_err("problem processing %s (%u) event at offset %#" PRIx64 ", skipping it\n", 3078 perf_event__name(event->header.type), event->header.type, 3079 sample->file_offset); 3080 rc = -1; 3081 goto out; 3082 } 3083 3084 if (sched->show_prio || sched->prio_str) 3085 timehist_update_task_prio(sample, machine); 3086 3087 thread = timehist_get_thread(sched, sample, machine); 3088 if (thread == NULL) { 3089 rc = -1; 3090 goto out; 3091 } 3092 3093 if (timehist_skip_sample(sched, thread, sample)) 3094 goto out; 3095 3096 tr = thread__get_runtime(thread); 3097 if (tr == NULL) { 3098 rc = -1; 3099 goto out; 3100 } 3101 3102 tprev = evsel__get_time(sample->evsel, sample->cpu); 3103 3104 /* 3105 * If start time given: 3106 * - sample time is under window user cares about - skip sample 3107 * - tprev is under window user cares about - reset to start of window 3108 */ 3109 if (ptime->start && ptime->start > t) 3110 goto out; 3111 3112 if (tprev && ptime->start > tprev) 3113 tprev = ptime->start; 3114 3115 /* 3116 * If end time given: 3117 * - previous sched event is out of window - we are done 3118 * - sample time is beyond window user cares about - reset it 3119 * to close out stats for time window interest 3120 * - If tprev is 0, that is, sched_in event for current task is 3121 * not recorded, cannot determine whether sched_in event is 3122 * within time window interest - ignore it 3123 */ 3124 if (ptime->end) { 3125 if (!tprev || tprev > ptime->end) 3126 goto out; 3127 3128 if (t > ptime->end) 3129 t = ptime->end; 3130 } 3131 3132 /* 3133 * Use is_idle_sample() not thread__tid() == 0: a crafted perf.data 3134 * can set common_pid=0 with prev_pid!=0, giving us a machine thread 3135 * whose priv is thread_runtime, not idle_thread_runtime — the cast 3136 * below would read past the allocation. 3137 */ 3138 if (!sched->idle_hist || is_idle_sample(sample)) { 3139 if (!cpu_list || (sample->cpu < MAX_NR_CPUS && 3140 test_bit(sample->cpu, cpu_bitmap))) 3141 timehist_update_runtime_stats(tr, t, tprev); 3142 3143 if (sched->idle_hist) { 3144 struct idle_thread_runtime *itr = (void *)tr; 3145 struct thread_runtime *last_tr; 3146 3147 if (itr->last_thread == NULL) 3148 goto out; 3149 3150 /* add current idle time as last thread's runtime */ 3151 last_tr = thread__get_runtime(itr->last_thread); 3152 if (last_tr == NULL) 3153 goto out; 3154 3155 timehist_update_runtime_stats(last_tr, t, tprev); 3156 /* 3157 * remove delta time of last thread as it's not updated 3158 * and otherwise it will show an invalid value next 3159 * time. we only care total run time and run stat. 3160 */ 3161 last_tr->dt_run = 0; 3162 last_tr->dt_delay = 0; 3163 last_tr->dt_sleep = 0; 3164 last_tr->dt_iowait = 0; 3165 last_tr->dt_preempt = 0; 3166 3167 if (itr->cursor.nr) 3168 callchain_append(&itr->callchain, &itr->cursor, t - tprev); 3169 3170 thread__zput(itr->last_thread); 3171 } 3172 3173 /* 3174 * If the process name is not set for the thread, use "prev_comm" 3175 * to set it. Otherwise the sched summary will have just pid information 3176 */ 3177 if (!thread__comm_set(thread)) { 3178 const char *prev_comm = perf_sample__strval(sample, "prev_comm"); 3179 3180 thread__set_comm(thread, prev_comm, sample->time); 3181 } 3182 3183 if (!sched->summary_only) 3184 timehist_print_sample(sched, sample, &al, thread, t, state); 3185 } 3186 3187 out: 3188 if (sched->hist_time.start == 0 && t >= ptime->start) 3189 sched->hist_time.start = t; 3190 if (ptime->end == 0 || t <= ptime->end) 3191 sched->hist_time.end = t; 3192 3193 if (tr) { 3194 /* time of this sched_switch event becomes last time task seen */ 3195 tr->last_time = sample->time; 3196 3197 /* last state is used to determine where to account wait time */ 3198 tr->last_state = state; 3199 3200 /* sched out event for task so reset ready to run time and migrated time */ 3201 if (state == 'R') 3202 tr->ready_to_run = t; 3203 else 3204 tr->ready_to_run = 0; 3205 3206 tr->migrated = 0; 3207 } 3208 3209 evsel__save_time(sample->evsel, sample->time, sample->cpu); 3210 3211 thread__put(thread); 3212 addr_location__exit(&al); 3213 return rc; 3214 } 3215 3216 static int timehist_sched_switch_event(const struct perf_tool *tool, 3217 union perf_event *event, 3218 struct perf_sample *sample, 3219 struct machine *machine __maybe_unused) 3220 { 3221 return timehist_sched_change_event(tool, event, sample, machine); 3222 } 3223 3224 static int process_lost(const struct perf_tool *tool __maybe_unused, 3225 union perf_event *event, 3226 struct perf_sample *sample, 3227 struct machine *machine __maybe_unused) 3228 { 3229 char tstr[64]; 3230 3231 timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr)); 3232 printf("%15s ", tstr); 3233 printf("lost %" PRI_lu64 " events on cpu %d\n", event->lost.lost, sample->cpu); 3234 3235 return 0; 3236 } 3237 3238 3239 static void print_thread_runtime(struct thread *t, 3240 struct thread_runtime *r) 3241 { 3242 double mean = avg_stats(&r->run_stats); 3243 float stddev; 3244 3245 printf("%*s %5d %9" PRIu64 " ", 3246 comm_width, timehist_get_commstr(t), thread__ppid(t), 3247 (u64) r->run_stats.n); 3248 3249 print_sched_time(r->total_run_time, 8); 3250 stddev = rel_stddev_stats(stddev_stats(&r->run_stats), mean); 3251 print_sched_time(r->run_stats.min, 6); 3252 printf(" "); 3253 print_sched_time((u64) mean, 6); 3254 printf(" "); 3255 print_sched_time(r->run_stats.max, 6); 3256 printf(" "); 3257 printf("%5.2f", stddev); 3258 printf(" %5" PRIu64, r->migrations); 3259 printf("\n"); 3260 } 3261 3262 static void print_thread_waittime(struct thread *t, 3263 struct thread_runtime *r) 3264 { 3265 printf("%*s %5d %9" PRIu64 " ", 3266 comm_width, timehist_get_commstr(t), thread__ppid(t), 3267 (u64) r->run_stats.n); 3268 3269 print_sched_time(r->total_run_time, 8); 3270 print_sched_time(r->total_sleep_time, 6); 3271 printf(" "); 3272 print_sched_time(r->total_iowait_time, 6); 3273 printf(" "); 3274 print_sched_time(r->total_preempt_time, 6); 3275 printf(" "); 3276 print_sched_time(r->total_delay_time, 6); 3277 printf("\n"); 3278 } 3279 3280 struct total_run_stats { 3281 struct perf_sched *sched; 3282 u64 sched_count; 3283 u64 task_count; 3284 u64 total_run_time; 3285 }; 3286 3287 static int show_thread_runtime(struct thread *t, void *priv) 3288 { 3289 struct total_run_stats *stats = priv; 3290 struct thread_runtime *r; 3291 3292 if (thread__is_filtered(t)) 3293 return 0; 3294 3295 r = thread__priv(t); 3296 if (r && r->run_stats.n) { 3297 stats->task_count++; 3298 stats->sched_count += r->run_stats.n; 3299 stats->total_run_time += r->total_run_time; 3300 3301 if (stats->sched->show_state) 3302 print_thread_waittime(t, r); 3303 else 3304 print_thread_runtime(t, r); 3305 } 3306 3307 return 0; 3308 } 3309 3310 static size_t callchain__fprintf_folded(FILE *fp, struct callchain_node *node) 3311 { 3312 const char *sep = " <- "; 3313 struct callchain_list *chain; 3314 size_t ret = 0; 3315 char bf[1024]; 3316 bool first; 3317 3318 if (node == NULL) 3319 return 0; 3320 3321 ret = callchain__fprintf_folded(fp, node->parent); 3322 first = (ret == 0); 3323 3324 list_for_each_entry(chain, &node->val, list) { 3325 if (chain->ip >= PERF_CONTEXT_MAX) 3326 continue; 3327 if (chain->ms.sym && symbol__ignore(chain->ms.sym)) 3328 continue; 3329 ret += fprintf(fp, "%s%s", first ? "" : sep, 3330 callchain_list__sym_name(chain, bf, sizeof(bf), 3331 false)); 3332 first = false; 3333 } 3334 3335 return ret; 3336 } 3337 3338 static size_t timehist_print_idlehist_callchain(struct rb_root_cached *root) 3339 { 3340 size_t ret = 0; 3341 FILE *fp = stdout; 3342 struct callchain_node *chain; 3343 /* sort() uses rb_insert_color() on rb_root, not rb_root_cached */ 3344 struct rb_node *rb_node = rb_first(&root->rb_root); 3345 3346 printf(" %16s %8s %s\n", "Idle time (msec)", "Count", "Callchains"); 3347 printf(" %.16s %.8s %.50s\n", graph_dotted_line, graph_dotted_line, 3348 graph_dotted_line); 3349 3350 while (rb_node) { 3351 chain = rb_entry(rb_node, struct callchain_node, rb_node); 3352 rb_node = rb_next(rb_node); 3353 3354 ret += fprintf(fp, " "); 3355 print_sched_time(chain->hit, 12); 3356 ret += 16; /* print_sched_time returns 2nd arg + 4 */ 3357 ret += fprintf(fp, " %8d ", chain->count); 3358 ret += callchain__fprintf_folded(fp, chain); 3359 ret += fprintf(fp, "\n"); 3360 } 3361 3362 return ret; 3363 } 3364 3365 static void timehist_print_summary(struct perf_sched *sched, 3366 struct perf_session *session) 3367 { 3368 struct machine *m = &session->machines.host; 3369 struct total_run_stats totals; 3370 u64 task_count; 3371 struct thread *t; 3372 struct thread_runtime *r; 3373 int i; 3374 u64 hist_time = sched->hist_time.end - sched->hist_time.start; 3375 3376 memset(&totals, 0, sizeof(totals)); 3377 totals.sched = sched; 3378 3379 if (sched->idle_hist) { 3380 printf("\nIdle-time summary\n"); 3381 printf("%*s parent sched-out ", comm_width, "comm"); 3382 printf(" idle-time min-idle avg-idle max-idle stddev migrations\n"); 3383 } else if (sched->show_state) { 3384 printf("\nWait-time summary\n"); 3385 printf("%*s parent sched-in ", comm_width, "comm"); 3386 printf(" run-time sleep iowait preempt delay\n"); 3387 } else { 3388 printf("\nRuntime summary\n"); 3389 printf("%*s parent sched-in ", comm_width, "comm"); 3390 printf(" run-time min-run avg-run max-run stddev migrations\n"); 3391 } 3392 printf("%*s (count) ", comm_width, ""); 3393 printf(" (msec) (msec) (msec) (msec) %s\n", 3394 sched->show_state ? "(msec)" : "%"); 3395 printf("%.117s\n", graph_dotted_line); 3396 3397 machine__for_each_thread(m, show_thread_runtime, &totals); 3398 task_count = totals.task_count; 3399 if (!task_count) 3400 printf("<no still running tasks>\n"); 3401 3402 /* CPU idle stats not tracked when samples were skipped */ 3403 if (sched->skipped_samples && !sched->idle_hist) 3404 return; 3405 3406 printf("\nIdle stats:\n"); 3407 for (i = 0; i < idle_max_cpu; ++i) { 3408 if (cpu_list && !test_bit(i, cpu_bitmap)) 3409 continue; 3410 3411 t = idle_threads[i]; 3412 if (!t) 3413 continue; 3414 3415 r = thread__priv(t); 3416 if (r && r->run_stats.n) { 3417 totals.sched_count += r->run_stats.n; 3418 printf(" CPU %2d idle for ", i); 3419 print_sched_time(r->total_run_time, 6); 3420 printf(" msec (%6.2f%%)\n", 100.0 * r->total_run_time / hist_time); 3421 } else 3422 printf(" CPU %2d idle entire time window\n", i); 3423 } 3424 3425 if (sched->idle_hist && sched->show_callchain) { 3426 callchain_param.mode = CHAIN_FOLDED; 3427 callchain_param.value = CCVAL_PERIOD; 3428 3429 callchain_register_param(&callchain_param); 3430 3431 printf("\nIdle stats by callchain:\n"); 3432 for (i = 0; i < idle_max_cpu; ++i) { 3433 struct idle_thread_runtime *itr; 3434 3435 t = idle_threads[i]; 3436 if (!t) 3437 continue; 3438 3439 itr = thread__priv(t); 3440 if (itr == NULL) 3441 continue; 3442 3443 callchain_param.sort(&itr->sorted_root.rb_root, &itr->callchain, 3444 0, &callchain_param); 3445 3446 printf(" CPU %2d:", i); 3447 print_sched_time(itr->tr.total_run_time, 6); 3448 printf(" msec\n"); 3449 timehist_print_idlehist_callchain(&itr->sorted_root); 3450 printf("\n"); 3451 } 3452 } 3453 3454 printf("\n" 3455 " Total number of unique tasks: %" PRIu64 "\n" 3456 "Total number of context switches: %" PRIu64 "\n", 3457 totals.task_count, totals.sched_count); 3458 3459 printf(" Total run time (msec): "); 3460 print_sched_time(totals.total_run_time, 2); 3461 printf("\n"); 3462 3463 printf(" Total scheduling time (msec): "); 3464 print_sched_time(hist_time, 2); 3465 printf(" (x %d)\n", sched->max_cpu.cpu); 3466 } 3467 3468 typedef int (*sched_handler)(const struct perf_tool *tool, 3469 union perf_event *event, 3470 struct perf_sample *sample, 3471 struct machine *machine); 3472 3473 static int perf_timehist__process_sample(const struct perf_tool *tool, 3474 union perf_event *event, 3475 struct perf_sample *sample, 3476 struct machine *machine) 3477 { 3478 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 3479 struct evsel *evsel = sample->evsel; 3480 int err = 0; 3481 struct perf_cpu this_cpu = { 3482 .cpu = sample->cpu, 3483 }; 3484 3485 /* max_cpu indexes arrays allocated with MAX_CPUS entries */ 3486 if (this_cpu.cpu >= 0 && this_cpu.cpu < MAX_CPUS && 3487 this_cpu.cpu > sched->max_cpu.cpu) 3488 sched->max_cpu = this_cpu; 3489 3490 if (evsel->handler != NULL) { 3491 sched_handler f = evsel->handler; 3492 3493 err = f(tool, event, sample, machine); 3494 } 3495 3496 return err; 3497 } 3498 3499 static int timehist_check_attr(struct perf_sched *sched, 3500 struct evlist *evlist) 3501 { 3502 struct evsel *evsel; 3503 struct evsel_runtime *er; 3504 3505 list_for_each_entry(evsel, &evlist__core(evlist)->entries, core.node) { 3506 er = evsel__get_runtime(evsel); 3507 if (er == NULL) { 3508 pr_err("Failed to allocate memory for evsel runtime data\n"); 3509 return -1; 3510 } 3511 3512 /* only need to save callchain related to sched_switch event */ 3513 if (sched->show_callchain && 3514 evsel__name_is(evsel, "sched:sched_switch") && 3515 !evsel__has_callchain(evsel)) { 3516 pr_info("Samples of sched_switch event do not have callchains.\n"); 3517 sched->show_callchain = 0; 3518 symbol_conf.use_callchain = 0; 3519 } 3520 } 3521 3522 return 0; 3523 } 3524 3525 static int timehist_parse_prio_str(struct perf_sched *sched) 3526 { 3527 char *p; 3528 unsigned long start_prio, end_prio; 3529 const char *str = sched->prio_str; 3530 3531 if (!str) 3532 return 0; 3533 3534 while (isdigit(*str)) { 3535 p = NULL; 3536 start_prio = strtoul(str, &p, 0); 3537 if (start_prio >= MAX_PRIO || (*p != '\0' && *p != ',' && *p != '-')) 3538 return -1; 3539 3540 if (*p == '-') { 3541 str = ++p; 3542 p = NULL; 3543 end_prio = strtoul(str, &p, 0); 3544 3545 if (end_prio >= MAX_PRIO || (*p != '\0' && *p != ',')) 3546 return -1; 3547 3548 if (end_prio < start_prio) 3549 return -1; 3550 } else { 3551 end_prio = start_prio; 3552 } 3553 3554 for (; start_prio <= end_prio; start_prio++) 3555 __set_bit(start_prio, sched->prio_bitmap); 3556 3557 if (*p) 3558 ++p; 3559 3560 str = p; 3561 } 3562 3563 return 0; 3564 } 3565 3566 static int perf_sched__timehist(struct perf_sched *sched) 3567 { 3568 struct evsel_str_handler handlers[] = { 3569 { "sched:sched_switch", timehist_sched_switch_event, }, 3570 { "sched:sched_wakeup", timehist_sched_wakeup_event, }, 3571 { "sched:sched_waking", timehist_sched_wakeup_event, }, 3572 { "sched:sched_wakeup_new", timehist_sched_wakeup_event, }, 3573 }; 3574 const struct evsel_str_handler migrate_handlers[] = { 3575 { "sched:sched_migrate_task", timehist_migrate_task_event, }, 3576 }; 3577 struct perf_data data = { 3578 .path = input_name, 3579 .mode = PERF_DATA_MODE_READ, 3580 .force = sched->force, 3581 }; 3582 3583 struct perf_session *session; 3584 struct perf_env *env; 3585 struct evlist *evlist; 3586 int err = -1; 3587 3588 /* 3589 * event handlers for timehist option 3590 */ 3591 sched->tool.sample = perf_timehist__process_sample; 3592 sched->tool.mmap = perf_event__process_mmap; 3593 sched->tool.mmap2 = perf_event__process_mmap2; 3594 sched->tool.comm = perf_event__process_comm; 3595 sched->tool.exit = perf_event__process_exit; 3596 sched->tool.fork = perf_event__process_fork; 3597 sched->tool.lost = process_lost; 3598 sched->tool.attr = perf_event__process_attr; 3599 sched->tool.tracing_data = perf_event__process_tracing_data; 3600 sched->tool.build_id = perf_event__process_build_id; 3601 3602 sched->tool.ordering_requires_timestamps = true; 3603 3604 symbol_conf.use_callchain = sched->show_callchain; 3605 3606 session = perf_session__new(&data, &sched->tool); 3607 if (IS_ERR(session)) 3608 return PTR_ERR(session); 3609 3610 env = perf_session__env(session); 3611 if (cpu_list) { 3612 err = perf_session__cpu_bitmap(session, cpu_list, cpu_bitmap); 3613 if (err < 0) 3614 goto out; 3615 } 3616 3617 evlist = session->evlist; 3618 3619 symbol__init(env); 3620 3621 if (perf_time__parse_str(&sched->ptime, sched->time_str) != 0) { 3622 pr_err("Invalid time string\n"); 3623 err = -EINVAL; 3624 goto out; 3625 } 3626 3627 if (timehist_check_attr(sched, evlist) != 0) 3628 goto out; 3629 3630 if (timehist_parse_prio_str(sched) != 0) { 3631 pr_err("Invalid prio string\n"); 3632 goto out; 3633 } 3634 3635 setup_pager(); 3636 3637 evsel__set_priv_destructor(timehist__evsel_priv_destructor); 3638 3639 /* prefer sched_waking if it is captured */ 3640 if (evlist__find_tracepoint_by_name(session->evlist, "sched:sched_waking")) 3641 handlers[1].handler = timehist_sched_wakeup_ignore; 3642 3643 /* setup per-evsel handlers */ 3644 if (perf_session__set_tracepoints_handlers(session, handlers)) 3645 goto out; 3646 3647 /* sched_switch event at a minimum needs to exist */ 3648 if (!evlist__find_tracepoint_by_name(session->evlist, "sched:sched_switch")) { 3649 pr_err("No sched_switch events found. Have you run 'perf sched record'?\n"); 3650 goto out; 3651 } 3652 3653 if ((sched->show_migrations || sched->pre_migrations) && 3654 perf_session__set_tracepoints_handlers(session, migrate_handlers)) 3655 goto out; 3656 3657 /* pre-allocate struct for per-CPU idle stats; cap to array bounds */ 3658 sched->max_cpu.cpu = min(env->nr_cpus_online, MAX_CPUS); 3659 if (sched->max_cpu.cpu == 0) 3660 sched->max_cpu.cpu = 4; 3661 if (init_idle_threads(sched->max_cpu.cpu)) 3662 goto out; 3663 3664 /* summary_only implies summary option, but don't overwrite summary if set */ 3665 if (sched->summary_only) 3666 sched->summary = sched->summary_only; 3667 3668 if (!sched->summary_only) 3669 timehist_header(sched); 3670 3671 err = perf_session__process_events(session); 3672 if (err) { 3673 pr_err("Failed to process events, error %d", err); 3674 goto out; 3675 } 3676 3677 sched->nr_events = evlist__stats(evlist)->nr_events[0]; 3678 sched->nr_lost_events = evlist__stats(evlist)->total_lost; 3679 sched->nr_lost_chunks = evlist__stats(evlist)->nr_events[PERF_RECORD_LOST]; 3680 3681 if (sched->summary) 3682 timehist_print_summary(sched, session); 3683 3684 out: 3685 free_idle_threads(); 3686 perf_session__delete(session); 3687 3688 return err; 3689 } 3690 3691 3692 static void print_bad_events(struct perf_sched *sched) 3693 { 3694 if (sched->nr_unordered_timestamps && sched->nr_timestamps) { 3695 printf(" INFO: %.3f%% unordered timestamps (%ld out of %ld)\n", 3696 (double)sched->nr_unordered_timestamps/(double)sched->nr_timestamps*100.0, 3697 sched->nr_unordered_timestamps, sched->nr_timestamps); 3698 } 3699 if (sched->nr_lost_events && sched->nr_events) { 3700 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", 3701 (double)sched->nr_lost_events/(double)sched->nr_events * 100.0, 3702 sched->nr_lost_events, sched->nr_events, sched->nr_lost_chunks); 3703 } 3704 if (sched->nr_context_switch_bugs && sched->nr_timestamps) { 3705 printf(" INFO: %.3f%% context switch bugs (%ld out of %ld)", 3706 (double)sched->nr_context_switch_bugs/(double)sched->nr_timestamps*100.0, 3707 sched->nr_context_switch_bugs, sched->nr_timestamps); 3708 if (sched->nr_lost_events) 3709 printf(" (due to lost events?)"); 3710 printf("\n"); 3711 } 3712 } 3713 3714 static void __merge_work_atoms(struct rb_root_cached *root, struct work_atoms *data) 3715 { 3716 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 3717 struct work_atoms *this; 3718 const char *comm = thread__comm_str(data->thread), *this_comm; 3719 bool leftmost = true; 3720 3721 while (*new) { 3722 int cmp; 3723 3724 this = container_of(*new, struct work_atoms, node); 3725 parent = *new; 3726 3727 this_comm = thread__comm_str(this->thread); 3728 cmp = strcmp(comm, this_comm); 3729 if (cmp > 0) { 3730 new = &((*new)->rb_left); 3731 } else if (cmp < 0) { 3732 new = &((*new)->rb_right); 3733 leftmost = false; 3734 } else { 3735 this->num_merged++; 3736 this->total_runtime += data->total_runtime; 3737 this->nb_atoms += data->nb_atoms; 3738 this->total_lat += data->total_lat; 3739 list_splice_init(&data->work_list, &this->work_list); 3740 if (this->max_lat < data->max_lat) { 3741 this->max_lat = data->max_lat; 3742 this->max_lat_start = data->max_lat_start; 3743 this->max_lat_end = data->max_lat_end; 3744 } 3745 for (int i = 0; i < NUM_LAT_BUCKETS; i++) 3746 this->hist[i] += data->hist[i]; 3747 free_work_atoms(data); 3748 return; 3749 } 3750 } 3751 3752 data->num_merged++; 3753 rb_link_node(&data->node, parent, new); 3754 rb_insert_color_cached(&data->node, root, leftmost); 3755 } 3756 3757 static void perf_sched__merge_lat(struct perf_sched *sched) 3758 { 3759 struct work_atoms *data; 3760 struct rb_node *node; 3761 3762 if (sched->skip_merge) 3763 return; 3764 3765 while ((node = rb_first_cached(&sched->atom_root))) { 3766 rb_erase_cached(node, &sched->atom_root); 3767 data = rb_entry(node, struct work_atoms, node); 3768 __merge_work_atoms(&sched->merged_atom_root, data); 3769 } 3770 } 3771 3772 static int setup_cpus_switch_event(struct perf_sched *sched) 3773 { 3774 unsigned int i; 3775 3776 sched->cpu_last_switched = calloc(MAX_CPUS, sizeof(*(sched->cpu_last_switched))); 3777 if (!sched->cpu_last_switched) 3778 return -1; 3779 3780 sched->curr_pid = calloc(MAX_CPUS, sizeof(*(sched->curr_pid))); 3781 if (!sched->curr_pid) { 3782 zfree(&sched->cpu_last_switched); 3783 return -1; 3784 } 3785 3786 for (i = 0; i < MAX_CPUS; i++) 3787 sched->curr_pid[i] = -1; 3788 3789 return 0; 3790 } 3791 3792 static void free_cpus_switch_event(struct perf_sched *sched) 3793 { 3794 zfree(&sched->curr_pid); 3795 zfree(&sched->cpu_last_switched); 3796 } 3797 3798 static int perf_sched__lat(struct perf_sched *sched) 3799 { 3800 int rc = -1; 3801 struct rb_node *next; 3802 char total_runtime_str[32]; 3803 3804 setup_pager(); 3805 3806 if (sched->hist_mode_str) { 3807 sched->show_histogram = true; 3808 if (!strcmp(sched->hist_mode_str, "linear")) 3809 sched->hist_mode = HIST_MODE_LINEAR; 3810 else if (!strcmp(sched->hist_mode_str, "log")) 3811 sched->hist_mode = HIST_MODE_LOG; 3812 else { 3813 pr_err("Invalid --hist-mode '%s', expected 'log' or 'linear'\n", 3814 sched->hist_mode_str); 3815 return -EINVAL; 3816 } 3817 } 3818 3819 if (sched->time_str && perf_time__parse_str(&sched->ptime, sched->time_str) != 0) { 3820 pr_err("Invalid time string\n"); 3821 return -EINVAL; 3822 } 3823 3824 if (setup_cpus_switch_event(sched)) 3825 return rc; 3826 3827 if (perf_sched__read_events(sched)) 3828 goto out_free_cpus_switch_event; 3829 3830 perf_sched__merge_lat(sched); 3831 perf_sched__sort_lat(sched); 3832 3833 next = rb_first_cached(&sched->sorted_atom_root); 3834 while (next) { 3835 struct work_atoms *work_list = rb_entry(next, struct work_atoms, node); 3836 3837 if (work_list->nb_atoms && thread__tid(work_list->thread) != 0) 3838 break; 3839 next = rb_next(next); 3840 } 3841 3842 if (!next) { 3843 pr_info("No matching trace samples found.\n"); 3844 rc = 0; 3845 goto out_free_atoms; 3846 } 3847 3848 printf("\n ------------------------------------------------------------------------------------------------------------------------------------------\n"); 3849 printf(" Task | Runtime | Count | Avg delay | Max delay | Max delay start | Max delay end |\n"); 3850 printf(" ------------------------------------------------------------------------------------------------------------------------------------------\n"); 3851 3852 next = rb_first_cached(&sched->sorted_atom_root); 3853 3854 while (next) { 3855 struct work_atoms *work_list; 3856 3857 work_list = rb_entry(next, struct work_atoms, node); 3858 output_lat_thread(sched, work_list); 3859 next = rb_next(next); 3860 } 3861 3862 printf(" ------------------------------------------------------------------------------------------------------------------------------------------\n"); 3863 scnprintf_latency_unit(total_runtime_str, sizeof(total_runtime_str), sched->all_runtime); 3864 printf(" TOTAL: |%15s |%9" PRIu64 " |\n", 3865 total_runtime_str, sched->all_count); 3866 3867 printf(" ------------------------------------------------------\n"); 3868 3869 print_bad_events(sched); 3870 printf("\n"); 3871 3872 if (sched->show_histogram) 3873 print_latency_histogram(sched, sched->global_hist, sched->all_count, 3874 "CPU Wait Latency Distribution Histogram (between snapshots)"); 3875 3876 rc = 0; 3877 3878 out_free_atoms: 3879 while ((next = rb_first_cached(&sched->sorted_atom_root))) { 3880 struct work_atoms *data; 3881 3882 data = rb_entry(next, struct work_atoms, node); 3883 rb_erase_cached(next, &sched->sorted_atom_root); 3884 free_work_atoms(data); 3885 } 3886 out_free_cpus_switch_event: 3887 free_cpus_switch_event(sched); 3888 return rc; 3889 } 3890 3891 static int setup_map_cpus(struct perf_sched *sched) 3892 { 3893 if (sched->map.comp) { 3894 sched->map.comp_cpus = calloc(MAX_CPUS, sizeof(*sched->map.comp_cpus)); 3895 if (!sched->map.comp_cpus) 3896 return -1; 3897 } 3898 3899 if (sched->map.cpus_str) { 3900 sched->map.cpus = perf_cpu_map__new(sched->map.cpus_str); 3901 if (!sched->map.cpus) { 3902 pr_err("failed to get cpus map from %s\n", sched->map.cpus_str); 3903 zfree(&sched->map.comp_cpus); 3904 return -1; 3905 } 3906 } 3907 3908 return 0; 3909 } 3910 3911 static int setup_color_pids(struct perf_sched *sched) 3912 { 3913 struct perf_thread_map *map; 3914 3915 if (!sched->map.color_pids_str) 3916 return 0; 3917 3918 map = thread_map__new_by_tid_str(sched->map.color_pids_str); 3919 if (!map) { 3920 pr_err("failed to get thread map from %s\n", sched->map.color_pids_str); 3921 return -1; 3922 } 3923 3924 sched->map.color_pids = map; 3925 return 0; 3926 } 3927 3928 static int setup_color_cpus(struct perf_sched *sched) 3929 { 3930 struct perf_cpu_map *map; 3931 3932 if (!sched->map.color_cpus_str) 3933 return 0; 3934 3935 map = perf_cpu_map__new(sched->map.color_cpus_str); 3936 if (!map) { 3937 pr_err("failed to get thread map from %s\n", sched->map.color_cpus_str); 3938 return -1; 3939 } 3940 3941 sched->map.color_cpus = map; 3942 return 0; 3943 } 3944 3945 static int perf_sched__map(struct perf_sched *sched) 3946 { 3947 int rc = -1; 3948 3949 sched->curr_thread = calloc(MAX_CPUS, sizeof(*(sched->curr_thread))); 3950 if (!sched->curr_thread) 3951 return rc; 3952 3953 sched->curr_out_thread = calloc(MAX_CPUS, sizeof(*(sched->curr_out_thread))); 3954 if (!sched->curr_out_thread) 3955 goto out_free_curr_thread; 3956 3957 if (setup_cpus_switch_event(sched)) 3958 goto out_free_curr_out_thread; 3959 3960 if (setup_map_cpus(sched)) 3961 goto out_free_cpus_switch_event; 3962 3963 if (setup_color_pids(sched)) 3964 goto out_put_map_cpus; 3965 3966 if (setup_color_cpus(sched)) 3967 goto out_put_color_pids; 3968 3969 setup_pager(); 3970 if (perf_sched__read_events(sched)) 3971 goto out_put_color_cpus; 3972 3973 rc = 0; 3974 print_bad_events(sched); 3975 3976 out_put_color_cpus: 3977 perf_cpu_map__put(sched->map.color_cpus); 3978 3979 out_put_color_pids: 3980 perf_thread_map__put(sched->map.color_pids); 3981 3982 out_put_map_cpus: 3983 zfree(&sched->map.comp_cpus); 3984 perf_cpu_map__put(sched->map.cpus); 3985 3986 out_free_cpus_switch_event: 3987 free_cpus_switch_event(sched); 3988 3989 out_free_curr_out_thread: 3990 for (int i = 0; i < MAX_CPUS; i++) 3991 thread__put(sched->curr_out_thread[i]); 3992 zfree(&sched->curr_out_thread); 3993 3994 out_free_curr_thread: 3995 for (int i = 0; i < MAX_CPUS; i++) 3996 thread__put(sched->curr_thread[i]); 3997 zfree(&sched->curr_thread); 3998 return rc; 3999 } 4000 4001 static int perf_sched__replay(struct perf_sched *sched) 4002 { 4003 int ret; 4004 unsigned long i; 4005 4006 mutex_init(&sched->start_work_mutex); 4007 mutex_init(&sched->work_done_wait_mutex); 4008 4009 ret = setup_cpus_switch_event(sched); 4010 if (ret) 4011 goto out_mutex_destroy; 4012 4013 calibrate_run_measurement_overhead(sched); 4014 calibrate_sleep_measurement_overhead(sched); 4015 4016 test_calibrations(sched); 4017 4018 ret = perf_sched__read_events(sched); 4019 if (ret) 4020 goto out_free_cpus_switch_event; 4021 4022 printf("nr_run_events: %ld\n", sched->nr_run_events); 4023 printf("nr_sleep_events: %ld\n", sched->nr_sleep_events); 4024 printf("nr_wakeup_events: %ld\n", sched->nr_wakeup_events); 4025 4026 if (sched->targetless_wakeups) 4027 printf("target-less wakeups: %ld\n", sched->targetless_wakeups); 4028 if (sched->multitarget_wakeups) 4029 printf("multi-target wakeups: %ld\n", sched->multitarget_wakeups); 4030 if (sched->nr_run_events_optimized) 4031 printf("run atoms optimized: %ld\n", 4032 sched->nr_run_events_optimized); 4033 4034 print_task_traces(sched); 4035 add_cross_task_wakeups(sched); 4036 4037 sched->thread_funcs_exit = false; 4038 create_tasks(sched); 4039 printf("------------------------------------------------------------\n"); 4040 if (sched->replay_repeat == 0) 4041 sched->replay_repeat = UINT_MAX; 4042 4043 for (i = 0; i < sched->replay_repeat; i++) 4044 run_one_test(sched); 4045 4046 sched->thread_funcs_exit = true; 4047 destroy_tasks(sched); 4048 4049 out_free_cpus_switch_event: 4050 free_cpus_switch_event(sched); 4051 4052 out_mutex_destroy: 4053 mutex_destroy(&sched->start_work_mutex); 4054 mutex_destroy(&sched->work_done_wait_mutex); 4055 return ret; 4056 } 4057 4058 static void setup_sorting(struct perf_sched *sched, const struct option *options, 4059 const char * const usage_msg[]) 4060 { 4061 char *tmp, *tok, *str = strdup(sched->sort_order); 4062 4063 for (tok = strtok_r(str, ", ", &tmp); 4064 tok; tok = strtok_r(NULL, ", ", &tmp)) { 4065 if (sort_dimension__add(tok, &sched->sort_list) < 0) { 4066 usage_with_options_msg(usage_msg, options, 4067 "Unknown --sort key: `%s'", tok); 4068 } 4069 } 4070 4071 free(str); 4072 4073 sort_dimension__add("pid", &sched->cmp_pid); 4074 } 4075 4076 static int process_synthesized_schedstat_event(const struct perf_tool *tool, 4077 union perf_event *event, 4078 struct perf_sample *sample __maybe_unused, 4079 struct machine *machine __maybe_unused) 4080 { 4081 struct perf_sched *sched = container_of(tool, struct perf_sched, tool); 4082 4083 if (perf_data__write(sched->data, event, event->header.size) <= 0) { 4084 pr_err("failed to write perf data, error: %m\n"); 4085 return -1; 4086 } 4087 4088 sched->session->header.data_size += event->header.size; 4089 return 0; 4090 } 4091 4092 static volatile sig_atomic_t done; 4093 4094 static void sighandler(int sig __maybe_unused) 4095 { 4096 done = 1; 4097 } 4098 4099 static int enable_sched_schedstats(int *reset) 4100 { 4101 char path[PATH_MAX]; 4102 FILE *fp; 4103 char ch; 4104 4105 snprintf(path, PATH_MAX, "%s/sys/kernel/sched_schedstats", procfs__mountpoint()); 4106 fp = fopen(path, "w+"); 4107 if (!fp) { 4108 pr_err("Failed to open %s\n", path); 4109 return -1; 4110 } 4111 4112 ch = getc(fp); 4113 if (ch == '0') { 4114 *reset = 1; 4115 rewind(fp); 4116 putc('1', fp); 4117 fclose(fp); 4118 } 4119 return 0; 4120 } 4121 4122 static int disable_sched_schedstat(void) 4123 { 4124 char path[PATH_MAX]; 4125 FILE *fp; 4126 4127 snprintf(path, PATH_MAX, "%s/sys/kernel/sched_schedstats", procfs__mountpoint()); 4128 fp = fopen(path, "w"); 4129 if (!fp) { 4130 pr_err("Failed to open %s\n", path); 4131 return -1; 4132 } 4133 4134 putc('0', fp); 4135 fclose(fp); 4136 return 0; 4137 } 4138 4139 /* perf.data or any other output file name used by stats subcommand (only). */ 4140 const char *output_name; 4141 4142 static int perf_sched__schedstat_record(struct perf_sched *sched, 4143 int argc, const char **argv) 4144 { 4145 struct perf_session *session; 4146 struct target target = {}; 4147 struct evlist *evlist; 4148 int reset = 0; 4149 int err = 0; 4150 int fd; 4151 struct perf_data data = { 4152 .path = output_name, 4153 .mode = PERF_DATA_MODE_WRITE, 4154 }; 4155 4156 done = 0; 4157 signal(SIGINT, sighandler); 4158 signal(SIGCHLD, sighandler); 4159 signal(SIGTERM, sighandler); 4160 4161 evlist = evlist__new(); 4162 if (!evlist) 4163 return -ENOMEM; 4164 4165 session = perf_session__new(&data, &sched->tool); 4166 if (IS_ERR(session)) { 4167 pr_err("Perf session creation failed.\n"); 4168 evlist__put(evlist); 4169 return PTR_ERR(session); 4170 } 4171 4172 session->evlist = evlist; 4173 4174 sched->session = session; 4175 sched->data = &data; 4176 4177 fd = perf_data__fd(&data); 4178 4179 /* 4180 * Capture all important metadata about the system. Although they are 4181 * not used by `perf sched stats` tool directly, they provide useful 4182 * information about profiled environment. 4183 */ 4184 perf_header__set_feat(&session->header, HEADER_HOSTNAME); 4185 perf_header__set_feat(&session->header, HEADER_OSRELEASE); 4186 perf_header__set_feat(&session->header, HEADER_VERSION); 4187 perf_header__set_feat(&session->header, HEADER_ARCH); 4188 perf_header__set_feat(&session->header, HEADER_NRCPUS); 4189 perf_header__set_feat(&session->header, HEADER_CPUDESC); 4190 perf_header__set_feat(&session->header, HEADER_CPUID); 4191 perf_header__set_feat(&session->header, HEADER_TOTAL_MEM); 4192 perf_header__set_feat(&session->header, HEADER_CMDLINE); 4193 perf_header__set_feat(&session->header, HEADER_CPU_TOPOLOGY); 4194 perf_header__set_feat(&session->header, HEADER_NUMA_TOPOLOGY); 4195 perf_header__set_feat(&session->header, HEADER_CACHE); 4196 perf_header__set_feat(&session->header, HEADER_MEM_TOPOLOGY); 4197 perf_header__set_feat(&session->header, HEADER_HYBRID_TOPOLOGY); 4198 perf_header__set_feat(&session->header, HEADER_CPU_DOMAIN_INFO); 4199 4200 err = perf_session__write_header(session, evlist, fd, false); 4201 if (err < 0) 4202 goto out; 4203 4204 /* 4205 * `perf sched stats` does not support workload profiling (-p pid) 4206 * since /proc/schedstat file contains cpu specific data only. Hence, a 4207 * profile target is either set of cpus or systemwide, never a process. 4208 * Note that, although `-- <workload>` is supported, profile data are 4209 * still cpu/systemwide. 4210 */ 4211 if (cpu_list) 4212 target.cpu_list = cpu_list; 4213 else 4214 target.system_wide = true; 4215 4216 if (argc) { 4217 err = evlist__prepare_workload(evlist, &target, argv, false, NULL); 4218 if (err) 4219 goto out; 4220 } 4221 4222 err = evlist__create_maps(evlist, &target); 4223 if (err < 0) 4224 goto out; 4225 4226 user_requested_cpus = evlist__core(evlist)->user_requested_cpus; 4227 4228 err = perf_event__synthesize_schedstat(&(sched->tool), 4229 process_synthesized_schedstat_event, 4230 user_requested_cpus); 4231 if (err < 0) 4232 goto out; 4233 4234 err = enable_sched_schedstats(&reset); 4235 if (err < 0) 4236 goto out; 4237 4238 if (argc) 4239 evlist__start_workload(evlist); 4240 4241 while (!done) { 4242 if (argc && waitpid(evlist__workload_pid(evlist), NULL, WNOHANG) > 0) 4243 break; 4244 sleep(1); 4245 } 4246 4247 if (reset) { 4248 err = disable_sched_schedstat(); 4249 if (err < 0) 4250 goto out; 4251 } 4252 4253 err = perf_event__synthesize_schedstat(&(sched->tool), 4254 process_synthesized_schedstat_event, 4255 user_requested_cpus); 4256 if (err < 0) 4257 goto out; 4258 4259 err = perf_session__write_header(session, evlist, fd, true); 4260 4261 out: 4262 if (!err) 4263 fprintf(stderr, "[ perf sched stats: Wrote samples to %s ]\n", data.path); 4264 else 4265 fprintf(stderr, "[ perf sched stats: Failed !! ]\n"); 4266 4267 perf_session__delete(session); 4268 evlist__put(evlist); 4269 return err; 4270 } 4271 4272 struct schedstat_domain { 4273 struct list_head domain_list; 4274 struct perf_record_schedstat_domain *domain_data; 4275 }; 4276 4277 struct schedstat_cpu { 4278 struct list_head cpu_list; 4279 struct list_head domain_head; 4280 struct perf_record_schedstat_cpu *cpu_data; 4281 }; 4282 4283 static struct list_head cpu_head = LIST_HEAD_INIT(cpu_head); 4284 static struct schedstat_cpu *cpu_second_pass; 4285 static struct schedstat_domain *domain_second_pass; 4286 static bool after_workload_flag; 4287 static bool verbose_field; 4288 4289 static void free_schedstat(struct list_head *head); 4290 4291 static void store_schedstat_cpu_diff(struct schedstat_cpu *after_workload) 4292 { 4293 struct perf_record_schedstat_cpu *before = cpu_second_pass->cpu_data; 4294 struct perf_record_schedstat_cpu *after = after_workload->cpu_data; 4295 __u16 version = after_workload->cpu_data->version; 4296 4297 #define CPU_FIELD(_type, _name, _desc, _format, _is_pct, _pct_of, _ver) \ 4298 (before->_ver._name = after->_ver._name - before->_ver._name) 4299 4300 if (version == 15) { 4301 #include <perf/schedstat-v15.h> 4302 } else if (version == 16) { 4303 #include <perf/schedstat-v16.h> 4304 } else if (version == 17) { 4305 #include <perf/schedstat-v17.h> 4306 } 4307 4308 #undef CPU_FIELD 4309 } 4310 4311 static void store_schedstat_domain_diff(struct schedstat_domain *after_workload) 4312 { 4313 struct perf_record_schedstat_domain *before = domain_second_pass->domain_data; 4314 struct perf_record_schedstat_domain *after = after_workload->domain_data; 4315 __u16 version = after_workload->domain_data->version; 4316 4317 #define DOMAIN_FIELD(_type, _name, _desc, _format, _is_jiffies, _ver) \ 4318 (before->_ver._name = after->_ver._name - before->_ver._name) 4319 4320 if (version == 15) { 4321 #include <perf/schedstat-v15.h> 4322 } else if (version == 16) { 4323 #include <perf/schedstat-v16.h> 4324 } else if (version == 17) { 4325 #include <perf/schedstat-v17.h> 4326 } 4327 #undef DOMAIN_FIELD 4328 } 4329 4330 #define PCT_CHNG(_x, _y) ((_x) ? ((double)((double)(_y) - (_x)) / (_x)) * 100 : 0.0) 4331 static inline void print_cpu_stats(struct perf_record_schedstat_cpu *cs1, 4332 struct perf_record_schedstat_cpu *cs2) 4333 { 4334 printf("%-65s ", "DESC"); 4335 if (!cs2) 4336 printf("%12s %12s", "COUNT", "PCT_CHANGE"); 4337 else 4338 printf("%12s %11s %12s %14s %10s", "COUNT1", "COUNT2", "PCT_CHANGE", 4339 "PCT_CHANGE1", "PCT_CHANGE2"); 4340 4341 printf("\n"); 4342 print_separator2(SEP_LEN, "", 0); 4343 4344 #define CALC_PCT(_x, _y) ((_y) ? ((double)(_x) / (_y)) * 100 : 0.0) 4345 4346 #define CPU_FIELD(_type, _name, _desc, _format, _is_pct, _pct_of, _ver) \ 4347 do { \ 4348 printf("%-65s: " _format, verbose_field ? _desc : #_name, \ 4349 cs1->_ver._name); \ 4350 if (!cs2) { \ 4351 if (_is_pct) \ 4352 printf(" ( %8.2lf%% )", \ 4353 CALC_PCT(cs1->_ver._name, cs1->_ver._pct_of)); \ 4354 } else { \ 4355 printf("," _format " | %8.2lf%% |", cs2->_ver._name, \ 4356 PCT_CHNG(cs1->_ver._name, cs2->_ver._name)); \ 4357 if (_is_pct) \ 4358 printf(" ( %8.2lf%%, %8.2lf%% )", \ 4359 CALC_PCT(cs1->_ver._name, cs1->_ver._pct_of), \ 4360 CALC_PCT(cs2->_ver._name, cs2->_ver._pct_of)); \ 4361 } \ 4362 printf("\n"); \ 4363 } while (0) 4364 4365 if (cs1->version == 15) { 4366 #include <perf/schedstat-v15.h> 4367 } else if (cs1->version == 16) { 4368 #include <perf/schedstat-v16.h> 4369 } else if (cs1->version == 17) { 4370 #include <perf/schedstat-v17.h> 4371 } 4372 4373 #undef CPU_FIELD 4374 #undef CALC_PCT 4375 } 4376 4377 static inline void print_domain_stats(struct perf_record_schedstat_domain *ds1, 4378 struct perf_record_schedstat_domain *ds2, 4379 __u64 jiffies1, __u64 jiffies2) 4380 { 4381 printf("%-65s ", "DESC"); 4382 if (!ds2) 4383 printf("%12s %14s", "COUNT", "AVG_JIFFIES"); 4384 else 4385 printf("%12s %11s %12s %16s %12s", "COUNT1", "COUNT2", "PCT_CHANGE", 4386 "AVG_JIFFIES1", "AVG_JIFFIES2"); 4387 printf("\n"); 4388 4389 #define DOMAIN_CATEGORY(_desc) \ 4390 do { \ 4391 size_t _len = strlen(_desc); \ 4392 size_t _pre_dash_cnt = (SEP_LEN - _len) / 2; \ 4393 size_t _post_dash_cnt = SEP_LEN - _len - _pre_dash_cnt; \ 4394 print_separator2((int)_pre_dash_cnt, _desc, (int)_post_dash_cnt);\ 4395 } while (0) 4396 4397 #define CALC_AVG(_x, _y) ((_y) ? (long double)(_x) / (_y) : 0.0) 4398 4399 #define DOMAIN_FIELD(_type, _name, _desc, _format, _is_jiffies, _ver) \ 4400 do { \ 4401 printf("%-65s: " _format, verbose_field ? _desc : #_name, \ 4402 ds1->_ver._name); \ 4403 if (!ds2) { \ 4404 if (_is_jiffies) \ 4405 printf(" $ %11.2Lf $", \ 4406 CALC_AVG(jiffies1, ds1->_ver._name)); \ 4407 } else { \ 4408 printf("," _format " | %8.2lf%% |", ds2->_ver._name, \ 4409 PCT_CHNG(ds1->_ver._name, ds2->_ver._name)); \ 4410 if (_is_jiffies) \ 4411 printf(" $ %11.2Lf, %11.2Lf $", \ 4412 CALC_AVG(jiffies1, ds1->_ver._name), \ 4413 CALC_AVG(jiffies2, ds2->_ver._name)); \ 4414 } \ 4415 printf("\n"); \ 4416 } while (0) 4417 4418 #define DERIVED_CNT_FIELD(_name, _desc, _format, _x, _y, _z, _ver) \ 4419 do { \ 4420 __u32 t1 = ds1->_ver._x - ds1->_ver._y - ds1->_ver._z; \ 4421 printf("*%-64s: " _format, verbose_field ? _desc : #_name, t1); \ 4422 if (ds2) { \ 4423 __u32 t2 = ds2->_ver._x - ds2->_ver._y - ds2->_ver._z; \ 4424 printf("," _format " | %8.2lf%% |", t2, \ 4425 PCT_CHNG(t1, t2)); \ 4426 } \ 4427 printf("\n"); \ 4428 } while (0) 4429 4430 #define DERIVED_AVG_FIELD(_name, _desc, _format, _x, _y, _z, _w, _ver) \ 4431 do { \ 4432 __u32 t1 = ds1->_ver._x - ds1->_ver._y - ds1->_ver._z; \ 4433 printf("*%-64s: " _format, verbose_field ? _desc : #_name, \ 4434 CALC_AVG(ds1->_ver._w, t1)); \ 4435 if (ds2) { \ 4436 __u32 t2 = ds2->_ver._x - ds2->_ver._y - ds2->_ver._z; \ 4437 printf("," _format " | %8.2Lf%% |", \ 4438 CALC_AVG(ds2->_ver._w, t2), \ 4439 PCT_CHNG(CALC_AVG(ds1->_ver._w, t1), \ 4440 CALC_AVG(ds2->_ver._w, t2))); \ 4441 } \ 4442 printf("\n"); \ 4443 } while (0) 4444 4445 if (ds1->version == 15) { 4446 #include <perf/schedstat-v15.h> 4447 } else if (ds1->version == 16) { 4448 #include <perf/schedstat-v16.h> 4449 } else if (ds1->version == 17) { 4450 #include <perf/schedstat-v17.h> 4451 } 4452 4453 #undef DERIVED_AVG_FIELD 4454 #undef DERIVED_CNT_FIELD 4455 #undef DOMAIN_FIELD 4456 #undef CALC_AVG 4457 #undef DOMAIN_CATEGORY 4458 } 4459 #undef PCT_CHNG 4460 4461 static void summarize_schedstat_cpu(struct schedstat_cpu *summary_cpu, 4462 struct schedstat_cpu *cptr, 4463 int cnt, bool is_last) 4464 { 4465 struct perf_record_schedstat_cpu *summary_cs = summary_cpu->cpu_data, 4466 *temp_cs = cptr->cpu_data; 4467 4468 #define CPU_FIELD(_type, _name, _desc, _format, _is_pct, _pct_of, _ver) \ 4469 do { \ 4470 summary_cs->_ver._name += temp_cs->_ver._name; \ 4471 if (is_last) \ 4472 summary_cs->_ver._name /= cnt; \ 4473 } while (0) 4474 4475 if (cptr->cpu_data->version == 15) { 4476 #include <perf/schedstat-v15.h> 4477 } else if (cptr->cpu_data->version == 16) { 4478 #include <perf/schedstat-v16.h> 4479 } else if (cptr->cpu_data->version == 17) { 4480 #include <perf/schedstat-v17.h> 4481 } 4482 #undef CPU_FIELD 4483 } 4484 4485 static void summarize_schedstat_domain(struct schedstat_domain *summary_domain, 4486 struct schedstat_domain *dptr, 4487 int cnt, bool is_last) 4488 { 4489 struct perf_record_schedstat_domain *summary_ds = summary_domain->domain_data, 4490 *temp_ds = dptr->domain_data; 4491 4492 #define DOMAIN_FIELD(_type, _name, _desc, _format, _is_jiffies, _ver) \ 4493 do { \ 4494 summary_ds->_ver._name += temp_ds->_ver._name; \ 4495 if (is_last) \ 4496 summary_ds->_ver._name /= cnt; \ 4497 } while (0) 4498 4499 if (dptr->domain_data->version == 15) { 4500 #include <perf/schedstat-v15.h> 4501 } else if (dptr->domain_data->version == 16) { 4502 #include <perf/schedstat-v16.h> 4503 } else if (dptr->domain_data->version == 17) { 4504 #include <perf/schedstat-v17.h> 4505 } 4506 #undef DOMAIN_FIELD 4507 } 4508 4509 /* 4510 * get_all_cpu_stats() appends the summary to the head of the list. 4511 */ 4512 static int get_all_cpu_stats(struct list_head *head) 4513 { 4514 struct schedstat_cpu *cptr, *summary_head = NULL; 4515 struct schedstat_domain *dptr, *tdptr; 4516 bool is_last = false; 4517 int cnt = 1; 4518 int ret = 0; 4519 struct list_head tmp_cleanup_list; 4520 4521 assert(!list_empty(head)); 4522 cptr = list_first_entry(head, struct schedstat_cpu, cpu_list); 4523 4524 INIT_LIST_HEAD(&tmp_cleanup_list); 4525 4526 summary_head = zalloc(sizeof(*summary_head)); 4527 if (!summary_head) 4528 return -ENOMEM; 4529 4530 INIT_LIST_HEAD(&summary_head->domain_head); 4531 INIT_LIST_HEAD(&summary_head->cpu_list); 4532 list_add(&summary_head->cpu_list, &tmp_cleanup_list); 4533 4534 summary_head->cpu_data = zalloc(sizeof(*summary_head->cpu_data)); 4535 if (!summary_head->cpu_data) { 4536 ret = -ENOMEM; 4537 goto out_cleanup; 4538 } 4539 memcpy(summary_head->cpu_data, cptr->cpu_data, sizeof(*summary_head->cpu_data)); 4540 4541 list_for_each_entry(dptr, &cptr->domain_head, domain_list) { 4542 tdptr = zalloc(sizeof(*tdptr)); 4543 if (!tdptr) { 4544 ret = -ENOMEM; 4545 goto out_cleanup; 4546 } 4547 INIT_LIST_HEAD(&tdptr->domain_list); 4548 4549 tdptr->domain_data = zalloc(sizeof(*tdptr->domain_data)); 4550 if (!tdptr->domain_data) { 4551 free(tdptr); 4552 ret = -ENOMEM; 4553 goto out_cleanup; 4554 } 4555 4556 memcpy(tdptr->domain_data, dptr->domain_data, sizeof(*tdptr->domain_data)); 4557 list_add_tail(&tdptr->domain_list, &summary_head->domain_head); 4558 } 4559 4560 list_for_each_entry(cptr, head, cpu_list) { 4561 if (list_is_first(&cptr->cpu_list, head)) 4562 continue; 4563 4564 if (list_is_last(&cptr->cpu_list, head)) 4565 is_last = true; 4566 4567 cnt++; 4568 summarize_schedstat_cpu(summary_head, cptr, cnt, is_last); 4569 if (list_empty(&summary_head->domain_head)) 4570 continue; 4571 4572 tdptr = list_first_entry(&summary_head->domain_head, struct schedstat_domain, 4573 domain_list); 4574 4575 list_for_each_entry(dptr, &cptr->domain_head, domain_list) { 4576 summarize_schedstat_domain(tdptr, dptr, cnt, is_last); 4577 if (list_is_last(&tdptr->domain_list, &summary_head->domain_head)) { 4578 tdptr = NULL; 4579 break; 4580 } 4581 tdptr = list_next_entry(tdptr, domain_list); 4582 } 4583 } 4584 4585 list_del_init(&summary_head->cpu_list); 4586 list_add(&summary_head->cpu_list, head); 4587 return 0; 4588 4589 out_cleanup: 4590 free_schedstat(&tmp_cleanup_list); 4591 return ret; 4592 } 4593 4594 static int show_schedstat_data(struct list_head *head1, struct cpu_domain_map **cd_map1, int nr1, 4595 struct list_head *head2, struct cpu_domain_map **cd_map2, int nr2, 4596 bool summary_only) 4597 { 4598 struct schedstat_cpu *cptr1 = list_first_entry(head1, struct schedstat_cpu, cpu_list); 4599 struct perf_record_schedstat_domain *ds1 = NULL, *ds2 = NULL; 4600 struct schedstat_domain *dptr1 = NULL, *dptr2 = NULL; 4601 struct schedstat_cpu *cptr2 = NULL; 4602 __u64 jiffies1 = 0, jiffies2 = 0; 4603 bool is_summary = true; 4604 int ret = 0; 4605 4606 if (!cd_map1) { 4607 pr_err("Error: CPU domain map 1 is missing.\n"); 4608 return -1; 4609 } 4610 if (head2 && !cd_map2) { 4611 pr_err("Error: CPU domain map 2 is missing.\n"); 4612 return -1; 4613 } 4614 4615 printf("Description\n"); 4616 print_separator2(SEP_LEN, "", 0); 4617 printf("%-30s-> %s\n", "DESC", "Description of the field"); 4618 printf("%-30s-> %s\n", "COUNT", "Value of the field"); 4619 printf("%-30s-> %s\n", "PCT_CHANGE", "Percent change with corresponding base value"); 4620 printf("%-30s-> %s\n", "AVG_JIFFIES", 4621 "Avg time in jiffies between two consecutive occurrence of event"); 4622 4623 print_separator2(SEP_LEN, "", 0); 4624 printf("\n"); 4625 4626 printf("%-65s: ", "Time elapsed (in jiffies)"); 4627 jiffies1 = cptr1->cpu_data->timestamp; 4628 printf("%11llu", jiffies1); 4629 if (head2) { 4630 cptr2 = list_first_entry(head2, struct schedstat_cpu, cpu_list); 4631 jiffies2 = cptr2->cpu_data->timestamp; 4632 printf(",%11llu", jiffies2); 4633 } 4634 printf("\n"); 4635 4636 ret = get_all_cpu_stats(head1); 4637 if (ret) 4638 return ret; 4639 if (cptr2) { 4640 ret = get_all_cpu_stats(head2); 4641 if (ret) 4642 return ret; 4643 cptr2 = list_first_entry(head2, struct schedstat_cpu, cpu_list); 4644 } 4645 4646 list_for_each_entry(cptr1, head1, cpu_list) { 4647 struct cpu_domain_map *cd_info1 = NULL, *cd_info2 = NULL; 4648 struct perf_record_schedstat_cpu *cs1 = cptr1->cpu_data; 4649 struct perf_record_schedstat_cpu *cs2 = NULL; 4650 4651 dptr2 = NULL; 4652 if (cs1->cpu >= (u32)nr1) { 4653 pr_err("Error: CPU %d exceeds domain map size %d\n", cs1->cpu, nr1); 4654 return -1; 4655 } 4656 cd_info1 = cd_map1[cs1->cpu]; 4657 if (!cd_info1) { 4658 pr_err("Error: CPU %d domain info is missing in map 1.\n", 4659 cs1->cpu); 4660 return -1; 4661 } 4662 if (cptr2) { 4663 cs2 = cptr2->cpu_data; 4664 if (cs2->cpu >= (u32)nr2) { 4665 pr_err("Error: CPU %d exceeds domain map size %d\n", cs2->cpu, nr2); 4666 return -1; 4667 } 4668 cd_info2 = cd_map2[cs2->cpu]; 4669 if (!cd_info2) { 4670 pr_err("Error: CPU %d domain info is missing in map 2.\n", 4671 cs2->cpu); 4672 return -1; 4673 } 4674 if (!list_empty(&cptr2->domain_head)) 4675 dptr2 = list_first_entry(&cptr2->domain_head, 4676 struct schedstat_domain, 4677 domain_list); 4678 } 4679 4680 if (cs2 && cs1->cpu != cs2->cpu) { 4681 pr_err("Failed because matching cpus not found for diff\n"); 4682 return -1; 4683 } 4684 4685 if (cd_info2 && cd_info1->nr_domains != cd_info2->nr_domains) { 4686 pr_err("Failed because nr_domains is not same for cpus\n"); 4687 return -1; 4688 } 4689 4690 print_separator2(SEP_LEN, "", 0); 4691 4692 if (is_summary) 4693 printf("CPU: <ALL CPUS SUMMARY>\n"); 4694 else 4695 printf("CPU: %d\n", cs1->cpu); 4696 4697 print_separator2(SEP_LEN, "", 0); 4698 print_cpu_stats(cs1, cs2); 4699 print_separator2(SEP_LEN, "", 0); 4700 4701 list_for_each_entry(dptr1, &cptr1->domain_head, domain_list) { 4702 struct domain_info *dinfo1 = NULL, *dinfo2 = NULL; 4703 4704 ds1 = dptr1->domain_data; 4705 ds2 = NULL; 4706 if (ds1->domain >= cd_info1->nr_domains) { 4707 pr_err("Error: Domain %d exceeds max domains %d for CPU %d in map 1.\n", 4708 ds1->domain, cd_info1->nr_domains, cs1->cpu); 4709 return -1; 4710 } 4711 dinfo1 = cd_info1->domains[ds1->domain]; 4712 if (!dinfo1) { 4713 pr_err("Error: Domain %d info is missing for CPU %d in map 1.\n", 4714 ds1->domain, cs1->cpu); 4715 return -1; 4716 } 4717 if (dptr2) { 4718 ds2 = dptr2->domain_data; 4719 if (ds2->domain >= cd_info2->nr_domains) { 4720 pr_err("Error: Domain %d exceeds max domains %d for CPU %d in map 2.\n", 4721 ds2->domain, cd_info2->nr_domains, cs2->cpu); 4722 return -1; 4723 } 4724 dinfo2 = cd_info2->domains[ds2->domain]; 4725 if (!dinfo2) { 4726 pr_err("Error: Domain %d info is missing for CPU %d in map 2.\n", 4727 ds2->domain, cs2->cpu); 4728 return -1; 4729 } 4730 } 4731 4732 if (dinfo2 && dinfo1->domain != dinfo2->domain) { 4733 pr_err("Failed because matching domain not found for diff\n"); 4734 return -1; 4735 } 4736 4737 if (is_summary) { 4738 if (dinfo1->dname) 4739 printf("CPU: <ALL CPUS SUMMARY> | DOMAIN: %s\n", 4740 dinfo1->dname); 4741 else 4742 printf("CPU: <ALL CPUS SUMMARY> | DOMAIN: %d\n", 4743 dinfo1->domain); 4744 } else { 4745 if (dinfo1->dname) 4746 printf("CPU: %d | DOMAIN: %s | DOMAIN_CPUS: ", 4747 cs1->cpu, dinfo1->dname); 4748 else 4749 printf("CPU: %d | DOMAIN: %d | DOMAIN_CPUS: ", 4750 cs1->cpu, dinfo1->domain); 4751 4752 printf("%s\n", dinfo1->cpulist); 4753 } 4754 print_separator2(SEP_LEN, "", 0); 4755 print_domain_stats(ds1, ds2, jiffies1, jiffies2); 4756 print_separator2(SEP_LEN, "", 0); 4757 4758 if (dptr2) { 4759 if (list_is_last(&dptr2->domain_list, &cptr2->domain_head)) 4760 dptr2 = NULL; 4761 else 4762 dptr2 = list_next_entry(dptr2, domain_list); 4763 } 4764 } 4765 if (summary_only) 4766 break; 4767 4768 if (cptr2) { 4769 if (list_is_last(&cptr2->cpu_list, head2)) 4770 cptr2 = NULL; 4771 else 4772 cptr2 = list_next_entry(cptr2, cpu_list); 4773 } 4774 4775 is_summary = false; 4776 } 4777 return ret; 4778 } 4779 4780 /* 4781 * Creates a linked list of cpu_data and domain_data. Below represents the structure of the linked 4782 * list where CPU0,CPU1,CPU2, ..., CPU(N-1) stores the cpu_data. Here N is the total number of cpus. 4783 * Each of the CPU points to the list of domain_data. Here DOMAIN0, DOMAIN1, DOMAIN2, ... represents 4784 * the domain_data. Here D0, D1, D2, ..., Dm are the number of domains in the respective cpus. 4785 * 4786 * +----------+ 4787 * | CPU_HEAD | 4788 * +----------+ 4789 * | 4790 * v 4791 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4792 * | CPU0 | -> | DOMAIN0 | -> | DOMAIN1 | -> | DOMAIN2 | -> ... -> | DOMAIN(D0-1) | 4793 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4794 * | 4795 * v 4796 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4797 * | CPU1 | -> | DOMAIN0 | -> | DOMAIN1 | -> | DOMAIN2 | -> ... -> | DOMAIN(D1-1) | 4798 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4799 * | 4800 * v 4801 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4802 * | CPU2 | -> | DOMAIN0 | -> | DOMAIN1 | -> | DOMAIN2 | -> ... -> | DOMAIN(D2-1) | 4803 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4804 * | 4805 * v 4806 * ... 4807 * | 4808 * v 4809 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4810 * | CPU(N-1) | -> | DOMAIN0 | -> | DOMAIN1 | -> | DOMAIN2 | -> ... -> | DOMAIN(Dm-1) | 4811 * +----------+ +---------+ +---------+ +---------+ +--------------+ 4812 * 4813 * Each cpu as well as domain has 2 enties in the event list one before the workload starts and 4814 * other after completion of the workload. The above linked list stores the diff of the cpu and 4815 * domain statistics. 4816 */ 4817 static int perf_sched__process_schedstat(const struct perf_tool *tool __maybe_unused, 4818 struct perf_session *session __maybe_unused, 4819 union perf_event *event) 4820 { 4821 struct perf_cpu this_cpu; 4822 static __u32 initial_cpu; 4823 4824 switch (event->header.type) { 4825 case PERF_RECORD_SCHEDSTAT_CPU: 4826 this_cpu.cpu = event->schedstat_cpu.cpu; 4827 break; 4828 case PERF_RECORD_SCHEDSTAT_DOMAIN: 4829 this_cpu.cpu = event->schedstat_domain.cpu; 4830 break; 4831 default: 4832 return 0; 4833 } 4834 4835 if (user_requested_cpus && !perf_cpu_map__has(user_requested_cpus, this_cpu)) 4836 return 0; 4837 4838 if (event->header.type == PERF_RECORD_SCHEDSTAT_CPU) { 4839 struct schedstat_cpu *temp = zalloc(sizeof(*temp)); 4840 4841 if (!temp) 4842 return -ENOMEM; 4843 4844 temp->cpu_data = zalloc(sizeof(*temp->cpu_data)); 4845 if (!temp->cpu_data) 4846 return -ENOMEM; 4847 4848 memcpy(temp->cpu_data, &event->schedstat_cpu, sizeof(*temp->cpu_data)); 4849 4850 if (!list_empty(&cpu_head) && temp->cpu_data->cpu == initial_cpu) 4851 after_workload_flag = true; 4852 4853 if (!after_workload_flag) { 4854 if (list_empty(&cpu_head)) 4855 initial_cpu = temp->cpu_data->cpu; 4856 4857 list_add_tail(&temp->cpu_list, &cpu_head); 4858 INIT_LIST_HEAD(&temp->domain_head); 4859 } else { 4860 if (temp->cpu_data->cpu == initial_cpu) { 4861 cpu_second_pass = list_first_entry(&cpu_head, struct schedstat_cpu, 4862 cpu_list); 4863 cpu_second_pass->cpu_data->timestamp = 4864 temp->cpu_data->timestamp - cpu_second_pass->cpu_data->timestamp; 4865 } else { 4866 cpu_second_pass = list_next_entry(cpu_second_pass, cpu_list); 4867 } 4868 domain_second_pass = list_first_entry(&cpu_second_pass->domain_head, 4869 struct schedstat_domain, domain_list); 4870 store_schedstat_cpu_diff(temp); 4871 free(temp->cpu_data); 4872 free(temp); 4873 } 4874 } else if (event->header.type == PERF_RECORD_SCHEDSTAT_DOMAIN) { 4875 struct schedstat_cpu *cpu_tail; 4876 struct schedstat_domain *temp = zalloc(sizeof(*temp)); 4877 4878 if (!temp) 4879 return -ENOMEM; 4880 4881 temp->domain_data = zalloc(sizeof(*temp->domain_data)); 4882 if (!temp->domain_data) 4883 return -ENOMEM; 4884 4885 memcpy(temp->domain_data, &event->schedstat_domain, sizeof(*temp->domain_data)); 4886 4887 if (!after_workload_flag) { 4888 cpu_tail = list_last_entry(&cpu_head, struct schedstat_cpu, cpu_list); 4889 list_add_tail(&temp->domain_list, &cpu_tail->domain_head); 4890 } else { 4891 store_schedstat_domain_diff(temp); 4892 domain_second_pass = list_next_entry(domain_second_pass, domain_list); 4893 free(temp->domain_data); 4894 free(temp); 4895 } 4896 } 4897 4898 return 0; 4899 } 4900 4901 static void free_schedstat(struct list_head *head) 4902 { 4903 struct schedstat_domain *dptr, *n1; 4904 struct schedstat_cpu *cptr, *n2; 4905 4906 list_for_each_entry_safe(cptr, n2, head, cpu_list) { 4907 list_for_each_entry_safe(dptr, n1, &cptr->domain_head, domain_list) { 4908 list_del_init(&dptr->domain_list); 4909 free(dptr->domain_data); 4910 free(dptr); 4911 } 4912 list_del_init(&cptr->cpu_list); 4913 free(cptr->cpu_data); 4914 free(cptr); 4915 } 4916 } 4917 4918 static int perf_sched__schedstat_report(struct perf_sched *sched) 4919 { 4920 struct cpu_domain_map **cd_map; 4921 struct perf_session *session; 4922 struct target target = {}; 4923 struct perf_data data = { 4924 .path = input_name, 4925 .mode = PERF_DATA_MODE_READ, 4926 }; 4927 int err = 0; 4928 4929 sched->tool.schedstat_cpu = perf_sched__process_schedstat; 4930 sched->tool.schedstat_domain = perf_sched__process_schedstat; 4931 4932 session = perf_session__new(&data, &sched->tool); 4933 if (IS_ERR(session)) { 4934 pr_err("Perf session creation failed.\n"); 4935 return PTR_ERR(session); 4936 } 4937 4938 if (cpu_list) 4939 target.cpu_list = cpu_list; 4940 else 4941 target.system_wide = true; 4942 4943 err = evlist__create_maps(session->evlist, &target); 4944 if (err < 0) 4945 goto out; 4946 4947 user_requested_cpus = evlist__core(session->evlist)->user_requested_cpus; 4948 4949 err = perf_session__process_events(session); 4950 4951 if (!err) { 4952 setup_pager(); 4953 4954 if (list_empty(&cpu_head)) { 4955 pr_err("Data is not available\n"); 4956 err = -1; 4957 goto out; 4958 } 4959 4960 cd_map = session->header.env.cpu_domain; 4961 err = show_schedstat_data(&cpu_head, cd_map, 4962 session->header.env.nr_cpus_avail, 4963 NULL, NULL, 0, false); 4964 } 4965 4966 out: 4967 free_schedstat(&cpu_head); 4968 perf_session__delete(session); 4969 return err; 4970 } 4971 4972 static int perf_sched__schedstat_diff(struct perf_sched *sched, 4973 int argc, const char **argv) 4974 { 4975 struct cpu_domain_map **cd_map0 = NULL, **cd_map1 = NULL; 4976 struct list_head cpu_head_ses0, cpu_head_ses1; 4977 struct perf_session *session[2]; 4978 struct perf_data data[2] = {0}; 4979 int ret = 0, err = 0; 4980 static const char *defaults[] = { 4981 "perf.data.old", 4982 "perf.data", 4983 }; 4984 4985 if (argc) { 4986 if (argc == 1) 4987 defaults[1] = argv[0]; 4988 else if (argc == 2) { 4989 defaults[0] = argv[0]; 4990 defaults[1] = argv[1]; 4991 } else { 4992 pr_err("perf sched stats diff is not supported with more than 2 files.\n"); 4993 goto out_ret; 4994 } 4995 } 4996 4997 INIT_LIST_HEAD(&cpu_head_ses0); 4998 INIT_LIST_HEAD(&cpu_head_ses1); 4999 5000 sched->tool.schedstat_cpu = perf_sched__process_schedstat; 5001 sched->tool.schedstat_domain = perf_sched__process_schedstat; 5002 5003 data[0].path = defaults[0]; 5004 data[0].mode = PERF_DATA_MODE_READ; 5005 session[0] = perf_session__new(&data[0], &sched->tool); 5006 if (IS_ERR(session[0])) { 5007 ret = PTR_ERR(session[0]); 5008 pr_err("Failed to open %s\n", data[0].path); 5009 goto out_delete_ses0; 5010 } 5011 5012 err = perf_session__process_events(session[0]); 5013 if (err) { 5014 free_schedstat(&cpu_head); 5015 goto out_delete_ses0; 5016 } 5017 5018 cd_map0 = session[0]->header.env.cpu_domain; 5019 list_replace_init(&cpu_head, &cpu_head_ses0); 5020 after_workload_flag = false; 5021 5022 data[1].path = defaults[1]; 5023 data[1].mode = PERF_DATA_MODE_READ; 5024 session[1] = perf_session__new(&data[1], &sched->tool); 5025 if (IS_ERR(session[1])) { 5026 ret = PTR_ERR(session[1]); 5027 pr_err("Failed to open %s\n", data[1].path); 5028 goto out_delete_ses1; 5029 } 5030 5031 err = perf_session__process_events(session[1]); 5032 if (err) { 5033 free_schedstat(&cpu_head); 5034 goto out_delete_ses1; 5035 } 5036 5037 cd_map1 = session[1]->header.env.cpu_domain; 5038 list_replace_init(&cpu_head, &cpu_head_ses1); 5039 after_workload_flag = false; 5040 setup_pager(); 5041 5042 if (list_empty(&cpu_head_ses1)) { 5043 pr_err("Data is not available\n"); 5044 ret = -1; 5045 goto out_delete_ses1; 5046 } 5047 5048 if (list_empty(&cpu_head_ses0)) { 5049 pr_err("Data is not available\n"); 5050 ret = -1; 5051 goto out_delete_ses1; 5052 } 5053 5054 ret = show_schedstat_data(&cpu_head_ses0, cd_map0, session[0]->header.env.nr_cpus_avail, 5055 &cpu_head_ses1, cd_map1, session[1]->header.env.nr_cpus_avail, true); 5056 if (ret) 5057 goto out_delete_ses1; 5058 5059 out_delete_ses1: 5060 free_schedstat(&cpu_head_ses1); 5061 if (!IS_ERR(session[1])) 5062 perf_session__delete(session[1]); 5063 5064 out_delete_ses0: 5065 free_schedstat(&cpu_head_ses0); 5066 if (!IS_ERR(session[0])) 5067 perf_session__delete(session[0]); 5068 5069 out_ret: 5070 return ret; 5071 } 5072 5073 static int process_synthesized_event_live(const struct perf_tool *tool __maybe_unused, 5074 union perf_event *event, 5075 struct perf_sample *sample __maybe_unused, 5076 struct machine *machine __maybe_unused) 5077 { 5078 return perf_sched__process_schedstat(tool, NULL, event); 5079 } 5080 5081 static int perf_sched__schedstat_live(struct perf_sched *sched, 5082 int argc, const char **argv) 5083 { 5084 struct cpu_domain_map **cd_map = NULL; 5085 struct target target = {}; 5086 u32 __maybe_unused md; 5087 struct evlist *evlist; 5088 u32 nr = 0, sv; 5089 int reset = 0; 5090 int err = 0; 5091 5092 done = 0; 5093 signal(SIGINT, sighandler); 5094 signal(SIGCHLD, sighandler); 5095 signal(SIGTERM, sighandler); 5096 5097 evlist = evlist__new(); 5098 if (!evlist) 5099 return -ENOMEM; 5100 5101 /* 5102 * `perf sched schedstat` does not support workload profiling (-p pid) 5103 * since /proc/schedstat file contains cpu specific data only. Hence, a 5104 * profile target is either set of cpus or systemwide, never a process. 5105 * Note that, although `-- <workload>` is supported, profile data are 5106 * still cpu/systemwide. 5107 */ 5108 if (cpu_list) 5109 target.cpu_list = cpu_list; 5110 else 5111 target.system_wide = true; 5112 5113 if (argc) { 5114 err = evlist__prepare_workload(evlist, &target, argv, false, NULL); 5115 if (err) 5116 goto out; 5117 } 5118 5119 err = evlist__create_maps(evlist, &target); 5120 if (err < 0) 5121 goto out; 5122 5123 user_requested_cpus = evlist__core(evlist)->user_requested_cpus; 5124 5125 err = perf_event__synthesize_schedstat(&(sched->tool), 5126 process_synthesized_event_live, 5127 user_requested_cpus); 5128 if (err < 0) 5129 goto out; 5130 5131 err = enable_sched_schedstats(&reset); 5132 if (err < 0) 5133 goto out; 5134 5135 if (argc) 5136 evlist__start_workload(evlist); 5137 5138 while (!done) { 5139 if (argc && waitpid(evlist__workload_pid(evlist), NULL, WNOHANG) > 0) 5140 break; 5141 sleep(1); 5142 } 5143 5144 if (reset) { 5145 err = disable_sched_schedstat(); 5146 if (err < 0) 5147 goto out; 5148 } 5149 5150 err = perf_event__synthesize_schedstat(&(sched->tool), 5151 process_synthesized_event_live, 5152 user_requested_cpus); 5153 if (err) 5154 goto out; 5155 5156 setup_pager(); 5157 5158 if (list_empty(&cpu_head)) { 5159 pr_err("Data is not available\n"); 5160 err = -1; 5161 goto out; 5162 } 5163 5164 nr = cpu__max_present_cpu().cpu; 5165 cd_map = build_cpu_domain_map(&sv, &md, nr); 5166 if (!cd_map) { 5167 pr_err("Unable to generate cpu-domain relation info"); 5168 goto out; 5169 } 5170 5171 err = show_schedstat_data(&cpu_head, cd_map, nr, NULL, NULL, 0, false); 5172 free_cpu_domain_info(cd_map, sv, nr); 5173 out: 5174 free_schedstat(&cpu_head); 5175 evlist__put(evlist); 5176 return err; 5177 } 5178 5179 static bool schedstat_events_exposed(void) 5180 { 5181 /* 5182 * Select "sched:sched_stat_wait" event to check 5183 * whether schedstat tracepoints are exposed. 5184 */ 5185 return IS_ERR(trace_event__tp_format("sched", "sched_stat_wait")) ? 5186 false : true; 5187 } 5188 5189 static int __cmd_record(int argc, const char **argv) 5190 { 5191 unsigned int rec_argc, i, j; 5192 char **rec_argv; 5193 const char **rec_argv_copy; 5194 const char * const record_args[] = { 5195 "record", 5196 "-a", 5197 "-R", 5198 "-m", "1024", 5199 "-c", "1", 5200 "-e", "sched:sched_switch", 5201 "-e", "sched:sched_stat_runtime", 5202 "-e", "sched:sched_process_fork", 5203 "-e", "sched:sched_wakeup_new", 5204 "-e", "sched:sched_migrate_task", 5205 }; 5206 5207 /* 5208 * The tracepoints trace_sched_stat_{wait, sleep, iowait} 5209 * are not exposed to user if CONFIG_SCHEDSTATS is not set, 5210 * to prevent "perf sched record" execution failure, determine 5211 * whether to record schedstat events according to actual situation. 5212 */ 5213 const char * const schedstat_args[] = { 5214 "-e", "sched:sched_stat_wait", 5215 "-e", "sched:sched_stat_sleep", 5216 "-e", "sched:sched_stat_iowait", 5217 }; 5218 unsigned int schedstat_argc = schedstat_events_exposed() ? 5219 ARRAY_SIZE(schedstat_args) : 0; 5220 5221 struct tep_event *waking_event; 5222 int ret; 5223 5224 /* 5225 * +2 for either "-e", "sched:sched_wakeup" or 5226 * "-e", "sched:sched_waking" 5227 */ 5228 rec_argc = ARRAY_SIZE(record_args) + 2 + schedstat_argc + argc - 1; 5229 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 5230 if (rec_argv == NULL) 5231 return -ENOMEM; 5232 rec_argv_copy = calloc(rec_argc + 1, sizeof(char *)); 5233 if (rec_argv_copy == NULL) { 5234 free(rec_argv); 5235 return -ENOMEM; 5236 } 5237 5238 for (i = 0; i < ARRAY_SIZE(record_args); i++) 5239 rec_argv[i] = strdup(record_args[i]); 5240 5241 rec_argv[i++] = strdup("-e"); 5242 waking_event = trace_event__tp_format("sched", "sched_waking"); 5243 if (!IS_ERR(waking_event)) 5244 rec_argv[i++] = strdup("sched:sched_waking"); 5245 else 5246 rec_argv[i++] = strdup("sched:sched_wakeup"); 5247 5248 for (j = 0; j < schedstat_argc; j++) 5249 rec_argv[i++] = strdup(schedstat_args[j]); 5250 5251 for (j = 1; j < (unsigned int)argc; j++, i++) 5252 rec_argv[i] = strdup(argv[j]); 5253 5254 BUG_ON(i != rec_argc); 5255 5256 memcpy(rec_argv_copy, rec_argv, sizeof(char *) * rec_argc); 5257 ret = cmd_record(rec_argc, rec_argv_copy); 5258 5259 for (i = 0; i < rec_argc; i++) 5260 free(rec_argv[i]); 5261 free(rec_argv); 5262 free(rec_argv_copy); 5263 5264 return ret; 5265 } 5266 5267 int cmd_sched(int argc, const char **argv) 5268 { 5269 static const char default_sort_order[] = "avg, max, switch, runtime"; 5270 struct perf_sched sched = { 5271 .cmp_pid = LIST_HEAD_INIT(sched.cmp_pid), 5272 .sort_list = LIST_HEAD_INIT(sched.sort_list), 5273 .sort_order = default_sort_order, 5274 .replay_repeat = 10, 5275 .profile_cpu = -1, 5276 .next_shortname1 = 'A', 5277 .next_shortname2 = '0', 5278 .skip_merge = 0, 5279 .show_callchain = 1, 5280 .max_stack = 5, 5281 }; 5282 const struct option sched_options[] = { 5283 OPT_STRING('i', "input", &input_name, "file", 5284 "input file name"), 5285 OPT_INCR('v', "verbose", &verbose, 5286 "be more verbose (show symbol address, etc)"), 5287 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 5288 "dump raw trace in ASCII"), 5289 OPT_BOOLEAN('f', "force", &sched.force, "don't complain, do it"), 5290 OPT_END() 5291 }; 5292 const struct option latency_options[] = { 5293 OPT_STRING('s', "sort", &sched.sort_order, "key[,key2...]", 5294 "sort by key(s): runtime, switch, avg, max"), 5295 OPT_INTEGER('C', "CPU", &sched.profile_cpu, 5296 "CPU to profile on"), 5297 OPT_BOOLEAN('p', "pids", &sched.skip_merge, 5298 "latency stats per pid instead of per comm"), 5299 OPT_BOOLEAN('H', "histogram", &sched.show_histogram, 5300 "show CPU wait latency distribution histogram"), 5301 OPT_STRING(0, "hist-mode", &sched.hist_mode_str, "log|linear", 5302 "latency bucket mode (log or linear, default: log)"), 5303 OPT_STRING(0, "time", &sched.time_str, "str", 5304 "Time span for analysis (start,stop)"), 5305 OPT_PARENT(sched_options) 5306 }; 5307 const struct option replay_options[] = { 5308 OPT_UINTEGER('r', "repeat", &sched.replay_repeat, 5309 "repeat the workload replay N times (0: infinite)"), 5310 OPT_PARENT(sched_options) 5311 }; 5312 const struct option map_options[] = { 5313 OPT_BOOLEAN(0, "compact", &sched.map.comp, 5314 "map output in compact mode"), 5315 OPT_STRING(0, "color-pids", &sched.map.color_pids_str, "pids", 5316 "highlight given pids in map"), 5317 OPT_STRING(0, "color-cpus", &sched.map.color_cpus_str, "cpus", 5318 "highlight given CPUs in map"), 5319 OPT_STRING(0, "cpus", &sched.map.cpus_str, "cpus", 5320 "display given CPUs in map"), 5321 OPT_STRING(0, "task-name", &sched.map.task_name, "task", 5322 "map output only for the given task name(s)."), 5323 OPT_BOOLEAN(0, "fuzzy-name", &sched.map.fuzzy, 5324 "given command name can be partially matched (fuzzy matching)"), 5325 OPT_PARENT(sched_options) 5326 }; 5327 const struct option timehist_options[] = { 5328 OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name, 5329 "file", "vmlinux pathname"), 5330 OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name, 5331 "file", "kallsyms pathname"), 5332 OPT_BOOLEAN('g', "call-graph", &sched.show_callchain, 5333 "Display call chains if present (default on)"), 5334 OPT_UINTEGER(0, "max-stack", &sched.max_stack, 5335 "Maximum number of functions to display backtrace."), 5336 OPT_CALLBACK(0, "symfs", NULL, "directory[,layout]", SYMFS_HELP, 5337 symbol__config_symfs), 5338 OPT_BOOLEAN('s', "summary", &sched.summary_only, 5339 "Show only syscall summary with statistics"), 5340 OPT_BOOLEAN('S', "with-summary", &sched.summary, 5341 "Show all syscalls and summary with statistics"), 5342 OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"), 5343 OPT_BOOLEAN('n', "next", &sched.show_next, "Show next task"), 5344 OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"), 5345 OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"), 5346 OPT_BOOLEAN('I', "idle-hist", &sched.idle_hist, "Show idle events only"), 5347 OPT_STRING(0, "time", &sched.time_str, "str", 5348 "Time span for analysis (start,stop)"), 5349 OPT_BOOLEAN(0, "state", &sched.show_state, "Show task state when sched-out"), 5350 OPT_STRING('p', "pid", &symbol_conf.pid_list_str, "pid[,pid...]", 5351 "analyze events only for given process id(s)"), 5352 OPT_STRING('t', "tid", &symbol_conf.tid_list_str, "tid[,tid...]", 5353 "analyze events only for given thread id(s)"), 5354 OPT_STRING('C', "cpu", &cpu_list, "cpu", "list of cpus to profile"), 5355 OPT_BOOLEAN(0, "show-prio", &sched.show_prio, "Show task priority"), 5356 OPT_STRING(0, "prio", &sched.prio_str, "prio", 5357 "analyze events only for given task priority(ies)"), 5358 OPT_BOOLEAN('P', "pre-migrations", &sched.pre_migrations, "Show pre-migration wait time"), 5359 OPT_PARENT(sched_options) 5360 }; 5361 const struct option stats_options[] = { 5362 OPT_STRING('i', "input", &input_name, "file", 5363 "`stats report` with input filename"), 5364 OPT_STRING('o', "output", &output_name, "file", 5365 "`stats record` with output filename"), 5366 OPT_STRING('C', "cpu", &cpu_list, "cpu", "list of cpus to profile"), 5367 OPT_BOOLEAN('v', "verbose", &verbose_field, "Show explanation for fields in the report"), 5368 OPT_END() 5369 }; 5370 5371 const char * const latency_usage[] = { 5372 "perf sched latency [<options>]", 5373 NULL 5374 }; 5375 const char * const replay_usage[] = { 5376 "perf sched replay [<options>]", 5377 NULL 5378 }; 5379 const char * const map_usage[] = { 5380 "perf sched map [<options>]", 5381 NULL 5382 }; 5383 const char * const timehist_usage[] = { 5384 "perf sched timehist [<options>]", 5385 NULL 5386 }; 5387 const char *stats_usage[] = { 5388 "perf sched stats {record|report} [<options>]", 5389 NULL 5390 }; 5391 const char *const sched_subcommands[] = { "record", "latency", "map", 5392 "replay", "script", 5393 "timehist", "stats", NULL }; 5394 const char *sched_usage[] = { 5395 NULL, 5396 NULL 5397 }; 5398 struct trace_sched_handler lat_ops = { 5399 .wakeup_event = latency_wakeup_event, 5400 .switch_event = latency_switch_event, 5401 .runtime_event = latency_runtime_event, 5402 .migrate_task_event = latency_migrate_task_event, 5403 }; 5404 struct trace_sched_handler map_ops = { 5405 .switch_event = map_switch_event, 5406 }; 5407 struct trace_sched_handler replay_ops = { 5408 .wakeup_event = replay_wakeup_event, 5409 .switch_event = replay_switch_event, 5410 .fork_event = replay_fork_event, 5411 }; 5412 struct trace_sched_handler stats_ops = {}; 5413 int ret; 5414 5415 perf_tool__init(&sched.tool, /*ordered_events=*/true); 5416 sched.tool.sample = perf_sched__process_tracepoint_sample; 5417 sched.tool.comm = perf_sched__process_comm; 5418 sched.tool.namespaces = perf_event__process_namespaces; 5419 sched.tool.lost = perf_event__process_lost; 5420 sched.tool.fork = perf_sched__process_fork_event; 5421 sched.tool.attr = perf_event__process_attr; 5422 sched.tool.tracing_data = perf_event__process_tracing_data; 5423 sched.tool.build_id = perf_event__process_build_id; 5424 sched.tool.feature = perf_event__process_feature; 5425 5426 argc = parse_options_subcommand(argc, argv, sched_options, sched_subcommands, 5427 sched_usage, PARSE_OPT_STOP_AT_NON_OPTION); 5428 if (!argc) 5429 usage_with_options(sched_usage, sched_options); 5430 5431 thread__set_priv_destructor(free); 5432 5433 /* 5434 * Aliased to 'perf script' for now: 5435 */ 5436 if (!strcmp(argv[0], "script")) { 5437 ret = cmd_script(argc, argv); 5438 } else if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) { 5439 ret = __cmd_record(argc, argv); 5440 } else if (strlen(argv[0]) > 2 && strstarts("latency", argv[0])) { 5441 sched.tp_handler = &lat_ops; 5442 if (argc > 1) { 5443 argc = parse_options(argc, argv, latency_options, latency_usage, 0); 5444 if (argc) 5445 usage_with_options(latency_usage, latency_options); 5446 } 5447 setup_sorting(&sched, latency_options, latency_usage); 5448 ret = perf_sched__lat(&sched); 5449 } else if (!strcmp(argv[0], "map")) { 5450 if (argc) { 5451 argc = parse_options(argc, argv, map_options, map_usage, 0); 5452 if (argc) 5453 usage_with_options(map_usage, map_options); 5454 5455 if (sched.map.task_name) { 5456 sched.map.task_names = strlist__new(sched.map.task_name, NULL); 5457 if (sched.map.task_names == NULL) { 5458 fprintf(stderr, "Failed to parse task names\n"); 5459 ret = -1; 5460 goto out; 5461 } 5462 } 5463 } 5464 sched.tp_handler = &map_ops; 5465 setup_sorting(&sched, latency_options, latency_usage); 5466 ret = perf_sched__map(&sched); 5467 } else if (strlen(argv[0]) > 2 && strstarts("replay", argv[0])) { 5468 sched.tp_handler = &replay_ops; 5469 if (argc) { 5470 argc = parse_options(argc, argv, replay_options, replay_usage, 0); 5471 if (argc) 5472 usage_with_options(replay_usage, replay_options); 5473 } 5474 ret = perf_sched__replay(&sched); 5475 } else if (!strcmp(argv[0], "timehist")) { 5476 if (argc) { 5477 argc = parse_options(argc, argv, timehist_options, 5478 timehist_usage, 0); 5479 if (argc) 5480 usage_with_options(timehist_usage, timehist_options); 5481 } 5482 if ((sched.show_wakeups || sched.show_next) && 5483 sched.summary_only) { 5484 pr_err(" Error: -s and -[n|w] are mutually exclusive.\n"); 5485 parse_options_usage(timehist_usage, timehist_options, "s", true); 5486 if (sched.show_wakeups) 5487 parse_options_usage(NULL, timehist_options, "w", true); 5488 if (sched.show_next) 5489 parse_options_usage(NULL, timehist_options, "n", true); 5490 ret = -EINVAL; 5491 goto out; 5492 } 5493 ret = symbol__validate_sym_arguments(); 5494 if (!ret) 5495 ret = perf_sched__timehist(&sched); 5496 } else if (!strcmp(argv[0], "stats")) { 5497 const char *const stats_subcommands[] = {"record", "report", NULL}; 5498 5499 sched.tp_handler = &stats_ops; 5500 argc = parse_options_subcommand(argc, argv, stats_options, 5501 stats_subcommands, 5502 stats_usage, 5503 PARSE_OPT_STOP_AT_NON_OPTION); 5504 5505 if (argv[0] && !strcmp(argv[0], "record")) { 5506 if (argc) 5507 argc = parse_options(argc, argv, stats_options, 5508 stats_usage, 0); 5509 ret = perf_sched__schedstat_record(&sched, argc, argv); 5510 } else if (argv[0] && !strcmp(argv[0], "report")) { 5511 if (argc) 5512 argc = parse_options(argc, argv, stats_options, 5513 stats_usage, 0); 5514 ret = perf_sched__schedstat_report(&sched); 5515 } else if (argv[0] && !strcmp(argv[0], "diff")) { 5516 if (argc) 5517 argc = parse_options(argc, argv, stats_options, 5518 stats_usage, 0); 5519 ret = perf_sched__schedstat_diff(&sched, argc, argv); 5520 } else { 5521 ret = perf_sched__schedstat_live(&sched, argc, argv); 5522 } 5523 } else { 5524 usage_with_options(sched_usage, sched_options); 5525 } 5526 5527 out: 5528 /* free usage string allocated by parse_options_subcommand */ 5529 free((void *)sched_usage[0]); 5530 5531 return ret; 5532 } 5533