Skip to contentSkip to conversation

dev_<level> and dynamic_debug cleanups

PATCH In review Joe Perches 6 participants 30 messages Aug 26, 2012 – Sep 26, 2012

Subsystems (5)
Networking Network drivers Library code Driver core +1 more subsystems
lore
Share & tools
lore

Joe Perches

author
#0 lore raw

cover dev_<level> and dynamic_debug cleanups

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

 drivers/base/core.c       |   87 +++++++++++++++++++++++++++++---------------
 include/linux/device.h    |   17 +++++++--
 include/linux/netdevice.h |    3 --
 lib/dynamic_debug.c       |   56 ++++++++++++++++++++++-------
 net/core/dev.c            |   20 +++++++----
 5 files changed, 126 insertions(+), 57 deletions(-)
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#1 lore raw

PATCH 1/5 dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack

commit c4e00daaa9
("driver-core: extend dev_printk() to pass structured data") changed __dev_printk and broke dynamic-debug's ability to control the dynamic prefix of dev_dbg(dev,..).

commit af7f2158fd
("drivers-core: make structured logging play nice with dynamic-debug") made a minimal correction.

The current dynamic debug code uses up to 3 recursion levels via %pV. This can consume quite a bit of stack. Directly call printk_emit to reduce the recursion depth.

These changes include:

dev_dbg:
o Create and use function create_syslog_header to format the syslog header for printk_emit uses.
o Call create_syslog_header and neaten __dev_printk
o Make __dev_printk static not global
o Remove include header declaration of __dev_printk
o Remove now unused EXPORT_SYMBOL() of __dev_printk
o Whitespace neatening

dynamic_dev_dbg:
o Remove KERN_DEBUG from dynamic_emit_prefix
o Call create_syslog_header and printk_emit
o Whitespace neatening

Signed-off-by Joe Perches <[email protected]>
---
 drivers/base/core.c    |   64 +++++++++++++++++++++++++----------------------
 include/linux/device.h |    8 +++---
 lib/dynamic_debug.c    |   39 +++++++++++++++++++++-------
 3 files changed, 67 insertions(+), 44 deletions(-)
drivers/base/core.c +34 -30
index 5e6e00b..d46b635 100644
@@ -1861,26 +1861,19 @@ void device_shutdown(void)
  */
 
 #ifdef CONFIG_PRINTK
-int __dev_printk(const char *level, const struct device *dev,
-		 struct va_format *vaf)
+int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 {
-	char dict[128];
-	const char *level_extra = "";
-	size_t dictlen = 0;
 	const char *subsys;
-
-	if (!dev)
-		return printk("%s(NULL device *): %pV", level, vaf);
+	size_t pos = 0;
 
 	if (dev->class)
 		subsys = dev->class->name;
 	else if (dev->bus)
 		subsys = dev->bus->name;
 	else
-		goto skip;
+		return 0;
 
-	dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-			    "SUBSYSTEM=%s", subsys);
+	pos += snprintf(hdr + pos, hdrlen - pos, "SUBSYSTEM=%s", subsys);
 
 	/*
 	 * Add device identifier DEVICE=:

@@ -1896,32 +1889,41 @@ int __dev_printk(const char *level, const struct device *dev,
 			c = 'b';
 		else
 			c = 'c';
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				   "DEVICE=%c%u:%u",
-				   c, MAJOR(dev->devt), MINOR(dev->devt));
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=%c%u:%u",
+				c, MAJOR(dev->devt), MINOR(dev->devt));
 	} else if (strcmp(subsys, "net") == 0) {
 		struct net_device *net = to_net_dev(dev);
 
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				    "DEVICE=n%u", net->ifindex);
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=n%u", net->ifindex);
 	} else {
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				    "DEVICE=+%s:%s", subsys, dev_name(dev));
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=+%s:%s", subsys, dev_name(dev));
 	}
-skip:
-	if (level[2])
-		level_extra = &level[2]; /* skip past KERN_SOH "L" */
 
-	return printk_emit(0, level[1] - '0',
-			   dictlen ? dict : NULL, dictlen,
-			   "%s %s: %s%pV",
-			   dev_driver_string(dev), dev_name(dev),
-			   level_extra, vaf);
+	return pos;
+}
+EXPORT_SYMBOL(create_syslog_header);
+
+static int __dev_printk(const char *level, const struct device *dev,
+			struct va_format *vaf)
+{
+	char hdr[128];
+	size_t hdrlen;
+
+	if (!dev)
+		return printk("%s(NULL device *): %pV", level, vaf);
+
+	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
+
+	return printk_emit(0, level[1] - '0', hdrlen ? hdr : NULL, hdrlen,
+			   "%s %s: %pV",
+			   dev_driver_string(dev), dev_name(dev), vaf);
 }
-EXPORT_SYMBOL(__dev_printk);
 
 int dev_printk(const char *level, const struct device *dev,
 	       const char *fmt, ...)

@@ -1936,6 +1938,7 @@ int dev_printk(const char *level, const struct device *dev,
 	vaf.va = &args;
 
 	r = __dev_printk(level, dev, &vaf);
+
 	va_end(args);
 
 	return r;

@@ -1955,6 +1958,7 @@ int func(const struct device *dev, const char *fmt, ...)	\
 	vaf.va = &args;						\
 								\
 	r = __dev_printk(kern_level, dev, &vaf);		\
+								\
 	va_end(args);						\
 								\
 	return r;						\
include/linux/device.h +4 -4
index 52a5f15..4800d73 100644
@@ -891,12 +891,12 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
-extern int __dev_printk(const char *level, const struct device *dev,
-			struct va_format *vaf);
+extern int create_syslog_header(const struct device *dev,
+				char *hdr, size_t hdrlen);
+
 extern __printf(3, 4)
 int dev_printk(const char *level, const struct device *dev,
-	       const char *fmt, ...)
-	;
+	       const char *fmt, ...);
 extern __printf(2, 3)
 int dev_emerg(const struct device *dev, const char *fmt, ...);
 extern __printf(2, 3)
lib/dynamic_debug.c +29 -10
index 7ca29a0..29ff2e4 100644
@@ -521,25 +521,25 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
 	int pos_after_tid;
 	int pos = 0;
 
-	pos += snprintf(buf + pos, remaining(pos), "%s", KERN_DEBUG);
+	*buf = '\0';
+
 	if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
 		if (in_interrupt())
-			pos += snprintf(buf + pos, remaining(pos), "%s ",
-						"<intr>");
+			pos += snprintf(buf + pos, remaining(pos), "<intr> ");
 		else
 			pos += snprintf(buf + pos, remaining(pos), "[%d] ",
-						task_pid_vnr(current));
+					task_pid_vnr(current));
 	}
 	pos_after_tid = pos;
 	if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
-					desc->modname);
+				desc->modname);
 	if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
-					desc->function);
+				desc->function);
 	if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
 		pos += snprintf(buf + pos, remaining(pos), "%d:",
-					desc->lineno);
+				desc->lineno);
 	if (pos - pos_after_tid)
 		pos += snprintf(buf + pos, remaining(pos), " ");
 	if (pos >= PREFIX_SIZE)

@@ -559,9 +559,13 @@ int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = printk("%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
+
+	res = printk(KERN_DEBUG "%s%pV",
+		     dynamic_emit_prefix(descriptor, buf), &vaf);
+
 	va_end(args);
 
 	return res;

@@ -574,15 +578,30 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
-	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = __dev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
+
+	if (!dev) {
+		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
+	} else {
+		char buf[PREFIX_SIZE];
+		char dict[128];
+		size_t dictlen;
+
+		dictlen = create_syslog_header(dev, dict, sizeof(dict));
+
+		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
+				  "%s%s %s: %pV",
+				  dynamic_emit_prefix(descriptor, buf),
+				  dev_driver_string(dev), dev_name(dev), &vaf);
+	}
+
 	va_end(args);
 
 	return res;
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#2 lore raw

PATCH 1/5 dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack

In reply to Joe Perches

commit c4e00daaa9
("driver-core: extend dev_printk() to pass structured data") changed __dev_printk and broke dynamic-debug's ability to control the dynamic prefix of dev_dbg(dev,..).

commit af7f2158fd
("drivers-core: make structured logging play nice with dynamic-debug") made a minimal correction.

The current dynamic debug code uses up to 3 recursion levels via %pV. This can consume quite a bit of stack. Directly call printk_emit to reduce the recursion depth.

These changes include:

dev_dbg:
o Create and use function create_syslog_header to format the syslog header for printk_emit uses.
o Call create_syslog_header and neaten __dev_printk
o Make __dev_printk static not global
o Remove include header declaration of __dev_printk
o Remove now unused EXPORT_SYMBOL() of __dev_printk
o Whitespace neatening

dynamic_dev_dbg:
o Remove KERN_DEBUG from dynamic_emit_prefix
o Call create_syslog_header and printk_emit
o Whitespace neatening

Signed-off-by Joe Perches <[email protected]>
Acked-by David S. Miller <[email protected]>
Tested-by Jim Cromie <[email protected]>
Acked-by Jason Baron <[email protected]>
---
 drivers/base/core.c    |   64 +++++++++++++++++++++++++----------------------
 include/linux/device.h |    8 +++---
 lib/dynamic_debug.c    |   39 +++++++++++++++++++++-------
 3 files changed, 67 insertions(+), 44 deletions(-)
drivers/base/core.c +34 -30
index 5e6e00b..d46b635 100644
@@ -1861,26 +1861,19 @@ void device_shutdown(void)
  */
 
 #ifdef CONFIG_PRINTK
-int __dev_printk(const char *level, const struct device *dev,
-		 struct va_format *vaf)
+int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 {
-	char dict[128];
-	const char *level_extra = "";
-	size_t dictlen = 0;
 	const char *subsys;
-
-	if (!dev)
-		return printk("%s(NULL device *): %pV", level, vaf);
+	size_t pos = 0;
 
 	if (dev->class)
 		subsys = dev->class->name;
 	else if (dev->bus)
 		subsys = dev->bus->name;
 	else
-		goto skip;
+		return 0;
 
-	dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-			    "SUBSYSTEM=%s", subsys);
+	pos += snprintf(hdr + pos, hdrlen - pos, "SUBSYSTEM=%s", subsys);
 
 	/*
 	 * Add device identifier DEVICE=:

@@ -1896,32 +1889,41 @@ int __dev_printk(const char *level, const struct device *dev,
 			c = 'b';
 		else
 			c = 'c';
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				   "DEVICE=%c%u:%u",
-				   c, MAJOR(dev->devt), MINOR(dev->devt));
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=%c%u:%u",
+				c, MAJOR(dev->devt), MINOR(dev->devt));
 	} else if (strcmp(subsys, "net") == 0) {
 		struct net_device *net = to_net_dev(dev);
 
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				    "DEVICE=n%u", net->ifindex);
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=n%u", net->ifindex);
 	} else {
-		dictlen++;
-		dictlen += snprintf(dict + dictlen, sizeof(dict) - dictlen,
-				    "DEVICE=+%s:%s", subsys, dev_name(dev));
+		pos++;
+		pos += snprintf(hdr + pos, hdrlen - pos,
+				"DEVICE=+%s:%s", subsys, dev_name(dev));
 	}
-skip:
-	if (level[2])
-		level_extra = &level[2]; /* skip past KERN_SOH "L" */
 
-	return printk_emit(0, level[1] - '0',
-			   dictlen ? dict : NULL, dictlen,
-			   "%s %s: %s%pV",
-			   dev_driver_string(dev), dev_name(dev),
-			   level_extra, vaf);
+	return pos;
+}
+EXPORT_SYMBOL(create_syslog_header);
+
+static int __dev_printk(const char *level, const struct device *dev,
+			struct va_format *vaf)
+{
+	char hdr[128];
+	size_t hdrlen;
+
+	if (!dev)
+		return printk("%s(NULL device *): %pV", level, vaf);
+
+	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
+
+	return printk_emit(0, level[1] - '0', hdrlen ? hdr : NULL, hdrlen,
+			   "%s %s: %pV",
+			   dev_driver_string(dev), dev_name(dev), vaf);
 }
-EXPORT_SYMBOL(__dev_printk);
 
 int dev_printk(const char *level, const struct device *dev,
 	       const char *fmt, ...)

@@ -1936,6 +1938,7 @@ int dev_printk(const char *level, const struct device *dev,
 	vaf.va = &args;
 
 	r = __dev_printk(level, dev, &vaf);
+
 	va_end(args);
 
 	return r;

@@ -1955,6 +1958,7 @@ int func(const struct device *dev, const char *fmt, ...)	\
 	vaf.va = &args;						\
 								\
 	r = __dev_printk(kern_level, dev, &vaf);		\
+								\
 	va_end(args);						\
 								\
 	return r;						\
include/linux/device.h +4 -4
index 52a5f15..4800d73 100644
@@ -891,12 +891,12 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
-extern int __dev_printk(const char *level, const struct device *dev,
-			struct va_format *vaf);
+extern int create_syslog_header(const struct device *dev,
+				char *hdr, size_t hdrlen);
+
 extern __printf(3, 4)
 int dev_printk(const char *level, const struct device *dev,
-	       const char *fmt, ...)
-	;
+	       const char *fmt, ...);
 extern __printf(2, 3)
 int dev_emerg(const struct device *dev, const char *fmt, ...);
 extern __printf(2, 3)
lib/dynamic_debug.c +29 -10
index 7ca29a0..29ff2e4 100644
@@ -521,25 +521,25 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
 	int pos_after_tid;
 	int pos = 0;
 
-	pos += snprintf(buf + pos, remaining(pos), "%s", KERN_DEBUG);
+	*buf = '\0';
+
 	if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
 		if (in_interrupt())
-			pos += snprintf(buf + pos, remaining(pos), "%s ",
-						"<intr>");
+			pos += snprintf(buf + pos, remaining(pos), "<intr> ");
 		else
 			pos += snprintf(buf + pos, remaining(pos), "[%d] ",
-						task_pid_vnr(current));
+					task_pid_vnr(current));
 	}
 	pos_after_tid = pos;
 	if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
-					desc->modname);
+				desc->modname);
 	if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
-					desc->function);
+				desc->function);
 	if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
 		pos += snprintf(buf + pos, remaining(pos), "%d:",
-					desc->lineno);
+				desc->lineno);
 	if (pos - pos_after_tid)
 		pos += snprintf(buf + pos, remaining(pos), " ");
 	if (pos >= PREFIX_SIZE)

@@ -559,9 +559,13 @@ int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = printk("%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
+
+	res = printk(KERN_DEBUG "%s%pV",
+		     dynamic_emit_prefix(descriptor, buf), &vaf);
+
 	va_end(args);
 
 	return res;

@@ -574,15 +578,30 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
-	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = __dev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
+
+	if (!dev) {
+		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
+	} else {
+		char buf[PREFIX_SIZE];
+		char dict[128];
+		size_t dictlen;
+
+		dictlen = create_syslog_header(dev, dict, sizeof(dict));
+
+		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
+				  "%s%s %s: %pV",
+				  dynamic_emit_prefix(descriptor, buf),
+				  dev_driver_string(dev), dev_name(dev), &vaf);
+	}
+
 	va_end(args);
 
 	return res;
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#3 lore raw

PATCH 2/5 netdev_printk/dynamic_netdev_dbg: Directly call printk_emit

In reply to Joe Perches

A lot of stack is used in recursive printks with %pV.

Using multiple levels of %pV (a logging function with %pV that calls another logging function with %pV) can consume more stack than necessary.

Avoid excessive stack use by not calling dev_printk from netdev_printk and dynamic_netdev_dbg. Duplicate the logic and form of dev_printk instead.

Make __netdev_printk static.
Remove EXPORT_SYMBOL(__netdev_printk)
Whitespace and brace style neatening.

Signed-off-by Joe Perches <[email protected]>
---
 include/linux/netdevice.h |    3 ---
 lib/dynamic_debug.c       |   26 +++++++++++++++++++++++---
 net/core/dev.c            |   24 +++++++++++++++++-------
 3 files changed, 40 insertions(+), 13 deletions(-)
include/linux/netdevice.h +0 -3
index 59dc05f3..5f49cc0 100644
@@ -2720,9 +2720,6 @@ static inline const char *netdev_name(const struct net_device *dev)
 	return dev->name;
 }
 
-extern int __netdev_printk(const char *level, const struct net_device *dev,
-			struct va_format *vaf);
-
 extern __printf(3, 4)
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...);
lib/dynamic_debug.c +23 -3
index 29ff2e4..2a29f4e 100644
@@ -611,20 +611,40 @@ EXPORT_SYMBOL(__dynamic_dev_dbg);
 #ifdef CONFIG_NET
 
 int __dynamic_netdev_dbg(struct _ddebug *descriptor,
-		      const struct net_device *dev, const char *fmt, ...)
+			 const struct net_device *dev, const char *fmt, ...)
 {
 	struct va_format vaf;
 	va_list args;
 	int res;
-	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = __netdev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
+
+	if (dev && dev->dev.parent) {
+		char buf[PREFIX_SIZE];
+		char dict[128];
+		size_t dictlen;
+
+		dictlen = create_syslog_header(dev->dev.parent,
+					       dict, sizeof(dict));
+
+		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
+				  "%s%s %s: %s: %pV",
+				  dynamic_emit_prefix(descriptor, buf),
+				  dev_driver_string(dev->dev.parent),
+				  dev_name(dev->dev.parent),
+				  netdev_name(dev), &vaf);
+	} else if (dev) {
+		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
+	} else {
+		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
+	}
+
 	va_end(args);
 
 	return res;
net/core/dev.c +17 -7
index 8398836..a588145 100644
@@ -6422,22 +6422,30 @@ const char *netdev_drivername(const struct net_device *dev)
 	return empty;
 }
 
-int __netdev_printk(const char *level, const struct net_device *dev,
+static int __netdev_printk(const char *level, const struct net_device *dev,
 			   struct va_format *vaf)
 {
 	int r;
 
-	if (dev && dev->dev.parent)
-		r = dev_printk(level, dev->dev.parent, "%s: %pV",
-			       netdev_name(dev), vaf);
-	else if (dev)
+	if (dev && dev->dev.parent) {
+		char dict[128];
+		size_t dictlen = create_syslog_header(dev->dev.parent,
+						      dict, sizeof(dict));
+
+		r = printk_emit(0, level[1] - '0',
+				dictlen ? dict : NULL, dictlen,
+				"%s %s: %s: %pV",
+				dev_driver_string(dev->dev.parent),
+				dev_name(dev->dev.parent),
+				netdev_name(dev), vaf);
+	} else if (dev) {
 		r = printk("%s%s: %pV", level, netdev_name(dev), vaf);
-	else
+	} else {
 		r = printk("%s(NULL net_device): %pV", level, vaf);
+	}
 
 	return r;
 }
-EXPORT_SYMBOL(__netdev_printk);
 
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...)

@@ -6452,6 +6460,7 @@ int netdev_printk(const char *level, const struct net_device *dev,
 	vaf.va = &args;
 
 	r = __netdev_printk(level, dev, &vaf);
+
 	va_end(args);
 
 	return r;

@@ -6471,6 +6480,7 @@ int func(const struct net_device *dev, const char *fmt, ...)	\
 	vaf.va = &args;						\
 								\
 	r = __netdev_printk(level, dev, &vaf);			\
+								\
 	va_end(args);						\
 								\
 	return r;						\
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#4 lore raw

PATCH 2/5 netdev_printk/dynamic_netdev_dbg: Directly call printk_emit

In reply to Joe Perches

A lot of stack is used in recursive printks with %pV.

Using multiple levels of %pV (a logging function with %pV that calls another logging function with %pV) can consume more stack than necessary.

Avoid excessive stack use by not calling dev_printk from netdev_printk and dynamic_netdev_dbg. Duplicate the logic and form of dev_printk instead.

Make __netdev_printk static.
Remove EXPORT_SYMBOL(__netdev_printk)
Whitespace and brace style neatening.

Signed-off-by Joe Perches <[email protected]>
Acked-by David S. Miller <[email protected]>
Tested-by Jim Cromie <[email protected]>
Acked-by Jason Baron <[email protected]>
---
 include/linux/netdevice.h |    3 ---
 lib/dynamic_debug.c       |   26 +++++++++++++++++++++++---
 net/core/dev.c            |   24 +++++++++++++++++-------
 3 files changed, 40 insertions(+), 13 deletions(-)
include/linux/netdevice.h +0 -3
index 59dc05f3..5f49cc0 100644
@@ -2720,9 +2720,6 @@ static inline const char *netdev_name(const struct net_device *dev)
 	return dev->name;
 }
 
-extern int __netdev_printk(const char *level, const struct net_device *dev,
-			struct va_format *vaf);
-
 extern __printf(3, 4)
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...);
lib/dynamic_debug.c +23 -3
index 29ff2e4..2a29f4e 100644
@@ -611,20 +611,40 @@ EXPORT_SYMBOL(__dynamic_dev_dbg);
 #ifdef CONFIG_NET
 
 int __dynamic_netdev_dbg(struct _ddebug *descriptor,
-		      const struct net_device *dev, const char *fmt, ...)
+			 const struct net_device *dev, const char *fmt, ...)
 {
 	struct va_format vaf;
 	va_list args;
 	int res;
-	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);
 
 	va_start(args, fmt);
+
 	vaf.fmt = fmt;
 	vaf.va = &args;
-	res = __netdev_printk(dynamic_emit_prefix(descriptor, buf), dev, &vaf);
+
+	if (dev && dev->dev.parent) {
+		char buf[PREFIX_SIZE];
+		char dict[128];
+		size_t dictlen;
+
+		dictlen = create_syslog_header(dev->dev.parent,
+					       dict, sizeof(dict));
+
+		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
+				  "%s%s %s: %s: %pV",
+				  dynamic_emit_prefix(descriptor, buf),
+				  dev_driver_string(dev->dev.parent),
+				  dev_name(dev->dev.parent),
+				  netdev_name(dev), &vaf);
+	} else if (dev) {
+		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
+	} else {
+		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
+	}
+
 	va_end(args);
 
 	return res;
net/core/dev.c +17 -7
index 8398836..a588145 100644
@@ -6422,22 +6422,30 @@ const char *netdev_drivername(const struct net_device *dev)
 	return empty;
 }
 
-int __netdev_printk(const char *level, const struct net_device *dev,
+static int __netdev_printk(const char *level, const struct net_device *dev,
 			   struct va_format *vaf)
 {
 	int r;
 
-	if (dev && dev->dev.parent)
-		r = dev_printk(level, dev->dev.parent, "%s: %pV",
-			       netdev_name(dev), vaf);
-	else if (dev)
+	if (dev && dev->dev.parent) {
+		char dict[128];
+		size_t dictlen = create_syslog_header(dev->dev.parent,
+						      dict, sizeof(dict));
+
+		r = printk_emit(0, level[1] - '0',
+				dictlen ? dict : NULL, dictlen,
+				"%s %s: %s: %pV",
+				dev_driver_string(dev->dev.parent),
+				dev_name(dev->dev.parent),
+				netdev_name(dev), vaf);
+	} else if (dev) {
 		r = printk("%s%s: %pV", level, netdev_name(dev), vaf);
-	else
+	} else {
 		r = printk("%s(NULL net_device): %pV", level, vaf);
+	}
 
 	return r;
 }
-EXPORT_SYMBOL(__netdev_printk);
 
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...)

@@ -6452,6 +6460,7 @@ int netdev_printk(const char *level, const struct net_device *dev,
 	vaf.va = &args;
 
 	r = __netdev_printk(level, dev, &vaf);
+
 	va_end(args);
 
 	return r;

@@ -6471,6 +6480,7 @@ int func(const struct net_device *dev, const char *fmt, ...)	\
 	vaf.va = &args;						\
 								\
 	r = __netdev_printk(level, dev, &vaf);			\
+								\
 	va_end(args);						\
 								\
 	return r;						\
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#5 lore raw

PATCH 3/5 netdev_printk/netif_printk: Remove a superfluous logging colon

In reply to Joe Perches

netdev_printk originally called dev_printk with %pV.

This style emitted the complete dev_printk header with a colon followed by the netdev_name prefix followed by a colon.

Now that netdev_printk does not call dev_printk, the extra colon is superfluous. Remove it.

Example:
old: sky2 0000:02:00.0: eth0: Link is up at 100 Mbps, full duplex, flow control both
new: sky2 0000:02:00.0 eth0: Link is up at 100 Mbps, full duplex, flow control both

Signed-off-by Joe Perches <[email protected]>
---
 lib/dynamic_debug.c |    2 +-
 net/core/dev.c      |    2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)
lib/dynamic_debug.c +1 -1
index 2a29f4e..6b3ebab 100644
@@ -634,7 +634,7 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 					       dict, sizeof(dict));
 
 		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s: %s: %pV",
+				  "%s%s %s %s: %pV",
 				  dynamic_emit_prefix(descriptor, buf),
 				  dev_driver_string(dev->dev.parent),
 				  dev_name(dev->dev.parent),
net/core/dev.c +1 -1
index a588145..1ec186a 100644
@@ -6434,7 +6434,7 @@ static int __netdev_printk(const char *level, const struct net_device *dev,
 
 		r = printk_emit(0, level[1] - '0',
 				dictlen ? dict : NULL, dictlen,
-				"%s %s: %s: %pV",
+				"%s %s %s: %pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), vaf);
Signature · 1 line
1.7.8.111.gad25c.dirty
maintainer Acked-by on the v1 series
#6 lore raw
In reply to Joe Perches

From: Joe Perches <[email protected]>
Date: Sun, 26 Aug 2012 04:25:25 -0700

Quoted 4 lines

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

I think these should go through the generic device tree, feel free to add my:

Acked-by David S. Miller <[email protected]>
maintainer
#7 lore raw
In reply to Joe Perches
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Ive tested this on 2 builds differing only by DYNAMIC_DEBUG It works for me on x86-64

However, I just booted a non-dyndbg build on x86-32, and got this.

root@voyage:~# dmesg | grep Unknown
mac80211: Unknown symbol __dynamic_dev_dbg (err 0)
mac80211: Unknown symbol __dynamic_pr_debug (err 0)
scx200_acb: Unknown symbol __dynamic_dev_dbg (err 0)
scx200_acb: Unknown symbol __dynamic_pr_debug (err 0)
hwmon: Unknown symbol __dynamic_dev_dbg (err 0)
nsc_gpio: Unknown symbol __dynamic_dev_dbg (err 0)
nsc_gpio: Unknown symbol __dynamic_dev_dbg (err 0)
root@voyage:~#

It may be my error, will investigate asap,
but wanted to report now.

thanks

author
#8 lore raw
Quoted 30 lines · Jim Cromie
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Ive tested this on 2 builds differing only by DYNAMIC_DEBUG It works for me on x86-64

However, I just booted a non-dyndbg build on x86-32, and got this.

root@voyage:~# dmesg | grep Unknown
mac80211: Unknown symbol __dynamic_dev_dbg (err 0)
mac80211: Unknown symbol __dynamic_pr_debug (err 0)
scx200_acb: Unknown symbol __dynamic_dev_dbg (err 0)
scx200_acb: Unknown symbol __dynamic_pr_debug (err 0)
hwmon: Unknown symbol __dynamic_dev_dbg (err 0)
nsc_gpio: Unknown symbol __dynamic_dev_dbg (err 0)
nsc_gpio: Unknown symbol __dynamic_dev_dbg (err 0)
root@voyage:~#
Quoted 2 lines

It may be my error, will investigate asap,
but wanted to report now.

Thanks, but I don't know how this is possible.
There are no 32/64 component tests in this code.

maintainer Tested-by
#9 lore raw
In reply to Jim Cromie
Quoted 14 lines · Jim Cromie
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Quoted 5 lines

Ive tested this on 2 builds differing only by DYNAMIC_DEBUG It works for me on x86-64

However, I just booted a non-dyndbg build on x86-32, and got this.

Ok, transient error, went away with a clean build.

Tested-by Jim Cromie <[email protected]>

thanks

maintainer
#10 lore raw
Quoted 18 lines · Jim Cromie
Quoted 17 lines · Jim Cromie
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Ive tested this on 2 builds differing only by DYNAMIC_DEBUG It works for me on x86-64

Quoted 6 lines
Quoted 2 lines

However, I just booted a non-dyndbg build on x86-32, and got this.

Ok, transient error, went away with a clean build.

Tested-by Jim Cromie <[email protected]>

Jason, any ACK on these, or any of the other random dynamic debug patches floating around? What am I supposed to be applying here?

thanks,

greg k-h

#11 lore raw
Quoted 22 lines · Greg Kroah-Hartman
Quoted 21 lines · Jim Cromie
Quoted 19 lines · Jim Cromie
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Ive tested this on 2 builds differing only by DYNAMIC_DEBUG It works for me on x86-64

However, I just booted a non-dyndbg build on x86-32, and got this.

Quoted 7 lines
Quoted 3 lines

Ok, transient error, went away with a clean build.

Tested-by Jim Cromie <[email protected]>

Jason, any ACK on these, or any of the other random dynamic debug patches floating around? What am I supposed to be applying here?

Hi Greg,

I just posted some follow up comments to Joe, so let's see where that discussion goes.

Thanks,

-Jason

author
#12 lore raw
Quoted 3 lines · Jason Baron
Quoted 2 lines · Greg Kroah-Hartman

Jason, any ACK on these, or any of the other random dynamic debug patches floating around? What am I supposed to be applying here?

[]

Quoted 2 lines

I just posted some follow up comments to Joe, so let's see where that discussion goes.

Jason, I think you need to ack these original 5 patches.

Acked-by
#13 lore raw
Quoted 10 lines · Joe Perches
Quoted 3 lines · Jason Baron
Quoted 2 lines · Greg Kroah-Hartman

Jason, any ACK on these, or any of the other random dynamic debug patches floating around? What am I supposed to be applying here?

[]

Quoted 2 lines

I just posted some follow up comments to Joe, so let's see where that discussion goes.

Jason, I think you need to ack these original 5 patches.

Hi,

Yes, they are certainly an improvement. Please add to the series:

Acked-by Jason Baron <[email protected]>

Thanks!

-Jason

maintainer
#14 lore raw
Quoted 9 lines · Jason Baron
Quoted 8 lines · Joe Perches
Quoted 3 lines · Jason Baron
Quoted 2 lines · Greg Kroah-Hartman

Jason, any ACK on these, or any of the other random dynamic debug patches floating around? What am I supposed to be applying here?

[]

Quoted 2 lines

I just posted some follow up comments to Joe, so let's see where that discussion goes.

Quoted 8 lines
Quoted 2 lines

Jason, I think you need to ack these original 5 patches.

Hi,

Yes, they are certainly an improvement. Please add to the series:

Acked-by Jason Baron <[email protected]>

Um, can someone please resend these with the ack so I can pick them up? They are long gone from my mboxes...

greg k-h

#15 lore raw
In reply to Joe Perches
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Looks Good.

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

Thanks,

-Jason

author
#16 lore raw
Quoted 14 lines · Jason Baron
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Quoted 8 lines

Looks Good.

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

I don't think that's an improvement actually.
Why don't you try it.

#17 lore raw
Quoted 24 lines · Joe Perches
Quoted 14 lines · Jason Baron
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Quoted 8 lines

Looks Good.

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

Quoted 3 lines

I don't think that's an improvement actually.
Why don't you try it.

Ok, below is what I was thinking. It winds up being more deletions than insertions.

Thanks,

-Jason

dynamic debug: remove duplicate __netdev_printk() and __dev_printk() logic

Add an option prefix string argument to __netdev_printk() and __dev_printk(). In this way dynamic debug does not have to contain duplicate logic.

Signed-off-by Jason Baron <[email protected]>
---
 drivers/base/core.c       |   13 +++++++------
 include/linux/device.h    |    3 +++
 include/linux/netdevice.h |    3 +++
 lib/dynamic_debug.c       |   32 ++++++++------------------------
 net/core/dev.c            |   11 ++++++-----
 5 files changed, 27 insertions(+), 35 deletions(-)
drivers/base/core.c +7 -6
index 65f82e3..7b4ee6d 100644
@@ -1937,15 +1937,16 @@ int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
 }
 EXPORT_SYMBOL(dev_printk_emit);
 
-static int __dev_printk(const char *level, const struct device *dev,
-			struct va_format *vaf)
+int __dev_printk(const char *level, const struct device *dev,
+		 char *prefix, struct va_format *vaf)
 {
 	if (!dev)
 		return printk("%s(NULL device *): %pV", level, vaf);
 
 	return dev_printk_emit(level[1] - '0', dev,
-			       "%s %s: %pV",
-			       dev_driver_string(dev), dev_name(dev), vaf);
+			       "%s%s %s: %pV",
+			       prefix, dev_driver_string(dev),
+			       dev_name(dev), vaf);
 }
 
 int dev_printk(const char *level, const struct device *dev,

@@ -1960,7 +1961,7 @@ int dev_printk(const char *level, const struct device *dev,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	r = __dev_printk(level, dev, &vaf);
+	r = __dev_printk(level, dev, "", &vaf);
 
 	va_end(args);
 

@@ -1980,7 +1981,7 @@ int func(const struct device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __dev_printk(kern_level, dev, &vaf);		\
+	r = __dev_printk(kern_level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\
include/linux/device.h +3 -0
index 2da4589..573b15e 100644
@@ -891,6 +891,9 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
+extern int __dev_printk(const char *level, const struct device *dev,
+			char *prefix, struct va_format *vaf);
+
 extern int dev_vprintk_emit(int level, const struct device *dev,
 			    const char *fmt, va_list args);
 extern __printf(3, 4)
include/linux/netdevice.h +3 -0
index 5f49cc0..63f6165 100644
@@ -2720,6 +2720,9 @@ static inline const char *netdev_name(const struct net_device *dev)
 	return dev->name;
 }
 
+extern int __netdev_printk(const char *level, const struct net_device *dev,
+			   char *prefix, struct va_format *vaf);
+
 extern __printf(3, 4)
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...);
lib/dynamic_debug.c +8 -24
index e7f7d99..83bf601 100644
@@ -578,6 +578,7 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -587,16 +588,9 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (!dev) {
-		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
-	} else {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev), dev_name(dev),
-				      &vaf);
-	}
+	res = __dev_printk(KERN_DEBUG, dev,
+			   dynamic_emit_prefix(descriptor, buf),
+			   &vaf);
 
 	va_end(args);
 

@@ -612,6 +606,7 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -621,20 +616,9 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (dev && dev->dev.parent) {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev->dev.parent,
-				      "%s%s %s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev->dev.parent),
-				      dev_name(dev->dev.parent),
-				      netdev_name(dev), &vaf);
-	} else if (dev) {
-		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
-	} else {
-		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
-	}
+	res = __netdev_printk(KERN_DEBUG, dev,
+			      dynamic_emit_prefix(descriptor, buf),
+			      &vaf);
 
 	va_end(args);
net/core/dev.c +6 -5
index 8ad42fd..5fef0f6 100644
@@ -6422,15 +6422,16 @@ const char *netdev_drivername(const struct net_device *dev)
 	return empty;
 }
 
-static int __netdev_printk(const char *level, const struct net_device *dev,
-			   struct va_format *vaf)
+int __netdev_printk(const char *level, const struct net_device *dev,
+		    char *prefix, struct va_format *vaf)
 {
 	int r;
 
 	if (dev && dev->dev.parent) {
 		r = dev_printk_emit(level[1] - '0',
 				    dev->dev.parent,
-				    "%s %s %s: %pV",
+				    "%s%s %s %s: %pV",
+				    prefix,
 				    dev_driver_string(dev->dev.parent),
 				    dev_name(dev->dev.parent),
 				    netdev_name(dev), vaf);

@@ -6455,7 +6456,7 @@ int netdev_printk(const char *level, const struct net_device *dev,
 	vaf.fmt = format;
 	vaf.va = &args;
 
-	r = __netdev_printk(level, dev, &vaf);
+	r = __netdev_printk(level, dev, "", &vaf);
 
 	va_end(args);
 

@@ -6475,7 +6476,7 @@ int func(const struct net_device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __netdev_printk(level, dev, &vaf);			\
+	r = __netdev_printk(level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\
Signature · 1 line
1.7.7.6
author
#18 lore raw
Quoted 219 lines · Jason Baron
Quoted 24 lines · Joe Perches
Quoted 14 lines · Jason Baron
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Quoted 8 lines

Looks Good.

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

Quoted 3 lines

I don't think that's an improvement actually.
Why don't you try it.

Ok, below is what I was thinking. It winds up being more deletions than insertions.

Thanks,

-Jason

dynamic debug: remove duplicate __netdev_printk() and __dev_printk() logic

Add an option prefix string argument to __netdev_printk() and __dev_printk(). In this way dynamic debug does not have to contain duplicate logic.

Signed-off-by Jason Baron <[email protected]>
---
 drivers/base/core.c       |   13 +++++++------
 include/linux/device.h    |    3 +++
 include/linux/netdevice.h |    3 +++
 lib/dynamic_debug.c       |   32 ++++++++------------------------
 net/core/dev.c            |   11 ++++++-----
 5 files changed, 27 insertions(+), 35 deletions(-)
drivers/base/core.c +7 -6
index 65f82e3..7b4ee6d 100644
@@ -1937,15 +1937,16 @@ int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
 }
 EXPORT_SYMBOL(dev_printk_emit);
 
-static int __dev_printk(const char *level, const struct device *dev,
-			struct va_format *vaf)
+int __dev_printk(const char *level, const struct device *dev,
+		 char *prefix, struct va_format *vaf)
 {
 	if (!dev)
 		return printk("%s(NULL device *): %pV", level, vaf);
 
 	return dev_printk_emit(level[1] - '0', dev,
-			       "%s %s: %pV",
-			       dev_driver_string(dev), dev_name(dev), vaf);
+			       "%s%s %s: %pV",
+			       prefix, dev_driver_string(dev),
+			       dev_name(dev), vaf);
 }
 
 int dev_printk(const char *level, const struct device *dev,

@@ -1960,7 +1961,7 @@ int dev_printk(const char *level, const struct device *dev,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	r = __dev_printk(level, dev, &vaf);
+	r = __dev_printk(level, dev, "", &vaf);
 
 	va_end(args);
 

@@ -1980,7 +1981,7 @@ int func(const struct device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __dev_printk(kern_level, dev, &vaf);		\
+	r = __dev_printk(kern_level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\
include/linux/device.h +3 -0
index 2da4589..573b15e 100644
@@ -891,6 +891,9 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
+extern int __dev_printk(const char *level, const struct device *dev,
+			char *prefix, struct va_format *vaf);
+
 extern int dev_vprintk_emit(int level, const struct device *dev,
 			    const char *fmt, va_list args);
 extern __printf(3, 4)
include/linux/netdevice.h +3 -0
index 5f49cc0..63f6165 100644
@@ -2720,6 +2720,9 @@ static inline const char *netdev_name(const struct net_device *dev)
 	return dev->name;
 }
 
+extern int __netdev_printk(const char *level, const struct net_device *dev,
+			   char *prefix, struct va_format *vaf);
+
 extern __printf(3, 4)
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...);
lib/dynamic_debug.c +8 -24
index e7f7d99..83bf601 100644
@@ -578,6 +578,7 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -587,16 +588,9 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (!dev) {
-		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
-	} else {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev), dev_name(dev),
-				      &vaf);
-	}
+	res = __dev_printk(KERN_DEBUG, dev,
+			   dynamic_emit_prefix(descriptor, buf),
+			   &vaf);
 
 	va_end(args);
 

@@ -612,6 +606,7 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -621,20 +616,9 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (dev && dev->dev.parent) {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev->dev.parent,
-				      "%s%s %s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev->dev.parent),
-				      dev_name(dev->dev.parent),
-				      netdev_name(dev), &vaf);
-	} else if (dev) {
-		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
-	} else {
-		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
-	}
+	res = __netdev_printk(KERN_DEBUG, dev,
+			      dynamic_emit_prefix(descriptor, buf),
+			      &vaf);
 
 	va_end(args);
net/core/dev.c +5 -4
index 8ad42fd..5fef0f6 100644
@@ -6422,15 +6422,16 @@ const char *netdev_drivername(const struct net_device *dev)
 	return empty;
 }
 
-static int __netdev_printk(const char *level, const struct net_device *dev,
-			   struct va_format *vaf)
+int __netdev_printk(const char *level, const struct net_device *dev,
+		    char *prefix, struct va_format *vaf)
 {
 	int r;
 
 	if (dev && dev->dev.parent) {
 		r = dev_printk_emit(level[1] - '0',
 				    dev->dev.parent,
-				    "%s %s %s: %pV",
+				    "%s%s %s %s: %pV",
+				    prefix,
 				    dev_driver_string(dev->dev.parent),
 				    dev_name(dev->dev.parent),
 				    netdev_name(dev), vaf);

@@ -6455,7 +6456,7 @@ int netdev_printk(const char *level, const struct net_device *dev,
 	vaf.fmt = format;
 	vaf.va = &args;
 
-	r = __netdev_printk(level, dev, &vaf);
+	r = __netdev_printk(level, dev, "", &vaf);
 
 	va_end(args);

net/core/dev.c int func(const struct net_device *dev, const char *fmt, ...) \ · line 6482

Quoted 8 lines
net/core/dev.c +1 -1
@@ -6475,7 +6476,7 @@ int func(const struct net_device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __netdev_printk(level, dev, &vaf);			\
+	r = __netdev_printk(level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\

'Morning Jason.

Funny. Crossed emails.

I still don't think this is better.

This does add an effectively unused "" to non-dynamic debug builds.
ie: the more common paths are encumbered as dynamic_debug isn't a normally enabled distribution CONFIG_ option.

About the patch:

Wouldn't dev_printk_emit now would have a single caller and could be made static?

Don't __dev_printk and __netdev_printk need EXPORT_SYMBOLs?

cheers, Joe

#19 lore raw
Quoted 231 lines · Joe Perches
Quoted 219 lines · Jason Baron
Quoted 24 lines · Joe Perches
Quoted 14 lines · Jason Baron
Quoted 5 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

Quoted 7 lines

Joe Perches (5):
dev_dbg/dynamic_debug: Update to use printk_emit, optimize stack netdev_printk/dynamic_netdev_dbg: Directly call printk_emit netdev_printk/netif_printk: Remove a superfluous logging colon
dev: Add dev_vprintk_emit and dev_printk_emit
device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

Quoted 8 lines

Looks Good.

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

Quoted 3 lines

I don't think that's an improvement actually.
Why don't you try it.

Ok, below is what I was thinking. It winds up being more deletions than insertions.

Thanks,

-Jason

dynamic debug: remove duplicate __netdev_printk() and __dev_printk() logic

Add an option prefix string argument to __netdev_printk() and __dev_printk(). In this way dynamic debug does not have to contain duplicate logic.

Signed-off-by Jason Baron <[email protected]>
---
 drivers/base/core.c       |   13 +++++++------
 include/linux/device.h    |    3 +++
 include/linux/netdevice.h |    3 +++
 lib/dynamic_debug.c       |   32 ++++++++------------------------
 net/core/dev.c            |   11 ++++++-----
 5 files changed, 27 insertions(+), 35 deletions(-)
drivers/base/core.c +7 -6
index 65f82e3..7b4ee6d 100644
@@ -1937,15 +1937,16 @@ int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
 }
 EXPORT_SYMBOL(dev_printk_emit);
 
-static int __dev_printk(const char *level, const struct device *dev,
-			struct va_format *vaf)
+int __dev_printk(const char *level, const struct device *dev,
+		 char *prefix, struct va_format *vaf)
 {
 	if (!dev)
 		return printk("%s(NULL device *): %pV", level, vaf);
 
 	return dev_printk_emit(level[1] - '0', dev,
-			       "%s %s: %pV",
-			       dev_driver_string(dev), dev_name(dev), vaf);
+			       "%s%s %s: %pV",
+			       prefix, dev_driver_string(dev),
+			       dev_name(dev), vaf);
 }
 
 int dev_printk(const char *level, const struct device *dev,

@@ -1960,7 +1961,7 @@ int dev_printk(const char *level, const struct device *dev,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	r = __dev_printk(level, dev, &vaf);
+	r = __dev_printk(level, dev, "", &vaf);
 
 	va_end(args);
 

@@ -1980,7 +1981,7 @@ int func(const struct device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __dev_printk(kern_level, dev, &vaf);		\
+	r = __dev_printk(kern_level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\
include/linux/device.h +3 -0
index 2da4589..573b15e 100644
@@ -891,6 +891,9 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
+extern int __dev_printk(const char *level, const struct device *dev,
+			char *prefix, struct va_format *vaf);
+
 extern int dev_vprintk_emit(int level, const struct device *dev,
 			    const char *fmt, va_list args);
 extern __printf(3, 4)
include/linux/netdevice.h +3 -0
index 5f49cc0..63f6165 100644
@@ -2720,6 +2720,9 @@ static inline const char *netdev_name(const struct net_device *dev)
 	return dev->name;
 }
 
+extern int __netdev_printk(const char *level, const struct net_device *dev,
+			   char *prefix, struct va_format *vaf);
+
 extern __printf(3, 4)
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...);
lib/dynamic_debug.c +8 -24
index e7f7d99..83bf601 100644
@@ -578,6 +578,7 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -587,16 +588,9 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (!dev) {
-		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
-	} else {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev), dev_name(dev),
-				      &vaf);
-	}
+	res = __dev_printk(KERN_DEBUG, dev,
+			   dynamic_emit_prefix(descriptor, buf),
+			   &vaf);
 
 	va_end(args);
 

@@ -612,6 +606,7 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	struct va_format vaf;
 	va_list args;
 	int res;
+	char buf[PREFIX_SIZE];
 
 	BUG_ON(!descriptor);
 	BUG_ON(!fmt);

@@ -621,20 +616,9 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 	vaf.fmt = fmt;
 	vaf.va = &args;
 
-	if (dev && dev->dev.parent) {
-		char buf[PREFIX_SIZE];
-
-		res = dev_printk_emit(7, dev->dev.parent,
-				      "%s%s %s %s: %pV",
-				      dynamic_emit_prefix(descriptor, buf),
-				      dev_driver_string(dev->dev.parent),
-				      dev_name(dev->dev.parent),
-				      netdev_name(dev), &vaf);
-	} else if (dev) {
-		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
-	} else {
-		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
-	}
+	res = __netdev_printk(KERN_DEBUG, dev,
+			      dynamic_emit_prefix(descriptor, buf),
+			      &vaf);
 
 	va_end(args);
net/core/dev.c +5 -4
index 8ad42fd..5fef0f6 100644
@@ -6422,15 +6422,16 @@ const char *netdev_drivername(const struct net_device *dev)
 	return empty;
 }
 
-static int __netdev_printk(const char *level, const struct net_device *dev,
-			   struct va_format *vaf)
+int __netdev_printk(const char *level, const struct net_device *dev,
+		    char *prefix, struct va_format *vaf)
 {
 	int r;
 
 	if (dev && dev->dev.parent) {
 		r = dev_printk_emit(level[1] - '0',
 				    dev->dev.parent,
-				    "%s %s %s: %pV",
+				    "%s%s %s %s: %pV",
+				    prefix,
 				    dev_driver_string(dev->dev.parent),
 				    dev_name(dev->dev.parent),
 				    netdev_name(dev), vaf);

@@ -6455,7 +6456,7 @@ int netdev_printk(const char *level, const struct net_device *dev,
 	vaf.fmt = format;
 	vaf.va = &args;
 
-	r = __netdev_printk(level, dev, &vaf);
+	r = __netdev_printk(level, dev, "", &vaf);
 
 	va_end(args);

net/core/dev.c int func(const struct net_device *dev, const char *fmt, ...) \ · line 6482

Quoted 8 lines
net/core/dev.c +1 -1
@@ -6475,7 +6476,7 @@ int func(const struct net_device *dev, const char *fmt, ...)	\
 	vaf.fmt = fmt;						\
 	vaf.va = &args;						\
 								\
-	r = __netdev_printk(level, dev, &vaf);			\
+	r = __netdev_printk(level, dev, "", &vaf);		\
 								\
 	va_end(args);						\
 								\

'Morning Jason.

Quoted 7 lines

Funny. Crossed emails.

I still don't think this is better.

This does add an effectively unused "" to non-dynamic debug builds.
ie: the more common paths are encumbered as dynamic_debug isn't a normally enabled distribution CONFIG_ option.

Yeah, not sure - I know Fedora enables it.

Quoted 6 lines

About the patch:

Wouldn't dev_printk_emit now would have a single caller and could be made static?

Yes, I believe so.

Quoted 2 lines

Don't __dev_printk and __netdev_printk need EXPORT_SYMBOLs?

The usage in lib/dynamic_debug.c can't be built as a module. So not required.

If nobody else thinks this patch is better, let's at least add a comment in __dev_printk() and __netdev_printk() to fix dynamic debug, if these are changed.

Thanks,

-Jason

author
#20 lore raw
Quoted 2 lines · Jason Baron

If nobody else thinks this patch is better, let's at least add a comment in __dev_printk() and __netdev_printk() to fix dynamic debug, if these are changed.

Or maybe make dynamic_emit_prefix a public function and move the __dynamic_<foo>_printk functions to nearby the __<foo>_printk functions so it's easier to see that changing one requires the other to change.

Something like:

 drivers/base/core.c           |   34 +++++++++++++++++++
 include/linux/dynamic_debug.h |    2 +
 lib/dynamic_debug.c           |   74 +----------------------------------------
 net/core/dev.c                |   40 ++++++++++++++++++++++
 4 files changed, 77 insertions(+), 73 deletions(-)
drivers/base/core.c +34 -0
index 65f82e3..2b4f3e8 100644
@@ -1948,6 +1948,40 @@ static int __dev_printk(const char *level, const struct device *dev,
 			       dev_driver_string(dev), dev_name(dev), vaf);
 }
 
+#ifdef CONFIG_DYNAMIC_DEBUG
+int __dynamic_dev_dbg(struct _ddebug *descriptor,
+		      const struct device *dev, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+	int res;
+
+	BUG_ON(!descriptor);
+	BUG_ON(!fmt);
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	if (!dev) {
+		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
+	} else {
+		char buf[PREFIX_SIZE];
+
+		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev), dev_name(dev),
+				      &vaf);
+	}
+
+	va_end(args);
+
+	return res;
+}
+EXPORT_SYMBOL(__dynamic_dev_dbg);
+#endif
+
 int dev_printk(const char *level, const struct device *dev,
 	       const char *fmt, ...)
 {
include/linux/dynamic_debug.h +2 -0
index c18257b..8de7573 100644
@@ -41,6 +41,8 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
 
 #if defined(CONFIG_DYNAMIC_DEBUG)
 extern int ddebug_remove_module(const char *mod_name);
+char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf);
+
 extern __printf(2, 3)
 int __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...);
lib/dynamic_debug.c +1 -73

86 lines not on this page · raw message

net/core/dev.c +40 -0
index 8ad42fd..fc69703 100644
@@ -6443,6 +6443,46 @@ static int __netdev_printk(const char *level, const struct net_device *dev,
 	return r;
 }
 
+#ifdef CONFIG_DYNAMIC_DEBUG
+
+int __dynamic_netdev_dbg(struct _ddebug *descriptor,
+			 const struct net_device *dev, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+	int res;
+
+	BUG_ON(!descriptor);
+	BUG_ON(!fmt);
+
+	va_start(args, fmt);
+
+	vaf.fmt = fmt;
+	vaf.va = &args;
+
+	if (dev && dev->dev.parent) {
+		char buf[PREFIX_SIZE];
+
+		res = dev_printk_emit(7, dev->dev.parent,
+				      "%s%s %s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev->dev.parent),
+				      dev_name(dev->dev.parent),
+				      netdev_name(dev), &vaf);
+	} else if (dev) {
+		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
+	} else {
+		res = printk(KERN_DEBUG "(NULL net_device): %pV", &vaf);
+	}
+
+	va_end(args);
+
+	return res;
+}
+EXPORT_SYMBOL(__dynamic_netdev_dbg);
+
+#endif
+
 int netdev_printk(const char *level, const struct net_device *dev,
 		  const char *format, ...)
 {
#21 lore raw
Quoted 9 lines · Joe Perches
Quoted 2 lines · Jason Baron

If nobody else thinks this patch is better, let's at least add a comment in __dev_printk() and __netdev_printk() to fix dynamic debug, if these are changed.

Or maybe make dynamic_emit_prefix a public function and move the __dynamic_<foo>_printk functions to nearby the __<foo>_printk functions so it's easier to see that changing one requires the other to change.

ok, that makes sense to me.

Thanks,

-Jason

author
#22 lore raw
In reply to Joe Perches
Quoted 6 lines · Joe Perches
Quoted 5 lines · Jason Baron
Quoted 4 lines · Joe Perches

The recent commit to fix dynamic_debug was a bit unclean. Neaten the style for dynamic_debug.
Reduce the stack use of message logging that uses netdev_printk Add utility functions dev_printk_emit and dev_vprintk_emit for /dev/kmsg.

[]

Quoted 8 lines
Quoted 6 lines

The one thing that is bothering me though, is that for __dynamic_dev_dbg(), __dynamic_netdev_dbg(), we are copying much of the core logic of __dev_printk(), __netdev_printk(), respectively. I would prefer have this in one place. Can we add a 'prefix' argument to __dev_printk(), and __netdev_printk() that dynamic debug can use, but is simply empty for dev_printk() and netdev_printk().

I don't think that's an improvement actually.

Because it would add an always effectively unused "" argument to dev_printk and netdev_printk calls in non dynamic_debug builds.

dynamic_debug is still mostly a developer feature and I believe most distros do not enable it.

author
#23 lore raw

PATCH 3/5 netdev_printk/netif_printk: Remove a superfluous logging colon

In reply to Joe Perches

netdev_printk originally called dev_printk with %pV.

This style emitted the complete dev_printk header with a colon followed by the netdev_name prefix followed by a colon.

Now that netdev_printk does not call dev_printk, the extra colon is superfluous. Remove it.

Example:
old: sky2 0000:02:00.0: eth0: Link is up at 100 Mbps, full duplex, flow control both
new: sky2 0000:02:00.0 eth0: Link is up at 100 Mbps, full duplex, flow control both

Signed-off-by Joe Perches <[email protected]>
Acked-by David S. Miller <[email protected]>
Tested-by Jim Cromie <[email protected]>
Acked-by Jason Baron <[email protected]>
---
 lib/dynamic_debug.c |    2 +-
 net/core/dev.c      |    2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)
lib/dynamic_debug.c +1 -1
index 2a29f4e..6b3ebab 100644
@@ -634,7 +634,7 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 					       dict, sizeof(dict));
 
 		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s: %s: %pV",
+				  "%s%s %s %s: %pV",
 				  dynamic_emit_prefix(descriptor, buf),
 				  dev_driver_string(dev->dev.parent),
 				  dev_name(dev->dev.parent),
net/core/dev.c +1 -1
index a588145..1ec186a 100644
@@ -6434,7 +6434,7 @@ static int __netdev_printk(const char *level, const struct net_device *dev,
 
 		r = printk_emit(0, level[1] - '0',
 				dictlen ? dict : NULL, dictlen,
-				"%s %s: %s: %pV",
+				"%s %s %s: %pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), vaf);
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#24 lore raw

PATCH 4/5 dev: Add dev_vprintk_emit and dev_printk_emit

In reply to Joe Perches

Add utility functions to consolidate the use of
create_syslog_header and vprintk_emit.

This allows conversion of logging functions that call create_syslog_header and then call vprintk_emit or printk_emit to the dev_ equivalents.

Signed-off-by Joe Perches <[email protected]>
---
 drivers/base/core.c    |   27 +++++++++++++++++++++++++++
 include/linux/device.h |   11 +++++++++++
 2 files changed, 38 insertions(+), 0 deletions(-)
drivers/base/core.c +27 -0
index d46b635..ffccb64 100644
@@ -1909,6 +1909,33 @@ int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 }
 EXPORT_SYMBOL(create_syslog_header);
 
+int dev_vprintk_emit(int level, const struct device *dev,
+		     const char *fmt, va_list args)
+{
+	char hdr[128];
+	size_t hdrlen;
+
+	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
+
+	return vprintk_emit(0, level, hdrlen ? hdr : NULL, hdrlen, fmt, args);
+}
+EXPORT_SYMBOL(dev_vprintk_emit);
+
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
+{
+	va_list args;
+	int r;
+
+	va_start(args, fmt);
+
+	r = dev_vprintk_emit(level, dev, fmt, args);
+
+	va_end(args);
+
+	return r;
+}
+EXPORT_SYMBOL(dev_printk_emit);
+
 static int __dev_printk(const char *level, const struct device *dev,
 			struct va_format *vaf)
 {
include/linux/device.h +11 -0
index 4800d73..0063d01 100644
@@ -893,6 +893,10 @@ extern const char *dev_driver_string(const struct device *dev);
 
 extern int create_syslog_header(const struct device *dev,
 				char *hdr, size_t hdrlen);
+extern int dev_vprintk_emit(int level, const struct device *dev,
+			    const char *fmt, va_list args);
+extern __printf(3, 4)
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...);
 
 extern __printf(3, 4)
 int dev_printk(const char *level, const struct device *dev,

@@ -914,6 +918,13 @@ int _dev_info(const struct device *dev, const char *fmt, ...);
 
 #else
 
+static int dev_vprintk_emit(int level, const struct device *dev,
+			    const char *fmt, va_list args)
+{ return 0; }
+static inline __printf(3, 4)
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
+{ return 0; }
+
 static inline int __dev_printk(const char *level, const struct device *dev,
 			       struct va_format *vaf)
 { return 0; }
Signature · 1 line
1.7.8.111.gad25c.dirty
#25 lore raw

Re: [PATCH 4/5] dev: Add dev_vprintk_emit and dev_printk_emit

include/linux/device.h int _dev_info(const struct device *dev, const char *fmt, ...); · line 921

Quoted 7 lines · Joe Perches
include/linux/device.h +1 -0
@@ -914,6 +918,13 @@ int _dev_info(const struct device *dev, const char *fmt, ...);
 
 #else
 
+static int dev_vprintk_emit(int level, const struct device *dev,

Missing "inline", cfr. http://kisskb.ellerman.id.au/kisskb/buildresult/7271354/

include/linux/device.h:930:12: error: 'dev_vprintk_emit' defined but not used [-Werror=unused-function]
cc1: all warnings being treated as errors
make[2]: *** [arch/sh/kernel/dma-nommu.o] Error 1

include/linux/device.h int _dev_info(const struct device *dev, const char *fmt, ...); · line 923

Quoted 2 lines
include/linux/device.h +2 -0
+                           const char *fmt, va_list args)
+{ return 0; }

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

author
#26 lore raw

PATCH 1/1 device.h: Add missing inline to #ifndef CONFIG_PRINTK dev_vprintk_emit

Also add __printf() verification for format string.

Reported-by Geert Uytterhoeven <[email protected]>
Signed-off-by Joe Perches <[email protected]>

---

 include/linux/device.h |   10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)
include/linux/device.h +6 -4
index 8873603..86ef6ab 100644
@@ -902,8 +902,9 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
-extern int dev_vprintk_emit(int level, const struct device *dev,
-			    const char *fmt, va_list args);
+extern __printf(3, 0)
+int dev_vprintk_emit(int level, const struct device *dev,
+		     const char *fmt, va_list args);
 extern __printf(3, 4)
 int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...);
 

@@ -927,8 +928,9 @@ int _dev_info(const struct device *dev, const char *fmt, ...);
 
 #else
 
-static int dev_vprintk_emit(int level, const struct device *dev,
-			    const char *fmt, va_list args)
+static inline __printf(3, 0)
+int dev_vprintk_emit(int level, const struct device *dev,
+		     const char *fmt, va_list args)
 { return 0; }
 static inline __printf(3, 4)
 int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
author
#27 lore raw

PATCH 4/5 dev: Add dev_vprintk_emit and dev_printk_emit

In reply to Joe Perches

Add utility functions to consolidate the use of create_syslog_header and vprintk_emit.

This allows conversion of logging functions that call create_syslog_header and then call vprintk_emit or printk_emit to the dev_ equivalents.

Signed-off-by Joe Perches <[email protected]>
Acked-by David S. Miller <[email protected]>
Tested-by Jim Cromie <[email protected]>
Acked-by Jason Baron <[email protected]>
---
 drivers/base/core.c    |   27 +++++++++++++++++++++++++++
 include/linux/device.h |   11 +++++++++++
 2 files changed, 38 insertions(+), 0 deletions(-)
drivers/base/core.c +27 -0
index d46b635..ffccb64 100644
@@ -1909,6 +1909,33 @@ int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 }
 EXPORT_SYMBOL(create_syslog_header);
 
+int dev_vprintk_emit(int level, const struct device *dev,
+		     const char *fmt, va_list args)
+{
+	char hdr[128];
+	size_t hdrlen;
+
+	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
+
+	return vprintk_emit(0, level, hdrlen ? hdr : NULL, hdrlen, fmt, args);
+}
+EXPORT_SYMBOL(dev_vprintk_emit);
+
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
+{
+	va_list args;
+	int r;
+
+	va_start(args, fmt);
+
+	r = dev_vprintk_emit(level, dev, fmt, args);
+
+	va_end(args);
+
+	return r;
+}
+EXPORT_SYMBOL(dev_printk_emit);
+
 static int __dev_printk(const char *level, const struct device *dev,
 			struct va_format *vaf)
 {
include/linux/device.h +11 -0
index 4800d73..0063d01 100644
@@ -893,6 +893,10 @@ extern const char *dev_driver_string(const struct device *dev);
 
 extern int create_syslog_header(const struct device *dev,
 				char *hdr, size_t hdrlen);
+extern int dev_vprintk_emit(int level, const struct device *dev,
+			    const char *fmt, va_list args);
+extern __printf(3, 4)
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...);
 
 extern __printf(3, 4)
 int dev_printk(const char *level, const struct device *dev,

@@ -914,6 +918,13 @@ int _dev_info(const struct device *dev, const char *fmt, ...);
 
 #else
 
+static int dev_vprintk_emit(int level, const struct device *dev,
+			    const char *fmt, va_list args)
+{ return 0; }
+static inline __printf(3, 4)
+int dev_printk_emit(int level, const struct device *dev, const char *fmt, ...)
+{ return 0; }
+
 static inline int __dev_printk(const char *level, const struct device *dev,
 			       struct va_format *vaf)
 { return 0; }
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#28 lore raw

PATCH 5/5 device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

In reply to Joe Perches

Convert direct calls of vprintk_emit and printk_emit to the dev_ equivalents.

Make create_syslog_header static.

Signed-off-by Joe Perches <[email protected]>
---
 drivers/base/core.c    |   14 +++++---------
 include/linux/device.h |    2 --
 lib/dynamic_debug.c    |   31 +++++++++++--------------------
 net/core/dev.c         |   16 ++++++----------
 4 files changed, 22 insertions(+), 41 deletions(-)
drivers/base/core.c +5 -9
index ffccb64..65f82e3 100644
@@ -1861,7 +1861,8 @@ void device_shutdown(void)
  */
 
 #ifdef CONFIG_PRINTK
-int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
+static int
+create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 {
 	const char *subsys;
 	size_t pos = 0;

@@ -1939,17 +1940,12 @@ EXPORT_SYMBOL(dev_printk_emit);
 static int __dev_printk(const char *level, const struct device *dev,
 			struct va_format *vaf)
 {
-	char hdr[128];
-	size_t hdrlen;
-
 	if (!dev)
 		return printk("%s(NULL device *): %pV", level, vaf);
 
-	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
-
-	return printk_emit(0, level[1] - '0', hdrlen ? hdr : NULL, hdrlen,
-			   "%s %s: %pV",
-			   dev_driver_string(dev), dev_name(dev), vaf);
+	return dev_printk_emit(level[1] - '0', dev,
+			       "%s %s: %pV",
+			       dev_driver_string(dev), dev_name(dev), vaf);
 }
 
 int dev_printk(const char *level, const struct device *dev,
include/linux/device.h +0 -2
index 0063d01..2da4589 100644
@@ -891,8 +891,6 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
-extern int create_syslog_header(const struct device *dev,
-				char *hdr, size_t hdrlen);
 extern int dev_vprintk_emit(int level, const struct device *dev,
 			    const char *fmt, va_list args);
 extern __printf(3, 4)
lib/dynamic_debug.c +11 -20
index 6b3ebab..e7f7d99 100644
@@ -591,15 +591,11 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
 	} else {
 		char buf[PREFIX_SIZE];
-		char dict[128];
-		size_t dictlen;
 
-		dictlen = create_syslog_header(dev, dict, sizeof(dict));
-
-		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s: %pV",
-				  dynamic_emit_prefix(descriptor, buf),
-				  dev_driver_string(dev), dev_name(dev), &vaf);
+		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev), dev_name(dev),
+				      &vaf);
 	}
 
 	va_end(args);

@@ -627,18 +623,13 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 
 	if (dev && dev->dev.parent) {
 		char buf[PREFIX_SIZE];
-		char dict[128];
-		size_t dictlen;
-
-		dictlen = create_syslog_header(dev->dev.parent,
-					       dict, sizeof(dict));
-
-		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s %s: %pV",
-				  dynamic_emit_prefix(descriptor, buf),
-				  dev_driver_string(dev->dev.parent),
-				  dev_name(dev->dev.parent),
-				  netdev_name(dev), &vaf);
+
+		res = dev_printk_emit(7, dev->dev.parent,
+				      "%s%s %s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev->dev.parent),
+				      dev_name(dev->dev.parent),
+				      netdev_name(dev), &vaf);
 	} else if (dev) {
 		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
 	} else {
net/core/dev.c +6 -10
index 1ec186a..8ad42fd 100644
@@ -6428,16 +6428,12 @@ static int __netdev_printk(const char *level, const struct net_device *dev,
 	int r;
 
 	if (dev && dev->dev.parent) {
-		char dict[128];
-		size_t dictlen = create_syslog_header(dev->dev.parent,
-						      dict, sizeof(dict));
-
-		r = printk_emit(0, level[1] - '0',
-				dictlen ? dict : NULL, dictlen,
-				"%s %s %s: %pV",
-				dev_driver_string(dev->dev.parent),
-				dev_name(dev->dev.parent),
-				netdev_name(dev), vaf);
+		r = dev_printk_emit(level[1] - '0',
+				    dev->dev.parent,
+				    "%s %s %s: %pV",
+				    dev_driver_string(dev->dev.parent),
+				    dev_name(dev->dev.parent),
+				    netdev_name(dev), vaf);
 	} else if (dev) {
 		r = printk("%s%s: %pV", level, netdev_name(dev), vaf);
 	} else {
Signature · 1 line
1.7.8.111.gad25c.dirty
author
#29 lore raw

PATCH 5/5 device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit

In reply to Joe Perches

Convert direct calls of vprintk_emit and printk_emit to the dev_ equivalents.

Make create_syslog_header static.

Signed-off-by Joe Perches <[email protected]>
Acked-by David S. Miller <[email protected]>
Tested-by Jim Cromie <[email protected]>
Acked-by Jason Baron <[email protected]>
---
 drivers/base/core.c    |   14 +++++---------
 include/linux/device.h |    2 --
 lib/dynamic_debug.c    |   31 +++++++++++--------------------
 net/core/dev.c         |   16 ++++++----------
 4 files changed, 22 insertions(+), 41 deletions(-)
drivers/base/core.c +5 -9
index ffccb64..65f82e3 100644
@@ -1861,7 +1861,8 @@ void device_shutdown(void)
  */
 
 #ifdef CONFIG_PRINTK
-int create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
+static int
+create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
 {
 	const char *subsys;
 	size_t pos = 0;

@@ -1939,17 +1940,12 @@ EXPORT_SYMBOL(dev_printk_emit);
 static int __dev_printk(const char *level, const struct device *dev,
 			struct va_format *vaf)
 {
-	char hdr[128];
-	size_t hdrlen;
-
 	if (!dev)
 		return printk("%s(NULL device *): %pV", level, vaf);
 
-	hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
-
-	return printk_emit(0, level[1] - '0', hdrlen ? hdr : NULL, hdrlen,
-			   "%s %s: %pV",
-			   dev_driver_string(dev), dev_name(dev), vaf);
+	return dev_printk_emit(level[1] - '0', dev,
+			       "%s %s: %pV",
+			       dev_driver_string(dev), dev_name(dev), vaf);
 }
 
 int dev_printk(const char *level, const struct device *dev,
include/linux/device.h +0 -2
index 0063d01..2da4589 100644
@@ -891,8 +891,6 @@ extern const char *dev_driver_string(const struct device *dev);
 
 #ifdef CONFIG_PRINTK
 
-extern int create_syslog_header(const struct device *dev,
-				char *hdr, size_t hdrlen);
 extern int dev_vprintk_emit(int level, const struct device *dev,
 			    const char *fmt, va_list args);
 extern __printf(3, 4)
lib/dynamic_debug.c +11 -20
index 6b3ebab..e7f7d99 100644
@@ -591,15 +591,11 @@ int __dynamic_dev_dbg(struct _ddebug *descriptor,
 		res = printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
 	} else {
 		char buf[PREFIX_SIZE];
-		char dict[128];
-		size_t dictlen;
 
-		dictlen = create_syslog_header(dev, dict, sizeof(dict));
-
-		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s: %pV",
-				  dynamic_emit_prefix(descriptor, buf),
-				  dev_driver_string(dev), dev_name(dev), &vaf);
+		res = dev_printk_emit(7, dev, "%s%s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev), dev_name(dev),
+				      &vaf);
 	}
 
 	va_end(args);

@@ -627,18 +623,13 @@ int __dynamic_netdev_dbg(struct _ddebug *descriptor,
 
 	if (dev && dev->dev.parent) {
 		char buf[PREFIX_SIZE];
-		char dict[128];
-		size_t dictlen;
-
-		dictlen = create_syslog_header(dev->dev.parent,
-					       dict, sizeof(dict));
-
-		res = printk_emit(0, 7, dictlen ? dict : NULL, dictlen,
-				  "%s%s %s %s: %pV",
-				  dynamic_emit_prefix(descriptor, buf),
-				  dev_driver_string(dev->dev.parent),
-				  dev_name(dev->dev.parent),
-				  netdev_name(dev), &vaf);
+
+		res = dev_printk_emit(7, dev->dev.parent,
+				      "%s%s %s %s: %pV",
+				      dynamic_emit_prefix(descriptor, buf),
+				      dev_driver_string(dev->dev.parent),
+				      dev_name(dev->dev.parent),
+				      netdev_name(dev), &vaf);
 	} else if (dev) {
 		res = printk(KERN_DEBUG "%s: %pV", netdev_name(dev), &vaf);
 	} else {
net/core/dev.c +6 -10
index 1ec186a..8ad42fd 100644
@@ -6428,16 +6428,12 @@ static int __netdev_printk(const char *level, const struct net_device *dev,
 	int r;
 
 	if (dev && dev->dev.parent) {
-		char dict[128];
-		size_t dictlen = create_syslog_header(dev->dev.parent,
-						      dict, sizeof(dict));
-
-		r = printk_emit(0, level[1] - '0',
-				dictlen ? dict : NULL, dictlen,
-				"%s %s %s: %pV",
-				dev_driver_string(dev->dev.parent),
-				dev_name(dev->dev.parent),
-				netdev_name(dev), vaf);
+		r = dev_printk_emit(level[1] - '0',
+				    dev->dev.parent,
+				    "%s %s %s: %pV",
+				    dev_driver_string(dev->dev.parent),
+				    dev_name(dev->dev.parent),
+				    netdev_name(dev), vaf);
 	} else if (dev) {
 		r = printk("%s%s: %pV", level, netdev_name(dev), vaf);
 	} else {
Signature · 1 line
1.7.8.111.gad25c.dirty