Analyzers
Talk to fellow users of Intel Analyzer tools (Intel VTune™ Profiler, Intel Advisor)
4998 Discussions

No Microarchitectural Profiling Data Available

Huzaifa
Novice
2,306 Views

Hello,

I am only able to get user mode hotspot profiling to work. I am unable to get microarchitectural information of any sort from any kind of application. I've tried runs from several seconds to a full minute, but in each run no data is collected and the tool reports 100% of cycles are spent retiring instructions and none on stalls. I know that is wrong because the same workloads are profiled correctly by VTune on other machines (with different hardware and OSes).

The closest issue I could find related to mine is this one, but it hasn't been addressed. When I run vtune-self-checker, it reports this:

HW event-based analysis check (Intel driver)
Example of analysis types: Hotspots with knob sampling-mode=hw, HPC Performance Characterization, etc.
Collection: Ok
Finalization: Ok...
Report: Fail
vtune: Error: 0x40000024 (No data) -- No data is collected. Possible reasons:

The interesting thing is that VTune used to run fine when this machine had Ubuntu 16.04. With 18.04, it doesn't work.

Setup details:

Xeon E-2236

32 GB DDR4

RTX 2080 with 455.23.04 drivers

Ubuntu 18.04

VTune 2020 Update 2

0 Kudos
1 Solution
Huzaifa
Novice
2,248 Views

When I tried running microarchitectural profiling without the drivers, VTune crashed my entire machine. After the reboot, microarchitectural profiling actually worked! However, the driver crashed again in the middle of a new profiling run, and I got the same results as before (no data collected). After that, I did rmmod-sep and insmod-sep, and so far things have been working fine. It is very flaky (I don't know what causes the crashes), but at least there is a workaround now. vtune-self-checker.sh reports no errors either.

I happened to look at dmesg when the driver was having issues, and noticed that there were several errors reported by sep. Sharing them below in case they are helpful.

Thank you for all your help!

 

dmesg output:

[ 130.716042] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716044] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716045] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716045] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716046] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716047] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716047] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716048] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716048] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716049] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 141.656348] NOHZ: local_softirq_pending 40
[ 142.267110] NOHZ: local_softirq_pending 40
[ 142.801054] NOHZ: local_softirq_pending 40
[ 142.801098] NOHZ: local_softirq_pending 40
[ 142.801152] NOHZ: local_softirq_pending 40
[ 142.994534] NOHZ: local_softirq_pending 40
[ 143.132770] NOHZ: local_softirq_pending 40
[ 143.132815] NOHZ: local_softirq_pending 40
[ 143.132861] NOHZ: local_softirq_pending 40
[ 143.132906] NOHZ: local_softirq_pending 40
[ 1619.625038] usb 1-11: reset high-speed USB device number 3 using xhci_hcd
[ 1838.904775] perf: interrupt took too long (2597 > 2500), lowering kernel.perf_event_max_sample_rate to 77000
[ 1838.915264] perf: interrupt took too long (3472 > 3246), lowering kernel.perf_event_max_sample_rate to 57500
[ 1838.932847] perf: interrupt took too long (4384 > 4340), lowering kernel.perf_event_max_sample_rate to 45500
[ 1838.954553] perf: interrupt took too long (5628 > 5480), lowering kernel.perf_event_max_sample_rate to 35500
[ 1839.103847] perf: interrupt took too long (7042 > 7035), lowering kernel.perf_event_max_sample_rate to 28250
[ 1839.426246] perf: interrupt took too long (8923 > 8802), lowering kernel.perf_event_max_sample_rate to 22250
[ 1839.442595] perf: interrupt took too long (11215 > 11153), lowering kernel.perf_event_max_sample_rate to 17750
[ 2022.550436] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550437] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550438] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550439] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550440] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550440] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550441] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550441] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550442] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550443] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255951] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255952] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255953] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255954] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255954] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255955] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255955] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255956] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255957] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255957] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.

 

View solution in original post

9 Replies
AthiraM_Intel
Moderator
2,292 Views

Hi,


Thanks for reaching out to us.


Could you please provide the complete error log ?

Also please make sure that the driver is installed correctly.

To verify that the sampling driver is installed correctly on the host Linux system, please follow the below commands:


cd <install-dir>/sepdk/src

./insmod-sep -q


Thanks


0 Kudos
Huzaifa
Novice
2,285 Views

Thank you for getting back to me.

Self checker result:

$ ./vtune-self-checker.sh
Intel(R) VTune(TM) Profiler Self Check Utility
Copyright (C) 2009-2019 Intel Corporation. All rights reserved.
Build Number: 610396

Instrumentation based analysis check
Example of analysis types: Hotspots with default knob sampling-mode=sw, Threading with default knob sampling-and-waits=sw
Collection: Ok
Finalization: Ok...
Report: Ok

HW event-based analysis check (Intel driver)
Example of analysis types: Hotspots with knob sampling-mode=hw, HPC Performance Characterization, etc.
Collection: Ok
Finalization: Ok...
Report: Fail
vtune: Error: 0x40000024 (No data) -- No data is collected. Possible reasons:

HW event-based analysis check (Intel driver)
Example of analysis types: Microarchitecture Exploration
Collection: Ok
Finalization: Ok...
vtune: Warning: Cannot locate debugging information for the Linux kernel. Source-level analysis will not be possible. Function-level analysis will be limited to kernel symbol tables. See the Enabling Linux Kernel Analysis topic in the product online help for instructions.
Report: Fail

HW event-based analysis with uncore events (Intel driver)
Example of analysis types: Memory Access
Collection: Ok
Finalization: Ok...
vtune: Warning: Cannot locate debugging information for the Linux kernel. Source-level analysis will not be possible. Function-level analysis will be limited to kernel symbol tables. See the Enabling Linux Kernel Analysis topic in the product online help for instructions.
Report: Fail

HW event-based analysis with stacks (Perf)
Example of analysis types: Hotspots with knob sampling-mode=hw and knob enable-stack-collection=true, etc.
Collection: Ok
vtune: Warning: To profile kernel modules during the session, make sure they are available in the /lib/modules/kernel_version/ location.
Finalization: Ok...
vtune: Warning: Cannot locate debugging information for the Linux kernel. Source-level analysis will not be possible. Function-level analysis will be limited to kernel symbol tables. See the Enabling Linux Kernel Analysis topic in the product online help for instructions.
Report: Ok

HW event-based analysis with context switches (Intel driver)
Example of analysis types: Threading with knob sampling-and-waits=hw
Collection: Ok
Finalization: Ok...
vtune: Warning: Cannot locate debugging information for the Linux kernel. Source-level analysis will not be possible. Function-level analysis will be limited to kernel symbol tables. See the Enabling Linux Kernel Analysis topic in the product online help for instructions.
Report: Ok

The check observed a product failure on your system.
Review errors in the output above to fix a problem or contact Intel technical support.

Log location: /tmp/vtune-tmp-huzaifa2/self-checker-2020.10.20_10.38.46/log.txt

 Sampling driver status:

$ ./insmod-sep -q
pax driver is loaded and owned by group "vtune" with file permissions "660".
socperf3 driver is loaded and owned by group "vtune" with file permissions "660".
sep5 driver is loaded and owned by group "vtune" with file permissions "660".
socwatch driver is loaded.
vtsspp driver is loaded and owned by group "vtune" with file permissions "660".

I have made sure that I am part of the vtune group.

 

One other thing that I would like to add is the performance counters on the machine in general are working fine. I am able to query them using perf.

 

Finally, this is what the output inside VTune looks like.

Huzaifa_0-1603209658577.png

0 Kudos
Kirill_U_Intel
Employee
2,272 Views

Hi.

Could you share some logs and files?

  • 'VTUNE_INSTALL_DIR/bin64/sep -version' output
  • The simplest driver collection 'VTUNE_INSTALL_DIR/bin64/sep -start -d 3 -out test.tb7'. Pls, share test.tb7
  • Could you share *.tb7 file from the r004ue/data.0 result dir?

You mentioned that perf is ok. Could you try driverless collection based on perf to collect data? just remove intel drivers './rmmod-sep'

Kirill

0 Kudos
Huzaifa
Novice
2,264 Views

Hi Kirill,

SEP version:

$ ./sep -version
Sampling Enabling Product version: 5.19 Beta built on Jun 24 2020 16:46:20
SEP User Mode Version: 5.19 Beta
SEP Driver Version: 5.19 Beta (public)
PAX Driver Version: 1.0
Platform type: 122
CPU name: Intel(R) microarchitecture code named Coffeelake
PMU: skylake
Driver configs: Non-Maskable Interrupt, REGISTER CHECK ON
Copyright(C) 2007-2019 Intel Corporation. All rights reserved.

Driver collection:

$ ./sep -start -d 3 -out test.tb7
A tbX file was not created because 0 samples were collected

The r004ue tb7 file is 325 MB in size and the attachment size limit on the forum is 71 MB. Is there another experiment that I could run to help you debug this?

Perf without SEP driver:

$ ./rmmod-sep
Removing sep5 driver from the kernel ... done.
The sep5 driver has been successfully unloaded.
Removing vtsspp driver from the kernel ... done.
The vtsspp driver has been successfully unloaded.
Removing socwatch2_12 driver from the kernel ... done.
The socwatch2_12 driver has been successfully unloaded.
Removing socperf3 driver from the kernel ... done.
The socperf3 driver has been successfully unloaded.
No driver needs PMU arbitration anymore: the PAX service can be safely removed.
Attempting to stop PAX service ...
Removing pax driver from the kernel ... done.
The pax driver has been successfully unloaded.
PAX service has been stopped.
$ perf stat -d -- solo.opt 1000 decode
Getting second/third order dodecahedron

Performance counter stats for 'solo.opt 1000 decode':

1,008.49 msec task-clock # 0.999 CPUs utilized
5 context-switches # 0.005 K/sec
0 cpu-migrations # 0.000 K/sec
867 page-faults # 0.860 K/sec
4,732,717,922 cycles # 4.693 GHz (61.93%)
16,226,535,324 instructions # 3.43 insn per cycle (74.62%)
716,489,660 branches # 710.460 M/sec (74.95%)
2,906,156 branch-misses # 0.41% of all branches (75.34%)
3,710,857,176 L1-dcache-loads # 3679.626 M/sec (75.41%)
94,742,412 L1-dcache-load-misses # 2.55% of all L1-dcache hits (75.41%)
1,383,042 LLC-loads # 1.371 M/sec (49.65%)
4,739 LLC-load-misses # 0.34% of all LL-cache hits (49.25%)

1.009175110 seconds time elapsed

1.004736000 seconds user
0.004002000 seconds sys

Thank you, and please let me know if you need more information.

0 Kudos
Kirill_U_Intel
Employee
2,261 Views

Could you try VTune collection without drivers? In general, it will use perf in this case. Is result ok or empty counters?

Kirill

0 Kudos
Huzaifa
Novice
2,249 Views

When I tried running microarchitectural profiling without the drivers, VTune crashed my entire machine. After the reboot, microarchitectural profiling actually worked! However, the driver crashed again in the middle of a new profiling run, and I got the same results as before (no data collected). After that, I did rmmod-sep and insmod-sep, and so far things have been working fine. It is very flaky (I don't know what causes the crashes), but at least there is a workaround now. vtune-self-checker.sh reports no errors either.

I happened to look at dmesg when the driver was having issues, and noticed that there were several errors reported by sep. Sharing them below in case they are helpful.

Thank you for all your help!

 

dmesg output:

[ 130.716042] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716044] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716045] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716045] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716046] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716047] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716047] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716048] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716048] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 130.716049] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 141.656348] NOHZ: local_softirq_pending 40
[ 142.267110] NOHZ: local_softirq_pending 40
[ 142.801054] NOHZ: local_softirq_pending 40
[ 142.801098] NOHZ: local_softirq_pending 40
[ 142.801152] NOHZ: local_softirq_pending 40
[ 142.994534] NOHZ: local_softirq_pending 40
[ 143.132770] NOHZ: local_softirq_pending 40
[ 143.132815] NOHZ: local_softirq_pending 40
[ 143.132861] NOHZ: local_softirq_pending 40
[ 143.132906] NOHZ: local_softirq_pending 40
[ 1619.625038] usb 1-11: reset high-speed USB device number 3 using xhci_hcd
[ 1838.904775] perf: interrupt took too long (2597 > 2500), lowering kernel.perf_event_max_sample_rate to 77000
[ 1838.915264] perf: interrupt took too long (3472 > 3246), lowering kernel.perf_event_max_sample_rate to 57500
[ 1838.932847] perf: interrupt took too long (4384 > 4340), lowering kernel.perf_event_max_sample_rate to 45500
[ 1838.954553] perf: interrupt took too long (5628 > 5480), lowering kernel.perf_event_max_sample_rate to 35500
[ 1839.103847] perf: interrupt took too long (7042 > 7035), lowering kernel.perf_event_max_sample_rate to 28250
[ 1839.426246] perf: interrupt took too long (8923 > 8802), lowering kernel.perf_event_max_sample_rate to 22250
[ 1839.442595] perf: interrupt took too long (11215 > 11153), lowering kernel.perf_event_max_sample_rate to 17750
[ 2022.550436] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550437] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550438] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550439] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550440] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550440] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550441] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550441] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550442] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2022.550443] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255951] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255952] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255953] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255954] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255954] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255955] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255955] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255956] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255957] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.
[ 2979.255957] sep5_19: [warning] [CONTROL_Allocate_Memory@691]: Cannot allocate a number of bytes <= 0.

 

AthiraM_Intel
Moderator
2,210 Views

Hi,


Hope your issue is resolved. Could you please confirm whether we can close this thread?


Thanks.


0 Kudos
Huzaifa
Novice
2,192 Views

I had marked the solution hoping that that would close the thread. But yeah, please go ahead. Thank you!

0 Kudos
AthiraM_Intel
Moderator
2,182 Views

Hi,


Thanks for the confirmation. We would discontinue monitoring this issue, please raise a new thread if you have further issues.


Thanks


0 Kudos
Reply