[RFC PATCH 0/2] netdev: implement a buffer to log network driver's information

[RFC PATCH 0/2] netdev: implement a buffer to log network driver's information

[Koki Sanagi]

This patch implements a buffer for recording network driver's message.
This patch extends below patch to make other network driver use it.

http://marc.info/?l=e1000-devel&m=126690500618157&w=2

When I investigate some network driver's trouble, I feel like I want more
detailed debug information, for example, all device register information
(like ethtool -d) when device reset was happened or tx/rx ring's move when
network stream is not smooth etc.
As a recording measure of such information, there are syslog and ftrace now.
but they have some weak points.
Syslog is not appropriate for the size of message is large(ex. recording
all register information) or the number of is large(ex.tracing internal move).
Ftrace is appropriate for recording such messages.
But ftrace has only one buffer for all ftrace event in kernel. As a result,
one adapter's event may be flushed by the others(Of course, syslog has same
weak point).

This patch implements a buffer system which beats those weak points.

Features of that are

1.Each interface can hold respective buffer.
     It prevents recorded data from being flowed by other's recorded data.

2.An interface can hold multi-buffers.
     It makes one adapter have several buffer for each different purpose.
     For example, one is to trace a driver's internal move, the another is to
     log error message and some releveant information.

3.resize and on/off per buffer.
     if you implement this patch's buffer and you regist buffer in driver's
	probe function, all adapter which use that driver must have same size
     buffer. If you want trace to one adapter, but not to another, you can make
     another adapter's buffer off.

The implementation example of igb is patch 2.

HOW TO USE:

If you want to know how to use from driver side, see patch 2.
User side is below.

# mount -t debugfs nodev /sys/kernel/debug
# ls /sys/kernel/debug/ndrvbuf
igb-trace-0000:03:00.0 igb-trace-0000:03:00.1
# ls /sys/kernel/debug/ndrvbuf/igb-trace-0000:03:00.0
buffer  buffer_size

"buffer" is output interface. If you set read_format function in
register_ndrvbuf, it is used. If not, default read function is used.
It displays recorded data by hex style.

# cat buffer
[  1] 50462.369207: clean_tx qidx=1 ntu=154->156
[  0] 50462.369241: clean_rx qidx=0 ntu=111->112
[  0] 50462.369250: xmit qidx=1 ntu=156->158
[  1] 50462.369256: clean_tx qidx=1 ntu=156->158
[  1] 50462.369342: clean_rx qidx=0 ntu=113->114
[  1] 50462.369439: clean_rx qidx=0 ntu=114->115

"buffer_size" is size of buffer per CPU. If you want to change that,
# echo 1000000 > buffer_size
# cat buffer_size
1000000

If you want to disable recording,
# echo 0 > buffer_size

Thanks,
Koki Sanagi.

[RFC PATCH 1/2] netdev: buffer infrastructure to log network driver's information

[Koki Sanagi]

This patch implements buffer infrastructure under driver/net.
This buffer records information from network driver.

Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
---
  drivers/net/Kconfig     |    8 +
  drivers/net/Makefile    |    1 +
  drivers/net/ndrvbuf.c   |  535 +++++++++++++++++++++++++++++++++++++++++++++++
  include/linux/ndrvbuf.h |   57 +++++
  4 files changed, 601 insertions(+), 0 deletions(-)

diff --git a/drivers/net/Kconfig b/drivers/net/Kconfig
index 7029cd5..98ac929 100644
--- a/drivers/net/Kconfig
+++ b/drivers/net/Kconfig
@@ -219,6 +219,14 @@ config MII
  	  or internal device.  It is safe to say Y or M here even if your
  	  ethernet card lack MII.
  
+config NDRVBUF
+	tristate "Use buffer for network device driver"
+	default m
+	help
+	  The ndrvbuf is a generally buffer for network driver. It can record
+	  some event or logging informaiton you want to preseve. ring_buffer
+	  is used as a buffer infrastructure.
+
  config MACB
  	tristate "Atmel MACB support"
  	depends on AVR32 || ARCH_AT91SAM9260 || ARCH_AT91SAM9263 || ARCH_AT91SAM9G20 || ARCH_AT91SAM9G45 || ARCH_AT91CAP9
diff --git a/drivers/net/Makefile b/drivers/net/Makefile
index 4788862..84319ba 100644
--- a/drivers/net/Makefile
+++ b/drivers/net/Makefile
@@ -5,6 +5,7 @@
  obj-$(CONFIG_MII) += mii.o
  obj-$(CONFIG_MDIO) += mdio.o
  obj-$(CONFIG_PHYLIB) += phy/
+obj-$(CONFIG_NDRVBUF) += ndrvbuf.o
  
  obj-$(CONFIG_TI_DAVINCI_EMAC) += davinci_emac.o
  
diff --git a/drivers/net/ndrvbuf.c b/drivers/net/ndrvbuf.c
new file mode 100644
index 0000000..7401334
--- /dev/null
+++ b/drivers/net/ndrvbuf.c
@@ -0,0 +1,535 @@
+#include <linux/ndrvbuf.h>
+
+MODULE_LICENSE("GPL");
+static struct dentry *ndrvbuf_root;
+
+/* This list links all ndrvbuf registered */
+static LIST_HEAD(ndrvbuf_list);
+static DEFINE_MUTEX(ndrvbuf_list_lock);
+static atomic_t ndrvbuf_disabled;
+/* control reading ring_buffer */
+struct ndrvbuf_reader {
+	struct ndrvbuf *ndrvbuf;
+	loff_t idx;
+	struct ring_buffer_iter **iter;
+	char *print;
+	size_t print_len;
+	loff_t print_pos;
+};
+
+/**
+ * typical_ndrvbuf_header - write a typical header
+ * @dst: buffer to write
+ * @cpu: The processor number
+ * @ts: The time stamp
+ *
+ * Write a typical header to buffer
+ **/
+size_t _typical_ndrvbuf_header(void *dst, size_t size, int cpu, u64 ts)
+{
+	int ret;
+	unsigned long usecs_rem, secs;
+
+	ts += 500;
+	do_div(ts, NSEC_PER_USEC);
+	usecs_rem = do_div(ts, USEC_PER_SEC);
+	secs = (unsigned long)ts;
+	ret = snprintf(dst, size, "[%3d] %5lu.%06lu: ", cpu, secs, usecs_rem);
+	return ret;
+}
+EXPORT_SYMBOL(_typical_ndrvbuf_header);
+
+/**
+ * ndrvbuf_default_read - print the event using hex format
+ * @ubuf: The buffer to write
+ * @bufsize: The maximum byte to write
+ * @entry: The adrress to read
+ * @len: The size of etnry
+ * @cpu: The processor nubmer
+ * @ts: The time stamp
+ *
+ * If read==NULL in register_ndrvbuf, this funcion is used when printing.
+ **/
+static size_t ndrvbuf_default_read(void *ubuf, size_t bufsize, void *entry,
+				unsigned len, int cpu, u64 ts)
+{
+	int bufpos = 0, lpos = 0;
+
+	bufpos += _typical_ndrvbuf_header(ubuf, bufsize, cpu, ts);
+	bufpos += snprintf(ubuf + bufpos, bufsize - bufpos, "\n");
+	while (lpos < len) {
+		hex_dump_to_buffer(entry + lpos, len - lpos, 16, 4,
+				ubuf + bufpos, bufsize - bufpos, 0);
+		bufpos = strlen(ubuf);
+		bufpos += snprintf(ubuf + bufpos, bufsize - bufpos, "\n");
+		lpos += 16;
+	}
+	return bufpos;
+}
+
+static int is_in_ndrvbuf_list(struct ndrvbuf *ndrvbuf)
+{
+	struct list_head *cur;
+	struct ndrvbuf *cbuf;
+
+	list_for_each(cur, &ndrvbuf_list) {
+		cbuf = list_entry(cur, struct ndrvbuf, list);
+		if (cbuf == ndrvbuf)
+			break;
+	}
+	if (cur == &ndrvbuf_list)
+		return 0;
+	else
+		return 1;
+}
+
+/**
+ * ndrvbuf_buffer_open - open ring_buffer and set itearator to read
+ * @inode: contain ndrvbuf pointer
+ * @file: The pointer to attach the ndrvbuf pointer
+ **/
+static int ndrvbuf_buffer_open(struct inode *inode, struct file *file)
+{
+	struct ndrvbuf *ndrvbuf = inode->i_private;
+	struct ndrvbuf_reader *reader;
+	int cpu;
+
+	reader = kzalloc(sizeof(struct ndrvbuf_reader), GFP_KERNEL);
+	if (!reader) {
+		pr_warning("Could not alloc reader->iter\n");
+		goto out;
+	}
+	reader->iter = kmalloc(sizeof(struct ring_buffer_iter *) * nr_cpu_ids,
+				GFP_KERNEL);
+	if (!reader->iter) {
+		pr_warning("Could not alloc reader->iter\n");
+		goto out_free_reader;
+	}
+	mutex_lock(&ndrvbuf_list_lock);
+	if (!is_in_ndrvbuf_list(ndrvbuf)) {
+		mutex_unlock(&ndrvbuf_list_lock);
+		goto out_free_iter;
+	}
+	atomic_inc(&ndrvbuf->reader_count);
+	mutex_unlock(&ndrvbuf_list_lock);
+	for_each_online_cpu(cpu)
+		reader->iter[cpu] = ring_buffer_read_start(ndrvbuf->rbuf, cpu);
+	reader->print = kmalloc(NDRVBUF_STR_LEN, GFP_KERNEL);
+	if (!reader->print) {
+		pr_warning("Could not alloc reader->print\n");
+		goto out_free_iter;
+	}
+	reader->ndrvbuf = ndrvbuf;
+	file->private_data = reader;
+	return 0;
+
+out_free_iter:
+	kfree(reader->iter);
+out_free_reader:
+	kfree(reader);
+out:
+	return -ENOMEM;
+}
+
+static int ndrvbuf_buffer_release(struct inode *inode, struct file *file)
+{
+	struct ndrvbuf_reader *reader = file->private_data;
+	struct ndrvbuf *ndrvbuf = reader->ndrvbuf;
+	int cpu;
+
+	for_each_online_cpu(cpu) {
+		ring_buffer_read_finish(reader->iter[cpu]);
+	}
+	kfree(reader->iter);
+	kfree(reader->print);
+	kfree(reader);
+	atomic_dec(&ndrvbuf->reader_count);
+	return 0;
+}
+
+static loff_t _ndrvbuf_lseek(struct ndrvbuf_reader *reader, loff_t pos)
+{
+	struct ndrvbuf *ndrvbuf = reader->ndrvbuf;
+	struct ring_buffer_iter **iter = reader->iter;
+	struct ring_buffer_event *event;
+	void *entry;
+	int cpu, next_cpu;
+	u64 ts, next_ts;
+	unsigned len;
+	int strlen;
+
+	reader->idx = 0;
+	for_each_online_cpu(cpu) {
+		ring_buffer_iter_reset(iter[cpu]);
+	}
+	while (1) {
+		next_ts = 0;
+		next_cpu = -1;
+		for_each_online_cpu(cpu) {
+			if (!iter[cpu])
+				continue;
+			event = ring_buffer_iter_peek(iter[cpu], &ts);
+			if (!event)
+				continue;
+			if (!next_ts || ts < next_ts) {
+				next_ts = ts;
+				next_cpu = cpu;
+			}
+		}
+		if (next_cpu < 0)
+			return -EINVAL;
+		event = ring_buffer_read(iter[next_cpu], &ts);
+		if (!event)
+			return -EINVAL;
+		entry = ring_buffer_event_data(event);
+		len = ring_buffer_event_length(event);
+		strlen = ndrvbuf->read(reader->print, NDRVBUF_STR_LEN,
+					entry, len, next_cpu, ts);
+		if (reader->idx + strlen > pos)
+			break;
+		reader->idx += strlen;
+	}
+	reader->print_len = strlen;
+	reader->print_pos = reader->idx + strlen - pos;
+	reader->idx = pos;
+	return pos;
+}
+
+/**
+ * ndrvbuf_buffer_read - read event and write it to user buffer
+ * @file: the file to read
+ * @buf: the file to write
+ * @nbytes: the maximum size to write
+ * @ppos: the position to read from
+ *
+ * Read an event from ring_buffer and write it user buffer.
+ * If read format function is set, use it.
+ **/
+static ssize_t ndrvbuf_buffer_read(struct file *file, char __user *buf,
+					size_t nbytes, loff_t *ppos)
+{
+	struct ndrvbuf_reader *reader = file->private_data;
+	struct ndrvbuf *ndrvbuf = reader->ndrvbuf;
+	struct ring_buffer_iter **iter = reader->iter;
+	struct ring_buffer_event *event;
+	void *entry;
+	unsigned len;
+	int cpu, next_cpu = -1;
+	u64 ts, next_ts = 0;
+	int ret;
+	size_t copy, strlen;
+	loff_t pos = *ppos;
+
+	if (pos != reader->idx)
+		_ndrvbuf_lseek(reader, pos);
+	if (reader->print_len) {
+		copy = min(reader->print_len, nbytes);
+		ret = copy_to_user(buf, reader->print + reader->print_pos,
+				copy);
+		copy -= ret;
+		reader->print_len -= copy;
+		reader->print_pos += copy;
+		reader->idx += copy;
+		*ppos += copy;
+		return copy;
+	}
+	for_each_online_cpu(cpu) {
+		if (!iter[cpu])
+			continue;
+		event = ring_buffer_iter_peek(iter[cpu], &ts);
+		if (!event)
+			continue;
+		if (!next_ts || ts < next_ts) {
+			next_ts = ts;
+			next_cpu = cpu;
+		}
+	}
+	if (next_cpu < 0)
+		return 0;
+	event = ring_buffer_read(iter[next_cpu], &ts);
+	if (!event)
+		return 0;
+	entry = ring_buffer_event_data(event);
+	len = ring_buffer_event_length(event);
+
+	strlen = ndrvbuf->read(reader->print, NDRVBUF_STR_LEN, entry,
+				len, next_cpu, ts);
+	reader->print_len = strlen;
+	copy = min(strlen, nbytes);
+	ret = copy_to_user(buf, reader->print, strlen);
+	copy -= ret;
+	reader->print_len -= copy;
+	reader->print_pos = copy;
+	*ppos = pos + copy;
+	reader->idx = *ppos;
+	return copy;
+}
+
+
+static const struct file_operations buffer_file_ops = {
+	.owner =	THIS_MODULE,
+	.open =		ndrvbuf_buffer_open,
+	.read =		ndrvbuf_buffer_read,
+	.release =	ndrvbuf_buffer_release,
+};
+
+static int ndrvbuf_buffer_size_open(struct inode *inode, struct file *file)
+{
+	file->private_data = inode->i_private;
+	return 0;
+}
+
+static ssize_t ndrvbuf_buffer_size_read(struct file *file, char __user *ubuf,
+					size_t nbytes, loff_t *ppos)
+{
+	struct ndrvbuf *ndrvbuf = file->private_data;
+	int ret;
+	char buf[16];
+	ssize_t size;
+
+	mutex_lock(&ndrvbuf_list_lock);
+	if (!is_in_ndrvbuf_list(ndrvbuf)) {
+		mutex_unlock(&ndrvbuf_list_lock);
+		return -ENODEV;
+
+	}
+	ret = snprintf(buf, 16, "%lu\n", ndrvbuf->buffer_size);
+	size = simple_read_from_buffer(ubuf, nbytes, ppos, buf, ret);
+	mutex_unlock(&ndrvbuf_list_lock);
+	return size;
+}
+
+/**
+ * ndrvbuf_buffer_size_write - resize the size of ring_buffer
+ * @file: the file to read
+ * @buf: the file to write
+ * @nbytes: the maximum size to write
+ * @ppos: the position to read from
+ **/
+static ssize_t ndrvbuf_buffer_size_write(struct file *file,
+			const char __user *ubuf, size_t nbytes, loff_t *ppos)
+{
+	struct ndrvbuf *ndrvbuf = file->private_data;
+	unsigned long cur_size = ndrvbuf->buffer_size;
+	unsigned long new_size;
+	int ret;
+	char buf[64];
+
+	if (nbytes >= sizeof(buf))
+		return -EINVAL;
+	if (copy_from_user(&buf, ubuf, nbytes))
+		return -EFAULT;
+	buf[nbytes] = 0;
+	ret = strict_strtoul(buf, 10, &new_size);
+	if (ret < 0)
+		return ret;
+	if (cur_size == new_size)
+		return nbytes;
+schedule:
+	mutex_lock(&ndrvbuf_list_lock);
+	if (atomic_read(&ndrvbuf->reader_count) != 0) {
+		mutex_unlock(&ndrvbuf_list_lock);
+		schedule();
+		goto schedule;
+	}
+	atomic_inc(&ndrvbuf_disabled);
+	synchronize_sched();
+	if (!is_in_ndrvbuf_list(ndrvbuf)) {
+		atomic_dec(&ndrvbuf_disabled);
+		mutex_unlock(&ndrvbuf_list_lock);
+		return -ENODEV;
+	}
+	ret = ring_buffer_resize(ndrvbuf->rbuf, new_size);
+	if (ret < 0)
+		pr_warning("Could not change buffer size\n");
+	ndrvbuf->buffer_size = new_size;
+	if (new_size)
+		atomic_set(&ndrvbuf->disabled, 0);
+	else
+		atomic_set(&ndrvbuf->disabled, 1);
+	atomic_dec(&ndrvbuf_disabled);
+	mutex_unlock(&ndrvbuf_list_lock);
+
+	return nbytes;
+}
+
+static const struct file_operations buffer_size_file_ops = {
+	.owner =	THIS_MODULE,
+	.open =		ndrvbuf_buffer_size_open,
+	.read =		ndrvbuf_buffer_size_read,
+	.write =	ndrvbuf_buffer_size_write,
+};
+
+static struct ndrvbuf *create_ndrvbuf(const char *name, size_t size)
+{
+	struct ndrvbuf *ndrvbuf;
+	struct dentry *buf_dir;
+
+	ndrvbuf = kzalloc(sizeof(struct ndrvbuf), GFP_KERNEL);
+	if (!ndrvbuf)
+		goto out;
+	strcpy(ndrvbuf->name, name);
+	buf_dir = debugfs_create_dir(name, ndrvbuf_root);
+	if (!buf_dir) {
+		pr_warning("Could not create debugfs dir '%s'\n", name);
+		goto out_free_ndrvbuf;
+	}
+	ndrvbuf->buf_dir = buf_dir;
+	ndrvbuf->buffer_dent = debugfs_create_file("buffer",
+				S_IFREG|S_IRUGO|S_IWUSR,
+				buf_dir, ndrvbuf, &buffer_file_ops);
+	if (!ndrvbuf->buffer_dent) {
+		pr_warning("Could not create debugfs file 'buffer'\n");
+		goto out_rem_buf_dir;
+	}
+	ndrvbuf->buffer_size_dent = debugfs_create_file("buffer_size",
+				S_IFREG|S_IRUGO|S_IWUSR,
+				buf_dir, ndrvbuf, &buffer_size_file_ops);
+	if (!ndrvbuf->buffer_size_dent) {
+		pr_warning("Could not create debugfs file 'buffer_size'\n");
+		goto out_rem_buffer;
+	}
+	ndrvbuf->rbuf = ring_buffer_alloc(size, RB_FL_OVERWRITE);
+	if (!ndrvbuf->rbuf) {
+		pr_warning("Could not alloc ring_buffer for %s\n",
+							name);
+		goto out_rem_buffer_size;
+	}
+	ndrvbuf->buffer_size = size;
+	if (size)
+		atomic_set(&ndrvbuf->disabled, 0);
+	else
+		atomic_set(&ndrvbuf->disabled, 1);
+	return ndrvbuf;
+
+out_rem_buffer_size:
+	debugfs_remove(ndrvbuf->buffer_size_dent);
+out_rem_buffer:
+	debugfs_remove(ndrvbuf->buffer_dent);
+out_rem_buf_dir:
+	debugfs_remove(ndrvbuf->buf_dir);
+out_free_ndrvbuf:
+	kfree(ndrvbuf);
+out:
+	return NULL;
+}
+
+static void remove_ndrvbuf(struct ndrvbuf *ndrvbuf)
+{
+	if (!ndrvbuf)
+		return;
+	debugfs_remove(ndrvbuf->buffer_size_dent);
+	debugfs_remove(ndrvbuf->buffer_dent);
+	debugfs_remove(ndrvbuf->buf_dir);
+	ring_buffer_free(ndrvbuf->rbuf);
+	kfree(ndrvbuf);
+}
+
+/**
+ * register_ndrvbuf - create ndrvbuf struct
+ * @name: The buffer dif name. Usually, it is created under
+ *        /sys/kernel/debug/ndrvbuf
+ * @size: The size of ring_buffer per cpu
+ * @read: The read format funcion. If NULL, use ndrvbuf_default_read.
+ *
+ * This is called when network driver want to set ndrvbuf.
+ * If registering is failed, return NULL.
+ **/
+struct ndrvbuf *_register_ndrvbuf(const char *name, size_t size,
+		size_t (*read)(void *, size_t, void *, size_t, int, u64))
+{
+	struct ndrvbuf *cbuf;
+	struct list_head *cur;
+
+	mutex_lock(&ndrvbuf_list_lock);
+	atomic_inc(&ndrvbuf_disabled);
+	synchronize_sched();
+	list_for_each(cur, &ndrvbuf_list) {
+		cbuf = list_entry(cur, struct ndrvbuf, list);
+		if (!strncmp(cbuf->name, name, NDRVBUF_NAME_SIZE))
+			break;
+	}
+	if (cur != &ndrvbuf_list) {
+		pr_warning("%s already exists\n", name);
+		cbuf = NULL;
+		goto out;
+	}
+	cbuf = create_ndrvbuf(name, size);
+	if (!cbuf)
+		goto out;
+
+	if (read)
+		cbuf->read = read;
+	else
+		cbuf->read = ndrvbuf_default_read;
+	list_add(&cbuf->list, &ndrvbuf_list);
+out:
+	atomic_dec(&ndrvbuf_disabled);
+	mutex_unlock(&ndrvbuf_list_lock);
+	return cbuf;
+}
+EXPORT_SYMBOL(_register_ndrvbuf);
+
+/**
+ * unregister_ndrvbuf - free ndrbuf struct and some resources
+ * @ndrvbuf: The pointer of ndrvbuf
+ **/
+void _unregister_ndrvbuf(struct ndrvbuf *ndrvbuf)
+{
+schedule:
+	mutex_lock(&ndrvbuf_list_lock);
+	if (atomic_read(&ndrvbuf->reader_count) != 0) {
+		mutex_unlock(&ndrvbuf_list_lock);
+		schedule();
+		goto schedule;
+	}
+	atomic_inc(&ndrvbuf_disabled);
+	synchronize_sched();
+	list_del(&ndrvbuf->list);
+	atomic_dec(&ndrvbuf_disabled);
+	mutex_unlock(&ndrvbuf_list_lock);
+
+	remove_ndrvbuf(ndrvbuf);
+}
+EXPORT_SYMBOL(_unregister_ndrvbuf);
+
+/**
+ * _write_ndrvbuf - Write a trace event to buffer
+ * @ndrvbuf: buffer to write
+ * @size: The size of trace event
+ * @buf: The pointer to read from
+ **/
+void _write_ndrvbuf(struct ndrvbuf *ndrvbuf, size_t size, void *buf)
+{
+	unsigned long flags;
+
+	preempt_disable();
+	local_irq_save(flags);
+	if (!atomic_read(&ndrvbuf_disabled) && is_in_ndrvbuf_list(ndrvbuf)
+		&& !atomic_read(&ndrvbuf->disabled))
+		ring_buffer_write(ndrvbuf->rbuf, size, buf);
+	local_irq_restore(flags);
+	preempt_enable();
+}
+EXPORT_SYMBOL(_write_ndrvbuf);
+
+static int __init ndrvbuf_init(void)
+{
+	ndrvbuf_root = debugfs_create_dir("ndrvbuf", NULL);
+	if (!ndrvbuf_root) {
+		pr_warning("Could not create debugfs dir 'ndrvbuf'\n");
+		return -ENODEV;
+	}
+	atomic_set(&ndrvbuf_disabled, 0);
+	return 0;
+}
+
+module_init(ndrvbuf_init);
+
+static void __exit ndrvbuf_exit(void)
+{
+	if (ndrvbuf_root)
+		debugfs_remove(ndrvbuf_root);
+}
+
+module_exit(ndrvbuf_exit);
diff --git a/include/linux/ndrvbuf.h b/include/linux/ndrvbuf.h
new file mode 100644
index 0000000..1d56b79
--- /dev/null
+++ b/include/linux/ndrvbuf.h
@@ -0,0 +1,57 @@
+#ifndef _NDRVBUF_H_
+#define _NDRVBUF_H_
+
+#include <linux/kernel.h>
+#include <linux/module.h>
+#include <linux/sched.h>
+#include <linux/ring_buffer.h>
+#include <linux/debugfs.h>
+#include <linux/netdevice.h>
+
+#define NDRVBUF_STR_LEN (2*PAGE_SIZE)
+#define NDRVBUF_NAME_SIZE 32
+
+struct ndrvbuf {
+	struct list_head list;
+	char name[NDRVBUF_NAME_SIZE];
+	struct dentry *buf_dir;
+	struct dentry *enable_dent;
+	struct dentry *buffer_size_dent;
+	struct dentry *buffer_dent;
+	unsigned long buffer_size;
+	atomic_t disabled;
+	size_t (*read)(void *ubuf, size_t bufsize, void *entry,
+			size_t size, int cpu, u64 ts);
+	struct ring_buffer *rbuf;
+	atomic_t reader_count;
+};
+
+extern __attribute__((weak)) struct ndrvbuf *_register_ndrvbuf(
+		const char *name, size_t size,
+		size_t (*read)(void *, size_t, void *, size_t, int, u64));
+extern __attribute__((weak)) void _unregister_ndrvbuf(struct ndrvbuf *ndrvbuf);
+extern __attribute__((weak)) void _write_ndrvbuf(struct ndrvbuf *ndrvbuf,
+		size_t size, void *buf);
+extern __attribute__((weak)) size_t _typical_ndrvbuf_header(void *dst,
+		size_t size, int cpu, u64 ts);
+
+#define register_ndrvbuf(name, size, read) ((_register_ndrvbuf) ? \
+	_register_ndrvbuf(name, size, read) : NULL)
+
+#define unregister_ndrvbuf(ndrvbuf)					\
+	do {								\
+		if (_unregister_ndrvbuf)				\
+			_unregister_ndrvbuf(ndrvbuf);			\
+	} while (0)
+
+#define write_ndrvbuf(ndrvbuf, size, buf)				\
+	do {								\
+		if (_write_ndrvbuf)					\
+			_write_ndrvbuf(ndrvbuf, size, buf);		\
+	} while (0)
+
+#define typical_ndrvbuf_header(dst, size, cpu, ts) (			\
+	(_typical_ndrvbuf_header) ? 					\
+	_typical_ndrvbuf_header(dst, size, cpu, ts) : 0)
+
+#endif /* _NDRVBUF_H_ */

[RFC PATCH 2/2] netdev: an usage example on igb

[Koki Sanagi]

This patch is usage example of previous patch's buffer on igb.
The output is like below.

# cat /sys/kernel/debug/ndrvbuf/igb-trace-0000\:03\:00.0/buffer
[  1] 50462.369207: clean_tx qidx=1 ntu=154->156
[  0] 50462.369241: clean_rx qidx=0 ntu=111->112
[  0] 50462.369250: xmit qidx=1 ntu=156->158
[  1] 50462.369256: clean_tx qidx=1 ntu=156->158
[  1] 50462.369342: clean_rx qidx=0 ntu=113->114
[  1] 50462.369439: clean_rx qidx=0 ntu=114->115

This example outputs original print style, because it sets original print
function(igb_trace_read) when registered.

register_ndrvbuf(buname, 1000000, igb_trace_read);

If you set NULL to arg3, outputs by ndrvbuf default style.
If you set 0 to size(arg2), recording is disabled at first(but small buffer is
alloced).
When you set non-zero to size, recording becomes enabled.

Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
---
  drivers/net/igb/Makefile    |    2 +-
  drivers/net/igb/igb.h       |    1 +
  drivers/net/igb/igb_main.c  |   10 +++++-
  drivers/net/igb/igb_trace.c |   81 +++++++++++++++++++++++++++++++++++++++++++
  drivers/net/igb/igb_trace.h |   21 +++++++++++
  5 files changed, 113 insertions(+), 2 deletions(-)

diff --git a/drivers/net/igb/Makefile b/drivers/net/igb/Makefile
index 8372cb9..286541e 100644
--- a/drivers/net/igb/Makefile
+++ b/drivers/net/igb/Makefile
@@ -33,5 +33,5 @@
  obj-$(CONFIG_IGB) += igb.o
  
  igb-objs := igb_main.o igb_ethtool.o e1000_82575.o \
-	    e1000_mac.o e1000_nvm.o e1000_phy.o e1000_mbx.o
+	    e1000_mac.o e1000_nvm.o e1000_phy.o e1000_mbx.o igb_trace.o
  
diff --git a/drivers/net/igb/igb.h b/drivers/net/igb/igb.h
index a177570..533c5e6 100644
--- a/drivers/net/igb/igb.h
+++ b/drivers/net/igb/igb.h
@@ -315,6 +315,7 @@ struct igb_adapter {
  	unsigned int vfs_allocated_count;
  	struct vf_data_storage *vf_data;
  	u32 rss_queues;
+	struct ndrvbuf *trace;
  };
  
  #define IGB_FLAG_HAS_MSI           (1 << 0)
diff --git a/drivers/net/igb/igb_main.c b/drivers/net/igb/igb_main.c
index 583a21c..f754fd1 100644
--- a/drivers/net/igb/igb_main.c
+++ b/drivers/net/igb/igb_main.c
@@ -48,6 +48,7 @@
  #include <linux/dca.h>
  #endif
  #include "igb.h"
+#include "igb_trace.h"
  
  #define DRV_VERSION "2.1.0-k2"
  char igb_driver_name[] = "igb";
@@ -1412,6 +1413,7 @@ static int __devinit igb_probe(struct pci_dev *pdev,
  	int err, pci_using_dac;
  	u16 eeprom_apme_mask = IGB_EEPROM_APME;
  	u32 part_num;
+	char bufname[NDRVBUF_NAME_SIZE];
  
  	err = pci_enable_device_mem(pdev);
  	if (err)
@@ -1674,6 +1676,8 @@ static int __devinit igb_probe(struct pci_dev *pdev,
  		(adapter->flags & IGB_FLAG_HAS_MSI) ? "MSI" : "legacy",
  		adapter->num_rx_queues, adapter->num_tx_queues);
  
+	sprintf(bufname, "igb-trace-%s", pci_name(pdev));
+	adapter->trace = register_ndrvbuf(bufname, 1000000, igb_trace_read);
  	return 0;
  
  err_register:
@@ -1734,6 +1738,7 @@ static void __devexit igb_remove(struct pci_dev *pdev)
  	 * would have already happened in close and is redundant. */
  	igb_release_hw_control(adapter);
  
+	unregister_ndrvbuf(adapter->trace);
  	unregister_netdev(netdev);
  
  	igb_clear_interrupt_scheme(adapter);
@@ -3814,6 +3819,7 @@ netdev_tx_t igb_xmit_frame_ring_adv(struct sk_buff *skb,
  	}
  
  	igb_tx_queue_adv(tx_ring, tx_flags, count, skb->len, hdr_len);
+	igb_trace_write_xmit(adapter->trace, tx_ring, first);
  
  	/* Make sure there is space in the ring for the next send. */
  	igb_maybe_stop_tx(tx_ring, MAX_SKB_FRAGS + 4);
@@ -5039,7 +5045,7 @@ static bool igb_clean_tx_irq(struct igb_q_vector *q_vector)
  		eop = tx_ring->buffer_info[i].next_to_watch;
  		eop_desc = E1000_TX_DESC_ADV(*tx_ring, eop);
  	}
-
+	igb_trace_write_clean_tx(adapter->trace, tx_ring, i);
  	tx_ring->next_to_clean = i;
  
  	if (unlikely(count &&
@@ -5195,6 +5201,7 @@ static bool igb_clean_rx_irq_adv(struct igb_q_vector *q_vector,
  {
  	struct igb_ring *rx_ring = q_vector->rx_ring;
  	struct net_device *netdev = rx_ring->netdev;
+	struct igb_adapter *adapter = netdev_priv(netdev);
  	struct pci_dev *pdev = rx_ring->pdev;
  	union e1000_adv_rx_desc *rx_desc , *next_rxd;
  	struct igb_buffer *buffer_info , *next_buffer;
@@ -5309,6 +5316,7 @@ next_desc:
  		staterr = le32_to_cpu(rx_desc->wb.upper.status_error);
  	}
  
+	igb_trace_write_clean_rx(adapter->trace, rx_ring, i);
  	rx_ring->next_to_clean = i;
  	cleaned_count = igb_desc_unused(rx_ring);
  
diff --git a/drivers/net/igb/igb_trace.c b/drivers/net/igb/igb_trace.c
new file mode 100644
index 0000000..ab96300
--- /dev/null
+++ b/drivers/net/igb/igb_trace.c
@@ -0,0 +1,81 @@
+#include "igb_trace.h"
+
+struct trace_data_common {
+	unsigned short type;
+	u8 qidx;
+	int from;
+	int to;
+};
+
+void igb_trace_write_xmit(struct ndrvbuf *ndrvbuf,
+				struct igb_ring *tx_ring, int i)
+{
+	struct trace_data_common tdata;
+
+	tdata.type = IGB_TRACE_EVENT_XMIT;
+	tdata.qidx = tx_ring->queue_index;
+	tdata.from = i;
+	tdata.to = tx_ring->next_to_use;
+
+	write_ndrvbuf(ndrvbuf, sizeof(struct trace_data_common), &tdata);
+}
+
+void igb_trace_write_clean_tx(struct ndrvbuf *ndrvbuf,
+				struct igb_ring *tx_ring, int i)
+{
+	struct trace_data_common tdata;
+
+	tdata.type = IGB_TRACE_EVENT_CLEAN_TX;
+	tdata.qidx = tx_ring->queue_index;
+	tdata.from = tx_ring->next_to_clean;
+	tdata.to = i;
+
+	write_ndrvbuf(ndrvbuf, sizeof(struct trace_data_common), &tdata);
+}
+
+void igb_trace_write_clean_rx(struct ndrvbuf *ndrvbuf,
+				struct igb_ring *rx_ring, int i)
+{
+	struct trace_data_common tdata;
+
+	tdata.type = IGB_TRACE_EVENT_CLEAN_RX;
+	tdata.qidx = rx_ring->queue_index;
+	tdata.from = rx_ring->next_to_clean;
+	tdata.to = i;
+
+	write_ndrvbuf(ndrvbuf, sizeof(struct trace_data_common), &tdata);
+}
+
+size_t igb_trace_read(void *ubuf, size_t bufsize, void *entry,
+			size_t size, int cpu, u64 ts)
+{
+	struct trace_data_common *tdata = entry;
+	int bufpos = 0;
+	size_t headlen;
+
+	headlen = typical_ndrvbuf_header(ubuf, bufsize, cpu, ts);
+	bufpos += headlen;
+
+	switch (tdata->type) {
+	case IGB_TRACE_EVENT_XMIT:
+		bufpos += snprintf(ubuf + bufpos, bufsize - bufpos,
+					"xmit qidx=%u ntu=%d->%d\n",
+					tdata->qidx, tdata->from, tdata->to);
+		break;
+	case IGB_TRACE_EVENT_CLEAN_TX:
+		bufpos += snprintf(ubuf + bufpos, bufsize - bufpos,
+					"clean_tx qidx=%u ntu=%d->%d\n",
+					tdata->qidx, tdata->from, tdata->to);
+		break;
+	case IGB_TRACE_EVENT_CLEAN_RX:
+		bufpos += snprintf(ubuf + bufpos, bufsize - bufpos,
+					"clean_rx qidx=%u ntu=%d->%d\n",
+					tdata->qidx, tdata->from, tdata->to);
+		break;
+	default:
+		bufpos += snprintf(ubuf + bufpos, bufsize - bufpos,
+					"EVENT ID:%u is not defined\n",
+					tdata->type);
+	}
+	return bufpos;
+}
diff --git a/drivers/net/igb/igb_trace.h b/drivers/net/igb/igb_trace.h
new file mode 100644
index 0000000..fa130e1
--- /dev/null
+++ b/drivers/net/igb/igb_trace.h
@@ -0,0 +1,21 @@
+#ifndef _IGB_TRACE_H_
+#define _IGB_TRACE_H_
+
+#include <linux/ndrvbuf.h>
+#include "igb.h"
+
+#define IGB_TRACE_EVENT_XMIT		0x01
+#define IGB_TRACE_EVENT_CLEAN_TX	0x02
+#define IGB_TRACE_EVENT_CLEAN_RX	0x03
+
+extern void igb_trace_write_xmit(struct ndrvbuf *ndrvbuf,
+			struct igb_ring *tx_ring, int i);
+extern void igb_trace_write_clean_tx(struct ndrvbuf *ndrvbuf,
+			struct igb_ring *tx_ring, int i);
+extern void igb_trace_write_clean_rx(struct ndrvbuf *ndrvbuf,
+			struct igb_ring *rx_ring, int i);
+
+extern size_t igb_trace_read(void *ubuf, size_t bufsize, void *entry,
+			size_t size, int cpu, u64 ts);
+
+#endif /*_IGB_TRACE_H_*/

Re: [RFC PATCH 2/2] netdev: an usage example on igb

[Eric Dumazet]

Le lundi 05 avril 2010 à 15:54 +0900, Koki Sanagi a écrit :
> This patch is usage example of previous patch's buffer on igb.
> The output is like below.
> 
> # cat /sys/kernel/debug/ndrvbuf/igb-trace-0000\:03\:00.0/buffer
> [  1] 50462.369207: clean_tx qidx=1 ntu=154->156
> [  0] 50462.369241: clean_rx qidx=0 ntu=111->112
> [  0] 50462.369250: xmit qidx=1 ntu=156->158
> [  1] 50462.369256: clean_tx qidx=1 ntu=156->158
> [  1] 50462.369342: clean_rx qidx=0 ntu=113->114
> [  1] 50462.369439: clean_rx qidx=0 ntu=114->115
> 
> This example outputs original print style, because it sets original print
> function(igb_trace_read) when registered.
> 
> register_ndrvbuf(buname, 1000000, igb_trace_read);
> 
> If you set NULL to arg3, outputs by ndrvbuf default style.
> If you set 0 to size(arg2), recording is disabled at first(but small buffer is
> alloced).
> When you set non-zero to size, recording becomes enabled.
> 
> Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
> ---
>   drivers/net/igb/Makefile    |    2 +-
>   drivers/net/igb/igb.h       |    1 +
>   drivers/net/igb/igb_main.c  |   10 +++++-
>   drivers/net/igb/igb_trace.c |   81 +++++++++++++++++++++++++++++++++++++++++++
>   drivers/net/igb/igb_trace.h |   21 +++++++++++
>   5 files changed, 113 insertions(+), 2 deletions(-)
> 

This depends on NDRVBUF, yet I see no Kconfig change in this patch.

Re: [RFC PATCH 1/2] netdev: buffer infrastructure to log network driver's information

[Eric Dumazet]

Le lundi 05 avril 2010 à 15:52 +0900, Koki Sanagi a écrit :
> This patch implements buffer infrastructure under driver/net.
> This buffer records information from network driver.
> 
> Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
> ---
>   drivers/net/Kconfig     |    8 +
>   drivers/net/Makefile    |    1 +
>   drivers/net/ndrvbuf.c   |  535 +++++++++++++++++++++++++++++++++++++++++++++++
>   include/linux/ndrvbuf.h |   57 +++++
>   4 files changed, 601 insertions(+), 0 deletions(-)
> 

Wow, 600 lines... thats what I call bloat...

Why no use a very simple interface (printk like) ?

xxx_printf(dev->trace, "xmit qidx=%u ntu=%d->%d\n",
	   tx_ring->queue_index, first, tx_ring->next_to_use);

Anyway, this has nothing to do with network drivers and should be
discussed on lkml.

Re: [RFC PATCH 1/2] netdev: buffer infrastructure to log network driver's information

[David Miller]

From: Eric Dumazet <eric.dumazet@gmail.com>
Date: Mon, 05 Apr 2010 10:42:26 +0200

> Le lundi 05 avril 2010 à 15:52 +0900, Koki Sanagi a écrit :
>> This patch implements buffer infrastructure under driver/net.
>> This buffer records information from network driver.
>> 
>> Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
>> ---
>>   drivers/net/Kconfig     |    8 +
>>   drivers/net/Makefile    |    1 +
>>   drivers/net/ndrvbuf.c   |  535 +++++++++++++++++++++++++++++++++++++++++++++++
>>   include/linux/ndrvbuf.h |   57 +++++
>>   4 files changed, 601 insertions(+), 0 deletions(-)
>> 
> 
> Wow, 600 lines... thats what I call bloat...

And we have all sorts of facilities for creating filesystem
streams and ring buffers of debug information.

You could even hook into 'perf' to log and process these
events in probably like 12 lines of code.

Re: [RFC PATCH 1/2] netdev: buffer infrastructure to log network driver's information

[Neil Horman]

On Mon, Apr 05, 2010 at 12:31:55PM -0700, David Miller wrote:
> From: Eric Dumazet <eric.dumazet@gmail.com>
> Date: Mon, 05 Apr 2010 10:42:26 +0200
> 
> > Le lundi 05 avril 2010 à 15:52 +0900, Koki Sanagi a écrit :
> >> This patch implements buffer infrastructure under driver/net.
> >> This buffer records information from network driver.
> >> 
> >> Signed-off-by: Koki Sanagi <sanagi.koki@jp.fujitsu.com>
> >> ---
> >>   drivers/net/Kconfig     |    8 +
> >>   drivers/net/Makefile    |    1 +
> >>   drivers/net/ndrvbuf.c   |  535 +++++++++++++++++++++++++++++++++++++++++++++++
> >>   include/linux/ndrvbuf.h |   57 +++++
> >>   4 files changed, 601 insertions(+), 0 deletions(-)
> >> 
> > 
> > Wow, 600 lines... thats what I call bloat...
> 
> And we have all sorts of facilities for creating filesystem
> streams and ring buffers of debug information.
> 
> You could even hook into 'perf' to log and process these
> events in probably like 12 lines of code.
> 
I'm still having a hard time understanding why this approach is preferable to
the previous approach you took using tracepoints.  Granted you can't get driver
internal state as easily, but its generic and doesn't do...this.
Neil

Re: [RFC PATCH 2/2] netdev: an usage example on igb

[Koki Sanagi]

(2010/04/05 17:30), Eric Dumazet wrote:
> Le lundi 05 avril 2010 à 15:54 +0900, Koki Sanagi a écrit :
>> This patch is usage example of previous patch's buffer on igb.
>> The output is like below.
>>
>> # cat /sys/kernel/debug/ndrvbuf/igb-trace-0000\:03\:00.0/buffer
>> [  1] 50462.369207: clean_tx qidx=1 ntu=154->156
>> [  0] 50462.369241: clean_rx qidx=0 ntu=111->112
>> [  0] 50462.369250: xmit qidx=1 ntu=156->158
>> [  1] 50462.369256: clean_tx qidx=1 ntu=156->158
>> [  1] 50462.369342: clean_rx qidx=0 ntu=113->114
>> [  1] 50462.369439: clean_rx qidx=0 ntu=114->115
>>
>> This example outputs original print style, because it sets original print
>> function(igb_trace_read) when registered.
>>
>> register_ndrvbuf(buname, 1000000, igb_trace_read);
>>
>> If you set NULL to arg3, outputs by ndrvbuf default style.
>> If you set 0 to size(arg2), recording is disabled at first(but small buffer is
>> alloced).
>> When you set non-zero to size, recording becomes enabled.
>>
>> Signed-off-by: Koki Sanagi<sanagi.koki@jp.fujitsu.com>
>> ---
>>    drivers/net/igb/Makefile    |    2 +-
>>    drivers/net/igb/igb.h       |    1 +
>>    drivers/net/igb/igb_main.c  |   10 +++++-
>>    drivers/net/igb/igb_trace.c |   81 +++++++++++++++++++++++++++++++++++++++++++
>>    drivers/net/igb/igb_trace.h |   21 +++++++++++
>>    5 files changed, 113 insertions(+), 2 deletions(-)
>>
>
> This depends on NDRVBUF, yet I see no Kconfig change in this patch.
>
This igb can exist without ndrvbuf.
If ndrvbuf modules is not loaded, igb operates originally.
So this doesn't depend on ndrvbuf.
  

Re: [RFC PATCH 1/2] netdev: buffer infrastructure to log network driver's information

[Koki Sanagi]

(2010/04/06 9:10), Neil Horman wrote:
> On Mon, Apr 05, 2010 at 12:31:55PM -0700, David Miller wrote:
>> From: Eric Dumazet<eric.dumazet@gmail.com>
>> Date: Mon, 05 Apr 2010 10:42:26 +0200
>>
>>> Le lundi 05 avril 2010 à 15:52 +0900, Koki Sanagi a écrit :
>>>> This patch implements buffer infrastructure under driver/net.
>>>> This buffer records information from network driver.
>>>>
>>>> Signed-off-by: Koki Sanagi<sanagi.koki@jp.fujitsu.com>
>>>> ---
>>>>    drivers/net/Kconfig     |    8 +
>>>>    drivers/net/Makefile    |    1 +
>>>>    drivers/net/ndrvbuf.c   |  535 +++++++++++++++++++++++++++++++++++++++++++++++
>>>>    include/linux/ndrvbuf.h |   57 +++++
>>>>    4 files changed, 601 insertions(+), 0 deletions(-)
>>>>
>>>
>>> Wow, 600 lines... thats what I call bloat...
>>
>> And we have all sorts of facilities for creating filesystem
>> streams and ring buffers of debug information.
>>
>> You could even hook into 'perf' to log and process these
>> events in probably like 12 lines of code.
>>
> I'm still having a hard time understanding why this approach is preferable to
> the previous approach you took using tracepoints.  Granted you can't get driver
> internal state as easily, but its generic and doesn't do...this.
> Neil
>
>
>

We can get below information with this patch

1. Driver operates normaly or not
2. Tx ring's state

About 1, the preivous approach meets, but about 2, some hooks need in driver
code like this patch. If we get it, it is available to solute "Tx Unit Hung"
message. This message indicates that tx descriptor ring's process is not smooth.
When a countermeasure was taken to system that outputs "Tx Unit Hung" message,
this state information is available to evaluate a countermeasure.
But what you say is true, this patch is not generic.
it may be good to rebase the previous approach to focus on 1.
And it is better to consider separately about 2.