[PATCH v4 12/39] dyndbg: handle [+T]:buf_name.flags grammar

[Łukasz Bartosik]

Add processing to handle the new [+T]:trace_name.flags grammar.

The name provided sets selected callsites' trace-destinations:

"0"  - pr_debug()s are written to prdbg and devdbg trace events.
name - pr_debug()s are written to named trace instance,
       if its already been open'd, else err.

A user can provide trace destination name by following T flag with
":" and trace destination name, for example:

echo "module thunderbolt =pT:tbt" > <debugfs>/dynamic_debug/control
echo "module thunderbolt =lT:tbt.p" > <debugfs>/dynamic_debug/control

Or user can provide only ":" and trace destination name, for example:

echo "module thunderbolt =p:tbt" > <debugfs>/dynamic_debug/control
echo "module thunderbolt =l:tbt.p" > <debugfs>/dynamic_debug/control

In the former examples trace destination is set (":tbt") and write of
pr_debug()s is enabled ("T"). In the latter examples only trace
destination is set (":tbt") for later use.

When T flag with argument is followed by other flag then the next
flag has to be preceded with ".".

When both T flag and ":" are provided together then ":" has
to follow T flag in the form of "T:".

Use of "." as a separator between flags allows a later patch to treat
',' as a space, which mostly eliminates the need to quote query/rules.
And this in turn avoids quoting hassles:

  modprobe test_dynamic_debug dyndbg=class,D2_CORE,+p

It is particularly good for passing boot-args into test-scripts.

  vng -p 4 -v \
  -a test_dynamic_debug.dyndbg=class,D2_CORE,+p

Signed-off-by: Łukasz Bartosik <ukaszb@xxxxxxxxxxxx>
Co-developed-by: Jim Cromie <jim.cromie@xxxxxxxxx>
Signed-off-by: Jim Cromie <jim.cromie@xxxxxxxxx>
---
 lib/dynamic_debug.c | 201 +++++++++++++++++++++++++++++++++++---------
 1 file changed, 162 insertions(+), 39 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 6668f265f2c3..8a81356c52b3 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -72,6 +72,7 @@ struct ddebug_iter {
 struct flag_settings {
 	unsigned int flags;
 	unsigned int mask;
+	unsigned int trace_dst;
 };
 
 #define DD_OPEN_CMD	"open"
@@ -84,11 +85,17 @@ struct dd_private_tracebuf {
 	int use_cnt;
 };
 
+#define DST_NOT_SET    (-1)
+
 /*
- * Trace destination value 0 is reserved for writing
- * debug logs to trace events (prdbg, devdbg), that
- * is why buf[0] is not used and we traverse bitmap
- * starting from bit 1 (bit 0 is also not used).
+ * When trace is enabled (T flag is set) and trace destination field
+ * value is in range [1..63] then debug logs will be written to trace
+ * instance whose name is stored in buf[trace destination].name, e.g.
+ * when trace destination value is 2 and buf[2].name is set to tbt then
+ * debug logs will be written to <debugfs>/tracing/instances/tbt.
+ * On the other hand trace destination value 0 is reserved for writing
+ * debug logs to trace events (prdbg, devdbg), that is why buf[0] is not
+ * used and we traverse bitmap starting from bit 1 (bit 0 is also not used).
  */
 struct dd_tracebuf_tbl_info {
 	struct dd_private_tracebuf buf[TRACE_DST_LAST];
@@ -126,6 +133,81 @@ static inline unsigned int get_trace_dst(const struct _ddebug *desc)
 	return desc->ctrl.trace_dst;
 }
 
+static int find_tr_instance(const char *name)
+{
+	int idx = 1;
+
+	for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
+		if (!strcmp(trc_tbl.buf[idx].name, name))
+			return idx;
+
+	return -ENOENT;
+}
+
+static const
+char *read_colon_args(const char *str, struct flag_settings *modifiers)
+{
+	int len, idx = 0;
+	char *end;
+
+	/* Check if trace destination was already set */
+	if (modifiers->trace_dst != DST_NOT_SET)
+		return NULL;
+	/*
+	 * When both T flag and ':' are provided then the T flag
+	 * has to be followed by ':' in the form of 'T:'.
+	 */
+	if (modifiers->flags & _DPRINTK_FLAGS_TRACE &&
+	    *(str-1) != 'T')
+		return NULL;
+
+	if (strchr(str, 'T'))
+		return NULL;
+
+	str++;
+	end = strchr(str, '.');
+	if (end) {
+		len = end - str;
+		*end = '\0';
+	} else
+		len = strlen(str);
+	len -= 1;
+
+	/* destination trace events */
+	if (!strcmp(str, DD_TR_EVENT))
+		goto end;
+
+	idx = find_tr_instance(str);
+	if (idx < 0)
+		return NULL;
+end:
+	modifiers->trace_dst = idx;
+	return end ? end : str + len;
+}
+
+/*
+ * Maximum number of characters which are being displayed when
+ * printing trace instance name, longer names are truncated
+ */
+#define FLAG_COLON_ARG_LEN 24
+
+static char *show_colon_args(struct dd_ctrl *ctrl, char *p)
+{
+	int n, len = FLAG_COLON_ARG_LEN;
+	const char *str;
+
+	str = !ctrl->trace_dst ? DD_TR_EVENT :
+	      trc_tbl.buf[ctrl->trace_dst].name;
+
+	n = snprintf(p, len, "%s", str);
+	if (n >= len) {
+		strscpy(&p[len-4], "...", 4);
+		n = len - 1;
+	}
+
+	return n < 0 ? p : p + n;
+}
+
 /* Return the path relative to source root */
 static inline const char *trim_prefix(const char *path)
 {
@@ -137,9 +219,28 @@ static inline const char *trim_prefix(const char *path)
 	return path + skip;
 }
 
-static const struct { unsigned flag:8; char opt_char; } opt_array[] = {
+typedef const char* (*read_flag_args_f)(const char *, struct flag_settings *);
+typedef char* (*show_flag_args_f)(struct dd_ctrl *, char *);
+
+static const struct
+{
+	unsigned flag:8;
+	char opt_char;
+	bool always_show;
+	read_flag_args_f read_args;
+	show_flag_args_f show_args;
+} opt_array[] = {
 	{ _DPRINTK_FLAGS_PRINTK, 'p' },
 	{ _DPRINTK_FLAGS_TRACE, 'T' },
+	/*
+	 * We don't reserve a flag for ':'. The ':' is used to provide
+	 * trace destination name and when provided together with T flag
+	 * it enables output to the trace destination. When ':' is provided
+	 * without T flag then it sets trace destination for a callsite for
+	 * future use. When both T flag and ':'are provided together then
+	 * ':' has to follow T flag in the form of 'T:'.
+	 */
+	{ _DPRINTK_FLAGS_NONE, ':', true, read_colon_args, show_colon_args },
 	{ _DPRINTK_FLAGS_INCL_MODNAME, 'm' },
 	{ _DPRINTK_FLAGS_INCL_FUNCNAME, 'f' },
 	{ _DPRINTK_FLAGS_INCL_SOURCENAME, 's' },
@@ -148,22 +249,31 @@ static const struct { unsigned flag:8; char opt_char; } opt_array[] = {
 	{ _DPRINTK_FLAGS_NONE, '_' },
 };
 
-struct flagsbuf { char buf[ARRAY_SIZE(opt_array)+1]; };
+struct ctrlbuf { char buf[ARRAY_SIZE(opt_array)+FLAG_COLON_ARG_LEN+1]; };
 
 /* format a string into buf[] which describes the _ddebug's flags */
-static char *ddebug_describe_flags(unsigned int flags, struct flagsbuf *fb)
+static char *ddebug_describe_ctrl(struct dd_ctrl *ctrl, struct ctrlbuf *cb)
 {
-	char *p = fb->buf;
+	show_flag_args_f show_args = NULL;
+	char *p = cb->buf;
 	int i;
 
 	for (i = 0; i < ARRAY_SIZE(opt_array); ++i)
-		if (flags & opt_array[i].flag)
+		if (ctrl->flags & opt_array[i].flag ||
+		    opt_array[i].always_show) {
+			if (show_args)
+				*p++ = '.';
 			*p++ = opt_array[i].opt_char;
-	if (p == fb->buf)
+			show_args = opt_array[i].show_args;
+			if (show_args)
+				p = show_args(ctrl, p);
+		}
+
+	if (p == cb->buf)
 		*p++ = '_';
 	*p = '\0';
 
-	return fb->buf;
+	return cb->buf;
 }
 
 #define vnpr_info(lvl, fmt, ...)				\
@@ -221,17 +331,6 @@ static bool dd_good_trace_name(const char *str)
 	return true;
 }
 
-static int find_tr_instance(const char *name)
-{
-	int idx = 1;
-
-	for_each_set_bit_from(idx, trc_tbl.bmap, trc_tbl.bmap_size)
-		if (!strcmp(trc_tbl.buf[idx].name, name))
-			return idx;
-
-	return -ENOENT;
-}
-
 static int handle_trace_open_cmd(const char *arg)
 {
 	struct dd_private_tracebuf *buf;
@@ -383,7 +482,7 @@ static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table cons
  * Search the tables for _ddebug's which match the given `query' and
  * apply the `flags' and `mask' to them.  Returns number of matching
  * callsites, normally the same as number of changes.  If verbose,
- * logs the changes.  Takes ddebug_lock.
+ * logs the changes.
  */
 static int ddebug_change(const struct ddebug_query *query,
 			 struct flag_settings *modifiers)
@@ -391,13 +490,12 @@ static int ddebug_change(const struct ddebug_query *query,
 	int i;
 	struct ddebug_table *dt;
 	unsigned int nfound = 0;
+	struct ctrlbuf cbuf, nbuf;
 	struct dd_ctrl nctrl = {0};
-	struct flagsbuf fbuf, nbuf;
 	struct ddebug_class_map *map = NULL;
 	int __outvar valid_class;
 
 	/* search for matching ddebugs */
-	mutex_lock(&ddebug_lock);
 	list_for_each_entry(dt, &ddebug_tables, link) {
 
 		/* match against the module name */
@@ -458,7 +556,8 @@ static int ddebug_change(const struct ddebug_query *query,
 			nfound++;
 
 			nctrl.flags = (get_flags(dp) & modifiers->mask) | modifiers->flags;
-			if (!memcmp(&nctrl, get_ctrl(dp), sizeof(struct dd_ctrl)))
+			nctrl.trace_dst = modifiers->trace_dst;
+			if (!memcmp(&nctrl, get_ctrl(dp), sizeof(nctrl)))
 				continue;
 #ifdef CONFIG_JUMP_LABEL
 			if (get_flags(dp) & _DPRINTK_FLAGS_ENABLED) {
@@ -471,13 +570,12 @@ static int ddebug_change(const struct ddebug_query *query,
 			v4pr_info("changed %s:%d [%s]%s %s => %s\n",
 				  trim_prefix(dp->filename), dp->lineno,
 				  dt->mod_name, dp->function,
-				  ddebug_describe_flags(get_flags(dp), &fbuf),
-				  ddebug_describe_flags(nctrl.flags, &nbuf));
+				  ddebug_describe_ctrl(&dp->ctrl, &cbuf),
+				  ddebug_describe_ctrl(&nctrl, &nbuf));
 			update_tr_dst(dp, &nctrl);
 			set_ctrl(dp, &nctrl);
 		}
 	}
-	mutex_unlock(&ddebug_lock);
 
 	if (!nfound && verbose)
 		pr_info("no matches for query\n");
@@ -698,6 +796,7 @@ static int ddebug_parse_query(char *words[], int nwords,
  */
 static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
 {
+	read_flag_args_f read_args;
 	int op, i;
 
 	switch (*str) {
@@ -716,6 +815,12 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
 		for (i = ARRAY_SIZE(opt_array) - 1; i >= 0; i--) {
 			if (*str == opt_array[i].opt_char) {
 				modifiers->flags |= opt_array[i].flag;
+				read_args = opt_array[i].read_args;
+				if (read_args) {
+					str = read_args(str, modifiers);
+					if (!str)
+						return -EINVAL;
+				}
 				break;
 			}
 		}
@@ -724,7 +829,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
 			return -EINVAL;
 		}
 	}
-	v3pr_info("flags=0x%x\n", modifiers->flags);
+	v3pr_info("flags=0x%x, trace_dest=0x%x\n", modifiers->flags, modifiers->trace_dst);
 
 	/* calculate final flags, mask based upon op */
 	switch (op) {
@@ -747,7 +852,7 @@ static int ddebug_parse_flags(const char *str, struct flag_settings *modifiers)
 
 static int ddebug_exec_query(char *query_string, const char *modname)
 {
-	struct flag_settings modifiers = {};
+	struct flag_settings modifiers = { .trace_dst = DST_NOT_SET };
 	struct ddebug_query query = {};
 #define MAXWORDS 9
 	int nwords, nfound;
@@ -763,20 +868,38 @@ static int ddebug_exec_query(char *query_string, const char *modname)
 	if (is_dd_trace_cmd(words[0]))
 		return ddebug_parse_cmd(words, nwords-1);
 
-	/* check flags 1st (last arg) so query is pairs of spec,val */
-	if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
-		pr_err("flags parse failed\n");
-		return -EINVAL;
-	}
 	if (ddebug_parse_query(words, nwords-1, &query, modname)) {
 		pr_err("query parse failed\n");
 		return -EINVAL;
 	}
+
+	/*
+	 * Both ddebug_parse_flags and ddebug_change have to be run
+	 * with locking because ddebug_parse_flags->read_T_args verifies
+	 * if a requested trace instance is opened. Next ddebug_change
+	 * sets the requested trace instance as output for debug logs of
+	 * callsite(s) which matched a query. Because ddebug_proc_write
+	 * function can be called concurrently then without locking we
+	 * could for example run into a scenario where ddebug_change uses
+	 * a trace instance which is already closed.
+	 */
+	mutex_lock(&ddebug_lock);
+
+	/* check flags 1st (last arg) so query is pairs of spec,val */
+	if (ddebug_parse_flags(words[nwords-1], &modifiers)) {
+		pr_err("flags parse failed\n");
+		goto err;
+	}
+
 	/* actually go and implement the change */
 	nfound = ddebug_change(&query, &modifiers);
-	vpr_info_dq(&query, nfound ? "applied" : "no-match");
 
+	mutex_unlock(&ddebug_lock);
+	vpr_info_dq(&query, nfound ? "applied" : "no-match");
 	return nfound;
+err:
+	mutex_unlock(&ddebug_lock);
+	return -EINVAL;
 }
 
 /* handle multiple queries in query string, continue on error, return
@@ -1466,7 +1589,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 {
 	struct ddebug_iter *iter = m->private;
 	struct _ddebug *dp = p;
-	struct flagsbuf flags;
+	struct ctrlbuf cbuf;
 	char const *class;
 
 	if (p == SEQ_START_TOKEN) {
@@ -1478,7 +1601,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 	seq_printf(m, "%s:%u [%s]%s =%s \"",
 		   trim_prefix(dp->filename), dp->lineno,
 		   iter->table->mod_name, dp->function,
-		   ddebug_describe_flags(get_flags(dp), &flags));
+		   ddebug_describe_ctrl(&dp->ctrl, &cbuf));
 	seq_escape_str(m, dp->format, ESCAPE_SPACE, "\t\r\n\"");
 	seq_puts(m, "\"");
 
-- 
2.43.0.687.g38aa6559b0-goog