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.

>
> 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