search

powerapi-ng / hwpc-sensor

Hardware Performance Counters monitoring agent for containers.
BSD 3-Clause "New" or "Revised" License
13 stars 14 forks source link

Sensor fails to initialize in recent update #63

Open henriquedavid opened 2 months ago

henriquedavid commented 2 months ago

Hi,

I was using the image powerapi/hwpc-sensor with the latest version (1.3.0), but until version 1.2.0, it was working well, but with the recent update to the 1.3.0, my machine does not initialize correctly the sensor.

Here are the logs from the docker: docker logs hwpc_sensor

I: 24-05-06 07:56:17 build: version v1.3.0 (rev: 4b8e54c88e7738aea9293a6dc75ea96fb3f8160b)
I: 24-05-06 07:56:17 uname: Linux 6.5.0-28-generic #29~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Thu Apr  4 14:39:20 UTC 2 x86_64
I: 24-05-06 07:56:17 pmu: found ix86arch 'Intel X86 architectural PMU' having 7 events, 7 counters (4 general, 3 fixed)
I: 24-05-06 07:56:17 pmu: found perf 'perf_events generic PMU' having 82 events, 0 counters (0 general, 0 fixed)
I: 24-05-06 07:56:17 pmu: found rapl 'Intel RAPL' having 4 events, 3 counters (0 general, 3 fixed)
I: 24-05-06 07:56:17 pmu: found perf_raw 'perf_events raw PMU' having 1 events, 0 counters (0 general, 0 fixed)
I: 24-05-06 07:56:17 pmu: found skl 'Intel Skylake' having 84 events, 11 counters (8 general, 3 fixed)
I: 24-05-06 07:56:17 pmu: found intel_msr 'Intel MSR' having 6 events, 6 counters (0 general, 6 fixed)
I: 24-05-06 07:56:17 sensor: configuration is valid, starting monitoring...
I: 24-05-06 07:56:17 perf<all>: monitoring actor started
E: 24-05-06 07:56:17 perf</pids/system.slice/thermald.service>: failed opening perf event for group=core cpu=7 event=CPU_CLK_THREAD_UNHALTED:REF_P errno=2
E: 24-05-06 07:56:17 perf</pids/system.slice/thermald.service>: failed to setup perf for group=core pkg=0 cpu=7
E: 24-05-06 07:56:17 perf</pids/system.slice/thermald.service>: cannot initialize perf monitoring
E: 24-05-06 07:56:17 perf</unified/user.slice/user-1000.slice/user@1000.service/app.slice/app-org.gnome.Terminal.slice/gnome-terminal-server.service>: failed opening perf event for group=core cpu=7 event=CPU_CLK_THREAD_UNHALTED:REF_P errno=2
E: 24-05-06 07:56:17 perf</unified/user.slice/user-1000.slice/user@1000.service/app.slice/app-org.gnome.Terminal.slice/gnome-terminal-server.service>: failed to setup perf for group=core pkg=0 cpu=7
E: 24-05-06 07:56:17 perf</unified/user.slice/user-1000.slice/user@1000.service/app.slice/app-org.gnome.Terminal.slice/gnome-terminal-server.service>: cannot initialize perf monitoring
E: 24-05-06 07:56:17 perf</systemd/user.slice/user-1000.slice/user@1000.service/app.slice/evolution-addressbook-factory.service>: failed opening perf event for group=core cpu=7 event=CPU_CLK_THREAD_UNHALTED:REF_P errno=2
E: 24-05-06 07:56:17 perf</systemd/user.slice/user-1000.slice/user@1000.service/app.slice/evolution-addressbook-factory.service>: failed to setup perf for group=core pkg=0 cpu=7
E: 24-05-06 07:56:17 perf</systemd/user.slice/user-1000.slice/user@1000.service/app.slice/evolution-addressbook-factory.service>: cannot initialize perf monitoring
File exists (src/epoll.cpp:100)

At the end, the container is removed, but ending with code Exited(134).

I was considering that maybe there can be some problems with permission, but it's weird that in the version of 1.2.0 everything works normally.

gfieni commented 2 months ago

Hello, This is very weird indeed, because the 1.3.0 release have very few code changes compared to 1.2.0 and it was mainly for updating the dependencies of the container image to support new CPUs. I tried to reproduce the problem on multiple Skylake (server) CPUs, but to no avail.

Could you please give me the command line/config file you use to setup the sensor and the full CPU model ? Also, you can try with this debug image: docker.io/gfieni/hwpc-sensor:issue63 ? (We may get more logs)

Thanks.

henriquedavid commented 2 months ago

Hello,

Here's all the commands executed that shows the failure:

docker run -d -v "$(pwd)"/results/powerapi:/app --name mongo_energie -p 27017:27017 mongo
docker pull powerapi/hwpc-sensor
docker pull powerapi/smartwatts-formula
docker run -d --name hwpc_sensor --rm --net=host --privileged --pid=host -v /sys:/sys -v /var/lib/docker/containers:/var/lib/docker/containers:ro -v /tmp/powerapi-sensor-reporting:/reporting -v $(pwd):/srv powerapi/hwpc-sensor -n "$(hostname -f)" -r "mongodb" -U "mongodb://127.0.0.1" -D "db_sensor" -C "report_0" -s "rapl" -o -e "RAPL_ENERGY_PKG" -s "msr" -e "TSC" -e "APERF" -e "MPERF" -c "core" -e "CPU_CLK_THREAD_UNHALTED:REF_P" -e "CPU_CLK_THREAD_UNHALTED:THREAD_P" -e "LLC_MISSES" -e "INSTRUCTIONS_RETIRED"
docker run --name smart_formula --restart always -t --net=host powerapi/smartwatts-formula --verbose --input mongodb --model HWPCReport --uri mongodb://127.0.0.1 --db db_sensor --collection report_0 --output mongodb --model PowerReport --uri mongodb://127.0.0.1 --db test_result --collection results --cpu-base-freq 4200 --cpu-error-threshold 2.0 --disable-dram-formula --sensor-reports-frequency 1000

I'm using mongoDB as input and output source. When I execute the following code, that will take the latest version of the sensor, resulting in the failure. To make it run properly, I need to specify the version 1.2.0 in the code.

Here's the full CPU model:

-cpu product: Intel(R) Core(TM) i7-8650U CPU @ 1.90GHz vendor: Intel Corp. physical id: 1 bus info: cpu@0 version: 6.142.10 size: 3GHz capacity: 4200MHz width: 64 bits capabilities: fpu fpu_exception wp vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp x86-64 constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb invpcid_single pti ssbd ibrs ibpb stibp tpr_shadow flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid mpx rdseed adx smap clflushopt intel_pt xsaveopt xsavec xgetbv1 xsaves dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp vnmi md_clear flush_l1d arch_capabilities cpufreq configuration: microcode=244

Executing with the debug image docker.io/gfieni/hwpc-sensor:issue63, I got the following logs from the container:

AddressSanitizer:DEADLYSIGNAL
AddressSanitizer:DEADLYSIGNAL
AddressSanitizer:DEADLYSIGNAL
AddressSanitizer:DEADLYSIGNAL
AddressSanitizer:DEADLYSIGNAL
gfieni commented 2 months ago

Thanks for the information. I will try to reproduce the problem with a similar configuration and get back to you.

gfieni commented 1 month ago

Hello, I tried to reproduce the problem on a machine with a Skylake CPU (Intel(R) Core(TM) i5-6300U) and similar software configuration (Ubuntu 22.04 with kernel 6.5.0-28-generic #29~22.04.1-Ubuntu) but to no avail. Both versions of the sensor (1.2.0, 1.3.0) are working on client/server Skylake CPUs with the commands you gave earlier.

I: 24-05-14 09:59:54 build: version v1.3.0 (rev: 4b8e54c88e7738aea9293a6dc75ea96fb3f8160b)
I: 24-05-14 09:59:54 uname: Linux 6.5.0-28-generic #29~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Thu Apr  4 14:39:20 UTC 2 x86_64
I: 24-05-14 09:59:54 pmu: found ix86arch 'Intel X86 architectural PMU' having 7 events, 7 counters (4 general, 3 fixed)
I: 24-05-14 09:59:54 pmu: found perf 'perf_events generic PMU' having 82 events, 0 counters (0 general, 0 fixed)
I: 24-05-14 09:59:54 pmu: found rapl 'Intel RAPL' having 4 events, 3 counters (0 general, 3 fixed)
I: 24-05-14 09:59:54 pmu: found perf_raw 'perf_events raw PMU' having 1 events, 0 counters (0 general, 0 fixed)
I: 24-05-14 09:59:54 pmu: found skl 'Intel Skylake' having 84 events, 11 counters (8 general, 3 fixed)
I: 24-05-14 09:59:54 pmu: found intel_msr 'Intel MSR' having 6 events, 6 counters (0 general, 6 fixed)
I: 24-05-14 09:59:54 sensor: configuration is valid, starting monitoring...
I: 24-05-14 09:59:54 perf<all>: monitoring actor started
I: 24-05-14 09:59:54 perf</user.slice/user-1000.slice/user@1000.service/session.slice/pipewire.service>: monitoring actor started
I: 24-05-14 09:59:54 perf</system.slice/cups-browsed.service>: monitoring actor started
I: 24-05-14 09:59:54 perf</user.slice/user-1000.slice/user@1000.service/session.slice/pipewire-media-session.service>: monitoring actor started
I: 24-05-14 09:59:54 perf</user.slice/user-128.slice/user@128.service/app.slice/dbus.socket>: monitoring actor started
I: 24-05-14 09:59:54 perf</system.slice/networkd-dispatcher.service>: monitoring actor started
I: 24-05-14 09:59:54 perf</user.slice/user-1000.slice/user@1000.service/session.slice/xdg-document-portal.service>: monitoring actor started
I: 24-05-14 09:59:54 perf</system.slice/packagekit.service>: monitoring actor started
[...]

The error message at the end, like File exists (src/epoll.cpp:100), are ZMQ messages that comes from the failure when initializing the perf monitoring actor. This is not a good behavior, and I will do something better.

However, the source of the problem is this: failed opening perf event for group=core cpu=7 event=CPU_CLK_THREAD_UNHALTED:REF_P errno=2

And this happen (mostly) when the perf event attributes are wrong, which is weird in your case because the code of the Skylake attributes (from the libpfm4 library) is the same for the two releases of the sensor.

If you change the CPU_CLK_THREAD_UNHALTED:REF_P and CPU_CLK_THREAD_UNHALTED:THREAD_P events by either :

Do you still have the same problem ? (If it work, you will probably have logs about perf multiplexing, you can ignore them in this case)

Just curious, but is the failed opening perf event error always about the cpu=7 or other cpu are also affected ?

gfieni commented 1 month ago

Hello @henriquedavid, Can you add the -p "/sys/fs/cgroup/perf_event" argument to the sensor command or add the "cgroup_basepath": "/sys/fs/cgroup/perf_event" field in your config file and retry ?