Bug 215513 - libtracefs/Synthetic events: problem using tracefs_synth_add_compare_field()
Summary: libtracefs/Synthetic events: problem using tracefs_synth_add_compare_field()
Status: RESOLVED CODE_FIX
Alias: None
Product: Tools
Classification: Unclassified
Component: Trace-cmd/Kernelshark (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Default virtual assignee for Trace-cmd and kernelshark
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2022-01-21 12:24 UTC by Yordan Karadzhov
Modified: 2022-02-21 22:11 UTC (History)
2 users (show)

See Also:
Kernel Version: 5.13.0-27
Subsystem:
Regression: No
Bisected commit-id:


Attachments
libtracefs: Problem using tracefs_synth_add_compare_field() (3.17 KB, text/x-csrc)
2022-01-21 12:24 UTC, Yordan Karadzhov
Details
fix expression is_signed state (1.19 KB, patch)
2022-01-25 22:30 UTC, Tom Zanussi
Details | Diff

Description Yordan Karadzhov 2022-01-21 12:24:38 UTC
Created attachment 300295 [details]
libtracefs: Problem using tracefs_synth_add_compare_field()

I am not sure if this is a bug or I am doing something wrong when trying to use the API tracefs_synth_add_compare_field().

To demonstrate the problem, I made the following changes in the example code given in the documentation:

47a48,49
>       tracefs_synth_add_compare_field(synth, "prio", "prev_prio",
>                                       TRACEFS_SYNTH_DELTA_END, "delta_prio");
94c96,103
< 			tracefs_synth_create(synth);
---
>                       if (tracefs_synth_create(synth)) {
>                               show_event();
>                               char *err = tracefs_error_all(NULL);
>                               tracefs_error_clear(NULL);
>                               puts(err);
>                               free(err);
>                               exit(-1);
>                       }


The code is attached.
When I am trying to create the synthetic event I am getting the following:

echo 'swakeup_lat s32 pid; s32 prio; char comm[16]; s32 prev_prio; u64 delta; s32 delta_prio;' > /sys/kernel/tracing/dynamic_events
echo 'hist:keys=pid:__arg_10076_1=prio,__arg_10076_3=common_timestamp.usecs,__arg_10076_4=prio if prio < 100' > /sys/kernel/tracing/events/sched/sched_waking/trigger
echo 'hist:keys=next_pid:pid=next_pid,prio=$__arg_10076_1,comm=next_comm,__arg_10076_2=prev_prio,delta=common_timestamp.usecs-$__arg_10076_3,delta_prio=prev_prio-$__arg_10076_4:onmatch(sched.sched_waking).trace(wakeup_lat,$pid,$prio,$comm,$__arg_10076_2,$delta,$delta_prio) if next_prio < 50||!(prev_prio >= 100)' > /sys/kernel/tracing/events/sched/sched_switch/trigger
[ 2216.558275] hist:sched:sched_switch: error: Param type doesn't match synthetic event field type
  Command: hist:keys=next_pid:pid=next_pid,prio=$__arg_10076_1,comm=next_comm,__arg_10076_2=prev_prio,delta=common_timestamp.usecs-$__arg_10076_3,delta_prio=prev_prio-$__arg_10076_4:onmatch(sched.sched_waking).trace(wakeup_lat,$pid,$prio,$comm,$__arg_100


In the error message '^' points to 'prio=$__arg_10076_1'

Any ideas?

Thanks!
Yordan
Comment 1 Steven Rostedt 2022-01-23 02:37:21 UTC
On Fri, 21 Jan 2022 12:24:38 +0000
bugzilla-daemon@bugzilla.kernel.org wrote:
> libtracefs: Problem using tracefs_synth_add_compare_field()
> 
> I am not sure if this is a bug or I am doing something wrong when trying to
> use
> the API tracefs_synth_add_compare_field().

May be a bug in the kernel.

> 
> The code is attached.
> When I am trying to create the synthetic event I am getting the following:
> 
> echo 'swakeup_lat s32 pid; s32 prio; char comm[16]; s32 prev_prio; u64 delta;
> s32 delta_prio;' > /sys/kernel/tracing/dynamic_events

Did you mean > synthetic_events or is the above "swakeup" suppose to be "s:wakeup_lat"?


> echo
> 'hist:keys=pid:__arg_10076_1=prio,__arg_10076_3=common_timestamp.usecs,__arg_10076_4=prio
> if prio < 100' > /sys/kernel/tracing/events/sched/sched_waking/trigger
> echo >
> 'hist:keys=next_pid:pid=next_pid,prio=$__arg_10076_1,comm=next_comm,__arg_10076_2=prev_prio,delta=common_timestamp.usecs-$__arg_10076_3,delta_prio=prev_prio-$__arg_10076_4:onmatch(sched.sched_waking).trace(wakeup_lat,$pid,$prio,$comm,$__arg_10076_2,$delta,$delta_prio)
> > if next_prio < 50||!(prev_prio >= 100)' >
> /sys/kernel/tracing/events/sched/sched_switch/trigger

> [ 2216.558275] hist:sched:sched_switch: error: Param type doesn't match
> synthetic event field type
>   Command:
>
> hist:keys=next_pid:pid=next_pid,prio=$__arg_10076_1,comm=next_comm,__arg_10076_2=prev_prio,delta=common_timestamp.usecs-$__arg_10076_3,delta_prio=prev_prio-$__arg_10076_4:onmatch(sched.sched_waking).trace(wakeup_lat,$pid,$prio,$comm,$__arg_100
> 
> 
> In the error message '^' points to 'prio=$__arg_10076_1'

Note, I see that it works if I switch "s32 prio" to "u32 prio". I
wonder if the variable passing is losing the sign?

And even after doing that, other things fail.

This looks more like a kernel bug than a library bug.

-- Steve
Comment 2 Tom Zanussi 2022-01-25 22:30:53 UTC
Created attachment 300319 [details]
fix expression is_signed state
Comment 3 Tom Zanussi 2022-01-25 22:34:36 UTC
Can you try the attached patch? The problem appears to be that the expression doesn't have the sign propagated to it, which this patch changes.

Also, it seems like the error text is cut off - I think your commands may be longer than 256 chars, which will also need a change in the kernel.  I can submit that as a second patch upstream if that's the cases.
Comment 4 Steven Rostedt 2022-02-21 22:11:51 UTC
Fixed in the kernel with 097f1eefedea ("tracing: Propagate is_signed to expression")

Note You need to log in before you can comment on or make changes to this bug.