Adrian Hunter
fc18380fb9
perf script: Display negative tid in non-sample events
The kernel can release tasks while they are still running. This can
result in a task having no tid, in which case perf records a tid of -1.
Improve the perf script output in that case.
Example:
Before:
# cat ./autoreap.c
#include <sys/types.h>
#include <unistd.h>
#include <sys/wait.h>
#include <signal.h>
struct sigaction act = {
.sa_handler = SIG_IGN,
};
int main()
{
pid_t child;
int status = 0;
sigaction(SIGCHLD, &act, NULL);
child = fork();
if (child == 0)
return 123;
wait(&status);
return 0;
}
# gcc -o autoreap autoreap.c
# ./perf record -a -e dummy --switch-events ./autoreap
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.948 MB perf.data ]
# ./perf script --show-task-events --show-switch-events | grep -C2 'autoreap\|4294967295\|-1'
swapper 0 [004] 18462.673613: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25189/25189
perf 25189 [004] 18462.673614: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
autoreap 25189 [004] 18462.673800: PERF_RECORD_COMM exec: autoreap:25189/25189
autoreap 25189 [004] 18462.674042: PERF_RECORD_FORK(25191:25191):(25189:25189)
autoreap 25189 [004] 18462.674050: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [004] 18462.674051: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 25189/25189
swapper 0 [005] 18462.674083: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25191/25191
autoreap 25191 [005] 18462.674084: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
swapper 0 [003] 18462.674121: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 11/11
rcu_preempt 11 [003] 18462.674121: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
rcu_preempt 11 [003] 18462.674124: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [003] 18462.674124: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 11/11
autoreap 25191 [005] 18462.674138: PERF_RECORD_EXIT(25191:25191):(25189:25189)
PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [005] 18462.674149: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 4294967295/4294967295
swapper 0 [004] 18462.674182: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25189/25189
autoreap 25189 [004] 18462.674183: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
autoreap 25189 [004] 18462.674218: PERF_RECORD_EXIT(25189:25189):(25188:25188)
autoreap 25189 [004] 18462.674225: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [004] 18462.674226: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 25189/25189
swapper 0 [007] 18462.674257: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25188/25188
After:
# ./perf script --show-task-events --show-switch-events | grep -C2 'autoreap\|4294967295\|-1'
swapper 0 [004] 18462.673613: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25189/25189
perf 25189 [004] 18462.673614: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
autoreap 25189 [004] 18462.673800: PERF_RECORD_COMM exec: autoreap:25189/25189
autoreap 25189 [004] 18462.674042: PERF_RECORD_FORK(25191:25191):(25189:25189)
autoreap 25189 [004] 18462.674050: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [004] 18462.674051: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 25189/25189
swapper 0 [005] 18462.674083: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25191/25191
autoreap 25191 [005] 18462.674084: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
swapper 0 [003] 18462.674121: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 11/11
rcu_preempt 11 [003] 18462.674121: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
rcu_preempt 11 [003] 18462.674124: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [003] 18462.674124: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 11/11
autoreap 25191 [005] 18462.674138: PERF_RECORD_EXIT(25191:25191):(25189:25189)
:-1 -1 [005] 18462.674149: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [005] 18462.674149: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: -1/-1
swapper 0 [004] 18462.674182: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25189/25189
autoreap 25189 [004] 18462.674183: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
autoreap 25189 [004] 18462.674218: PERF_RECORD_EXIT(25189:25189):(25188:25188)
autoreap 25189 [004] 18462.674225: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [004] 18462.674226: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 25189/25189
swapper 0 [007] 18462.674257: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 25188/25188
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Yu-cheng Yu <yu-cheng.yu@intel.com>
Link: http://lore.kernel.org/lkml/20200909084923.9096-2-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2020-09-17 16:06:22 -03:00
..
2020-09-17 15:47:58 -03:00
2020-09-14 18:30:26 -03:00
2020-09-17 16:03:31 -03:00
2020-01-28 16:02:33 -08:00
2020-02-18 10:13:28 -03:00
2020-05-29 16:51:38 -03:00
2020-09-17 15:45:05 -03:00
2019-06-05 17:37:14 +02:00
2020-07-03 08:19:52 -03:00
2020-09-17 15:48:49 -03:00
2020-08-12 08:43:51 -03:00
2020-09-01 12:15:52 -03:00
2020-09-17 16:06:22 -03:00
2020-03-25 11:50:48 +01:00
2019-02-14 15:18:08 -03:00
2020-05-28 10:03:24 -03:00
2020-07-31 09:32:11 -03:00
2019-09-20 15:58:11 -03:00
2019-09-20 15:58:11 -03:00
2020-06-22 16:28:09 -03:00
2019-09-20 09:19:20 -03:00
2020-08-06 09:43:37 -03:00
2020-05-05 16:35:31 -03:00
2020-05-28 10:03:24 -03:00
2020-09-04 16:11:16 -03:00
2019-08-31 19:10:19 -03:00
2020-07-08 13:51:12 -03:00
2019-08-31 22:24:10 -03:00
2020-07-10 09:37:55 -03:00
2020-06-22 16:28:09 -03:00
2020-09-09 11:12:10 -03:00
2020-05-05 16:35:31 -03:00
2020-05-28 10:03:25 -03:00
2020-05-28 10:03:24 -03:00
2020-09-04 16:11:16 -03:00
2020-09-01 12:20:25 -03:00
2020-08-21 10:22:23 -03:00
2020-09-17 16:06:22 -03:00
2020-09-17 15:48:08 -03:00
2020-05-28 10:03:27 -03:00
2020-08-21 10:22:23 -03:00
2020-08-04 08:50:04 -03:00
2020-09-04 17:11:59 -03:00
2019-08-28 17:19:34 -03:00
2020-08-12 08:43:51 -03:00
2018-09-19 14:53:36 -03:00
2020-04-16 12:19:08 -03:00
2020-03-06 17:08:28 -03:00
2020-09-04 17:11:59 -03:00
2020-09-04 17:11:59 -03:00
2020-01-06 11:46:09 -03:00
2019-01-08 13:28:13 -03:00
2020-09-10 11:55:37 -03:00
2019-06-17 12:29:16 +02:00
2019-09-25 09:51:49 -03:00
2019-08-29 17:38:32 -03:00