2003-08-25 21:34:31

by Jim Keniston

[permalink] [raw]
Subject: [PATCH 1/4] Net device error logging, revised

diff -Naur linux.org/include/linux/netdevice.h linux.netdev.patched/include/linux/netdevice.h
--- linux.org/include/linux/netdevice.h Mon Aug 25 13:29:38 2003
+++ linux.netdev.patched/include/linux/netdevice.h Mon Aug 25 13:29:38 2003
@@ -470,6 +470,9 @@
struct divert_blk *divert;
#endif /* CONFIG_NET_DIVERT */

+ /* NETIF_MSG_* flags to control the types of events we log */
+ int msg_enable;
+
/* class/net/name entry */
struct class_device class_dev;
};
@@ -743,6 +746,8 @@
NETIF_MSG_PKTDATA = 0x1000,
NETIF_MSG_HW = 0x2000,
NETIF_MSG_WOL = 0x4000,
+ NETIF_MSG_ALL = -1, /* always log message */
+ NETIF_MSG_ = -1 /* always log message */
};

#define netif_msg_drv(p) ((p)->msg_enable & NETIF_MSG_DRV)
@@ -869,6 +874,36 @@
extern void dev_clear_fastroute(struct net_device *dev);
#endif

+/* debugging and troubleshooting/diagnostic helpers. */
+/**
+ * netdev_printk() - Log message with interface name, gated by message level
+ * @sevlevel: severity level -- e.g., KERN_INFO
+ * @netdev: net_device pointer
+ * @msglevel: a standard message-level flag with the NETIF_MSG_ prefix removed.
+ * Unless msglevel is NETIF_MSG_ALL, or omitted, log the message only if
+ * that flag is set in netdev->msg_enable.
+ * @format: as with printk
+ * @args: as with printk
+ */
+extern int __netdev_printk(const char *sevlevel,
+ const struct net_device *netdev, int msglevel, const char *format, ...);
+#define netdev_printk(sevlevel, netdev, msglevel, format, arg...) \
+ __netdev_printk(sevlevel , netdev , NETIF_MSG_##msglevel , \
+ format , ## arg)
+
+#ifdef DEBUG
+#define netdev_dbg(netdev, msglevel, format, arg...) \
+ netdev_printk(KERN_DEBUG , netdev , msglevel , format , ## arg)
+#else
+#define netdev_dbg(netdev, msglevel, format, arg...) do {} while (0)
+#endif
+
+#define netdev_err(netdev, msglevel, format, arg...) \
+ netdev_printk(KERN_ERR , netdev , msglevel , format , ## arg)
+#define netdev_info(netdev, msglevel, format, arg...) \
+ netdev_printk(KERN_INFO , netdev , msglevel , format , ## arg)
+#define netdev_warn(netdev, msglevel, format, arg...) \
+ netdev_printk(KERN_WARNING , netdev , msglevel , format , ## arg)

#endif /* __KERNEL__ */

diff -Naur linux.org/net/core/dev.c linux.netdev.patched/net/core/dev.c
--- linux.org/net/core/dev.c Mon Aug 25 13:29:38 2003
+++ linux.netdev.patched/net/core/dev.c Mon Aug 25 13:29:38 2003
@@ -3116,5 +3116,71 @@
out:
return rc;
}
-
subsys_initcall(net_dev_init);
+
+/**
+ * __netdev_printk() - Log message with interface name, gated by message level
+ * @sevlevel: severity level -- e.g., KERN_INFO
+ * @netdev: net_device pointer
+ * @msglevel: a standard message-level flag such as NETIF_MSG_PROBE.
+ * Unless msglevel is NETIF_MSG_ALL, log the message only if
+ * that flag is set in netdev->msg_enable.
+ * @format: as with printk
+ * @args: as with printk
+ *
+ * Does the work for the netdev_printk macro.
+ * For a lot of network drivers, the probe function looks like
+ * ...
+ * netdev = alloc_netdev(...); // or alloc_etherdev(...)
+ * SET_NETDEV_DEV(netdev, dev);
+ * ...
+ * register_netdev(netdev);
+ * ...
+ * netdev_printk and its wrappers (e.g., netdev_err) can be used as
+ * soon as you have a valid net_device pointer -- e.g., from alloc_netdev,
+ * alloc_etherdev, or init_etherdev. (Before that, use dev_printk and
+ * its wrappers to report device errors.) It's common for an interface to
+ * have a name like "eth%d" until the device is successfully configured,
+ * and the call to register_netdev changes it to a "real" name like "eth0".
+ *
+ * If the interface's reg_state is NETREG_REGISTERED, we assume that it has
+ * been successfully set up in sysfs, and we prepend only the interface name
+ * to the message -- e.g., "eth0: NIC Link is Down". The interface
+ * name can be used to find eth0's driver, bus ID, etc. in sysfs.
+ *
+ * For any other value of reg_state, we prepend the driver name and bus ID
+ * as well as the (possibly incomplete) interface name -- e.g.,
+ * "eth%d (e100 0000:00:03.0): Failed to map PCI address..."
+ *
+ * Probe functions that alloc and register in one step (via init_etherdev),
+ * or otherwise register the device before the probe completes successfully,
+ * may need to take other steps to ensure that the failing device is clearly
+ * identified.
+ */
+int __netdev_printk(const char *sevlevel, const struct net_device *netdev,
+ int msglevel, const char *format, ...)
+{
+ if (!netdev || !format) {
+ return -EINVAL;
+ }
+ if (msglevel == NETIF_MSG_ALL || (netdev->msg_enable & msglevel)) {
+ char msg[512];
+ va_list args;
+ struct device *dev = netdev->class_dev.dev;
+
+ va_start(args, format);
+ vsnprintf(msg, 512, format, args);
+ va_end(args);
+
+ if (!sevlevel) {
+ sevlevel = "";
+ }
+ if (netdev->reg_state == NETREG_REGISTERED || !dev) {
+ printk("%s%s: %s", sevlevel, netdev->name, msg);
+ } else {
+ printk("%s%s (%s %s): %s", sevlevel, netdev->name,
+ dev->driver->name, dev->bus_id, msg);
+ }
+ }
+ return 0;
+}
diff -Naur linux.org/net/netsyms.c linux.netdev.patched/net/netsyms.c
--- linux.org/net/netsyms.c Mon Aug 25 13:29:38 2003
+++ linux.netdev.patched/net/netsyms.c Mon Aug 25 13:29:38 2003
@@ -210,6 +210,7 @@
EXPORT_SYMBOL(net_ratelimit);
EXPORT_SYMBOL(net_random);
EXPORT_SYMBOL(net_srandom);
+EXPORT_SYMBOL(__netdev_printk);

/* Needed by smbfs.o */
EXPORT_SYMBOL(__scm_destroy);


Attachments:
netdev-2.6.0-test4.patch (5.29 kB)

2003-08-26 19:04:51

by Greg KH

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

On Mon, Aug 25, 2003 at 02:31:19PM -0700, Jim Keniston wrote:
> +int __netdev_printk(const char *sevlevel, const struct net_device *netdev,
> + int msglevel, const char *format, ...)
> +{
> + if (!netdev || !format) {
> + return -EINVAL;
> + }
> + if (msglevel == NETIF_MSG_ALL || (netdev->msg_enable & msglevel)) {
> + char msg[512];

512 bytes on the stack? Any way to prevent this from happening? With
the push to make the stack even smaller in 2.7, people will not like
this.

thanks,

greg k-h

2003-08-26 23:36:35

by Jim Keniston

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Greg KH wrote:
>
> On Mon, Aug 25, 2003 at 02:31:19PM -0700, Jim Keniston wrote:
> > +int __netdev_printk(const char *sevlevel, const struct net_device *netdev,
> > + int msglevel, const char *format, ...)
> > +{
> > + if (!netdev || !format) {
> > + return -EINVAL;
> > + }
> > + if (msglevel == NETIF_MSG_ALL || (netdev->msg_enable & msglevel)) {
> > + char msg[512];
>
> 512 bytes on the stack? Any way to prevent this from happening? With
> the push to make the stack even smaller in 2.7, people will not like
> this.
>
> thanks,
>
> greg k-h

The following options come to mind:
1. Keep the msg buffer, but make it smaller. Around 120 bytes would probably be
big enough for the vast majority of messages. (printk() uses a 1024-byte buffer,
but it's static -- see #2.)

2. Use a big, static buffer, protected by a spinlock. printk() does this.

3. Do the whole thing in a macro, as in previous proposals. The size of the macro
expansion could be reduced somewhat by doing the encode-prefix step in a function --
something like:

#define netdev_printk(sevlevel, netdev, msglevel, format, arg...) \
do { \
if (NETIF_MSG_##msglevel == NETIF_MSG_ALL || ((netdev)->msg_enable & NETIF_MSG_##msglevel)) { \
char pfx[40]; \
printk(sevlevel "%s: " format , make_netdev_msg_prefix(pfx, netdev) , ## arg); \
}} while (0)

This would make your code bigger, but not that much bigger for the common case where
the msglevel is omitted (and the 'if(...)' is optimized out).

Jim

2003-08-26 23:51:29

by Jeff Garzik

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Jim Keniston wrote:
> #define netdev_printk(sevlevel, netdev, msglevel, format, arg...) \
> do { \
> if (NETIF_MSG_##msglevel == NETIF_MSG_ALL || ((netdev)->msg_enable & NETIF_MSG_##msglevel)) { \
> char pfx[40]; \
> printk(sevlevel "%s: " format , make_netdev_msg_prefix(pfx, netdev) , ## arg); \
> }} while (0)
>
> This would make your code bigger, but not that much bigger for the common case where
> the msglevel is omitted (and the 'if(...)' is optimized out).


"NETIF_MSG_" is silly and should be eliminated.
A separate "NETIF_MSG_ALL" test is not needed, because msg_enable is a
bitmask. A msg_enable of 0xffffffff will naturally create a NETIF_MSG_ALL.

Also, whatever mechanism is created, it needs to preserve the feature of
the existing system:

if (a quick bitmask test)
do something

And preferably "do something" is not inlined, because printk'ing --
although it may appear in a fast path during debugging -- cannot be
considered a fast path itself.

Jeff



2003-08-27 01:10:23

by Jim Keniston

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Jeff Garzik wrote:
>
> Jim Keniston wrote:
> > #define netdev_printk(sevlevel, netdev, msglevel, format, arg...) \
> > do { \
> > if (NETIF_MSG_##msglevel == NETIF_MSG_ALL || ((netdev)->msg_enable & NETIF_MSG_##msglevel)) { \
> > char pfx[40]; \
> > printk(sevlevel "%s: " format , make_netdev_msg_prefix(pfx, netdev) , ## arg); \
> > }} while (0)
> >
> > This would make your code bigger, but not that much bigger for the common case where
> > the msglevel is omitted (and the 'if(...)' is optimized out).
>
> "NETIF_MSG_" is silly and should be eliminated.

>From this, I infer that you think that the option to "omit" the msglevel arg --
e.g.,
netdev_err(dev,, "NIC is fried!\n"); /* always logged */
-- is silly. No big deal. Its sole purpose is to help keep netdev_* calls terse.

> A separate "NETIF_MSG_ALL" test is not needed, because msg_enable is a
> bitmask. A msg_enable of 0xffffffff will naturally create a NETIF_MSG_ALL.

But how do you code a netdev_* call where you ALWAYS want the message (including
netdev_printk-style prefix) logged, regardless of the value of msg_enable? That's
what NETIF_MSG_ALL is for (and why it might be better called NETIF_MSG_ALWAYS)...
netdev_err(dev, ALL, "NIC is fried!\n"); /* always logged */
or
netdev_err(dev, ALWAYS, "NIC is fried!\n"); /* always logged */

>
> Also, whatever mechanism is created, it needs to preserve the feature of
> the existing system:
>
> if (a quick bitmask test)
> do something
>
> And preferably "do something" is not inlined, because printk'ing --
> although it may appear in a fast path during debugging -- cannot be
> considered a fast path itself.
>
> Jeff

Sorry, I'm not sure what you're getting at here. netdev_* doesn't prevent
people from using the existing netif_msg_* macros; it just provides shorthand
for the (usual) case where "do something" is "printk".

Jim

2003-08-27 01:06:52

by Stephen Hemminger

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised


> The following options come to mind:
> 1. Keep the msg buffer, but make it smaller. Around 120 bytes would probably be
> big enough for the vast majority of messages. (printk() uses a 1024-byte buffer,
> but it's static -- see #2.)
>
> 2. Use a big, static buffer, protected by a spinlock. printk() does this.
>
> 3. Do the whole thing in a macro, as in previous proposals. The size of the macro
> expansion could be reduced somewhat by doing the encode-prefix step in a function --
> something like:
>
> #define netdev_printk(sevlevel, netdev, msglevel, format, arg...) \
> do { \
> if (NETIF_MSG_##msglevel == NETIF_MSG_ALL || ((netdev)->msg_enable & NETIF_MSG_##msglevel)) { \
> char pfx[40]; \
> printk(sevlevel "%s: " format , make_netdev_msg_prefix(pfx, netdev) , ## arg); \
> }} while (0)
>
> This would make your code bigger, but not that much bigger for the common case where
> the msglevel is omitted (and the 'if(...)' is optimized out).

Is there some way to tack copy and prepend what you want onto the format
string, and add additional arguments to the call to printk? That way you
wouldn't need space for the potentially large resulting string, but only
enough room for the expanded format string.

2003-08-29 21:24:35

by Jim Keniston

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Stephen Hemminger wrote:
>
> > The following options come to mind:
> > 1. Keep the msg buffer, but make it smaller. Around 120 bytes would probably be
> > big enough for the vast majority of messages. (printk() uses a 1024-byte buffer,
> > but it's static -- see #2.)
> >
> > 2. Use a big, static buffer, protected by a spinlock. printk() does this.
> >
> > 3. Do the whole thing in a macro, as in previous proposals. The size of the macro
> > expansion could be reduced somewhat by doing the encode-prefix step in a function --
> > something like:
[more on #3 snipped]
>
> Is there some way to tack copy and prepend what you want onto the format
> string, and add additional arguments to the call to printk? That way you
> wouldn't need space for the potentially large resulting string, but only
> enough room for the expanded format string.

Interesting idea. I pondered this for a while. But even if you postulate
a varargs version of printk (which doesn't exist), it's not really
feasible to do this in a function. There's no way for a function to
prepend args to a va_list. That means you'd have to encode the text of
the prefix as part of the format string, and that would require you to
allocate room for prefix+format, which is still a lot of stack. Also,
the fact that the interface name itself may contain "%d" or some such
makes it even messier.

Greg K-H thinks #2 is a reasonable solution (you're about to serialize on printk's
lock anyway), so I'll go with that.

Thanks.
Jim

2003-09-03 17:32:24

by Jeff Garzik

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Jim Keniston wrote:
> Jeff Garzik wrote:
>>"NETIF_MSG_" is silly and should be eliminated.
>
>
>>From this, I infer that you think that the option to "omit" the msglevel arg --
> e.g.,
> netdev_err(dev,, "NIC is fried!\n"); /* always logged */
> -- is silly. No big deal. Its sole purpose is to help keep netdev_* calls terse.

yes


>>A separate "NETIF_MSG_ALL" test is not needed, because msg_enable is a
>>bitmask. A msg_enable of 0xffffffff will naturally create a NETIF_MSG_ALL.
>
>
> But how do you code a netdev_* call where you ALWAYS want the message (including
> netdev_printk-style prefix) logged, regardless of the value of msg_enable? That's
> what NETIF_MSG_ALL is for (and why it might be better called NETIF_MSG_ALWAYS)...

I understand the purpose of NETIF_MSG_ALL; re-read what I said. You
don't need a separate _test_, as your implementation includes. Defining
NETIF_MSG_ALL to 0xffffffff will naturally create the effect you seek.


>>Also, whatever mechanism is created, it needs to preserve the feature of
>>the existing system:
>>
>> if (a quick bitmask test)
>> do something
>>
>>And preferably "do something" is not inlined, because printk'ing --
>>although it may appear in a fast path during debugging -- cannot be
>>considered a fast path itself.

> Sorry, I'm not sure what you're getting at here. netdev_* doesn't prevent
> people from using the existing netif_msg_* macros; it just provides shorthand
> for the (usual) case where "do something" is "printk".


I would prefer to be more ambitious. If we're gonna go in and change
every printk in a driver, we might as well do it right, and (a) make
sure the driver does msg_enable, and (b) make the source code a bit more
clean by hiding the "if (test bitmap)" test in your netdev_xxx stuff.

Jeff


2003-09-03 20:59:20

by Jim Keniston

[permalink] [raw]
Subject: Re: [PATCH 1/4] Net device error logging, revised

Jeff Garzik wrote:
>
> Jim Keniston wrote:
> > Jeff Garzik wrote:
> ...
> >>A separate "NETIF_MSG_ALL" test is not needed, because msg_enable is a
> >>bitmask. A msg_enable of 0xffffffff will naturally create a NETIF_MSG_ALL.
> >
> >
> > But how do you code a netdev_* call where you ALWAYS want the message (including
> > netdev_printk-style prefix) logged, regardless of the value of msg_enable? That's
> > what NETIF_MSG_ALL is for (and why it might be better called NETIF_MSG_ALWAYS)...
>
> I understand the purpose of NETIF_MSG_ALL; re-read what I said. You
> don't need a separate _test_, as your implementation includes. Defining
> NETIF_MSG_ALL to 0xffffffff will naturally create the effect you seek.
>

So the test becomes
if (netdev->msg_enable & msglevel) { /* log message */ }
If netdev->msg_enable == 0, the message is suppressed even if msglevel == NETIF_MSG_ALL.
I had intended that "ALL" would override the msg_enable setting (even 0), but we can do
it this way as well.

> ...
>
> Jeff

Jim