Skip to content

Commit 3116d60

Browse files
vineethribmnamhyung
authored andcommitted
perf sched map: Add task-name option to filter the output map
By default, perf sched map prints sched-in events for all the tasks which may not be required all the time as it prints lot of symbols and rows to the terminal. With --task-name option, one could specify the specific task name for which the map has to be shown. This would help in analyzing the CPU usage patterns easier for that specific task. Since multiple PID's might have the same task name, using task-name filter would be more useful for debugging. For other tasks, instead of printing the symbol, '-' is printed and the same '.' is used to represent idle. '-' is used instead of symbol for other tasks because it helps in clear visualization of task of interest and secondly the symbol itself doesn't mean anything because the sched-in of that symbol will not be printed(first sched-in contains pid and the corresponding symbol). When using the --task-name option, the sched-out time is represented by a '*-'. Since not all task sched-in events are printed, the sched-out time of the relevant task might be lost. This representation ensures that the sched-out time of the interested task is not overlooked. 6.10.0-rc1 ========== *A0 131040.639793 secs A0 => migration/0:19 *. 131040.639801 secs . => swapper:0 . *B0 131040.639830 secs B0 => migration/1:24 . *. 131040.639836 secs . . *C0 131040.640108 secs C0 => migration/2:30 . . *. 131040.640163 secs . . . *D0 131040.640386 secs D0 => migration/3:36 . . . *. 131040.640395 secs 6.10.0-rc1 + patch (--task-name wdavdaemon) ============= . *A0 . . . . - . 131040.641346 secs A0 => wdavdaemon:62509 . A0 *B0 . . . - . 131040.641378 secs B0 => wdavdaemon:62274 - *- B0 . . . - . 131040.641379 secs *C0 . B0 . . . . . 131040.641572 secs C0 => wdavdaemon:62283 C0 . B0 . *D0 . . . 131040.641572 secs D0 => wdavdaemon:62277 C0 . B0 . D0 . *E0 . 131040.641578 secs E0 => wdavdaemon:62270 *- . B0 . D0 . E0 . 131040.641581 secs . . B0 . D0 . *- . 131040.641583 secs Reviewed-and-tested-by: Athira Rajeev <[email protected]> Signed-off-by: Madadi Vineeth Reddy <[email protected]> Cc: Chen Yu <[email protected]> Link: https://lore.kernel.org/r/[email protected] Signed-off-by: Namhyung Kim <[email protected]>
1 parent 1d302f6 commit 3116d60

File tree

2 files changed

+117
-36
lines changed

2 files changed

+117
-36
lines changed

tools/perf/Documentation/perf-sched.txt

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -130,6 +130,12 @@ OPTIONS for 'perf sched map'
130130
--color-pids::
131131
Highlight the given pids.
132132

133+
--task-name <task>::
134+
Map output only for the given task name. The sched-out
135+
time is printed and is represented by '*-' for the given
136+
task name
137+
('-' indicates other tasks while '.' is idle).
138+
133139
OPTIONS for 'perf sched timehist'
134140
---------------------------------
135141
-k::

tools/perf/builtin-sched.c

Lines changed: 111 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -156,6 +156,7 @@ struct perf_sched_map {
156156
const char *color_pids_str;
157157
struct perf_cpu_map *color_cpus;
158158
const char *color_cpus_str;
159+
const char *task_name;
159160
struct perf_cpu_map *cpus;
160161
const char *cpus_str;
161162
};
@@ -177,6 +178,7 @@ struct perf_sched {
177178
struct perf_cpu max_cpu;
178179
u32 *curr_pid;
179180
struct thread **curr_thread;
181+
struct thread **curr_out_thread;
180182
char next_shortname1;
181183
char next_shortname2;
182184
unsigned int replay_repeat;
@@ -1538,23 +1540,75 @@ map__findnew_thread(struct perf_sched *sched, struct machine *machine, pid_t pid
15381540
return thread;
15391541
}
15401542

1543+
static void print_sched_map(struct perf_sched *sched, struct perf_cpu this_cpu, int cpus_nr,
1544+
const char *color, bool sched_out)
1545+
{
1546+
for (int i = 0; i < cpus_nr; i++) {
1547+
struct perf_cpu cpu = {
1548+
.cpu = sched->map.comp ? sched->map.comp_cpus[i].cpu : i,
1549+
};
1550+
struct thread *curr_thread = sched->curr_thread[cpu.cpu];
1551+
struct thread *curr_out_thread = sched->curr_out_thread[cpu.cpu];
1552+
struct thread_runtime *curr_tr;
1553+
const char *pid_color = color;
1554+
const char *cpu_color = color;
1555+
char symbol = ' ';
1556+
struct thread *thread_to_check = sched_out ? curr_out_thread : curr_thread;
1557+
1558+
if (thread_to_check && thread__has_color(thread_to_check))
1559+
pid_color = COLOR_PIDS;
1560+
1561+
if (sched->map.color_cpus && perf_cpu_map__has(sched->map.color_cpus, cpu))
1562+
cpu_color = COLOR_CPUS;
1563+
1564+
if (cpu.cpu == this_cpu.cpu)
1565+
symbol = '*';
1566+
1567+
color_fprintf(stdout, cpu.cpu != this_cpu.cpu ? color : cpu_color, "%c", symbol);
1568+
1569+
thread_to_check = sched_out ? sched->curr_out_thread[cpu.cpu] :
1570+
sched->curr_thread[cpu.cpu];
1571+
1572+
if (thread_to_check) {
1573+
curr_tr = thread__get_runtime(thread_to_check);
1574+
if (curr_tr == NULL)
1575+
return;
1576+
1577+
if (sched_out) {
1578+
if (cpu.cpu == this_cpu.cpu)
1579+
color_fprintf(stdout, color, "- ");
1580+
else {
1581+
curr_tr = thread__get_runtime(sched->curr_thread[cpu.cpu]);
1582+
if (curr_tr != NULL)
1583+
color_fprintf(stdout, pid_color, "%2s ",
1584+
curr_tr->shortname);
1585+
}
1586+
} else
1587+
color_fprintf(stdout, pid_color, "%2s ", curr_tr->shortname);
1588+
} else
1589+
color_fprintf(stdout, color, " ");
1590+
}
1591+
}
1592+
15411593
static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
15421594
struct perf_sample *sample, struct machine *machine)
15431595
{
15441596
const u32 next_pid = evsel__intval(evsel, sample, "next_pid");
1545-
struct thread *sched_in;
1597+
const u32 prev_pid = evsel__intval(evsel, sample, "prev_pid");
1598+
struct thread *sched_in, *sched_out;
15461599
struct thread_runtime *tr;
15471600
int new_shortname;
15481601
u64 timestamp0, timestamp = sample->time;
15491602
s64 delta;
1550-
int i;
15511603
struct perf_cpu this_cpu = {
15521604
.cpu = sample->cpu,
15531605
};
15541606
int cpus_nr;
1607+
int proceed;
15551608
bool new_cpu = false;
15561609
const char *color = PERF_COLOR_NORMAL;
15571610
char stimestamp[32];
1611+
const char *str;
15581612

15591613
BUG_ON(this_cpu.cpu >= MAX_CPUS || this_cpu.cpu < 0);
15601614

@@ -1583,7 +1637,8 @@ static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
15831637
}
15841638

15851639
sched_in = map__findnew_thread(sched, machine, -1, next_pid);
1586-
if (sched_in == NULL)
1640+
sched_out = map__findnew_thread(sched, machine, -1, prev_pid);
1641+
if (sched_in == NULL || sched_out == NULL)
15871642
return -1;
15881643

15891644
tr = thread__get_runtime(sched_in);
@@ -1593,7 +1648,9 @@ static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
15931648
}
15941649

15951650
sched->curr_thread[this_cpu.cpu] = thread__get(sched_in);
1651+
sched->curr_out_thread[this_cpu.cpu] = thread__get(sched_out);
15961652

1653+
str = thread__comm_str(sched_in);
15971654
new_shortname = 0;
15981655
if (!tr->shortname[0]) {
15991656
if (!strcmp(thread__comm_str(sched_in), "swapper")) {
@@ -1603,7 +1660,7 @@ static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
16031660
*/
16041661
tr->shortname[0] = '.';
16051662
tr->shortname[1] = ' ';
1606-
} else {
1663+
} else if (!sched->map.task_name || !strcmp(str, sched->map.task_name)) {
16071664
tr->shortname[0] = sched->next_shortname1;
16081665
tr->shortname[1] = sched->next_shortname2;
16091666

@@ -1616,49 +1673,38 @@ static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
16161673
else
16171674
sched->next_shortname2 = '0';
16181675
}
1676+
} else {
1677+
tr->shortname[0] = '-';
1678+
tr->shortname[1] = ' ';
16191679
}
16201680
new_shortname = 1;
16211681
}
16221682

16231683
if (sched->map.cpus && !perf_cpu_map__has(sched->map.cpus, this_cpu))
16241684
goto out;
16251685

1626-
printf(" ");
1627-
1628-
for (i = 0; i < cpus_nr; i++) {
1629-
struct perf_cpu cpu = {
1630-
.cpu = sched->map.comp ? sched->map.comp_cpus[i].cpu : i,
1631-
};
1632-
struct thread *curr_thread = sched->curr_thread[cpu.cpu];
1633-
struct thread_runtime *curr_tr;
1634-
const char *pid_color = color;
1635-
const char *cpu_color = color;
1636-
1637-
if (curr_thread && thread__has_color(curr_thread))
1638-
pid_color = COLOR_PIDS;
1639-
1640-
if (sched->map.cpus && !perf_cpu_map__has(sched->map.cpus, cpu))
1641-
continue;
1642-
1643-
if (sched->map.color_cpus && perf_cpu_map__has(sched->map.color_cpus, cpu))
1644-
cpu_color = COLOR_CPUS;
1645-
1646-
if (cpu.cpu != this_cpu.cpu)
1647-
color_fprintf(stdout, color, " ");
1686+
proceed = 0;
1687+
str = thread__comm_str(sched_in);
1688+
/*
1689+
* Check which of sched_in and sched_out matches the passed --task-name
1690+
* arguments and call the corresponding print_sched_map.
1691+
*/
1692+
if (sched->map.task_name && strcmp(str, sched->map.task_name)) {
1693+
if (strcmp(thread__comm_str(sched_out), sched->map.task_name))
1694+
goto out;
16481695
else
1649-
color_fprintf(stdout, cpu_color, "*");
1696+
goto sched_out;
16501697

1651-
if (sched->curr_thread[cpu.cpu]) {
1652-
curr_tr = thread__get_runtime(sched->curr_thread[cpu.cpu]);
1653-
if (curr_tr == NULL) {
1654-
thread__put(sched_in);
1655-
return -1;
1656-
}
1657-
color_fprintf(stdout, pid_color, "%2s ", curr_tr->shortname);
1658-
} else
1659-
color_fprintf(stdout, color, " ");
1698+
} else {
1699+
str = thread__comm_str(sched_out);
1700+
if (!(sched->map.task_name && strcmp(str, sched->map.task_name)))
1701+
proceed = 1;
16601702
}
16611703

1704+
printf(" ");
1705+
1706+
print_sched_map(sched, this_cpu, cpus_nr, color, false);
1707+
16621708
timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp));
16631709
color_fprintf(stdout, color, " %12s secs ", stimestamp);
16641710
if (new_shortname || tr->comm_changed || (verbose > 0 && thread__tid(sched_in))) {
@@ -1675,9 +1721,32 @@ static int map_switch_event(struct perf_sched *sched, struct evsel *evsel,
16751721
if (sched->map.comp && new_cpu)
16761722
color_fprintf(stdout, color, " (CPU %d)", this_cpu);
16771723

1724+
if (proceed != 1) {
1725+
color_fprintf(stdout, color, "\n");
1726+
goto out;
1727+
}
1728+
1729+
sched_out:
1730+
if (sched->map.task_name) {
1731+
tr = thread__get_runtime(sched->curr_out_thread[this_cpu.cpu]);
1732+
if (strcmp(tr->shortname, "") == 0)
1733+
goto out;
1734+
1735+
if (proceed == 1)
1736+
color_fprintf(stdout, color, "\n");
1737+
1738+
printf(" ");
1739+
print_sched_map(sched, this_cpu, cpus_nr, color, true);
1740+
timestamp__scnprintf_usec(timestamp, stimestamp, sizeof(stimestamp));
1741+
color_fprintf(stdout, color, " %12s secs ", stimestamp);
1742+
}
1743+
16781744
color_fprintf(stdout, color, "\n");
16791745

16801746
out:
1747+
if (sched->map.task_name)
1748+
thread__put(sched_out);
1749+
16811750
thread__put(sched_in);
16821751

16831752
return 0;
@@ -3310,6 +3379,10 @@ static int perf_sched__map(struct perf_sched *sched)
33103379
if (!sched->curr_thread)
33113380
return rc;
33123381

3382+
sched->curr_out_thread = calloc(MAX_CPUS, sizeof(*(sched->curr_out_thread)));
3383+
if (!sched->curr_out_thread)
3384+
return rc;
3385+
33133386
if (setup_cpus_switch_event(sched))
33143387
goto out_free_curr_thread;
33153388

@@ -3566,6 +3639,8 @@ int cmd_sched(int argc, const char **argv)
35663639
"highlight given CPUs in map"),
35673640
OPT_STRING(0, "cpus", &sched.map.cpus_str, "cpus",
35683641
"display given CPUs in map"),
3642+
OPT_STRING(0, "task-name", &sched.map.task_name, "task",
3643+
"map output only for the given task name"),
35693644
OPT_PARENT(sched_options)
35703645
};
35713646
const struct option timehist_options[] = {

0 commit comments

Comments
 (0)