| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20200106143717.GC29905@leoy-ThinkPad-X240s>
Date: Mon, 6 Jan 2020 22:37:17 +0800
From: Leo Yan <leo.yan@...aro.org>
To: "liwei (GF)" <liwei391@...wei.com>
Cc: acme@...nel.org, mark.rutland@....com,
alexander.shishkin@...ux.intel.com, jolsa@...hat.com,
namhyung@...nel.org, suzuki.poulose@....com,
mathieu.poirier@...aro.org, ilubashe@...mai.com,
peterz@...radead.org, mingo@...hat.com,
linux-arm-kernel@...ts.infradead.org, linux-kernel@...r.kernel.org,
huawei.libin@...wei.com
Subject: Re: [RFC PATCH] perf tools: cs-etm: fix endless record after being
terminated
Hi Wei,
On Mon, Jan 06, 2020 at 11:00:19AM +0800, liwei (GF) wrote:
> 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?
Thanks for the test code.
I tested it with perf/cs-etm, but cannot reproduce the issue. But after
capturing trace data with trace-cmd, I think this indeed is an
potential issue; the reason for Arm cs-etm cannot produce this issue,
one possibility is because cs-etm doesn't trigger interrupt; if the
interrupt is triggered, perf tool might fail to stop hardware events
with below flow:
Perf thread: Profiled thread(s)
__cmd_record()
evlist__disable()
set_affinity()
migration to prfiled thread's CPU
evsel__disable_cpu()
ioctl(PERF_EVENT_IOC_DISABLE)
Thread is scheduled out
ctx_sched_out()
event_sched_out()
etm4_disable()
record__mmap_read_all()
record__auxtrace_mmap_read()
auxtrace_mmap__read()
itr->read_finish()
cs_etm_read_finish()
ioctl(PERF_EVENT_IOC_ENABLE)
Thread is scheduled in
__perf_event_task_sched_in()
perf_event_sched_in()
event_sched_in()
etm4_enable()
the condition (hits == rec->samples) is
never true, infinite loop in
__cmd_record()
So a minor suggestion for your patch:
diff --git a/tools/perf/arch/arm/util/cs-etm.c b/tools/perf/arch/arm/util/cs-etm.c
index ede040cf82ad..29c5eefa6e41 100644
--- a/tools/perf/arch/arm/util/cs-etm.c
+++ b/tools/perf/arch/arm/util/cs-etm.c
@@ -864,6 +864,9 @@ static int cs_etm_read_finish(struct auxtrace_record *itr, int idx)
container_of(itr, struct cs_etm_recording, itr);
struct evsel *evsel;
+ if (!ptr->evlist->enabled)
+ return 0;
+
evlist__for_each_entry(ptr->evlist, evsel) {
if (evsel->core.attr.type == ptr->cs_etm_pmu->type)
return perf_evlist__enable_event_idx(ptr->evlist,
I'd like to wait a bit if others can find more general method to fix
this issue.
Thanks,
Leo
> 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;
> }
>
Powered by blists - more mailing lists