Messages in this thread |  | | From | "liwei (GF)" <> | Subject | Re: [RFC PATCH] perf tools: cs-etm: fix endless record after being terminated | Date | Mon, 6 Jan 2020 11:00:19 +0800 |
| |
Hi Leo,
Thanks for your test and sorry for missing the reproducing info. The attachment is my test procedure, i can reproduce this issue with it on kernel 5.5-rc4 definitely.
I have tested these patches on kernel 5.5-rc4, with intel-pt on Xeon Gold 6140 (72 cores) and arm-spe on HiSilicon Hi1620 (128 cores). But i can not test CoreSight temporarily, could you please test it with the test procedure again?
P.s. Running the test procedure as a normal process is enough.
Thanks, Wei
On 2020/1/3 16:24, Leo Yan wrote:
> > I took some time to test on Arm CoreSight, the perf program can be > terminated by Ctrl+c with SIGINT signal on the mainline kernel. > > And after capturing ftrace data with below log: > > 5242 migration/2-19 [002] d..3 4648.383155: sched_migrate_task: comm=perf pid=1692 prio=120 orig_cpu=2 dest_cpu=0 > 5243 migration/2-19 [002] d..2 4648.383167: sched_switch: prev_comm=migration/2 prev_pid=19 prev_prio=0 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120 > 5244 <idle>-0 [000] d..2 4648.383167: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=1692 next_prio=120 > 5245 perf-1692 [000] d..2 4648.383193: sched_stat_runtime: comm=perf pid=1692 runtime=35420 [ns] vruntime=1636633943 [ns] > 5246 perf-1692 [000] d..3 4648.383200: sched_waking: comm=migration/0 pid=11 prio=0 target_cpu=000 > 5247 perf-1692 [000] dN.4 4648.383203: sched_wakeup: comm=migration/0 pid=11 prio=0 target_cpu=000 > 5248 perf-1692 [000] dN.2 4648.383205: sched_stat_runtime: comm=perf pid=1692 runtime=9340 [ns] vruntime=1636643283 [ns] > 5249 perf-1692 [000] d..2 4648.383208: sched_switch: prev_comm=perf prev_pid=1692 prev_prio=120 prev_state=R+ ==> next_comm=migration/0 next_pid=11 next_prio=0 > 5250 migration/0-11 [000] d..3 4648.383215: sched_migrate_task: comm=perf pid=1692 prio=120 orig_cpu=0 dest_cpu=1 > 5251 algorithm1-721 [001] dN.2 4648.383225: sched_stat_runtime: comm=algorithm1 pid=721 runtime=2906000 [ns] vruntime=3501282256244 [ns] > 5252 algorithm1-721 [001] d..2 4648.383229: sched_switch: prev_comm=algorithm1 prev_pid=721 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=1692 next_prio=120 > 5253 migration/0-11 [000] d..2 4648.383235: sched_switch: prev_comm=migration/0 prev_pid=11 prev_prio=0 prev_state=S ==> next_comm=swapper/0 next_pid=0 next_prio=120 > 5254 algorithm1-721 [001] d..4 4648.383241: <stack trace> > 5255 => kprobe_breakpoint_handler > 5256 => call_break_hook > 5257 => brk_handler > 5258 => do_debug_exception > 5259 => el1_sync_handler > 5260 => el1_sync > 5261 => etm_event_stop > 5262 => event_sched_out.isra.106 > 5263 => group_sched_out.part.108 > 5264 => ctx_sched_out > 5265 => task_ctx_sched_out > 5266 => __perf_event_task_sched_out > 5267 => __schedule > 5268 => schedule > 5269 => do_notify_resume > 5270 => work_pending > > We can see after send SIGINT signal, the process 'perf' will be > migrated from CPU2 to CPU0 (line 5242) and it will preempt process > 'algorithm1' (line 5252); after the process 'algorithm1' is scheduled > out, the function etm_event_stop() will be invoked to stop tracing. > > If we connect with the code in cs_etm_read_finish(), it tries to call > ioctl PERF_EVENT_IOC_ENABLE, but because the process 'algorithm1' is > scheduled out, so the perf event should not be enabled afterwards. > > I may miss something at here ... Could you confirm what's the type of > attached process? normal process or RT process? > > Thanks, > Leo > > P.s. I tested IntelPT with 5.2-rc3 kernel, it also can be terminated > properly. > >> return -EINVAL; >> -- >> 2.17.1 >> > > . >
#define _GNU_SOURCE
#include <stdlib.h> #include <stdio.h> #include <sys/types.h> #include <sys/sysinfo.h> #include <unistd.h> #include <sched.h> #include <ctype.h> #include <string.h> #include <pthread.h>
int num = 0; int test[65535];
int mess_rw(int data) { int i;
while (1) { for (i = 0; i < (sizeof(test) / sizeof(test[0])); i++) { if (test[i] != data) test[i] = data; } } }
void *test_thread(void *arg) { int cpu = *(int *)arg; cpu_set_t mask;
CPU_ZERO(&mask); CPU_SET(cpu, &mask); if (!sched_setaffinity(0, sizeof(mask), &mask)) printf("thread %d: running on cpu %d\n", cpu, cpu); else printf("thread %d: fail to set CPU affinity\n", cpu);
mess_rw(cpu);
return NULL; }
int main(int argc, char *argv[]) { num = sysconf(_SC_NPROCESSORS_CONF); pthread_t thread[num]; int id[num]; int i;
printf("PID %d on system with %d processor(s)\n", getpid(), num);
for (i = 0; i < num; i++) { id[i] = i; pthread_create(&thread[i], NULL, test_thread, (void *)&id[i]); }
for (i = 0; i < num; i++) { pthread_join(thread[i], NULL); }
return 0; }
|  |