lkml.org 
[lkml]   [2020]   [Jul]   [2]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    Date
    From
    Subject[PATCH v2 07/15] tools lib traceevent: Optimize pretty_print() function
    From: "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com>

    Each time the pretty_print() function is called to print an event,
    the event's format string is parsed. As this format string does not
    change, this parsing can be done only once - when the event struct
    is initialized.

    Link: https://lore.kernel.org/linux-trace-devel/20200529134929.537110-1-tz.stoyanov@gmail.com
    Link: http://lore.kernel.org/linux-trace-devel/20200625100516.365338-8-tz.stoyanov@gmail.com

    Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
    Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
    ---
    tools/lib/traceevent/event-parse-local.h | 17 +
    tools/lib/traceevent/event-parse.c | 672 ++++++++++++++++-------
    tools/lib/traceevent/event-parse.h | 3 +
    3 files changed, 495 insertions(+), 197 deletions(-)

    diff --git a/tools/lib/traceevent/event-parse-local.h b/tools/lib/traceevent/event-parse-local.h
    index 96a0b0ca0675..e71296a62236 100644
    --- a/tools/lib/traceevent/event-parse-local.h
    +++ b/tools/lib/traceevent/event-parse-local.h
    @@ -85,6 +85,23 @@ struct tep_handle {
    struct tep_plugins_dir *plugins_dir;
    };

    +enum tep_print_parse_type {
    + PRINT_FMT_STING,
    + PRINT_FMT_ARG_DIGIT,
    + PRINT_FMT_ARG_POINTER,
    + PRINT_FMT_ARG_STRING,
    +};
    +
    +struct tep_print_parse {
    + struct tep_print_parse *next;
    +
    + char *format;
    + int ls;
    + enum tep_print_parse_type type;
    + struct tep_print_arg *arg;
    + struct tep_print_arg *len_as_arg;
    +};
    +
    void tep_free_event(struct tep_event *event);
    void tep_free_format_field(struct tep_format_field *field);
    void tep_free_plugin_paths(struct tep_handle *tep);
    diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
    index c28cbba34d39..d8115d7af812 100644
    --- a/tools/lib/traceevent/event-parse.c
    +++ b/tools/lib/traceevent/event-parse.c
    @@ -5161,13 +5161,25 @@ static int print_function(struct trace_seq *s, const char *format,
    return 0;
    }

    -static int print_pointer(struct trace_seq *s, const char *format, int plen,
    - void *data, int size,
    - struct tep_event *event, struct tep_print_arg *arg)
    +static int print_arg_pointer(struct trace_seq *s, const char *format, int plen,
    + void *data, int size,
    + struct tep_event *event, struct tep_print_arg *arg)
    {
    unsigned long long val;
    int ret = 1;

    + if (arg->type == TEP_PRINT_BSTRING) {
    + trace_seq_puts(s, arg->string.string);
    + return 0;
    + }
    + while (*format) {
    + if (*format == 'p') {
    + format++;
    + break;
    + }
    + format++;
    + }
    +
    switch (*format) {
    case 'F':
    case 'f':
    @@ -5200,231 +5212,493 @@ static int print_pointer(struct trace_seq *s, const char *format, int plen,

    }

    -static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_event *event)
    +static int print_arg_number(struct trace_seq *s, const char *format, int plen,
    + void *data, int size, int ls,
    + struct tep_event *event, struct tep_print_arg *arg)
    {
    - struct tep_handle *tep = event->tep;
    - struct tep_print_fmt *print_fmt = &event->print_fmt;
    - struct tep_print_arg *arg = print_fmt->args;
    - struct tep_print_arg *args = NULL;
    - const char *ptr = print_fmt->format;
    unsigned long long val;
    - const char *saveptr;
    +
    + val = eval_num_arg(data, size, event, arg);
    +
    + switch (ls) {
    + case -2:
    + if (plen >= 0)
    + trace_seq_printf(s, format, plen, (char)val);
    + else
    + trace_seq_printf(s, format, (char)val);
    + break;
    + case -1:
    + if (plen >= 0)
    + trace_seq_printf(s, format, plen, (short)val);
    + else
    + trace_seq_printf(s, format, (short)val);
    + break;
    + case 0:
    + if (plen >= 0)
    + trace_seq_printf(s, format, plen, (int)val);
    + else
    + trace_seq_printf(s, format, (int)val);
    + break;
    + case 1:
    + if (plen >= 0)
    + trace_seq_printf(s, format, plen, (long)val);
    + else
    + trace_seq_printf(s, format, (long)val);
    + break;
    + case 2:
    + if (plen >= 0)
    + trace_seq_printf(s, format, plen, (long long)val);
    + else
    + trace_seq_printf(s, format, (long long)val);
    + break;
    + default:
    + do_warning_event(event, "bad count (%d)", ls);
    + event->flags |= TEP_EVENT_FL_FAILED;
    + }
    + return 0;
    +}
    +
    +
    +static void print_arg_string(struct trace_seq *s, const char *format, int plen,
    + void *data, int size,
    + struct tep_event *event, struct tep_print_arg *arg)
    +{
    struct trace_seq p;
    - char *bprint_fmt = NULL;
    - char format[32];
    - int len_as_arg;
    - int len_arg = 0;
    - int len;
    - int ls;
    - int ret;

    - if (event->flags & TEP_EVENT_FL_FAILED) {
    - trace_seq_printf(s, "[FAILED TO PARSE]");
    - tep_print_fields(s, data, size, event);
    - return;
    + /* Use helper trace_seq */
    + trace_seq_init(&p);
    + print_str_arg(&p, data, size, event,
    + format, plen, arg);
    + trace_seq_terminate(&p);
    + trace_seq_puts(s, p.buffer);
    + trace_seq_destroy(&p);
    +}
    +
    +static int parse_arg_format_pointer(const char *format)
    +{
    + int ret = 0;
    + int index;
    + int loop;
    +
    + switch (*format) {
    + case 'F':
    + case 'S':
    + case 'f':
    + case 's':
    + ret++;
    + break;
    + case 'M':
    + case 'm':
    + /* [mM]R , [mM]F */
    + switch (format[1]) {
    + case 'R':
    + case 'F':
    + ret++;
    + break;
    + }
    + ret++;
    + break;
    + case 'I':
    + case 'i':
    + index = 2;
    + loop = 1;
    + switch (format[1]) {
    + case 'S':
    + /*[S][pfs]*/
    + while (loop) {
    + switch (format[index]) {
    + case 'p':
    + case 'f':
    + case 's':
    + ret++;
    + index++;
    + break;
    + default:
    + loop = 0;
    + break;
    + }
    + }
    + /* fall through */
    + case '4':
    + /* [4S][hnbl] */
    + switch (format[index]) {
    + case 'h':
    + case 'n':
    + case 'l':
    + case 'b':
    + ret++;
    + index++;
    + break;
    + }
    + if (format[1] == '4') {
    + ret++;
    + break;
    + }
    + /* fall through */
    + case '6':
    + /* [6S]c */
    + if (format[index] == 'c')
    + ret++;
    + ret++;
    + break;
    + }
    + ret++;
    + break;
    + case 'U':
    + switch (format[1]) {
    + case 'L':
    + case 'l':
    + case 'B':
    + case 'b':
    + ret++;
    + break;
    + }
    + ret++;
    + break;
    + case 'h':
    + switch (format[1]) {
    + case 'C':
    + case 'D':
    + case 'N':
    + ret++;
    + break;
    + }
    + ret++;
    + break;
    + default:
    + break;
    }

    - if (event->flags & TEP_EVENT_FL_ISBPRINT) {
    - bprint_fmt = get_bprint_format(data, size, event);
    - args = make_bprint_args(bprint_fmt, data, size, event);
    - arg = args;
    - ptr = bprint_fmt;
    + return ret;
    +}
    +
    +static void free_parse_args(struct tep_print_parse *arg)
    +{
    + struct tep_print_parse *del;
    +
    + while (arg) {
    + del = arg;
    + arg = del->next;
    + free(del->format);
    + free(del);
    }
    +}

    - for (; *ptr; ptr++) {
    - ls = 0;
    - if (*ptr == '\\') {
    - ptr++;
    - switch (*ptr) {
    +static int parse_arg_add(struct tep_print_parse **parse, char *format,
    + enum tep_print_parse_type type,
    + struct tep_print_arg *arg,
    + struct tep_print_arg *len_as_arg,
    + int ls)
    +{
    + struct tep_print_parse *parg = NULL;
    +
    + parg = calloc(1, sizeof(*parg));
    + if (!parg)
    + goto error;
    + parg->format = strdup(format);
    + if (!parg->format)
    + goto error;
    + parg->type = type;
    + parg->arg = arg;
    + parg->len_as_arg = len_as_arg;
    + parg->ls = ls;
    + *parse = parg;
    + return 0;
    +error:
    + if (parg) {
    + free(parg->format);
    + free(parg);
    + }
    + return -1;
    +}
    +
    +static int parse_arg_format(struct tep_print_parse **parse,
    + struct tep_event *event,
    + const char *format, struct tep_print_arg **arg)
    +{
    + struct tep_print_arg *len_arg = NULL;
    + char print_format[32];
    + const char *start = format;
    + int ret = 0;
    + int ls = 0;
    + int res;
    + int len;
    +
    + format++;
    + ret++;
    + for (; *format; format++) {
    + switch (*format) {
    + case '#':
    + /* FIXME: need to handle properly */
    + break;
    + case 'h':
    + ls--;
    + break;
    + case 'l':
    + ls++;
    + break;
    + case 'L':
    + ls = 2;
    + break;
    + case '.':
    + case 'z':
    + case 'Z':
    + case '0' ... '9':
    + case '-':
    + break;
    + case '*':
    + /* The argument is the length. */
    + if (!*arg) {
    + do_warning_event(event, "no argument match");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + goto out_failed;
    + }
    + if (len_arg) {
    + do_warning_event(event, "argument already matched");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + goto out_failed;
    + }
    + len_arg = *arg;
    + *arg = (*arg)->next;
    + break;
    + case 'p':
    + if (!*arg) {
    + do_warning_event(event, "no argument match");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + goto out_failed;
    + }
    + res = parse_arg_format_pointer(format + 1);
    + if (res > 0) {
    + format += res;
    + ret += res;
    + }
    + len = ((unsigned long)format + 1) -
    + (unsigned long)start;
    + /* should never happen */
    + if (len > 31) {
    + do_warning_event(event, "bad format!");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + len = 31;
    + }
    + memcpy(print_format, start, len);
    + print_format[len] = 0;
    +
    + parse_arg_add(parse, print_format,
    + PRINT_FMT_ARG_POINTER, *arg, len_arg, ls);
    + *arg = (*arg)->next;
    + ret++;
    + return ret;
    + case 'd':
    + case 'u':
    + case 'i':
    + case 'x':
    + case 'X':
    + case 'o':
    + if (!*arg) {
    + do_warning_event(event, "no argument match");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + goto out_failed;
    + }
    +
    + len = ((unsigned long)format + 1) -
    + (unsigned long)start;
    +
    + /* should never happen */
    + if (len > 30) {
    + do_warning_event(event, "bad format!");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + len = 31;
    + }
    + memcpy(print_format, start, len);
    + print_format[len] = 0;
    +
    + if (event->tep->long_size == 8 && ls == 1 &&
    + sizeof(long) != 8) {
    + char *p;
    +
    + /* make %l into %ll */
    + if (ls == 1 && (p = strchr(print_format, 'l')))
    + memmove(p+1, p, strlen(p)+1);
    + ls = 2;
    + }
    + if (ls < -2 || ls > 2) {
    + do_warning_event(event, "bad count (%d)", ls);
    + event->flags |= TEP_EVENT_FL_FAILED;
    + }
    + parse_arg_add(parse, print_format,
    + PRINT_FMT_ARG_DIGIT, *arg, len_arg, ls);
    + *arg = (*arg)->next;
    + ret++;
    + return ret;
    + case 's':
    + if (!*arg) {
    + do_warning_event(event, "no matching argument");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + goto out_failed;
    + }
    +
    + len = ((unsigned long)format + 1) -
    + (unsigned long)start;
    +
    + /* should never happen */
    + if (len > 31) {
    + do_warning_event(event, "bad format!");
    + event->flags |= TEP_EVENT_FL_FAILED;
    + len = 31;
    + }
    +
    + memcpy(print_format, start, len);
    + print_format[len] = 0;
    +
    + parse_arg_add(parse, print_format,
    + PRINT_FMT_ARG_STRING, *arg, len_arg, 0);
    + *arg = (*arg)->next;
    + ret++;
    + return ret;
    + default:
    + snprintf(print_format, 32, ">%c<", *format);
    + parse_arg_add(parse, print_format,
    + PRINT_FMT_STING, NULL, NULL, 0);
    + ret++;
    + return ret;
    + }
    + ret++;
    + }
    +
    +out_failed:
    + return ret;
    +
    +}
    +
    +static int parse_arg_string(struct tep_print_parse **parse, const char *format)
    +{
    + struct trace_seq s;
    + int ret = 0;
    +
    + trace_seq_init(&s);
    + for (; *format; format++) {
    + if (*format == '\\') {
    + format++;
    + ret++;
    + switch (*format) {
    case 'n':
    - trace_seq_putc(s, '\n');
    + trace_seq_putc(&s, '\n');
    break;
    case 't':
    - trace_seq_putc(s, '\t');
    + trace_seq_putc(&s, '\t');
    break;
    case 'r':
    - trace_seq_putc(s, '\r');
    + trace_seq_putc(&s, '\r');
    break;
    case '\\':
    - trace_seq_putc(s, '\\');
    + trace_seq_putc(&s, '\\');
    break;
    default:
    - trace_seq_putc(s, *ptr);
    + trace_seq_putc(&s, *format);
    break;
    }
    -
    - } else if (*ptr == '%') {
    - saveptr = ptr;
    - len_as_arg = 0;
    - cont_process:
    - ptr++;
    - switch (*ptr) {
    - case '%':
    - trace_seq_putc(s, '%');
    - break;
    - case '#':
    - /* FIXME: need to handle properly */
    - goto cont_process;
    - case 'h':
    - ls--;
    - goto cont_process;
    - case 'l':
    - ls++;
    - goto cont_process;
    - case 'L':
    - ls = 2;
    - goto cont_process;
    - case '*':
    - /* The argument is the length. */
    - if (!arg) {
    - do_warning_event(event, "no argument match");
    - event->flags |= TEP_EVENT_FL_FAILED;
    - goto out_failed;
    - }
    - len_arg = eval_num_arg(data, size, event, arg);
    - len_as_arg = 1;
    - arg = arg->next;
    - goto cont_process;
    - case '.':
    - case 'z':
    - case 'Z':
    - case '0' ... '9':
    - case '-':
    - goto cont_process;
    - case 'p':
    - if (arg->type == TEP_PRINT_BSTRING) {
    - if (isalnum(ptr[1]))
    - ptr++;
    - trace_seq_puts(s, arg->string.string);
    - arg = arg->next;
    - break;
    - }
    - ret = print_pointer(s, ptr + 1,
    - len_as_arg ? len_arg : 1,
    - data, size,
    - event, arg);
    - arg = arg->next;
    - if (ret > 0)
    - ptr += ret;
    + } else if (*format == '%') {
    + if (*(format + 1) == '%') {
    + trace_seq_putc(&s, '%');
    + format++;
    + ret++;
    + } else
    break;
    - case 'd':
    - case 'u':
    - case 'i':
    - case 'x':
    - case 'X':
    - case 'o':
    - if (!arg) {
    - do_warning_event(event, "no argument match");
    - event->flags |= TEP_EVENT_FL_FAILED;
    - goto out_failed;
    - }
    -
    - len = ((unsigned long)ptr + 1) -
    - (unsigned long)saveptr;
    -
    - /* should never happen */
    - if (len > 31) {
    - do_warning_event(event, "bad format!");
    - event->flags |= TEP_EVENT_FL_FAILED;
    - len = 31;
    - }
    -
    - memcpy(format, saveptr, len);
    - format[len] = 0;
    + } else
    + trace_seq_putc(&s, *format);

    - val = eval_num_arg(data, size, event, arg);
    - arg = arg->next;
    + ret++;
    + }
    + trace_seq_terminate(&s);
    + parse_arg_add(parse, s.buffer, PRINT_FMT_STING, NULL, NULL, 0);
    + trace_seq_destroy(&s);

    - if (tep->long_size == 8 && ls == 1 &&
    - sizeof(long) != 8) {
    - char *p;
    + return ret;
    +}

    - /* make %l into %ll */
    - if (ls == 1 && (p = strchr(format, 'l')))
    - memmove(p+1, p, strlen(p)+1);
    - ls = 2;
    - }
    - switch (ls) {
    - case -2:
    - if (len_as_arg)
    - trace_seq_printf(s, format, len_arg, (char)val);
    - else
    - trace_seq_printf(s, format, (char)val);
    - break;
    - case -1:
    - if (len_as_arg)
    - trace_seq_printf(s, format, len_arg, (short)val);
    - else
    - trace_seq_printf(s, format, (short)val);
    - break;
    - case 0:
    - if (len_as_arg)
    - trace_seq_printf(s, format, len_arg, (int)val);
    - else
    - trace_seq_printf(s, format, (int)val);
    - break;
    - case 1:
    - if (len_as_arg)
    - trace_seq_printf(s, format, len_arg, (long)val);
    - else
    - trace_seq_printf(s, format, (long)val);
    - break;
    - case 2:
    - if (len_as_arg)
    - trace_seq_printf(s, format, len_arg,
    - (long long)val);
    - else
    - trace_seq_printf(s, format, (long long)val);
    - break;
    - default:
    - do_warning_event(event, "bad count (%d)", ls);
    - event->flags |= TEP_EVENT_FL_FAILED;
    - }
    - break;
    - case 's':
    - if (!arg) {
    - do_warning_event(event, "no matching argument");
    - event->flags |= TEP_EVENT_FL_FAILED;
    - goto out_failed;
    - }
    +static struct tep_print_parse *
    +parse_args(struct tep_event *event, const char *format, struct tep_print_arg *arg)
    +{
    + struct tep_print_parse *parse_ret = NULL;
    + struct tep_print_parse **parse = NULL;
    + int ret;
    + int len;

    - len = ((unsigned long)ptr + 1) -
    - (unsigned long)saveptr;
    + len = strlen(format);
    + while (*format) {
    + if (!parse_ret)
    + parse = &parse_ret;
    + if (*format == '%' && *(format + 1) != '%')
    + ret = parse_arg_format(parse, event, format, &arg);
    + else
    + ret = parse_arg_string(parse, format);
    + if (*parse)
    + parse = &((*parse)->next);

    - /* should never happen */
    - if (len > 31) {
    - do_warning_event(event, "bad format!");
    - event->flags |= TEP_EVENT_FL_FAILED;
    - len = 31;
    - }
    + len -= ret;
    + if (len > 0)
    + format += ret;
    + else
    + break;
    + }
    + return parse_ret;
    +}

    - memcpy(format, saveptr, len);
    - format[len] = 0;
    - if (!len_as_arg)
    - len_arg = -1;
    - /* Use helper trace_seq */
    - trace_seq_init(&p);
    - print_str_arg(&p, data, size, event,
    - format, len_arg, arg);
    - trace_seq_terminate(&p);
    - trace_seq_puts(s, p.buffer);
    - trace_seq_destroy(&p);
    - arg = arg->next;
    - break;
    - default:
    - trace_seq_printf(s, ">%c<", *ptr);
    +static void print_event_cache(struct tep_print_parse *parse, struct trace_seq *s,
    + void *data, int size, struct tep_event *event)
    +{
    + int len_arg;

    - }
    - } else
    - trace_seq_putc(s, *ptr);
    + while (parse) {
    + if (parse->len_as_arg)
    + len_arg = eval_num_arg(data, size, event, parse->len_as_arg);
    + switch (parse->type) {
    + case PRINT_FMT_ARG_DIGIT:
    + print_arg_number(s, parse->format,
    + parse->len_as_arg ? len_arg : -1, data,
    + size, parse->ls, event, parse->arg);
    + break;
    + case PRINT_FMT_ARG_POINTER:
    + print_arg_pointer(s, parse->format,
    + parse->len_as_arg ? len_arg : 1,
    + data, size, event, parse->arg);
    + break;
    + case PRINT_FMT_ARG_STRING:
    + print_arg_string(s, parse->format,
    + parse->len_as_arg ? len_arg : -1,
    + data, size, event, parse->arg);
    + break;
    + case PRINT_FMT_STING:
    + default:
    + trace_seq_printf(s, "%s", parse->format);
    + break;
    + }
    + parse = parse->next;
    }
    +}
    +
    +static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_event *event)
    +{
    + struct tep_print_parse *parse = event->print_fmt.print_cache;
    + struct tep_print_arg *args = NULL;
    + char *bprint_fmt = NULL;

    if (event->flags & TEP_EVENT_FL_FAILED) {
    -out_failed:
    trace_seq_printf(s, "[FAILED TO PARSE]");
    + tep_print_fields(s, data, size, event);
    + return;
    + }
    +
    + if (event->flags & TEP_EVENT_FL_ISBPRINT) {
    + bprint_fmt = get_bprint_format(data, size, event);
    + args = make_bprint_args(bprint_fmt, data, size, event);
    + parse = parse_args(event, bprint_fmt, args);
    }

    - if (args) {
    + print_event_cache(parse, s, data, size, event);
    +
    + if (event->flags & TEP_EVENT_FL_ISBPRINT) {
    + free_parse_args(parse);
    free_args(args);
    free(bprint_fmt);
    }
    @@ -6523,9 +6797,13 @@ enum tep_errno __tep_parse_format(struct tep_event **eventp,
    *list = arg;
    list = &arg->next;
    }
    - return 0;
    }

    + if (!(event->flags & TEP_EVENT_FL_ISBPRINT))
    + event->print_fmt.print_cache = parse_args(event,
    + event->print_fmt.format,
    + event->print_fmt.args);
    +
    return 0;

    event_parse_failed:
    @@ -7192,7 +7470,7 @@ void tep_free_event(struct tep_event *event)

    free(event->print_fmt.format);
    free_args(event->print_fmt.args);
    -
    + free_parse_args(event->print_fmt.print_cache);
    free(event);
    }

    diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
    index 91f462f5a606..ac162472268b 100644
    --- a/tools/lib/traceevent/event-parse.h
    +++ b/tools/lib/traceevent/event-parse.h
    @@ -272,9 +272,12 @@ struct tep_print_arg {
    };
    };

    +struct tep_print_parse;
    +
    struct tep_print_fmt {
    char *format;
    struct tep_print_arg *args;
    + struct tep_print_parse *print_cache;
    };

    struct tep_event {
    --
    2.26.2

    \
     
     \ /
      Last update: 2020-07-02 20:58    [W:5.040 / U:0.056 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site