[PATCHSET v3] netconsole: implement extended console support

[PATCHSET v3] netconsole: implement extended console support

[Tejun Heo]

This patchset is v3 of netconsole extended console support.  v1 was
part of "printk, netconsole: implement reliable netconsole"
patchset[1].  The printk part is broken off to a separate patchset[2]
"printk: implement extended console support" which this patchset is
dependent upon.

Changes from the last version[3] are

* 0001-netconsole-remove-unnecessary-netconsole_target_get-.patch
  added so that we don't end up adding unnecessary get/put to
  write_ext_msg() for consistency.

* In 0004-netconsole-implement-extended-console-support.patch,
  send_ext_msg_udp() restructured to address Tetsuo and Sabrina's
  review points.

netconsole emits one or more udp messages per each log message and
only transmits the body, which works fine when it's used as a
debugging tool on local network; however, netconsole, due to its
advantages for troubleshooting kernel issues, is also used as a
mechanism to collect kernel messages at larger scale where the packets
may have to travel across congested networks or networks with multiple
paths.

Of the handful large cluster setups that I've seen, two were using
netconsole for fleet-wide kernel logging and having problem with lost
messages.  One was a HPC cluster which had a dedicated slower
management network which was used for all management traffic where
packet losses were fairly common for several different reasons - the
network itself could get fairly overloaded at times and IPMI sharing
the interface didn't seem to help either.  The other is a large web
service cluster where the aggregator is some hops away and packet
losses do happen from time to time.

Because netconsole packets don't carry any metadata, it's impossible
to tell what happened to the messages during transit and even
combining it with messages transmitted via a separate reliable
mechanism is challenging as it boils down to matching message content
textually.

The "printk, netconsole: implement reliable netconsole" patchset[1]
implements extended console support.  If a console driver sets
CON_EXTENDED, printk formats each message in the same way /dev/kmsg
messages are formatted which includes all metadata and, for structured
log messages, KEY=VALUE dictionary.

This patchset implements extended console support for netconsole,
which allows log consumers access to complete log information and to
tell which messages are missing and/or reordered, which can be used to
implement reliable kernel message logging when combined with userland
helpers.

Changes to netconsole are straight-forward.  It optionally registers a
separate extended console driver.  printk passes in extended format
messages which are transmitted the same way.  The only complication is
when the message is longer than the maximum payload size (1k).  As
each message should have proper header and the log receiver should be
able to tell which part the fragment is, netconsole duplicates full
header on each fragment and also adds an extra ncfrag=OFF/LEN header.

 0001-netconsole-remove-unnecessary-netconsole_target_get-.patch
 0002-netconsole-make-netconsole_target-enabled-a-bool.patch
 0003-netconsole-make-all-dynamic-netconsoles-share-a-mute.patch
 0004-netconsole-implement-extended-console-support.patch

diffstat follows.  Thanks.

 Documentation/networking/netconsole.txt |   35 ++++++
 drivers/net/netconsole.c                |  169 ++++++++++++++++++++++++++++----
 2 files changed, 185 insertions(+), 19 deletions(-)

--
tejun

[1] http://lkml.kernel.org/g/1429225433-11946-1-git-send-email-tj@kernel.org
[2] http://lkml.kernel.org/g/1430318704-32374-1-git-send-email-tj@kernel.org
[3] http://lkml.kernel.org/g/1430505220-25160-1-git-send-email-tj@kernel.org

[PATCH 1/4] netconsole: remove unnecessary netconsole_target_get/out() from write_msg()

[Tejun Heo]

write_msg() grabs target_list_lock and walks target_list invoking
netpool_send_udp() on each target.  Curiously, it protects each
iteration with netconsole_target_get/put() even though it never
releases target_list_lock which protects all the members.

While this doesn't harm anything, it doesn't serve any purpose either.
The items on the list can't go away while target_list_lock is held.
Remove the unnecessary get/put pair.

Signed-off-by: Tejun Heo <tj@kernel.org>
Cc: David Miller <davem@davemloft.net>
---
 drivers/net/netconsole.c | 2 --
 1 file changed, 2 deletions(-)

diff --git a/drivers/net/netconsole.c b/drivers/net/netconsole.c
index 15731d1..30c0524 100644
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -744,7 +744,6 @@ static void write_msg(struct console *con, const char *msg, unsigned int len)
 
 	spin_lock_irqsave(&target_list_lock, flags);
 	list_for_each_entry(nt, &target_list, list) {
-		netconsole_target_get(nt);
 		if (nt->enabled && netif_running(nt->np.dev)) {
 			/*
 			 * We nest this inside the for-each-target loop above
@@ -760,7 +759,6 @@ static void write_msg(struct console *con, const char *msg, unsigned int len)
 				left -= frag;
 			}
 		}
-		netconsole_target_put(nt);
 	}
 	spin_unlock_irqrestore(&target_list_lock, flags);
 }
-- 
2.1.0

[PATCH 2/4] netconsole: make netconsole_target->enabled a bool

[Tejun Heo]

netconsole uses both bool and int for boolean values.  Let's convert
nt->enabled to bool for consistency.

Signed-off-by: Tejun Heo <tj@kernel.org>
Cc: David Miller <davem@davemloft.net>
---
 drivers/net/netconsole.c | 18 +++++++++---------
 1 file changed, 9 insertions(+), 9 deletions(-)

diff --git a/drivers/net/netconsole.c b/drivers/net/netconsole.c
index 30c0524..8dd1e55 100644
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -104,7 +104,7 @@ struct netconsole_target {
 #ifdef	CONFIG_NETCONSOLE_DYNAMIC
 	struct config_item	item;
 #endif
-	int			enabled;
+	bool			enabled;
 	struct mutex		mutex;
 	struct netpoll		np;
 };
@@ -197,7 +197,7 @@ static struct netconsole_target *alloc_param_target(char *target_config)
 	if (err)
 		goto fail;
 
-	nt->enabled = 1;
+	nt->enabled = true;
 
 	return nt;
 
@@ -322,13 +322,13 @@ static ssize_t store_enabled(struct netconsole_target *nt,
 		return err;
 	if (enabled < 0 || enabled > 1)
 		return -EINVAL;
-	if (enabled == nt->enabled) {
+	if ((bool)enabled == nt->enabled) {
 		pr_info("network logging has already %s\n",
 			nt->enabled ? "started" : "stopped");
 		return -EINVAL;
 	}
 
-	if (enabled) {	/* 1 */
+	if (enabled) {	/* true */
 		/*
 		 * Skip netpoll_parse_options() -- all the attributes are
 		 * already configured via configfs. Just print them out.
@@ -340,13 +340,13 @@ static ssize_t store_enabled(struct netconsole_target *nt,
 			return err;
 
 		pr_info("netconsole: network logging started\n");
-	} else {	/* 0 */
+	} else {	/* false */
 		/* We need to disable the netconsole before cleaning it up
 		 * otherwise we might end up in write_msg() with
-		 * nt->np.dev == NULL and nt->enabled == 1
+		 * nt->np.dev == NULL and nt->enabled == true
 		 */
 		spin_lock_irqsave(&target_list_lock, flags);
-		nt->enabled = 0;
+		nt->enabled = false;
 		spin_unlock_irqrestore(&target_list_lock, flags);
 		netpoll_cleanup(&nt->np);
 	}
@@ -594,7 +594,7 @@ static struct config_item *make_netconsole_target(struct config_group *group,
 
 	/*
 	 * Allocate and initialize with defaults.
-	 * Target is disabled at creation (enabled == 0).
+	 * Target is disabled at creation (!enabled).
 	 */
 	nt = kzalloc(sizeof(*nt), GFP_KERNEL);
 	if (!nt)
@@ -695,7 +695,7 @@ restart:
 				spin_lock_irqsave(&target_list_lock, flags);
 				dev_put(nt->np.dev);
 				nt->np.dev = NULL;
-				nt->enabled = 0;
+				nt->enabled = false;
 				stopped = true;
 				netconsole_target_put(nt);
 				goto restart;
-- 
2.1.0

[PATCH 3/4] netconsole: make all dynamic netconsoles share a mutex

[Tejun Heo]

Currently, each dynamic netconsole_target uses its own separate mutex
to synchronize the configuration operations.  This patch replaces the
per-netconsole_target mutexes with a single mutex -
dynamic_netconsole_mutex.  The reduced granularity doesn't hurt
anything, the code is minutely simpler and this'd allow adding
operations which should be synchronized across all dynamic
netconsoles.

Signed-off-by: Tejun Heo <tj@kernel.org>
Cc: David Miller <davem@davemloft.net>
---
 drivers/net/netconsole.c | 8 +++-----
 1 file changed, 3 insertions(+), 5 deletions(-)

diff --git a/drivers/net/netconsole.c b/drivers/net/netconsole.c
index 8dd1e55..9b0c81e 100644
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -105,13 +105,13 @@ struct netconsole_target {
 	struct config_item	item;
 #endif
 	bool			enabled;
-	struct mutex		mutex;
 	struct netpoll		np;
 };
 
 #ifdef	CONFIG_NETCONSOLE_DYNAMIC
 
 static struct configfs_subsystem netconsole_subsys;
+static DEFINE_MUTEX(dynamic_netconsole_mutex);
 
 static int __init dynamic_netconsole_init(void)
 {
@@ -185,7 +185,6 @@ static struct netconsole_target *alloc_param_target(char *target_config)
 	strlcpy(nt->np.dev_name, "eth0", IFNAMSIZ);
 	nt->np.local_port = 6665;
 	nt->np.remote_port = 6666;
-	mutex_init(&nt->mutex);
 	eth_broadcast_addr(nt->np.remote_mac);
 
 	/* Parse parameters and setup netpoll */
@@ -562,10 +561,10 @@ static ssize_t netconsole_target_attr_store(struct config_item *item,
 	struct netconsole_target_attr *na =
 		container_of(attr, struct netconsole_target_attr, attr);
 
-	mutex_lock(&nt->mutex);
+	mutex_lock(&dynamic_netconsole_mutex);
 	if (na->store)
 		ret = na->store(nt, buf, count);
-	mutex_unlock(&nt->mutex);
+	mutex_unlock(&dynamic_netconsole_mutex);
 
 	return ret;
 }
@@ -604,7 +603,6 @@ static struct config_item *make_netconsole_target(struct config_group *group,
 	strlcpy(nt->np.dev_name, "eth0", IFNAMSIZ);
 	nt->np.local_port = 6665;
 	nt->np.remote_port = 6666;
-	mutex_init(&nt->mutex);
 	eth_broadcast_addr(nt->np.remote_mac);
 
 	/* Initialize the config_item member */
-- 
2.1.0

[PATCH 4/4] netconsole: implement extended console support

[Tejun Heo]

printk logbuf keeps various metadata and optional key=value dictionary
for structured messages, both of which are stripped when messages are
handed to regular console drivers.

It can be useful to have this metadata and dictionary available to
netconsole consumers.  This obviously makes logging via netconsole
more complete and the sequence number in particular is useful in
environments where messages may be lost or reordered in transit -
e.g. when netconsole is used to collect messages in a large cluster
where packets may have to travel congested hops to reach the
aggregator.  The lost and reordered messages can easily be identified
and handled accordingly using the sequence numbers.

printk recently added extended console support which can be selected
by setting CON_EXTENDED flag.  From console driver side, not much
changes.  The only difference is that the text passed to the write
callback is formatted the same way as /dev/kmsg.

This patch implements extended console support for netconsole which
can be enabled by either prepending "+" to a netconsole boot param
entry or echoing 1 to "extended" file in configfs.  When enabled,
netconsole transmits extended log messages with headers identical to
/dev/kmsg output.

There's one complication due to message fragments.  netconsole limits
the maximum message size to 1k and messages longer than that are split
into multiple fragments.  As all extended console messages should
carry matching headers and be uniquely identifiable, each extended
message fragment carries full copy of the metadata and an extra header
field to identify the specific fragment.  The optional header is of
the form "ncfrag=OFF/LEN" where OFF is the byte offset into the
message body and LEN is the total length.

To avoid unnecessarily making printk format extended messages,
Extended netconsole is registered with printk when the first extended
netconsole is configured.

v4: send_ext_msg_udp() restructured.

v3: Tweaked documentation to make clarify that the example assumes a
    lot smaller chunk size.  Updated to apply on top of spurious
    target get/put removal in write_msg().

v2: Dropped dynamic unregistration of extended console driver, which
    added complexity while not being too beneficial given that most
    netconsole configurations are static.  ncfrag updated to use just
    byte offset and message length.

Signed-off-by: Tejun Heo <tj@kernel.org>
Cc: Tetsuo Handa <penguin-kernel@I-love.SAKURA.ne.jp>
Cc: David Miller <davem@davemloft.net>
---
 Documentation/networking/netconsole.txt |  35 +++++++-
 drivers/net/netconsole.c                | 141 +++++++++++++++++++++++++++++++-
 2 files changed, 173 insertions(+), 3 deletions(-)

diff --git a/Documentation/networking/netconsole.txt b/Documentation/networking/netconsole.txt
index a5d574a..30409a3 100644
--- a/Documentation/networking/netconsole.txt
+++ b/Documentation/networking/netconsole.txt
@@ -2,6 +2,7 @@
 started by Ingo Molnar <mingo@redhat.com>, 2001.09.17
 2.6 port and netpoll api by Matt Mackall <mpm@selenic.com>, Sep 9 2003
 IPv6 support by Cong Wang <xiyou.wangcong@gmail.com>, Jan 1 2013
+Extended console support by Tejun Heo <tj@kernel.org>, May 1 2015
 
 Please send bug reports to Matt Mackall <mpm@selenic.com>
 Satyam Sharma <satyam.sharma@gmail.com>, and Cong Wang <xiyou.wangcong@gmail.com>
@@ -24,9 +25,10 @@ Sender and receiver configuration:
 It takes a string configuration parameter "netconsole" in the
 following format:
 
- netconsole=[src-port]@[src-ip]/[<dev>],[tgt-port]@<tgt-ip>/[tgt-macaddr]
+ netconsole=[+][src-port]@[src-ip]/[<dev>],[tgt-port]@<tgt-ip>/[tgt-macaddr]
 
    where
+        +             if present, enable extended console support
         src-port      source for UDP packets (defaults to 6665)
         src-ip        source IP to use (interface address)
         dev           network interface (eth0)
@@ -107,6 +109,7 @@ To remove a target:
 The interface exposes these parameters of a netconsole target to userspace:
 
 	enabled		Is this target currently enabled?	(read-write)
+	extended	Extended mode enabled			(read-write)
 	dev_name	Local network interface name		(read-write)
 	local_port	Source UDP port to use			(read-write)
 	remote_port	Remote agent's UDP port			(read-write)
@@ -132,6 +135,36 @@ You can also update the local interface dynamically. This is especially
 useful if you want to use interfaces that have newly come up (and may not
 have existed when netconsole was loaded / initialized).
 
+Extended console:
+=================
+
+If '+' is prefixed to the configuration line or "extended" config file
+is set to 1, extended console support is enabled. An example boot
+param follows.
+
+ linux netconsole=+4444@10.0.0.1/eth1,9353@10.0.0.2/12:34:56:78:9a:bc
+
+Log messages are transmitted with extended metadata header in the
+following format which is the same as /dev/kmsg.
+
+ <level>,<sequnum>,<timestamp>,<contflag>;<message text>
+
+Non printable characters in <message text> are escaped using "\xff"
+notation. If the message contains optional dictionary, verbatim
+newline is used as the delimeter.
+
+If a message doesn't fit in certain number of bytes (currently 1000),
+the message is split into multiple fragments by netconsole. These
+fragments are transmitted with "ncfrag" header field added.
+
+ ncfrag=<byte-offset>/<total-bytes>
+
+For example, assuming a lot smaller chunk size, a message "the first
+chunk, the 2nd chunk." may be split as follows.
+
+ 6,416,1758426,-,ncfrag=0/31;the first chunk,
+ 6,416,1758426,-,ncfrag=16/31; the 2nd chunk.
+
 Miscellaneous notes:
 ====================
 
diff --git a/drivers/net/netconsole.c b/drivers/net/netconsole.c
index 9b0c81e..731c9d3 100644
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -79,6 +79,12 @@ static LIST_HEAD(target_list);
 /* This needs to be a spinlock because write_msg() cannot sleep */
 static DEFINE_SPINLOCK(target_list_lock);
 
+/*
+ * Console driver for extended netconsoles.  Registered on the first use to
+ * avoid unnecessarily enabling ext message formatting.
+ */
+static struct console netconsole_ext;
+
 /**
  * struct netconsole_target - Represents a configured netconsole target.
  * @list:	Links this target into the target_list.
@@ -105,6 +111,7 @@ struct netconsole_target {
 	struct config_item	item;
 #endif
 	bool			enabled;
+	bool			extended;
 	struct netpoll		np;
 };
 
@@ -187,6 +194,11 @@ static struct netconsole_target *alloc_param_target(char *target_config)
 	nt->np.remote_port = 6666;
 	eth_broadcast_addr(nt->np.remote_mac);
 
+	if (*target_config == '+') {
+		nt->extended = true;
+		target_config++;
+	}
+
 	/* Parse parameters and setup netpoll */
 	err = netpoll_parse_options(&nt->np, target_config);
 	if (err)
@@ -257,6 +269,11 @@ static ssize_t show_enabled(struct netconsole_target *nt, char *buf)
 	return snprintf(buf, PAGE_SIZE, "%d\n", nt->enabled);
 }
 
+static ssize_t show_extended(struct netconsole_target *nt, char *buf)
+{
+	return snprintf(buf, PAGE_SIZE, "%d\n", nt->extended);
+}
+
 static ssize_t show_dev_name(struct netconsole_target *nt, char *buf)
 {
 	return snprintf(buf, PAGE_SIZE, "%s\n", nt->np.dev_name);
@@ -328,6 +345,11 @@ static ssize_t store_enabled(struct netconsole_target *nt,
 	}
 
 	if (enabled) {	/* true */
+		if (nt->extended && !(netconsole_ext.flags & CON_ENABLED)) {
+			netconsole_ext.flags |= CON_ENABLED;
+			register_console(&netconsole_ext);
+		}
+
 		/*
 		 * Skip netpoll_parse_options() -- all the attributes are
 		 * already configured via configfs. Just print them out.
@@ -355,6 +377,30 @@ static ssize_t store_enabled(struct netconsole_target *nt,
 	return strnlen(buf, count);
 }
 
+static ssize_t store_extended(struct netconsole_target *nt,
+			      const char *buf,
+			      size_t count)
+{
+	int extended;
+	int err;
+
+	if (nt->enabled) {
+		pr_err("target (%s) is enabled, disable to update parameters\n",
+		       config_item_name(&nt->item));
+		return -EINVAL;
+	}
+
+	err = kstrtoint(buf, 10, &extended);
+	if (err < 0)
+		return err;
+	if (extended < 0 || extended > 1)
+		return -EINVAL;
+
+	nt->extended = extended;
+
+	return strnlen(buf, count);
+}
+
 static ssize_t store_dev_name(struct netconsole_target *nt,
 			      const char *buf,
 			      size_t count)
@@ -507,6 +553,7 @@ static struct netconsole_target_attr netconsole_target_##_name =	\
 	__CONFIGFS_ATTR(_name, S_IRUGO | S_IWUSR, show_##_name, store_##_name)
 
 NETCONSOLE_TARGET_ATTR_RW(enabled);
+NETCONSOLE_TARGET_ATTR_RW(extended);
 NETCONSOLE_TARGET_ATTR_RW(dev_name);
 NETCONSOLE_TARGET_ATTR_RW(local_port);
 NETCONSOLE_TARGET_ATTR_RW(remote_port);
@@ -517,6 +564,7 @@ NETCONSOLE_TARGET_ATTR_RW(remote_mac);
 
 static struct configfs_attribute *netconsole_target_attrs[] = {
 	&netconsole_target_enabled.attr,
+	&netconsole_target_extended.attr,
 	&netconsole_target_dev_name.attr,
 	&netconsole_target_local_port.attr,
 	&netconsole_target_remote_port.attr,
@@ -727,6 +775,82 @@ static struct notifier_block netconsole_netdev_notifier = {
 	.notifier_call  = netconsole_netdev_event,
 };
 
+/**
+ * send_ext_msg_udp - send extended log message to target
+ * @nt: target to send message to
+ * @msg: extended log message to send
+ * @msg_len: length of message
+ *
+ * Transfer extended log @msg to @nt.  If @msg is longer than
+ * MAX_PRINT_CHUNK, it'll be split and transmitted in multiple chunks with
+ * ncfrag header field added to identify them.
+ */
+static void send_ext_msg_udp(struct netconsole_target *nt, const char *msg,
+			     int msg_len)
+{
+	static char buf[MAX_PRINT_CHUNK];
+	const char *header, *body;
+	int offset = 0;
+	int header_len, body_len;
+
+	if (msg_len <= MAX_PRINT_CHUNK) {
+		netpoll_send_udp(&nt->np, msg, msg_len);
+		return;
+	}
+
+	/* need to insert extra header fields, detect header and body */
+	header = msg;
+	body = memchr(msg, ';', msg_len);
+	if (WARN_ON_ONCE(!body))
+		return;
+
+	header_len = body - header;
+	body_len = msg_len - header_len - 1;
+	body++;
+
+	/*
+	 * Transfer multiple chunks with the following extra header.
+	 * "ncfrag=<byte-offset>/<total-bytes>"
+	 */
+	memcpy(buf, header, header_len);
+
+	while (offset < body_len) {
+		int this_header = header_len;
+		int this_chunk;
+
+		this_header += scnprintf(buf + this_header,
+					 sizeof(buf) - this_header,
+					 ",ncfrag=%d/%d;", offset, body_len);
+
+		this_chunk = min(body_len - offset,
+				 MAX_PRINT_CHUNK - this_header);
+		if (WARN_ON_ONCE(this_chunk <= 0))
+			return;
+
+		memcpy(buf + this_header, body + offset, this_chunk);
+
+		netpoll_send_udp(&nt->np, buf, this_header + this_chunk);
+
+		offset += this_chunk;
+	}
+}
+
+static void write_ext_msg(struct console *con, const char *msg,
+			  unsigned int len)
+{
+	struct netconsole_target *nt;
+	unsigned long flags;
+
+	if ((oops_only && !oops_in_progress) || list_empty(&target_list))
+		return;
+
+	spin_lock_irqsave(&target_list_lock, flags);
+	list_for_each_entry(nt, &target_list, list)
+		if (nt->extended && nt->enabled && netif_running(nt->np.dev))
+			send_ext_msg_udp(nt, msg, len);
+	spin_unlock_irqrestore(&target_list_lock, flags);
+}
+
 static void write_msg(struct console *con, const char *msg, unsigned int len)
 {
 	int frag, left;
@@ -742,7 +866,7 @@ static void write_msg(struct console *con, const char *msg, unsigned int len)
 
 	spin_lock_irqsave(&target_list_lock, flags);
 	list_for_each_entry(nt, &target_list, list) {
-		if (nt->enabled && netif_running(nt->np.dev)) {
+		if (!nt->extended && nt->enabled && netif_running(nt->np.dev)) {
 			/*
 			 * We nest this inside the for-each-target loop above
 			 * so that we're able to get as much logging out to
@@ -761,6 +885,12 @@ static void write_msg(struct console *con, const char *msg, unsigned int len)
 	spin_unlock_irqrestore(&target_list_lock, flags);
 }
 
+static struct console netconsole_ext = {
+	.name	= "netcon_ext",
+	.flags	= CON_EXTENDED,	/* starts disabled, registered on first use */
+	.write	= write_ext_msg,
+};
+
 static struct console netconsole = {
 	.name	= "netcon",
 	.flags	= CON_ENABLED,
@@ -783,7 +913,11 @@ static int __init init_netconsole(void)
 				goto fail;
 			}
 			/* Dump existing printks when we register */
-			netconsole.flags |= CON_PRINTBUFFER;
+			if (nt->extended)
+				netconsole_ext.flags |= CON_PRINTBUFFER |
+							CON_ENABLED;
+			else
+				netconsole.flags |= CON_PRINTBUFFER;
 
 			spin_lock_irqsave(&target_list_lock, flags);
 			list_add(&nt->list, &target_list);
@@ -799,6 +933,8 @@ static int __init init_netconsole(void)
 	if (err)
 		goto undonotifier;
 
+	if (netconsole_ext.flags & CON_ENABLED)
+		register_console(&netconsole_ext);
 	register_console(&netconsole);
 	pr_info("network logging started\n");
 
@@ -827,6 +963,7 @@ static void __exit cleanup_netconsole(void)
 {
 	struct netconsole_target *nt, *tmp;
 
+	unregister_console(&netconsole_ext);
 	unregister_console(&netconsole);
 	dynamic_netconsole_exit();
 	unregister_netdevice_notifier(&netconsole_netdev_notifier);
-- 
2.1.0

Re: [PATCH 4/4] netconsole: implement extended console support

[David Miller]

From: Tejun Heo <tj@kernel.org>
Date: Mon, 11 May 2015 12:41:34 -0400

> +	/* need to insert extra header fields, detect header and body */
> +	header = msg;
> +	body = memchr(msg, ';', msg_len);
> +	if (WARN_ON_ONCE(!body))
> +		return;
> +
> +	header_len = body - header;
> +	body_len = msg_len - header_len - 1;
> +	body++;
> +
> +	/*
> +	 * Transfer multiple chunks with the following extra header.
> +	 * "ncfrag=<byte-offset>/<total-bytes>"
> +	 */
> +	memcpy(buf, header, header_len);
> +
> +	while (offset < body_len) {
> +		int this_header = header_len;
> +		int this_chunk;
> +
> +		this_header += scnprintf(buf + this_header,
> +					 sizeof(buf) - this_header,
> +					 ",ncfrag=%d/%d;", offset, body_len);
> +

Hmmm, do you intend ncfrag= to be amongst the other metadata in the first
fragment?  The way I read the code above it's going to be:

	<level>,<sequnum>,<timestamp>,<contflag>;,ncfrag=x/y;

If you intend to keep all the metadata, including the ncfrag bit,
together, you probably need to clip off the initial semicolon, so
that it looks like:

	<level>,<sequnum>,<timestamp>,<contflag>,ncfrag=x/y;

Re: [PATCH 4/4] netconsole: implement extended console support

[Tejun Heo]

Hello,

On Mon, May 11, 2015 at 01:23:39PM -0400, David Miller wrote:
> From: Tejun Heo <tj@kernel.org>
> Date: Mon, 11 May 2015 12:41:34 -0400
> 
> > +	/* need to insert extra header fields, detect header and body */
> > +	header = msg;
> > +	body = memchr(msg, ';', msg_len);
> > +	if (WARN_ON_ONCE(!body))
> > +		return;
> > +
> > +	header_len = body - header;
> > +	body_len = msg_len - header_len - 1;
> > +	body++;
> > +
> > +	/*
> > +	 * Transfer multiple chunks with the following extra header.
> > +	 * "ncfrag=<byte-offset>/<total-bytes>"
> > +	 */
> > +	memcpy(buf, header, header_len);
> > +
> > +	while (offset < body_len) {
> > +		int this_header = header_len;
> > +		int this_chunk;
> > +
> > +		this_header += scnprintf(buf + this_header,
> > +					 sizeof(buf) - this_header,
> > +					 ",ncfrag=%d/%d;", offset, body_len);
> > +
> 
> Hmmm, do you intend ncfrag= to be amongst the other metadata in the first
> fragment?  The way I read the code above it's going to be:
> 
> 	<level>,<sequnum>,<timestamp>,<contflag>;,ncfrag=x/y;
> 
> If you intend to keep all the metadata, including the ncfrag bit,
> together, you probably need to clip off the initial semicolon, so
> that it looks like:
> 
> 	<level>,<sequnum>,<timestamp>,<contflag>,ncfrag=x/y;

The current code does produce the latter outcome.

	header = msg;
	body = memchr(msg, ';', msg_len);
	if (WARN_ON_ONCE(!body))
		return;

	header_len = body - header;
	body_len = msg_len - header_len - 1;
	body++;

@body points to ';' after memchr(), so @header_len doesn't include
';'.  @body is incremented after calculating @header_len.

Thanks.

-- 
tejun

Re: [PATCH 4/4] netconsole: implement extended console support

[David Miller]

From: Tejun Heo <tj@kernel.org>
Date: Mon, 11 May 2015 16:37:45 -0400

> The current code does produce the latter outcome.
> 
> 	header = msg;
> 	body = memchr(msg, ';', msg_len);
> 	if (WARN_ON_ONCE(!body))
> 		return;
> 
> 	header_len = body - header;
> 	body_len = msg_len - header_len - 1;
> 	body++;
> 
> @body points to ';' after memchr(), so @header_len doesn't include
> ';'.  @body is incremented after calculating @header_len.

Ok, thanks for explaining, it is clear to me now.

Second question, is there an upper bound on this header size?

Because if there is, it seems to me that there is no reason why we
can't just avoid the fragmentation support altogether.

The current code limits to 1000 bytes, and that limit seems arbitrary.
Obviously this code is meant to work on interfaces with an ethernet
MTU or larger.  So you could bump the limit enough to accomodate the
new header size, yet still be within the real constraints.

What do you think?

Re: [PATCH 4/4] netconsole: implement extended console support

[Tejun Heo]

Hello, David.

On Tue, May 12, 2015 at 07:23:22PM -0400, David Miller wrote:
> Second question, is there an upper bound on this header size?
> Because if there is, it seems to me that there is no reason why we
> can't just avoid the fragmentation support altogether.
>
> The current code limits to 1000 bytes, and that limit seems arbitrary.
> Obviously this code is meant to work on interfaces with an ethernet
> MTU or larger.  So you could bump the limit enough to accomodate the
> new header size, yet still be within the real constraints.
> 
> What do you think?

Yeah, if we can bump the tx size enough to accomodate all messages,
it'd be great.  It can get fairly large tho.  The absolute maximum
right now is 8k.  While regular prink message bodies are capped
slightly below 1k, the dictionary printed through vprintk_emit()
doesn't have such length limit.  Another factor is that non-printables
are escaped using \xXX and vprintk_emit() is supposed to be useable
with transmitting binary data (like low level device error
descriptors) although I'm not sure anybody is doing that yet.

Thanks.

-- 
tejun

Re: [PATCH 4/4] netconsole: implement extended console support

[David Miller]

From: Tejun Heo <tj@kernel.org>
Date: Wed, 13 May 2015 11:46:20 -0400

> Hello, David.
> 
> On Tue, May 12, 2015 at 07:23:22PM -0400, David Miller wrote:
>> Second question, is there an upper bound on this header size?
>> Because if there is, it seems to me that there is no reason why we
>> can't just avoid the fragmentation support altogether.
>>
>> The current code limits to 1000 bytes, and that limit seems arbitrary.
>> Obviously this code is meant to work on interfaces with an ethernet
>> MTU or larger.  So you could bump the limit enough to accomodate the
>> new header size, yet still be within the real constraints.
>> 
>> What do you think?
> 
> Yeah, if we can bump the tx size enough to accomodate all messages,
> it'd be great.  It can get fairly large tho.  The absolute maximum
> right now is 8k.  While regular prink message bodies are capped
> slightly below 1k, the dictionary printed through vprintk_emit()
> doesn't have such length limit.  Another factor is that non-printables
> are escaped using \xXX and vprintk_emit() is supposed to be useable
> with transmitting binary data (like low level device error
> descriptors) although I'm not sure anybody is doing that yet.

Yeah, 8K is too much to handle, oh well.

Ok I'm fine with this series from my end, and you can merge this
wherever the extended console support bits go.

Signed-off-by: David S. Miller <davem@davemloft.net>

Thanks.

Re: [PATCH 4/4] netconsole: implement extended console support

[Tejun Heo]

Hello, David.

On Thu, May 14, 2015 at 12:39:17AM -0400, David Miller wrote:
> Ok I'm fine with this series from my end, and you can merge this
> wherever the extended console support bits go.
> 
> Signed-off-by: David S. Miller <davem@davemloft.net>

Awesome, thanks.  Andrew, I think it'd be best to route this with the
extended printk patchset through -mm.  I'll repost the combined
patchset with the suggested comment added.

Thanks.

-- 
tejun

Re: [PATCH 4/4] netconsole: implement extended console support

[Andrew Morton]

On Mon, 11 May 2015 12:41:34 -0400 Tejun Heo <tj@kernel.org> wrote:

> printk logbuf keeps various metadata and optional key=value dictionary
> for structured messages, both of which are stripped when messages are
> handed to regular console drivers.
> 
> It can be useful to have this metadata and dictionary available to
> netconsole consumers.  This obviously makes logging via netconsole
> more complete and the sequence number in particular is useful in
> environments where messages may be lost or reordered in transit -
> e.g. when netconsole is used to collect messages in a large cluster
> where packets may have to travel congested hops to reach the
> aggregator.  The lost and reordered messages can easily be identified
> and handled accordingly using the sequence numbers.
> 
> printk recently added extended console support which can be selected
> by setting CON_EXTENDED flag.

There's no such thing as CON_EXTENDED.  Not sure what this is trying to
say.

>  From console driver side, not much
> changes.  The only difference is that the text passed to the write
> callback is formatted the same way as /dev/kmsg.
> 
> This patch implements extended console support for netconsole which
> can be enabled by either prepending "+" to a netconsole boot param
> entry or echoing 1 to "extended" file in configfs.  When enabled,
> netconsole transmits extended log messages with headers identical to
> /dev/kmsg output.
> 
> There's one complication due to message fragments.  netconsole limits
> the maximum message size to 1k and messages longer than that are split
> into multiple fragments.  As all extended console messages should
> carry matching headers and be uniquely identifiable, each extended
> message fragment carries full copy of the metadata and an extra header
> field to identify the specific fragment.  The optional header is of
> the form "ncfrag=OFF/LEN" where OFF is the byte offset into the
> message body and LEN is the total length.
> 
> To avoid unnecessarily making printk format extended messages,
> Extended netconsole is registered with printk when the first extended
> netconsole is configured.
>
> ...
>
> +static ssize_t store_extended(struct netconsole_target *nt,
> +			      const char *buf,
> +			      size_t count)
> +{
> +	int extended;
> +	int err;
> +
> +	if (nt->enabled) {
> +		pr_err("target (%s) is enabled, disable to update parameters\n",
> +		       config_item_name(&nt->item));
> +		return -EINVAL;
> +	}

What's the reason for the above?

It's unclear (to me, at least ;)) what "disable" means?  Specifically
what steps must the operator take to successfully perform this
operation?  A sentence detailing those steps in netconsole.txt would be
nice.

> +	err = kstrtoint(buf, 10, &extended);
> +	if (err < 0)
> +		return err;
> +	if (extended < 0 || extended > 1)
> +		return -EINVAL;
> +
> +	nt->extended = extended;
> +
> +	return strnlen(buf, count);
> +}
> +
>
> ...
>
> +static void send_ext_msg_udp(struct netconsole_target *nt, const char *msg,
> +			     int msg_len)
> +{
> +	static char buf[MAX_PRINT_CHUNK];
> +	const char *header, *body;
> +	int offset = 0;
> +	int header_len, body_len;
> +
> +	if (msg_len <= MAX_PRINT_CHUNK) {
> +		netpoll_send_udp(&nt->np, msg, msg_len);
> +		return;
> +	}
> +
> +	/* need to insert extra header fields, detect header and body */
> +	header = msg;
> +	body = memchr(msg, ';', msg_len);
> +	if (WARN_ON_ONCE(!body))
> +		return;
> +
> +	header_len = body - header;
> +	body_len = msg_len - header_len - 1;
> +	body++;
> +
> +	/*
> +	 * Transfer multiple chunks with the following extra header.
> +	 * "ncfrag=<byte-offset>/<total-bytes>"
> +	 */
> +	memcpy(buf, header, header_len);
> +
> +	while (offset < body_len) {
> +		int this_header = header_len;
> +		int this_chunk;
> +
> +		this_header += scnprintf(buf + this_header,
> +					 sizeof(buf) - this_header,
> +					 ",ncfrag=%d/%d;", offset, body_len);
> +
> +		this_chunk = min(body_len - offset,
> +				 MAX_PRINT_CHUNK - this_header);
> +		if (WARN_ON_ONCE(this_chunk <= 0))
> +			return;
> +
> +		memcpy(buf + this_header, body + offset, this_chunk);
> +
> +		netpoll_send_udp(&nt->np, buf, this_header + this_chunk);
> +
> +		offset += this_chunk;
> +	}

What protects `buf'?  console_sem, I assume?

-	static char buf[MAX_PRINT_CHUNK];
+	static char buf[MAX_PRINT_CHUNK];	/* Protected by console_sem */

wouldn't hurt.

> +}
> +
> +static void write_ext_msg(struct console *con, const char *msg,


I've forgotten what's happening with this patchset.  There were a few
design-level issues raised against an earlier version.  What were those
and how have they been addressed?

Re: [PATCH 4/4] netconsole: implement extended console support

[David Miller]

From: Andrew Morton <akpm@linux-foundation.org>
Date: Tue, 12 May 2015 16:36:02 -0700

> There's no such thing as CON_EXTENDED.  Not sure what this is trying to
> say.

Please read the patch series that, in the title posting of this series,
Tejun explains this series depends upon.

Re: [PATCH 4/4] netconsole: implement extended console support

[Tejun Heo]

Hello, Andrew.

On Tue, May 12, 2015 at 04:36:02PM -0700, Andrew Morton wrote:
> > printk recently added extended console support which can be selected
> > by setting CON_EXTENDED flag.
> 
> There's no such thing as CON_EXTENDED.  Not sure what this is trying to
> say.

Yeah, I ended up splitting the original patchset into two.  One
implementing CON_EXTENDED and this set updating netconsole to use it.
The patchset head message contains the link to the prerequisite
patchset.

 http://article.gmane.org/gmane.linux.kernel/1940567

> > +static ssize_t store_extended(struct netconsole_target *nt,
> > +			      const char *buf,
> > +			      size_t count)
> > +{
> > +	int extended;
> > +	int err;
> > +
> > +	if (nt->enabled) {
> > +		pr_err("target (%s) is enabled, disable to update parameters\n",
> > +		       config_item_name(&nt->item));
> > +		return -EINVAL;
> > +	}
> 
> What's the reason for the above?
> 
> It's unclear (to me, at least ;)) what "disable" means?  Specifically
> what steps must the operator take to successfully perform this
> operation?  A sentence detailing those steps in netconsole.txt would be
> nice.

So, there are configfs dynamic netconsole targets which is created by
mkdir, configured through interface files there and enabled by echoing
1 to the enable file.  The parameters can't be changed while the
target is enabled.  This is the standard warning used for all other
knobs and I think what the warning message means is pretty clear given
the context.  Right?

> What protects `buf'?  console_sem, I assume?
> 
> -	static char buf[MAX_PRINT_CHUNK];
> +	static char buf[MAX_PRINT_CHUNK];	/* Protected by console_sem */
> 
> wouldn't hurt.

Yeah, the whole send path is serialized by console_sem and
target_list_lock.  I'll add the comment.

> > +}
> > +
> > +static void write_ext_msg(struct console *con, const char *msg,
> 
> 
> I've forgotten what's happening with this patchset.  There were a few
> design-level issues raised against an earlier version.  What were those
> and how have they been addressed?

The retransmission part was the most contentious point and Dave
pointed out that there isn't much to be gained by doing that from the
kernel side, so that part got dropped from the patchset and will
become a separate userland program, so the only remaining parts are
support for sending out extended messages from netconsole which
shouldn't be too controversial.

Thanks.

-- 
tejun