tools lib traceevent: Optimize pretty_print() function

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>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: linux-trace-devel@vger.kernel.org
Link: http://lore.kernel.org/lkml/20200702185704.559785000@goodmis.org
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
This commit is contained in:
Tzvetomir Stoyanov (VMware) 2020-07-02 14:53:51 -04:00 committed by Arnaldo Carvalho de Melo
parent 487ae1f4a1
commit e7a90882b0
3 changed files with 511 additions and 213 deletions

View File

@ -85,6 +85,23 @@ struct tep_handle {
struct tep_plugins_dir *plugins_dir; 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_event(struct tep_event *event);
void tep_free_format_field(struct tep_format_field *field); void tep_free_format_field(struct tep_format_field *field);
void tep_free_plugin_paths(struct tep_handle *tep); void tep_free_plugin_paths(struct tep_handle *tep);

View File

@ -5215,13 +5215,25 @@ static int print_function(struct trace_seq *s, const char *format,
return 0; return 0;
} }
static int print_pointer(struct trace_seq *s, const char *format, int plen, static int print_arg_pointer(struct trace_seq *s, const char *format, int plen,
void *data, int size, void *data, int size,
struct tep_event *event, struct tep_print_arg *arg) struct tep_event *event, struct tep_print_arg *arg)
{ {
unsigned long long val; unsigned long long val;
int ret = 1; 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) { switch (*format) {
case 'F': case 'F':
case 'f': case 'f':
@ -5254,23 +5266,476 @@ static int print_pointer(struct trace_seq *s, const char *format, int plen,
} }
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)
{
unsigned long long val;
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;
/* 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;
}
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);
}
}
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');
break;
case 't':
trace_seq_putc(&s, '\t');
break;
case 'r':
trace_seq_putc(&s, '\r');
break;
case '\\':
trace_seq_putc(&s, '\\');
break;
default:
trace_seq_putc(&s, *format);
break;
}
} else if (*format == '%') {
if (*(format + 1) == '%') {
trace_seq_putc(&s, '%');
format++;
ret++;
} else
break;
} else
trace_seq_putc(&s, *format);
ret++;
}
trace_seq_terminate(&s);
parse_arg_add(parse, s.buffer, PRINT_FMT_STING, NULL, NULL, 0);
trace_seq_destroy(&s);
return ret;
}
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 = 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);
len -= ret;
if (len > 0)
format += ret;
else
break;
}
return parse_ret;
}
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;
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) static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_event *event)
{ {
struct tep_handle *tep = event->tep; struct tep_print_parse *parse = event->print_fmt.print_cache;
struct tep_print_fmt *print_fmt = &event->print_fmt;
struct tep_print_arg *arg = print_fmt->args;
struct tep_print_arg *args = NULL; struct tep_print_arg *args = NULL;
const char *ptr = print_fmt->format;
unsigned long long val;
const char *saveptr;
struct trace_seq p;
char *bprint_fmt = NULL; 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) { if (event->flags & TEP_EVENT_FL_FAILED) {
trace_seq_printf(s, "[FAILED TO PARSE]"); trace_seq_printf(s, "[FAILED TO PARSE]");
@ -5281,204 +5746,13 @@ static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_e
if (event->flags & TEP_EVENT_FL_ISBPRINT) { if (event->flags & TEP_EVENT_FL_ISBPRINT) {
bprint_fmt = get_bprint_format(data, size, event); bprint_fmt = get_bprint_format(data, size, event);
args = make_bprint_args(bprint_fmt, data, size, event); args = make_bprint_args(bprint_fmt, data, size, event);
arg = args; parse = parse_args(event, bprint_fmt, args);
ptr = bprint_fmt;
} }
for (; *ptr; ptr++) { print_event_cache(parse, s, data, size, event);
ls = 0;
if (*ptr == '\\') {
ptr++;
switch (*ptr) {
case 'n':
trace_seq_putc(s, '\n');
break;
case 't':
trace_seq_putc(s, '\t');
break;
case 'r':
trace_seq_putc(s, '\r');
break;
case '\\':
trace_seq_putc(s, '\\');
break;
default:
trace_seq_putc(s, *ptr);
break;
}
} else if (*ptr == '%') { if (event->flags & TEP_EVENT_FL_ISBPRINT) {
saveptr = ptr; free_parse_args(parse);
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;
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;
val = eval_num_arg(data, size, event, arg);
arg = arg->next;
if (tep->long_size == 8 && ls == 1 &&
sizeof(long) != 8) {
char *p;
/* 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;
}
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;
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);
}
} else
trace_seq_putc(s, *ptr);
}
if (event->flags & TEP_EVENT_FL_FAILED) {
out_failed:
trace_seq_printf(s, "[FAILED TO PARSE]");
}
if (args) {
free_args(args); free_args(args);
free(bprint_fmt); free(bprint_fmt);
} }
@ -6577,9 +6851,13 @@ enum tep_errno __tep_parse_format(struct tep_event **eventp,
*list = arg; *list = arg;
list = &arg->next; 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; return 0;
event_parse_failed: event_parse_failed:
@ -7246,7 +7524,7 @@ void tep_free_event(struct tep_event *event)
free(event->print_fmt.format); free(event->print_fmt.format);
free_args(event->print_fmt.args); free_args(event->print_fmt.args);
free_parse_args(event->print_fmt.print_cache);
free(event); free(event);
} }

View File

@ -272,9 +272,12 @@ struct tep_print_arg {
}; };
}; };
struct tep_print_parse;
struct tep_print_fmt { struct tep_print_fmt {
char *format; char *format;
struct tep_print_arg *args; struct tep_print_arg *args;
struct tep_print_parse *print_cache;
}; };
struct tep_event { struct tep_event {