When unpacking the event which is from dynamic pmu, the array
output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
PERF_TYPE_MAX + 1).
/* In builtin-script.c */
process_event()
{
unsigned int type = output_type(attr->type);
if (output[type].fields == 0)
return;
}
output[10] is overrun.
Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
between old perf.data files that had a dynamicaliy allocated PMU number
that would then be the same as a fixed PERF_TYPE.
Example:
perf record --switch-events -C 0 -e "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a -- sleep 1
perf script
Before:
swapper 0 [000] 1479253.987551: 277766 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.987797: 246709 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.988127: 329883 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.988273: 146393 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.988523: 249977 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.988877: 354090 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.989023: 145940 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.989383: 359856 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1479253.989523: 140082 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
After:
swapper 0 [000] 1397040.402011: 272384 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1397040.402011: 5396 uncore_imc/data_reads/:
swapper 0 [000] 1397040.402011: 967 uncore_imc/data_writes/:
swapper 0 [000] 1397040.402259: 249153 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1397040.402259: 7231 uncore_imc/data_reads/:
swapper 0 [000] 1397040.402259: 1297 uncore_imc/data_writes/:
swapper 0 [000] 1397040.402508: 249108 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
swapper 0 [000] 1397040.402508: 5333 uncore_imc/data_reads/:
swapper 0 [000] 1397040.402508: 1008 uncore_imc/data_writes/:
Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized events")
Signed-off-by: Jin Yao <[email protected]>
---
tools/perf/builtin-script.c | 18 +++++++++++++++++-
1 file changed, 17 insertions(+), 1 deletion(-)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 48588ccf902e..d68684fb9b53 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -183,6 +183,7 @@ struct output_option {
enum {
OUTPUT_TYPE_SYNTH = PERF_TYPE_MAX,
+ OUTPUT_TYPE_OTHER,
OUTPUT_TYPE_MAX
};
@@ -279,6 +280,18 @@ static struct {
.invalid_fields = PERF_OUTPUT_TRACE | PERF_OUTPUT_BPF_OUTPUT,
},
+
+ [OUTPUT_TYPE_OTHER] = {
+ .user_set = false,
+
+ .fields = PERF_OUTPUT_COMM | PERF_OUTPUT_TID |
+ PERF_OUTPUT_CPU | PERF_OUTPUT_TIME |
+ PERF_OUTPUT_EVNAME | PERF_OUTPUT_IP |
+ PERF_OUTPUT_SYM | PERF_OUTPUT_SYMOFFSET |
+ PERF_OUTPUT_DSO | PERF_OUTPUT_PERIOD,
+
+ .invalid_fields = PERF_OUTPUT_TRACE | PERF_OUTPUT_BPF_OUTPUT,
+ },
};
struct evsel_script {
@@ -339,8 +352,11 @@ static inline int output_type(unsigned int type)
case PERF_TYPE_SYNTH:
return OUTPUT_TYPE_SYNTH;
default:
- return type;
+ if (type < PERF_TYPE_MAX)
+ return type;
}
+
+ return OUTPUT_TYPE_OTHER;
}
static inline unsigned int attr_type(unsigned int type)
--
2.17.1
Hi Adrian,
On 11/26/2020 2:51 PM, Adrian Hunter wrote:
> On 26/11/20 5:24 am, Jin Yao wrote:
>> When unpacking the event which is from dynamic pmu, the array
>> output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
>> SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
>> PERF_TYPE_MAX + 1).
>>
>> /* In builtin-script.c */
>> process_event()
>> {
>> unsigned int type = output_type(attr->type);
>>
>> if (output[type].fields == 0)
>> return;
>> }
>>
>> output[10] is overrun.
>>
>> Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
>> output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
>>
>> Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
>> between old perf.data files that had a dynamicaliy allocated PMU number
>> that would then be the same as a fixed PERF_TYPE.
>>
>> Example:
>>
>> perf record --switch-events -C 0 -e "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a -- sleep 1
>> perf script
>>
>> Before:
>> swapper 0 [000] 1479253.987551: 277766 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.987797: 246709 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.988127: 329883 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.988273: 146393 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.988523: 249977 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.988877: 354090 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.989023: 145940 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.989383: 359856 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1479253.989523: 140082 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>
>> After:
>> swapper 0 [000] 1397040.402011: 272384 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1397040.402011: 5396 uncore_imc/data_reads/:
>> swapper 0 [000] 1397040.402011: 967 uncore_imc/data_writes/:
>> swapper 0 [000] 1397040.402259: 249153 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1397040.402259: 7231 uncore_imc/data_reads/:
>> swapper 0 [000] 1397040.402259: 1297 uncore_imc/data_writes/:
>> swapper 0 [000] 1397040.402508: 249108 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>> swapper 0 [000] 1397040.402508: 5333 uncore_imc/data_reads/:
>> swapper 0 [000] 1397040.402508: 1008 uncore_imc/data_writes/:
>>
>> Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized events")
>
> It does not look to me like the problem was introduced by that commit. Are
> you sure this Fixes tag is correct?
>
Commit 1405720d4f26 added the change:
@@ -1215,8 +1253,9 @@ static void process_event(struct perf_script *script,
{
struct thread *thread = al->thread;
struct perf_event_attr *attr = &evsel->attr;
+ unsigned int type = output_type(attr->type);
- if (output[attr->type].fields == 0)
+ if (output[type].fields == 0)
return;
But of course, we can also say the original "output[attr->type].fields" introduced the issue, I'm
not sure. Maybe Arnaldo can help to make the decision. :)
Thanks
Jin Yao
On 26/11/20 9:06 am, Jin, Yao wrote:
> Hi Adrian,
>
> On 11/26/2020 2:51 PM, Adrian Hunter wrote:
>> On 26/11/20 5:24 am, Jin Yao wrote:
>>> When unpacking the event which is from dynamic pmu, the array
>>> output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
>>> SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
>>> PERF_TYPE_MAX + 1).
>>>
>>> /* In builtin-script.c */
>>> process_event()
>>> {
>>> unsigned int type = output_type(attr->type);
>>>
>>> if (output[type].fields == 0)
>>> return;
>>> }
>>>
>>> output[10] is overrun.
>>>
>>> Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
>>> output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
>>>
>>> Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
>>> between old perf.data files that had a dynamicaliy allocated PMU number
>>> that would then be the same as a fixed PERF_TYPE.
>>>
>>> Example:
>>>
>>> perf record --switch-events -C 0 -e
>>> "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a --
>>> sleep 1
>>> perf script
>>>
>>> Before:
>>> swapper 0 [000] 1479253.987551: 277766
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.987797: 246709
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.988127: 329883
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.988273: 146393
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.988523: 249977
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.988877: 354090
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.989023: 145940
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.989383: 359856
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1479253.989523: 140082
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>
>>> After:
>>> swapper 0 [000] 1397040.402011: 272384
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1397040.402011: 5396
>>> uncore_imc/data_reads/:
>>> swapper 0 [000] 1397040.402011: 967
>>> uncore_imc/data_writes/:
>>> swapper 0 [000] 1397040.402259: 249153
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1397040.402259: 7231
>>> uncore_imc/data_reads/:
>>> swapper 0 [000] 1397040.402259: 1297
>>> uncore_imc/data_writes/:
>>> swapper 0 [000] 1397040.402508: 249108
>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>> swapper 0 [000] 1397040.402508: 5333
>>> uncore_imc/data_reads/:
>>> swapper 0 [000] 1397040.402508: 1008
>>> uncore_imc/data_writes/:
>>>
>>> Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized
>>> events")
>>
>> It does not look to me like the problem was introduced by that commit. Are
>> you sure this Fixes tag is correct?
>>
>
> Commit 1405720d4f26 added the change:
>
> @@ -1215,8 +1253,9 @@ static void process_event(struct perf_script *script,
> {
> struct thread *thread = al->thread;
> struct perf_event_attr *attr = &evsel->attr;
> + unsigned int type = output_type(attr->type);
>
> - if (output[attr->type].fields == 0)
> + if (output[type].fields == 0)
> return;
That is a nop if attr->type != PERF_TYPE_SYNTH
Given that PERF_TYPE_SYNTH is (INT_MAX + 1), it is a nop for all kernel
dynamically allocated PMU numbers.
>
> But of course, we can also say the original "output[attr->type].fields"
> introduced the issue, I'm not sure. Maybe Arnaldo can help to make the
> decision. :)
I think perf script has always had this problem.
Hi Adrian,
On 11/26/2020 4:36 PM, Adrian Hunter wrote:
> On 26/11/20 9:06 am, Jin, Yao wrote:
>> Hi Adrian,
>>
>> On 11/26/2020 2:51 PM, Adrian Hunter wrote:
>>> On 26/11/20 5:24 am, Jin Yao wrote:
>>>> When unpacking the event which is from dynamic pmu, the array
>>>> output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
>>>> SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
>>>> PERF_TYPE_MAX + 1).
>>>>
>>>> /* In builtin-script.c */
>>>> process_event()
>>>> {
>>>> unsigned int type = output_type(attr->type);
>>>>
>>>> if (output[type].fields == 0)
>>>> return;
>>>> }
>>>>
>>>> output[10] is overrun.
>>>>
>>>> Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
>>>> output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
>>>>
>>>> Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
>>>> between old perf.data files that had a dynamicaliy allocated PMU number
>>>> that would then be the same as a fixed PERF_TYPE.
>>>>
>>>> Example:
>>>>
>>>> perf record --switch-events -C 0 -e
>>>> "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a --
>>>> sleep 1
>>>> perf script
>>>>
>>>> Before:
>>>> swapper 0 [000] 1479253.987551: 277766
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.987797: 246709
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.988127: 329883
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.988273: 146393
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.988523: 249977
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.988877: 354090
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.989023: 145940
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.989383: 359856
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1479253.989523: 140082
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>
>>>> After:
>>>> swapper 0 [000] 1397040.402011: 272384
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1397040.402011: 5396
>>>> uncore_imc/data_reads/:
>>>> swapper 0 [000] 1397040.402011: 967
>>>> uncore_imc/data_writes/:
>>>> swapper 0 [000] 1397040.402259: 249153
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1397040.402259: 7231
>>>> uncore_imc/data_reads/:
>>>> swapper 0 [000] 1397040.402259: 1297
>>>> uncore_imc/data_writes/:
>>>> swapper 0 [000] 1397040.402508: 249108
>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>> swapper 0 [000] 1397040.402508: 5333
>>>> uncore_imc/data_reads/:
>>>> swapper 0 [000] 1397040.402508: 1008
>>>> uncore_imc/data_writes/:
>>>>
>>>> Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized
>>>> events")
>>>
>>> It does not look to me like the problem was introduced by that commit. Are
>>> you sure this Fixes tag is correct?
>>>
>>
>> Commit 1405720d4f26 added the change:
>>
>> @@ -1215,8 +1253,9 @@ static void process_event(struct perf_script *script,
>> {
>> struct thread *thread = al->thread;
>> struct perf_event_attr *attr = &evsel->attr;
>> + unsigned int type = output_type(attr->type);
>>
>> - if (output[attr->type].fields == 0)
>> + if (output[type].fields == 0)
>> return;
>
> That is a nop if attr->type != PERF_TYPE_SYNTH
> Given that PERF_TYPE_SYNTH is (INT_MAX + 1), it is a nop for all kernel
> dynamically allocated PMU numbers.
>
>>
>> But of course, we can also say the original "output[attr->type].fields"
>> introduced the issue, I'm not sure. Maybe Arnaldo can help to make the
>> decision. :)
>
> I think perf script has always had this problem.
>
Since perf-script has always had this problem, I'm OK to remove the fixes tag from the patch
description.
Thanks
Jin Yao
On 26/11/20 5:24 am, Jin Yao wrote:
> When unpacking the event which is from dynamic pmu, the array
> output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
> SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
> PERF_TYPE_MAX + 1).
>
> /* In builtin-script.c */
> process_event()
> {
> unsigned int type = output_type(attr->type);
>
> if (output[type].fields == 0)
> return;
> }
>
> output[10] is overrun.
>
> Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
> output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
>
> Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
> between old perf.data files that had a dynamicaliy allocated PMU number
> that would then be the same as a fixed PERF_TYPE.
>
> Example:
>
> perf record --switch-events -C 0 -e "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a -- sleep 1
> perf script
>
> Before:
> swapper 0 [000] 1479253.987551: 277766 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.987797: 246709 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.988127: 329883 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.988273: 146393 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.988523: 249977 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.988877: 354090 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.989023: 145940 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.989383: 359856 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1479253.989523: 140082 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>
> After:
> swapper 0 [000] 1397040.402011: 272384 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1397040.402011: 5396 uncore_imc/data_reads/:
> swapper 0 [000] 1397040.402011: 967 uncore_imc/data_writes/:
> swapper 0 [000] 1397040.402259: 249153 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1397040.402259: 7231 uncore_imc/data_reads/:
> swapper 0 [000] 1397040.402259: 1297 uncore_imc/data_writes/:
> swapper 0 [000] 1397040.402508: 249108 cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
> swapper 0 [000] 1397040.402508: 5333 uncore_imc/data_reads/:
> swapper 0 [000] 1397040.402508: 1008 uncore_imc/data_writes/:
>
> Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized events")
It does not look to me like the problem was introduced by that commit. Are
you sure this Fixes tag is correct?
Hi Adrian,
On 11/26/2020 10:47 PM, Jin, Yao wrote:
> Hi Adrian,
>
> On 11/26/2020 4:36 PM, Adrian Hunter wrote:
>> On 26/11/20 9:06 am, Jin, Yao wrote:
>>> Hi Adrian,
>>>
>>> On 11/26/2020 2:51 PM, Adrian Hunter wrote:
>>>> On 26/11/20 5:24 am, Jin Yao wrote:
>>>>> When unpacking the event which is from dynamic pmu, the array
>>>>> output[OUTPUT_TYPE_MAX] may be overrun. For example, type number of
>>>>> SKL uncore_imc is 10, but OUTPUT_TYPE_MAX is 7 now (OUTPUT_TYPE_MAX =
>>>>> PERF_TYPE_MAX + 1).
>>>>>
>>>>> /* In builtin-script.c */
>>>>> process_event()
>>>>> {
>>>>> unsigned int type = output_type(attr->type);
>>>>>
>>>>> if (output[type].fields == 0)
>>>>> return;
>>>>> }
>>>>>
>>>>> output[10] is overrun.
>>>>>
>>>>> Create a type OUTPUT_TYPE_OTHER for dynamic pmu events, then
>>>>> output_type(attr->type) will return OUTPUT_TYPE_OTHER here.
>>>>>
>>>>> Note that if PERF_TYPE_MAX ever changed, then there would be a conflict
>>>>> between old perf.data files that had a dynamicaliy allocated PMU number
>>>>> that would then be the same as a fixed PERF_TYPE.
>>>>>
>>>>> Example:
>>>>>
>>>>> perf record --switch-events -C 0 -e
>>>>> "{cpu-clock,uncore_imc/data_reads/,uncore_imc/data_writes/}:SD" -a --
>>>>> sleep 1
>>>>> perf script
>>>>>
>>>>> Before:
>>>>> swapper 0 [000] 1479253.987551: 277766
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.987797: 246709
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.988127: 329883
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.988273: 146393
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.988523: 249977
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.988877: 354090
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.989023: 145940
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.989383: 359856
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1479253.989523: 140082
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>>
>>>>> After:
>>>>> swapper 0 [000] 1397040.402011: 272384
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1397040.402011: 5396
>>>>> uncore_imc/data_reads/:
>>>>> swapper 0 [000] 1397040.402011: 967
>>>>> uncore_imc/data_writes/:
>>>>> swapper 0 [000] 1397040.402259: 249153
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1397040.402259: 7231
>>>>> uncore_imc/data_reads/:
>>>>> swapper 0 [000] 1397040.402259: 1297
>>>>> uncore_imc/data_writes/:
>>>>> swapper 0 [000] 1397040.402508: 249108
>>>>> cpu-clock: ffffffff9d4ddb6f cpuidle_enter_state+0xdf ([kernel.kallsyms])
>>>>> swapper 0 [000] 1397040.402508: 5333
>>>>> uncore_imc/data_reads/:
>>>>> swapper 0 [000] 1397040.402508: 1008
>>>>> uncore_imc/data_writes/:
>>>>>
>>>>> Fixes: 1405720d4f26 ("perf script: Add 'synth' event type for synthesized
>>>>> events")
>>>>
>>>> It does not look to me like the problem was introduced by that commit. Are
>>>> you sure this Fixes tag is correct?
>>>>
>>>
>>> Commit 1405720d4f26 added the change:
>>>
>>> @@ -1215,8 +1253,9 @@ static void process_event(struct perf_script *script,
>>> {
>>> struct thread *thread = al->thread;
>>> struct perf_event_attr *attr = &evsel->attr;
>>> + unsigned int type = output_type(attr->type);
>>>
>>> - if (output[attr->type].fields == 0)
>>> + if (output[type].fields == 0)
>>> return;
>>
>> That is a nop if attr->type != PERF_TYPE_SYNTH
>> Given that PERF_TYPE_SYNTH is (INT_MAX + 1), it is a nop for all kernel
>> dynamically allocated PMU numbers.
>>
>>>
>>> But of course, we can also say the original "output[attr->type].fields"
>>> introduced the issue, I'm not sure. Maybe Arnaldo can help to make the
>>> decision. :)
>>
>> I think perf script has always had this problem.
>>
>
> Since perf-script has always had this problem, I'm OK to remove the fixes tag from the patch
> description.
>
> Thanks
> Jin Yao
Can I get your ACK if the fixes tag is removed from this patch?
Do I need to post a new version which just removes the fixes tag?
Thanks
Jin Yao