On Thu, 12 Apr 2018 10:13:17 -0500
Tom Zanussi <tom.zanu...@linux.intel.com> wrote:
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 6fb46a0..f2dc7e6 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -1765,6 +1765,9 @@ extern ssize_t trace_parse_run_command(struct file
> *file,
> const char __user *buffer, size_t count, loff_t *ppos,
> int (*createfn)(int, char**));
>
> +extern void event_log_err(const char *loc, const char *cmd, const char *fmt,
> + ...);
> +
> /*
> * Normal trace_printk() and friends allocates special buffers
> * to do the manipulation, as well as saves the print formats
> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index 05c7172..fd02e22 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -1668,6 +1668,164 @@ static void ignore_task_cpu(void *data)
> return ret;
> }
>
> +#define EVENT_LOG_ERRS_MAX (PAGE_SIZE / sizeof(struct event_log_err))
> +#define EVENT_ERR_LOG_MASK (EVENT_LOG_ERRS_MAX - 1)
BTW, the above only works if EVENT_LOG_ERRS_MAX is a power of two,
which it's not guaranteed to be.
> +
> +struct event_log_err {
> + char err[MAX_FILTER_STR_VAL];
> + char cmd[MAX_FILTER_STR_VAL];
> +};
I like the event_log_err idea, but the above can be shrunk to:
struct err_info {
u8 type; /* I can only imagine 254 types */
u8 pos; /* MAX_FILTER_STR_VAR = 256 */
};
struct event_log_err {
struct err_info info;
char cmd[MAX_FILTER_STR_VAL];
};
There's no reason to put in a bunch of text that's going to be static
anyway. Have a lookup table like we do for filters.
+ log_err("Variable name not unique, need to use
fully qualified name (%s) for variable: ", fqvar(system, event_name, var_name,
true));
Instead of making the fqvar, find the location of the variable, and add:
blah blah $var blah blah
^
Variable name not unique, need to use fully qualified name for variable
> +
> +static char *event_err_log;
> +static unsigned int event_err_log_tail;
> +
> +struct event_log_err *get_event_log_err(void)
> +{
> + struct event_log_err *err;
> + char *errpos;
> +
> + if (!event_err_log) {
> + event_err_log = (char *)get_zeroed_page(GFP_KERNEL);
> + if (!event_err_log)
> + return NULL;
> + }
> +
> + errpos = event_err_log + event_err_log_tail * sizeof(*err);
> + err = (struct event_log_err *)errpos;
> +
> + event_err_log_tail = (event_err_log_tail + 1) & EVENT_ERR_LOG_MASK;
So you add errors one after the other:
First error:
err1,NULL,NULL,NULL,...
^
tail
Second error:
err1,err2,NULL,NULL,...
^
tail
Third error:
err1,err2,err3,NULL,
^
tail
> +
> + return err;
> +}
> +
> +/**
> + * event_log_err - write an error to the trace event error log
> + * @loc: A string describing where the error occurred
> + * @cmd: The trace event command that caused the error
> + * @fmt: snprintf format string
> + * @...: variable length list of snprintf args
> + *
> + * Writes an error into tracing/events/error_log of the form:
> + *
> + * ERROR(<loc>): <error text ala snprintf>
> + * Command: <command that caused the error>
> + *
> + * tracing/events/error_log is a small log file containing the last
> + * EVENT_LOG_ERRS_MAX errors (8). Memory for the error log isn't
> + * allocated unless there has been a trace event error, and the error
> + * log can be cleared and have its memory freed by writing the empty
> + * string in truncation mode to it i.e. echo > error_log.
> + *
> + * Must be called with event_mutex held.
> + */
> +void event_log_err(const char *loc, const char *cmd, const char *fmt, ...)
> +{
> + struct event_log_err *err;
> + va_list args;
> + int len;
> +
> + err = get_event_log_err();
> + if (!err)
> + return;
> +
> + snprintf(err->cmd, MAX_FILTER_STR_VAL,"\n Command: %s\n", cmd);
> +
> + len = snprintf(err->err, MAX_FILTER_STR_VAL, "ERROR(%s): ", loc);
> + if (len >= MAX_FILTER_STR_VAL)
> + return;
> +
> + va_start(args, fmt);
> + vsnprintf(err->err + len, MAX_FILTER_STR_VAL - len, fmt, args);
> + va_end(args);
> +}
> +
> +static void clear_event_err_log(void)
> +{
> + free_page((long unsigned int)event_err_log);
> + event_err_log_tail = 0;
> + event_err_log = NULL;
> +}
> +
> +static void *event_err_log_inc(loff_t *pos)
> +{
> + struct event_log_err *err = NULL;
> + char *errpos = NULL;
> + int i = *pos;
> +
> + ++*pos;
> +
> + if (i >= EVENT_LOG_ERRS_MAX)
> + return NULL;
> +
> + i += event_err_log_tail;
> + i &= EVENT_ERR_LOG_MASK;
> +
> + errpos = event_err_log + (i * sizeof(*err));
> + err = (struct event_log_err *)errpos;
Now I'm confused. i += tail, so on *pos = 0, and tail = 3, we have
i = 3 (or i = tail)
err1,err2,err3,NULL,...
^
tail
i
How do we return anything when the buffer isn't full yet?
What did I miss?
Wouldn't this need to go backwards?
i = event_err_log_tail - (i + 1);
if (i < 0)
i = EVENT_ERROR_LOG - 1;
-- Steve
> +
> + return err;
> +}
> +
> +static void *event_err_log_seq_start(struct seq_file *m, loff_t *pos)
> +{
> + mutex_lock(&event_mutex);
> +
> + return event_err_log_inc(pos);
> +}
> +
> +static void *event_err_log_seq_next(struct seq_file *m, void *v, loff_t *pos)
> +{
> + return event_err_log_inc(pos);
> +}
> +
> +static void event_err_log_seq_stop(struct seq_file *m, void *v)
> +{
> + mutex_unlock(&event_mutex);
> +}
> +
> +static int event_err_log_seq_show(struct seq_file *m, void *v)
> +{
> + struct event_log_err *err = v;
> +
> + if (err)
> + seq_printf(m, "%s%s", err->err, err->cmd);
> +
> + return 0;
> +}
> +
> +static const struct seq_operations event_err_log_seq_op = {
> + .start = event_err_log_seq_start,
> + .next = event_err_log_seq_next,
> + .stop = event_err_log_seq_stop,
> + .show = event_err_log_seq_show
> +};
> +
> +static int event_err_log_open(struct inode *inode, struct file *file)
> +{
> + if (file->f_mode & FMODE_WRITE) {
> + if (file->f_flags & O_TRUNC)
> + return 0;
> + else
> + return -EINVAL;
> + }
> +
> + return seq_open(file, &event_err_log_seq_op);
> +}
> +
> +static ssize_t event_err_log_write(struct file *file,
> + const char __user *buffer,
> + size_t count, loff_t *ppos)
> +{
> + if (count == 1)
> + clear_event_err_log();
> + else
> + return -EINVAL;
> +
> + *ppos += count;
> +
> + return count;
> +}
> +
> static int ftrace_event_avail_open(struct inode *inode, struct file *file);
> static int ftrace_event_set_open(struct inode *inode, struct file *file);
> static int ftrace_event_set_pid_open(struct inode *inode, struct file *file);
> @@ -1767,6 +1925,13 @@ static void ignore_task_cpu(void *data)
> .release = subsystem_release,
> };
>
> +static const struct file_operations ftrace_event_err_log_fops = {
> + .open = event_err_log_open,
> + .write = event_err_log_write,
> + .read = seq_read,
> + .llseek = seq_lseek,
> +};
> +
> static const struct file_operations ftrace_show_header_fops = {
> .open = tracing_open_generic,
> .read = show_header,
> @@ -2927,6 +3092,13 @@ static __init int setup_trace_event(char *str)
> return -ENOMEM;
> }
>
> + entry = trace_create_file("error_log", 0644, d_events,
> + tr, &ftrace_event_err_log_fops);
> + if (!entry) {
> + pr_warn("Could not create tracefs 'error_log' entry\n");
> + return -ENOMEM;
> + }
> +
> /* There are not as crucial, just warn if they are not created */
>
> entry = tracefs_create_file("set_event_pid", 0644, parent,
