From 798efc60e4276825df34af0e91ecbe0781237834 Mon Sep 17 00:00:00 2001 From: Joe Perches Date: Wed, 12 Sep 2012 20:11:29 -0700 Subject: 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 Acked-by: David S. Miller Tested-by: Jim Cromie Acked-by: Jason Baron Signed-off-by: Greg Kroah-Hartman --- lib/dynamic_debug.c | 39 +++++++++++++++++++++++++++++---------- 1 file changed, 29 insertions(+), 10 deletions(-) (limited to 'lib/dynamic_debug.c') diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 7ca29a0a301..29ff2e4cfb7 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -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 ", - ""); + pos += snprintf(buf + pos, remaining(pos), " "); 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; -- cgit v1.2.3-70-g09d2 From b004ff4972e2a42aa4512c90cc6a9e4dc1bb36b6 Mon Sep 17 00:00:00 2001 From: Joe Perches Date: Wed, 12 Sep 2012 20:12:19 -0700 Subject: netdev_printk/dynamic_netdev_dbg: Directly call printk_emit 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 Acked-by: David S. Miller Tested-by: Jim Cromie Acked-by: Jason Baron Signed-off-by: Greg Kroah-Hartman --- include/linux/netdevice.h | 3 --- lib/dynamic_debug.c | 26 +++++++++++++++++++++++--- net/core/dev.c | 24 +++++++++++++++++------- 3 files changed, 40 insertions(+), 13 deletions(-) (limited to 'lib/dynamic_debug.c') diff --git a/include/linux/netdevice.h b/include/linux/netdevice.h index 59dc05f3824..5f49cc0a107 100644 --- a/include/linux/netdevice.h +++ b/include/linux/netdevice.h @@ -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, ...); diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 29ff2e4cfb7..2a29f4e04bd 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -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; diff --git a/net/core/dev.c b/net/core/dev.c index d7fe32c946c..ac890f14613 100644 --- a/net/core/dev.c +++ b/net/core/dev.c @@ -6423,22 +6423,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, ...) @@ -6453,6 +6461,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; @@ -6472,6 +6481,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; \ -- cgit v1.2.3-70-g09d2 From c2c5a7051c556036b7beb8f4a89eefdc91c3245b Mon Sep 17 00:00:00 2001 From: Joe Perches Date: Wed, 12 Sep 2012 20:13:01 -0700 Subject: netdev_printk/netif_printk: Remove a superfluous logging colon 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 Acked-by: David S. Miller Tested-by: Jim Cromie Acked-by: Jason Baron Signed-off-by: Greg Kroah-Hartman --- lib/dynamic_debug.c | 2 +- net/core/dev.c | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) (limited to 'lib/dynamic_debug.c') diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 2a29f4e04bd..6b3ebabacfa 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -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), diff --git a/net/core/dev.c b/net/core/dev.c index ac890f14613..cb9d43be07e 100644 --- a/net/core/dev.c +++ b/net/core/dev.c @@ -6435,7 +6435,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); -- cgit v1.2.3-70-g09d2 From 666f355f3805d68b6ed5f7013806f1f65abfbf03 Mon Sep 17 00:00:00 2001 From: Joe Perches Date: Wed, 12 Sep 2012 20:14:11 -0700 Subject: device and dynamic_debug: Use dev_vprintk_emit and dev_printk_emit Convert direct calls of vprintk_emit and printk_emit to the dev_ equivalents. Make create_syslog_header static. Signed-off-by: Joe Perches Acked-by: David S. Miller Tested-by: Jim Cromie Acked-by: Jason Baron Signed-off-by: Greg Kroah-Hartman --- 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(-) (limited to 'lib/dynamic_debug.c') diff --git a/drivers/base/core.c b/drivers/base/core.c index dff94c8fb35..abea76c36a4 100644 --- a/drivers/base/core.c +++ b/drivers/base/core.c @@ -1865,7 +1865,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; @@ -1943,17 +1944,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, diff --git a/include/linux/device.h b/include/linux/device.h index 0d9ba0c0979..6d37e59db57 100644 --- a/include/linux/device.h +++ b/include/linux/device.h @@ -895,8 +895,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) diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c index 6b3ebabacfa..e7f7d993357 100644 --- a/lib/dynamic_debug.c +++ b/lib/dynamic_debug.c @@ -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 { diff --git a/net/core/dev.c b/net/core/dev.c index cb9d43be07e..76c0fe66fdc 100644 --- a/net/core/dev.c +++ b/net/core/dev.c @@ -6429,16 +6429,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 { -- cgit v1.2.3-70-g09d2