linux-kernel - RE: [PATCH] perf/x86: fix event counter update issue

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Tue, 29 Nov 2016 19:08:39 +0000
From:   "Odzioba, Lukasz" <lukasz.odzioba@...el.com>
To:     Stephane Eranian <eranian@...gle.com>,
        Peter Zijlstra <peterz@...radead.org>
CC:     "Liang, Kan" <kan.liang@...el.com>,
        "mingo@...hat.com" <mingo@...hat.com>,
        LKML <linux-kernel@...r.kernel.org>,
        Alexander Shishkin <alexander.shishkin@...ux.intel.com>,
        "ak@...ux.intel.com" <ak@...ux.intel.com>
Subject: RE: [PATCH] perf/x86: fix event counter update issue

On Tuesday, November 29, 2016 6:20 PM Stephane Eranian wrote:
>> On Tue, Nov 29, 2016 at 1:25 AM, Peter Zijlstra <peterz@...radead.org> wrote:
>>  How can this happen? IIRC the thing increments, we program a negative
>>  value, and when it passes 0 we generate a PMI.
>>	
> Yeah, that's the part I don't quite understand thus my initial
> question. What you describe
> is what is supposed to happen regardless of the counter width.

I don't see any interrupts flying around:
# cat /proc/interrupts | grep PMI
PMI:         10         14         12         18   Performance monitoring interrupts
(test case here)
# cat /proc/interrupts | grep PMI
PMI:         10         14         12         18   Performance monitoring interrupts

What I also don't understand is why this is only seen on per cpu, or system wide mode.
PMIs seems to be programmed because if we wait long enough it will eventually overflow,
what we saw in one of tests cases from commit msg.
In the failing case (system wide) x86_perf_event_update is called only once at the end of workload:

259.154530: x86_perf_event_set_period: x86_perf_event_set_period left = ffffffffff, ret = 0
550.079623: x86_pmu_stop: x86_pmu_stop -> need update
550.079625: x86_perf_event_update: x86_perf_event_update config = 11003c, period = ffff880276212000
550.079627: x86_perf_event_update: x86_perf_event_update sample_period = ffffffffff,  last_period = ffffffffff, period_left = ffffffffff
550.079629: x86_perf_event_update: x86_perf_event_update(1) prev = ffffff0000000001, new = 8bba934b9e, delta = ffffff8bba934b9d, shift=24

In the good case -per pid case, x86_perf_event_update is called every ~3 seconds.
568.448083: x86_perf_event_set_period: x86_perf_event_set_period left = ffffffffff, ret = 0
568.949105: x86_pmu_stop: x86_pmu_stop -> need update
568.949106: x86_perf_event_update: x86_perf_event_update config = 11003c, period = ffff880276212000
568.949108: x86_perf_event_update: x86_perf_event_update sample_period = ffffffffff,  last_period = ffffffffff, period_left = ffffffffff
568.949110: x86_perf_event_update: x86_perf_event_update(1) prev = ffffff0000000001, new = 3d9525cc, delta = 3d9525cb, shift=24
568.949135: x86_perf_event_set_period: x86_perf_event_set_period left = ffc26ada34, ret = 0
570.679697: x86_pmu_stop: x86_pmu_stop -> need update
570.679699: x86_perf_event_update: x86_perf_event_update config = 11003c, period = ffff880276212000
570.679700: x86_perf_event_update: x86_perf_event_update sample_period = ffffffffff,  last_period = ffffffffff, period_left = ffc26ada34
570.679701: x86_perf_event_update: x86_perf_event_update(1) prev = ffffff003d9525cc, new = 112601ddf, delta = d4caf813, shift=24
570.679723: x86_perf_event_set_period: x86_perf_event_set_period left = feed9fe221, ret = 0
(... ~115 similar calls here)
859.431686: x86_pmu_stop: x86_pmu_stop -> need update
859.431687: x86_perf_event_update: x86_perf_event_update config = 11003c, period = ffff880276209000
859.431688: x86_perf_event_update: x86_perf_event_update sample_period = ffffffffff,  last_period = ffffffffff, period_left = 7453fc7d0d
859.431689: x86_perf_event_update: x86_perf_event_update(1) prev = ffffff8bac0382f3, new = 8bbaa4a147, delta = ea11e54, shift=24

Thanks,
Lukas