On 21 March 2017 at 05:00, Mike Leach mike.leach@linaro.org wrote:
On 17 March 2017 at 14:28, Mathieu Poirier mathieu.poirier@linaro.org wrote:
On 17 March 2017 at 05:57, Mike Leach mike.leach@linaro.org wrote:
I can confirm this applies and runs OK on my juno-r1 system - linaro gcc6.2 built perf and kernel. (with no hard hang) I am also seeing the additional printout when I do perf report --dump on the collected data.
Perfect - thanks for the confirmation. I'll push to gitHub.
I can also confirm the issue Kim sees when using the 'sudo ./perf record -e cs_etm// uname ' command line.
A sink needs to be specified within the //. Otherwise perf doesn't know what sink to use.
Agreed. A re-test shows that if a sink is enabled using sysfs before 'sudo ./perf record -e cs_etm// uname' , then data is captured and no crash occurs. This matches what the coresight.txt documentation states, though re-enabling this way is required before each run
- a patch to the docs has been submitted to make this clear - along with
the option of defining the sink in the perf command line.
Without pre-enabling, missing the sink between cs_etm// causes the crash. Ideally, bad input should result in an error message. Something worth looking at in future?
When writing the driver I (mistakenly) thought the error message you get from perf was enough. To fix this we need to enhance the flex/bison infrastructure. If you guys think it's absolutely needed I can have a look but I'm pretty sure we can live with it.
On the flip side that part will need a huge overhaul when we add support for the multiple sink - I suggest we tackle it then.
Mathieu
Mike
Mike
On 16 March 2017 at 22:33, Kim Phillips kim.phillips@arm.com wrote:
On Thu, 16 Mar 2017 12:04:33 -0600 Mathieu Poirier mathieu.poirier@linaro.org wrote:
Reported-by: Kim Phillips kim.phillips@arm.com Signed-off-by: Mathieu Poirier mathieu.poirier@linaro.org
I wish I'd be able to add my Tested-by:, but unfortunately, I can't:
When I build perf natively with gcc 6.3, with this patch:
kim@juno perf perf-opencsd-4.11-rc1$ strings -a ./perf | grep GCC | head -1 GCC: (Debian 6.3.0-6) 6.3.0 20170205
and invoke perf slightly differently than in the other thread (no tasksets, no etr spec), I get the memory allocation failure:
kim@juno perf perf-opencsd-4.11-rc1$ sudo ./perf record -e cs_etm// uname failed to mmap with 12 (Cannot allocate memory) kim@juno perf perf-opencsd-4.11-rc1$ uname -a Linux juno 4.11.0-rc1-g8e9e2e2 #4 SMP PREEMPT Thu Mar 16 15:55:24 CDT 2017 aarch64 GNU/Linux kim@juno perf perf-opencsd-4.11-rc1$ dmesg |grep gcc [ 0.000000] Linux version 4.11.0-rc1-g8e9e2e2 (kim@dupont) (gcc version 4.9.4 20151028 (prerelease) (Linaro GCC 4.9-2016.02) ) #4 SMP PREEMPT Thu Mar 16 15:55:24 CDT 2017
but this time, there is a stacktrace on the serial console:
[ 119.044143] ------------[ cut here ]------------ [ 119.048729] WARNING: CPU: 0 PID: 2819 at ../kernel/workqueue.c:1442 __queue_work+0x3c8/0x478 [ 119.057080] Modules linked in: [ 119.060100] [ 119.061574] CPU: 0 PID: 2819 Comm: perf Not tainted 4.11.0-rc1-g8e9e2e2 #4 [ 119.068376] Hardware name: ARM Juno development board (r2) (DT) [ 119.074232] task: ffff8009732f0c80 task.stack: ffff80097612c000 [ 119.080090] PC is at __queue_work+0x3c8/0x478 [ 119.084400] LR is at __queue_work+0x29c/0x478 [ 119.088709] pc : [<ffff0000080e60c4>] lr : [<ffff0000080e5f98>] pstate: a00001c5 [ 119.096026] sp : ffff80097612fac0 [ 119.099302] x29: ffff80097612fac0 x28: 0000000000000000 [ 119.104560] x27: 0000000000000400 x26: ffff000009157740 [ 119.109818] x25: 0000000000000000 x24: ffff800976804400 [ 119.115075] x23: 0000000000000040 x22: ffff80097fea8280 [ 119.120333] x21: ffff000008fb4000 x20: ffff80097152ad80 [ 119.125591] x19: ffff80097feac100 x18: 0000000000000000 [ 119.130849] x17: 0000ffff7994a7a8 x16: ffff0000080894e0 [ 119.136106] x15: 000000000000013b x14: 0000000000000000 [ 119.141364] x13: 626b5f6b636f6c6d x12: 0000000000000000 [ 119.146621] x11: 0000000000000000 x10: 0000000000000000 [ 119.151879] x9 : 0000000000000000 x8 : ffff80097152ab80 [ 119.157136] x7 : 0000000000000000 x6 : 0000000000000001 [ 119.162393] x5 : 0000000000000000 x4 : 0000000000000000 [ 119.167650] x3 : 0000000000000000 x2 : 0000000000000000 [ 119.172907] x1 : 0000000000000000 x0 : ffff80097152ad88 [ 119.178164] [ 119.179634] ---[ end trace c565de4a9bd0da95 ]--- [ 119.184199] Call trace: [ 119.186618] Exception stack(0xffff80097612f8f0 to 0xffff80097612fa20) [ 119.192991] f8e0: ffff80097feac100 0001000000000000 [ 119.200742] f900: ffff80097612fac0 ffff0000080e60c4 ffff80097612f930 ffff0000081c19e8 [ 119.208492] f920: ffff000009134a80 0000000000000000 ffff80097612fa20 ffff0000081c2370 [ 119.216242] f940: 0000000000000000 ffff000009135780 0000000000000001 0000000000000000 [ 119.223992] f960: ffff800972500000 0000000000000020 0000000000000000 00000000014092c0 [ 119.231742] f980: ffff800972506000 ffff7e0025c5de00 ffff80097152ad88 0000000000000000 [ 119.239491] f9a0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 [ 119.247241] f9c0: 0000000000000001 0000000000000000 ffff80097152ab80 0000000000000000 [ 119.254991] f9e0: 0000000000000000 0000000000000000 0000000000000000 626b5f6b636f6c6d [ 119.262741] fa00: 0000000000000000 000000000000013b ffff0000080894e0 0000ffff7994a7a8 [ 119.270490] [<ffff0000080e60c4>] __queue_work+0x3c8/0x478 [ 119.275833] [<ffff0000080e61c4>] queue_work_on+0x50/0x6c [ 119.281092] [<ffff0000088d76b4>] etm_setup_aux+0x168/0x208 [ 119.286523] [<ffff0000081b30b0>] rb_alloc_aux+0x230/0x2b4 [ 119.291866] [<ffff0000081ae418>] perf_mmap+0x408/0x558 [ 119.296952] [<ffff0000081fc5f8>] mmap_region+0x340/0x55c [ 119.302209] [<ffff0000081fcb00>] do_mmap+0x2ec/0x394 [ 119.307122] [<ffff0000081dcce4>] vm_mmap_pgoff+0xcc/0xf0 [ 119.312379] [<ffff0000081fa53c>] SyS_mmap_pgoff+0xb0/0x23c [ 119.317809] [<ffff000008089538>] sys_mmap+0x58/0x74 [ 119.322636] [<ffff000008083730>] el0_svc_naked+0x24/0x28
It's 100% consistent. I don't expect this to be expected behaviour, esp. given the same way of invocation is in Documentation/trace/coresight.txt:
The Coresight PMUs can be configured to work in "full trace" or "snapshot" mode. In full trace mode trace acquisition is enabled from beginning to end with trace data being recorded continuously:
linaro@linaro-nano:~$ perf record -e cs_etm// dd if=/dev/random of=./test.txt bs=1k count=1000
Resolving the stack address from the etm_setup_aux entry in the stack trace:
kim@dupont juno perf-opencsd-4.11-rc1$ addr2line -e vmlinux ffff0000088d76b4
/home/kim/git/OpenCSD/juno/../drivers/hwtracing/coresight/coresight-etm-perf.c:260
Line 260 is the closing '}' to the function. I'm not sure whether that means it's the INIT_WORK in the function that's not happy with something it was passed?
Looking at kernel/workqueue.c line 1442, it has:
if (WARN_ON(!list_empty(&work->entry))) {
So perhaps one of INIT_WORK's params was NULL? Can you take a look?
btw, thanks for applying Sebastian's 'perf tools: fix printing of auxtrace_info': now, when using the invocation style mentioned in the other thread with Mike Leach (tasksets & etr spec), it makes perf 'finish its sentence' prior to locking up the system:
kim@juno perf perf-opencsd-4.11-rc1$ sudo ./perf record -e cs_etm/@20070000.etr/u --per-thread taskset -c 0 uname Linux [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.021 MB perf.data ]
<hang>
Thanks,
Kim _______________________________________________ CoreSight mailing list CoreSight@lists.linaro.org https://lists.linaro.org/mailman/listinfo/coresight
-- Mike Leach Principal Engineer, ARM Ltd. Blackburn Design Centre. UK
-- Mike Leach Principal Engineer, ARM Ltd. Blackburn Design Centre. UK