Re: [PATCH v1] libtraceevent: Fix event-parse memory leak in process_cond

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Tue, Apr 30, 2024 at 12:39 AM Ian Rogers <irogers@xxxxxxxxxx> wrote:
>
> Leak sanitizer was reporting a stack trace with perf:
> ```
> $ perf stat -e 'kvm:kvm_inj_exception' true
>
>  Performance counter stats for 'true':
>
>                  0      kvm:kvm_inj_exception
>
>        0.001701473 seconds time elapsed
>
>        0.000000000 seconds user
>        0.001865000 seconds sys
>
> =================================================================
> ==1705137==ERROR: LeakSanitizer: detected memory leaks
>
> Direct leak of 2 byte(s) in 1 object(s) allocated from:
>     #0 0x7f413ee80778 in __interceptor_strdup ../../../../src/libsanitizer/asan/asan_interceptors.cpp:454
>     #1 0x7f413ecb7b66 in __read_token libtraceevent/src/event-parse.c:1274
>     #2 0x7f413ecb85bb in read_token libtraceevent/src/event-parse.c:1432
>     #3 0x7f413ecbeaaa in process_entry libtraceevent/src/event-parse.c:2554
>     #4 0x7f413ecc54ae in process_arg_token libtraceevent/src/event-parse.c:3698
>     #5 0x7f413ecbb52e in process_arg libtraceevent/src/event-parse.c:2017
>     #6 0x7f413ecbd05a in process_op libtraceevent/src/event-parse.c:2357
>     #7 0x7f413ecc5a56 in process_arg_token libtraceevent/src/event-parse.c:3752
>     #8 0x7f413ecbb52e in process_arg libtraceevent/src/event-parse.c:2017
>     #9 0x7f413ecc5dd6 in event_read_print_args libtraceevent/src/event-parse.c:3791
>     #10 0x7f413ecc6511 in event_read_print libtraceevent/src/event-parse.c:3879
>     #11 0x7f413ecda16c in parse_format libtraceevent/src/event-parse.c:7808
>     #12 0x7f413ecda667 in __parse_event libtraceevent/src/event-parse.c:7866
>     #13 0x7f413ecda71b in tep_parse_format libtraceevent/src/event-parse.c:7908
>     #14 0x561672439029 in tp_format util/trace-event.c:94
>     #15 0x561672439141 in trace_event__tp_format util/trace-event.c:109
>     #16 0x56167230a429 in evsel__newtp_idx util/evsel.c:472
>     #17 0x561672329f99 in add_tracepoint util/parse-events.c:552
>     #18 0x56167232a5b4 in add_tracepoint_event util/parse-events.c:627
>     #19 0x56167232ebf2 in parse_events_add_tracepoint util/parse-events.c:1313
>     #20 0x561672411e0e in parse_events_parse util/parse-events.y:500
>     #21 0x561672332409 in parse_events__scanner util/parse-events.c:1878
>     #22 0x561672333cd4 in __parse_events util/parse-events.c:2146
>     #23 0x561672334e74 in parse_events_option util/parse-events.c:2349
>     #24 0x56167269ec23 in get_value tools/lib/subcmd/parse-options.c:251
>     #25 0x56167269fe65 in parse_short_opt tools/lib/subcmd/parse-options.c:351
>     #26 0x5616726a0e4d in parse_options_step tools/lib/subcmd/parse-options.c:539
>     #27 0x5616726a1d86 in parse_options_subcommand tools/lib/subcmd/parse-options.c:654
>     #28 0x5616720e6ad2 in cmd_stat tools/perf/builtin-stat.c:2531
>     #29 0x5616722b0f5d in run_builtin tools/perf/perf.c:350
> $ cat /sys/kernel/tracing/events/kvm/kvm_inj_exception/format
> name: kvm_inj_exception
> ID: 1956
> format:
>         field:unsigned short common_type;       offset:0;       size:2; signed:0;
>         field:unsigned char common_flags;       offset:2;       size:1; signed:0;
>         field:unsigned char common_preempt_count;       offset:3;       size:1; signed:0;
>         field:int common_pid;   offset:4;       size:4; signed:1;
>
>         field:u8 exception;     offset:8;       size:1; signed:0;
>         field:u8 has_error;     offset:9;       size:1; signed:0;
>         field:u32 error_code;   offset:12;      size:4; signed:0;
>         field:bool reinjected;  offset:16;      size:1; signed:0;
>
> print fmt: "%s%s%s%s%s", __print_symbolic(REC->exception, { 0, "#" "DE" }, { 1, "#" "DB" }, { 3, "#" "BP" }, { 4, "#" "OF" }, { 5, "#" "BR" }, { 6, "#" "UD" }, { 7, "#" "NM" }, { 8, "#" "DF" }, { 10, "#" "TS" }, { 11, "#" "NP" }, { 12, "#" "SS" }, { 13, "#" "GP" }, { 14, "#" "PF" }, { 16, "#" "MF" }, { 17, "#" "AC" }, { 18, "#" "MC" }), !REC->has_error ? "" : " (", !REC->has_error ? "" : __print_symbolic(REC->error_code, { }), !REC->has_error ? "" : ")", REC->reinjected ? " [reinjected]" : ""
> ```

Some more context. The place in the input where the leak appears is of
a string "?" read as a token at:
? "" : __print_symbolic(REC->error_code, { }), !REC->has_error ? "" :
")", REC->reinjected ? " [reinjected]" : ""

Laboriously debugged using printf. My belief that errors should clean
up allocations comes from:
https://git.kernel.org/pub/scm/libs/libtrace/libtraceevent.git/tree/src/event-parse.c#n3754

The error comes from:
https://git.kernel.org/pub/scm/libs/libtrace/libtraceevent.git/tree/src/event-parse.c#n2082
and that error originally comes from:
https://git.kernel.org/pub/scm/libs/libtrace/libtraceevent.git/tree/src/event-parse.c#n2332
where the bad token in "}". The stack trace is:

#0  process_op (event=0x6080000003a0, arg=0x604000000ed0,
tok=0x7ffff2a01920) at event-parse.c:2333
#1  0x00007ffff5efba81 in process_arg_token (event=0x6080000003a0,
arg=0x604000000ed0,
   tok=0x7ffff2912360, type=TEP_EVENT_OP) at event-parse.c:3754
#2  0x00007ffff5ef152f in process_arg (event=0x6080000003a0,
arg=0x604000000ed0,
   tok=0x7ffff2912360) at event-parse.c:2017
#3  0x00007ffff5ef6fdb in process_fields (event=0x6080000003a0,
list=0x604000000e68,
   tok=0x7ffff29122a0) at event-parse.c:2939
#4  0x00007ffff5ef7c0a in process_symbols (event=0x6080000003a0,
arg=0x604000000e50,
   tok=0x7ffff2a01820) at event-parse.c:3076
#5  0x00007ffff5efaebd in process_function (event=0x6080000003a0,
arg=0x604000000e50,
   token=0x603000001840 "\270\002", tok=0x7ffff2a01820) at event-parse.c:3626
#6  0x00007ffff5efb631 in process_arg_token (event=0x6080000003a0,
arg=0x604000000e50,
   tok=0x7ffff29121e0, type=TEP_EVENT_DELIM) at event-parse.c:3715
#7  0x00007ffff5ef152f in process_arg (event=0x6080000003a0,
arg=0x604000000e50,
   tok=0x7ffff29121e0) at event-parse.c:2017
#8  0x00007ffff5ef19c5 in process_cond (event=0x6080000003a0,
top=0x604000000cd0,
   tok=0x7ffff2a016a0) at event-parse.c:2082
#9  0x00007ffff5ef3364 in process_op (event=0x6080000003a0,
arg=0x604000000cd0, tok=0x7ffff2a016a0)
   at event-parse.c:2375
#10 0x00007ffff5ef44e1 in process_op (event=0x6080000003a0,
arg=0x604000000cd0, tok=0x7ffff2a016a0)
   at event-parse.c:2500
#11 0x00007ffff5efba81 in process_arg_token (event=0x6080000003a0,
arg=0x604000000cd0,
   tok=0x7ffff2910e20, type=TEP_EVENT_OP) at event-parse.c:3754
#12 0x00007ffff5ef152f in process_arg (event=0x6080000003a0,
arg=0x604000000cd0,
   tok=0x7ffff2910e20) at event-parse.c:2017
#13 0x00007ffff5efbe01 in event_read_print_args (event=0x6080000003a0,
list=0x604000000b10)
   at event-parse.c:3793
#14 0x00007ffff5efc53c in event_read_print (event=0x6080000003a0) at
event-parse.c:3881
#15 0x00007ffff5f10197 in parse_format (eventp=0x7ffff3008020,
tep=0x6120000004c0,
   buf=0x619000000a80 "name: kvm_inj_exception\nID:
1956\nformat:\n\tfield:unsigned short common_ty
pe;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char
common_flags;\toffset:2;\tsize:1;\tsigned:
0;\n\tfield:unsigned char common_preem"..., size=992, sys=0x602000005450 "kvm")
   at event-parse.c:7810
#16 0x00007ffff5f10692 in __parse_event (tep=0x6120000004c0,
eventp=0x7ffff3008020,
   buf=0x619000000a80 "name: kvm_inj_exception\nID:
1956\nformat:\n\tfield:unsigned short common_ty
pe;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char
common_flags;\toffset:2;\tsize:1;\tsigned:
0;\n\tfield:unsigned char common_preem"..., size=992, sys=0x602000005450 "kvm")
   at event-parse.c:7868
#17 0x00007ffff5f10746 in tep_parse_format (tep=0x6120000004c0,
eventp=0x7ffff3008020,
   buf=0x619000000a80 "name: kvm_inj_exception\nID:
1956\nformat:\n\tfield:unsigned short common_ty
pe;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char
common_flags;\toffset:2;\tsize:1;\tsigned:
0;\n\tfield:unsigned char common_preem"..., size=992, sys=0x602000005450 "kvm")
   at event-parse.c:7910
#18 0x0000555555b1e02a in tp_format (sys=0x602000005450 "kvm",
   name=0x6030000013f0 "kvm_inj_exception") at util/trace-event.c:94

So I think the error is in the "{}" in
"__print_symbolic(REC->error_code, { })" but I'm just guessing.

Thanks,
Ian

> The issue appears to be that when process_cond returns an error,
> callers clear the variable holding the string but the string was never
> freed. This change adds the free when process_cond returns
> TEP_EVENT_ERROR.
>
> Signed-off-by: Ian Rogers <irogers@xxxxxxxxxx>
> ---
>  src/event-parse.c | 2 ++
>  1 file changed, 2 insertions(+)
>
> diff --git a/src/event-parse.c b/src/event-parse.c
> index d607556..b6ae67e 100644
> --- a/src/event-parse.c
> +++ b/src/event-parse.c
> @@ -2373,6 +2373,8 @@ process_op(struct tep_event *event, struct tep_print_arg *arg, char **tok)
>
>                 /* it will set arg->op.right */
>                 type = process_cond(event, arg, tok);
> +               if (type == TEP_EVENT_ERROR)
> +                       free(token);
>
>         } else if (strcmp(token, ">>") == 0 ||
>                    strcmp(token, "<<") == 0 ||
> --
> 2.44.0.769.g3c40516874-goog
>





[Index of Archives]     [Linux USB Development]     [Linux USB Development]     [Linux Audio Users]     [Yosemite Hiking]     [Linux Kernel]     [Linux SCSI]

  Powered by Linux