Re: Having trouble profiling multiple events for an existing process in ARM CortexA53
William Cohen <[email protected]> Wed, 1 May 2019 13:54:39 -0400
| Newsgroups | gmane.linux.oprofile |
|---|---|
| Message-ID | <[email protected]> |
On 5/1/19 1:41 PM, Jerry Duan via oprofile-list wrote: > Hi Will, > Thanks a lot for your response. > > Two things I just noticed. > The first one is that my issue might have something to do with my particular app (i.e,"myapp"). Because, when I switched to a simple app (i.e, myCacheTest), the issue is gone. Any ideas what could be the cause? > > $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 -p 6247 > operf: Press Ctl-c or 'kill -SIGINT 6250' to stop profiling > operf: Profiler started > ^C > $ opreport > Using /mnt/localdisk/tmp1/oprofile_data/samples/ for samples directory. > CPU: ARM Cortex-A53, speed 1200 MHz (estimated) > Counted L2D_CACHE events (Level 2 data cache access) with a unit mask of 0x00 (No unit mask) count 5000 > Counted L2D_CACHE_REFILL events (Level 2 data cache refill) with a unit mask of 0x00 (No unit mask) count 5000 > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 404764 100.000 2021 100.000 myCacheTest > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 403377 99.6573 1918 94.9035 myCacheTest > 1387 0.3427 103 5.0965 vmlinux-4.9.0 > $ Hi, The problem could be due to the short duration of the task being measured. You should be able to more directly run the experiment with: $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 ./myCacheTest That would ensure oprofile collecting data for the duration of the application. -Will > > The second one is if I use "--system-wide" instead of "-p 3253", the issue is gone too. I mean that it profiles all the processes including the trouble one (i.e, "myapp") > $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 --system-wide > operf: Press Ctl-c or 'kill -SIGINT 6269' to stop profiling > operf: Profiler started > ^C > Profiling done. > $ opreport > Using /mnt/localdisk/tmp1/oprofile_data/samples/ for samples directory. > CPU: ARM Cortex-A53, speed 1200 MHz (estimated) > Counted L2D_CACHE events (Level 2 data cache access) with a unit mask of 0x00 (No unit mask) count 5000 > Counted L2D_CACHE_REFILL events (Level 2 data cache refill) with a unit mask of 0x00 (No unit mask) count 5000 > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 40070 93.4446 4860 90.8241 myapp > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 17237 43.0172 1903 39.1564 myapp > 14090 35.1635 1678 34.5267 vmlinux-4.9.0 > 3609 9.0067 510 10.4938 libc-2.24.so > 2664 6.6484 383 7.8807 libzmq.so.5.0.1 > 1471 3.6711 215 4.4239 libpthread-2.24.so > 429 1.0706 96 1.9753 libczmq.so.4.0.2 > 339 0.8460 37 0.7613 [vdso] (tgid:3253 range:0x7fa4845000-0x7fa4845fff) > 180 0.4492 23 0.4733 libmemTrace.so.0.0.0 > 32 0.0799 7 0.1440 librt-2.24.so > 7 0.0175 1 0.0206 libsystemd.so.0.15.0 > 6 0.0150 4 0.0823 mylib > 4 0.0100 1 0.0206 ld-2.24.so > 2 0.0050 2 0.0412 libcrypto.so.1.0.2 > 1751 4.0834 40 0.7475 operf > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 955 54.5403 23 57.5000 vmlinux-4.9.0 > 479 27.3558 11 27.5000 operf > 273 15.5911 5 12.5000 libc-2.24.so > 42 2.3986 1 2.5000 libstdc++.so.6.0.22 > 2 0.1142 0 0 ld-2.24.so > 386 0.9002 162 3.0275 rcu_sched > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 386 100.000 162 100.000 vmlinux-4.9.0 > 280 0.6530 98 1.8314 tcf-agent > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 181 64.6429 47 47.9592 vmlinux-4.9.0 > 43 15.3571 15 15.3061 libc-2.24.so > 39 13.9286 26 26.5306 tcf-agent > 11 3.9286 5 5.1020 libpthread-2.24.so > 6 2.1429 5 5.1020 [vdso] (tgid:2873 range:0x7f9933d000-0x7f9933dfff) > ... > $ > > I guess that the issue might also have something to do with the "-p <PID>" option, but not sure. > According to 1.3.0 release note, it has the following known issue triggered by "--pid" option, but, it doesn't seem to have the same symptom as mine (i.e, operf just simply failed to start profiling the app). > [ > - Monitoring processes that frequently create and destroy threads via > the "--pid" option can be problematic. The pipes used within operf > and ocount may fill up can cause these programs to hang and require > multiple cntl-C to exit rather than successfully collecting data on > fast spawning processes and children. > ] > > My SoC is zynqmp, and my dmesg output is the following: > [ 30.515339] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available > (BTW, why does it say 7 counters? as you mentioned that all the cortex a53 should have the same pmu with 6 counters) > > My dts/pmu binding has the following: > compatible = "arm,armv8-pmuv3" > Not sure if I have to change to "arm,cortex-a53-pmu", I will give it a try. > > Thanks, > Jerry > > > On Tuesday, April 30, 2019, 9:22:08 p.m. EDT, William Cohen <[email protected]> wrote: > > > On 4/29/19 2:37 PM, Jerry Duan via oprofile-list wrote: > > Hi, > > I am trying to use Oprofile (1.3.0) to get some cache miss rate for our application in our platform (ARMv8 CortexA53, kernel 4.9.0, Yocto). It is kind of working now. But, when using operf to profile multiple events for an existing process, it always failed to start profiling by saying the target program is already ended. > > > > $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 -p 3253 > > events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 -p 3253x /boot/vmlinux-4.9.0 -- > > !!!! No samples collected !!! > > The target program/command ended before profiling was started. > > operf record init failed > > usage: operf [ options ] [ --system-wide | --pid <pid> | [ command [ args ] ] ] > > $ > > > > Am I doing something wrong? Could someone shed a light for me? > > > > But I don't have any issue if I profile only one event (i.e, L2D_CACHE,L2D_CACHE_WB or L2D_CACHE_REFILL) for the same existing process,at least the operf started profiling and opreport gave me some result. > > > > $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE:5000:0:1:1 -p 3253 > > operf: Press Ctl-c or 'kill -SIGINT 4800' to stop profiling > > operf: Profiler started > > ^C > > Profiling done. > > $ opreport > > Using /mnt/localdisk/oprofile_data/samples/ for samples directory. > > CPU: ARM Cortex-A53, speed 1200 MHz (estimated) > > Counted L2D_CACHE events (Level 2 data cache access) with a unit mask of 0x00 (No unit mask) count 5000 > > L2D_CACHE:5000| > > samples| %| > > ------------------ > > 39594 100.000 wl4app > > L2D_CACHE:5000| > > samples| %| > > ------------------ > > 15632 39.4807 myapp > > 15191 38.3669 vmlinux-4.9.0 > > 3578 9.0367 libc-2.24.so > > 2732 6.9000 libzmq.so.5.0.1 > > 1624 4.1016 libpthread-2.24.so > > 327 0.8259 libczmq.so.4.0.2 > > 287 0.7249 [vdso] (tgid:3253 range:0x7fa4845000-0x7fa4845fff) > > 180 0.4546 libmemTrace.so.0.0.0 > > 31 0.0783 librt-2.24.so > > 6 0.0152 ld-2.24.so > > 3 0.0076 libcrypto.so.1.0.2 > > 2 0.0051 mylib > > 1 0.0025 libsystemd.so.0.15.0 > > $ > > $operf --vmlinux /boot/vmlinux-4.9.0 --events L2D_CACHE_REFILL:5000:0:1:1 -p 3253 > > operf: Press Ctl-c or 'kill -SIGINT 4831' to stop profiling > > operf: Profiler started > > ^C > > Profiling done. > > $ > > > > $ operf --version > > operf: oprofile 1.3.0 compiled on Apr 25 2019 12:06:54 > > $ > > > > Regards, > > Jerry > > Hi, > > What particular armv8 SoC are you using? In theory all the cortex a53 processors should have the same pmu hardware with 6 programmable counters, but I wonder if this processor might be limited to one programmable counter or whether some other driver in the system is reserving the counters such as "perf -a -e ...". Is there anything else on the machine that might be reserving counters such a watchdog? You might take a look through the dmesg output for a something that looks like the following stating the number of performance counters that are available: > > [ 1.571915] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 counters available > > Also if you are using a device tree file make sure that it properly describes the performance monitoring hardware. In the past incorrect descriptions have prevented > > I tried something similar on a dragonboad 410c, a 96board with 4 cortext a53 processors. It is much newer 5.0.9 kernel. Maybe there is something going on in the kernel that is preventing both events from being set at the same time. Below is the output. > > > > $ rpm -q oprofile > oprofile-1.3.0-1.fc29.aarch64 > $ sudo operf --vmlinux /usr/lib/debug/lib/modules/5.0.9-200.fc29.aarch64/vmlinux --events L2D_CACHE:5000:0:1:1,L2D_CACHE_REFILL:5000:0:1:1 -p 1896 -- > operf: Press Ctl-c or 'kill -SIGINT 11648' to stop profiling > operf: Profiler started > ^C^Cwaitpid for operf-record process failed: Interrupted system call > ^Cwaitpid for operf-read process failed: Interrupted system call > Error running profiler > [wcohen@localhost <mailto:wcohen@localhost> ~]$ opreport > Using /home/wcohen/oprofile_data/samples/ for samples directory. > CPU: ARM Cortex-A53, speed 57 MHz (estimated) > > Counted L2D_CACHE events (Level 2 data cache access) with a unit mask of 0x00 (No unit mask) count 5000 > > Counted L2D_CACHE_REFILL events (Level 2 data cache refill) with a unit mask of 0x00 (No unit mask) count 5000 > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 10529 99.4991 661 97.7811 du > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 8808 83.6547 568 85.9304 vmlinux > 876 8.3199 49 7.4130 libc-2.28.so > 844 8.0160 43 6.5053 du > 1 0.0095 1 0.1513 ld-2.28.so > 30 0.2835 7 1.0355 rpm > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 27 90.0000 6 85.7143 vmlinux > 3 10.0000 1 14.2857 ld-2.28.so > 23 0.2174 8 1.1834 bash > L2D_CACHE:5000|L2D_CACHE_REFI...| > samples| %| samples| %| > ------------------------------------ > 20 86.9565 5 62.5000 vmlinux > 2 8.6957 1 12.5000 bash > 1 4.3478 2 25.0000 libc-2.28.so > > > -Will Cohen > > > > _______________________________________________ > oprofile-list mailing list > [email protected] > https://lists.sourceforge.net/lists/listinfo/oprofile-list _______________________________________________ oprofile-list mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/oprofile-list