Messages in this thread | | | Subject | Re: [RESEND PATCH 2/2] perf/x86: improve the event scheduling to avoid unnecessary pmu_stop/start | From | Wen Yang <> | Date | Fri, 18 Mar 2022 01:54:55 +0800 |
| |
在 2022/3/14 下午6:55, Peter Zijlstra 写道: > On Thu, Mar 10, 2022 at 11:50:33AM +0800, Wen Yang wrote: > >> As you pointed out, some non-compliant rdpmc can cause problems. But you >> also know that linux is the foundation of cloud servers, and many >> third-party programs run on it (we don't have any code for it), and we can >> only observe that the monitoring data will jitter abnormally (the >> probability of this issue is not high, about dozens of tens of thousands of >> machines). > > This might be a novel insight, but I *really* don't give a crap about > any of that. If they're not using it right, they get to keep the pieces. > > I'd almost make it reschedule more to force them to fix their stuff. >
Thank you for your guidance.
We also found a case in thousands of servers where the PMU counter is no longer updated due to frequent x86_pmu_stop/x86_pmu_start.
We added logs in the kernel and found that a third-party program would cause the PMU counter to start/stop several times in just a few seconds, as follows:
[8993460.537776] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000001 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802a877ef302, hw.period_left=0x7fd578810cfe, event.count=0x14db802a877ecab4, event.prev_count=0x14db802a877ecab4 [8993460.915873] XXX x86_pmu_start line=1312 [cpu1] active_mask=200000008 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0xffff802a9cf6a166, hw.period_left=0x7fd563095e9a, event.count=0x14db802a9cf67918, event.prev_count=0x14db802a9cf67918 [8993461.104643] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000001 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0xffff802a9cf6a166, hw.period_left=0x7fd563095e9a, event.count=0x14db802a9cf67918, event.prev_count=0x14db802a9cf67918 [8993461.442508] XXX x86_pmu_start line=1312 [cpu1] active_mask=200000004 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0xffff802a9cf8492e, hw.period_left=0x7fd56307b6d2, event.count=0x14db802a9cf820e0, event.prev_count=0x14db802a9cf820e0 [8993461.736927] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000001 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0xffff802a9cf8492e, hw.period_left=0x7fd56307b6d2, event.count=0x14db802a9cf820e0, event.prev_count=0x14db802a9cf820e0 [8993461.983135] XXX x86_pmu_start line=1312 [cpu1] active_mask=200000004 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0xffff802a9cfc29ed, hw.period_left=0x7fd56303d613, event.count=0x14db802a9cfc019f, event.prev_count=0x14db802a9cfc019f [8993462.274599] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000001 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0x802a9d24040e, hw.period_left=0x7fd562dbfbf2, event.count=0x14db802a9d23dbc0, event.prev_count=0x14db802a9d23dbc0 [8993462.519488] XXX x86_pmu_start line=1312 [cpu1] active_mask=200000004 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0xffff802ab0bb4719, hw.period_left=0x7fd54f44b8e7, event.count=0x14db802ab0bb1ecb, event.prev_count=0x14db802ab0bb1ecb [8993462.726929] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000003 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=2, hw.prev_count=0xffff802ab0bb4719, hw.period_left=0x7fd54f44b8e7, event.count=0x14db802ab0bb1ecb, event.prev_count=0x14db802ab0bb1ecb [8993463.035674] XXX x86_pmu_start line=1312 [cpu1] active_mask=200000008 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0xffff802ab0bcd328, hw.period_left=0x7fd54f432cd8, event.count=0x14db802ab0bcaada, event.prev_count=0x14db802ab0bcaada
Then, the PMU counter will not be updated:
[8993463.333622] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802abea31354 [8993463.359905] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802abea31354, hw.period_left=0x7fd5415cecac, event.count=0x14db802abea2eb06, [8993463.504783] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802ad8760160 [8993463.521138] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802ad8760160, hw.period_left=0x7fd52789fea0, event.count=0x14db802ad875d912, [8993463.638337] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993463.654441] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, [8993463.837321] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993463.861625] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, [8993464.012398] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993464.012402] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, [8993464.013676] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993464.013678] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, [8993464.016123] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993464.016125] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, [8993464.016196] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aecb4747b [8993464.016199] x86_perf_event_update [cpu1] active_mask=30000000f event=ffff880a53411000, state=1, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d,
......
Until 6 seconds later, the counter is stopped/started again:
[8993470.243959] XXX x86_pmu_stop line=1388 [cpu1] active_mask=100000001 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0x802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, event.prev_count=0x14db802aecb44c2d [8993470.243998] XXX x86_pmu_start line=1305 [cpu1] active_mask=200000000 event=ffff880a53411000, state=1, attr.type=0, attr.config=0x0, attr.pinned=1, hw.idx=3, hw.prev_count=0xffff802aecb4747b, hw.period_left=0x7fd5134b8b85, event.count=0x14db802aecb44c2d, event.prev_count=0x14db802aecb44c2d
[8993470.245285] x86_perf_event_update, event=ffff880a53411000, new_raw_count=802aece1e6f6
...
Such problems can be solved by avoiding unnecessary x86_pmu_{stop|start}.
Please have a look again. Thanks.
-- Best wishes, Wen
| |