Re: [PATCH 04/16] printk: implement support for extended console drivers
Hello, Petr. On Tue, Apr 28, 2015 at 11:42:44AM +0200, Petr Mladek wrote: Note that cont buffer is only a memory optimization. You could put every text snippet into the ring buffer and console immediately. You need to set LOG_CONT instead of LOG_NEWLINE flag. This is already used when the line is too long for the cont buffer or when there is printed a message from another cpu in the middle of a continuing message. Yeah, hmmm, I wonder whether the right solution here is to bypass cont buffer if ext_console is present. This would use a bit more memory and hurt users catting /proc/kmsg but everyone else should be able to get the same result and things get a lot simpler on both sending and receiving sides. What do you think? Thanks. -- tejun -- To unsubscribe from this list: send the line unsubscribe netdev in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 04/16] printk: implement support for extended console drivers
On Tue 2015-04-28 10:10:14, Tejun Heo wrote: Hello, Petr. On Tue, Apr 28, 2015 at 11:42:44AM +0200, Petr Mladek wrote: Note that cont buffer is only a memory optimization. You could put every text snippet into the ring buffer and console immediately. You need to set LOG_CONT instead of LOG_NEWLINE flag. This is already used when the line is too long for the cont buffer or when there is printed a message from another cpu in the middle of a continuing message. Yeah, hmmm, I wonder whether the right solution here is to bypass cont buffer if ext_console is present. This would use a bit more memory and hurt users catting /proc/kmsg but everyone else should be able to get the same result and things get a lot simpler on both sending and receiving sides. What do you think? I would personally give it a try. If it works well, we might eventually get rid of the cont buffer completely and make the printk code a bit easier again. Best Regards, Petr -- To unsubscribe from this list: send the line unsubscribe netdev in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 04/16] printk: implement support for extended console drivers
On Mon 2015-04-27 17:09:22, Tejun Heo wrote: Hello, Petr. Sorry about the delay. np On Mon, Apr 20, 2015 at 05:43:07PM +0200, Petr Mladek wrote: I was afraid that there might be a potential buffer overflow because the user-provided dict need not be limited by '\0'. But LOG_DICT_META is used only with the internal data that are safe. We might document this as well. BTW: Do you want to print the internal dict when calling this function in devkmsg_read()? No, plesae see below. I see, it is not printed there because the dict_len is zero for the internal info. + scnprintf(fragid_buf, sizeof(fragid_buf), + ,fragid=%llu, fragid); + return scnprintf(buf, size, %u,%llu,%llu,%c%s;, + (msg-facility 3) | msg-level, seq, ts_usec, cont, + fragid_buf); The above comment suggests that cont and fragid_buf are delimited by a comma but it is not used here. Is it by intention. Hmm... how is it not? The fragid printf has preceding comma. I see it now. + dict_len = scnprintf(dict_buf, sizeof(dict_buf), FRAGID=%llu, + cont.fragid); + log_store(cont.facility, cont.level, + flags | LOG_NOCONS | LOG_DICT_META, + cont.ts_nsec, dict_buf, dict_len, cont.buf, cont.len); I wonder if it would make sense to restart fragid here. Another line will get distinguished by seqnum. That'd assume that there can only ever be a single continuation buffer, which is true now but it's possible that we may want to make it per-cpu in the future. I am not sure if any more complications will get accepted. Anyway, each CPU should print an independent message. Therefore each pre-CPU cont buffer would be printed on separate line and would get another seqnum. We could have per-CPU fragid counter. Sigh, the whole mess is caused by the fact that we could not extend struct printk_log easily. It would be much better if we could put fragid there. I finally understand why you need to reuse the dict. I've been thinking about it and using dict area for internal metadata is indeed quite messy. I think a better way to do it is declaring dict_len as a union w/ fragid. This'd limit the fragid to 16bit but that should be more than enough and we can do away with the string formatting and reading back. Nice idea. I like it much more. Another solution would be to allow to disable the continuous buffer via some boot option or /sys/kernel/debug entry if you want to debug such a problem and have problem with the partial flushing. It isn't really about debugging partial flushing itself but rather always being able to push out the messages before the printk invocation finishes. I did not mean cont-buffer debugging. I meant debugging with netconsole. Note that cont buffer is only a memory optimization. You could put every text snippet into the ring buffer and console immediately. You need to set LOG_CONT instead of LOG_NEWLINE flag. This is already used when the line is too long for the cont buffer or when there is printed a message from another cpu in the middle of a continuing message. Best Regards, Petr -- To unsubscribe from this list: send the line unsubscribe netdev in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 04/16] printk: implement support for extended console drivers
Hello, Petr. Sorry about the delay. On Mon, Apr 20, 2015 at 05:43:07PM +0200, Petr Mladek wrote: ... * Extended message formatting for console drivers is enabled iff there s/iff/if/ if and only if I was afraid that there might be a potential buffer overflow because the user-provided dict need not be limited by '\0'. But LOG_DICT_META is used only with the internal data that are safe. We might document this as well. BTW: Do you want to print the internal dict when calling this function in devkmsg_read()? No, plesae see below. + scnprintf(fragid_buf, sizeof(fragid_buf), + ,fragid=%llu, fragid); + return scnprintf(buf, size, %u,%llu,%llu,%c%s;, +(msg-facility 3) | msg-level, seq, ts_usec, cont, +fragid_buf); The above comment suggests that cont and fragid_buf are delimited by a comma but it is not used here. Is it by intention. Hmm... how is it not? The fragid printf has preceding comma. + dict_len = scnprintf(dict_buf, sizeof(dict_buf), FRAGID=%llu, +cont.fragid); + log_store(cont.facility, cont.level, + flags | LOG_NOCONS | LOG_DICT_META, + cont.ts_nsec, dict_buf, dict_len, cont.buf, cont.len); I wonder if it would make sense to restart fragid here. Another line will get distinguished by seqnum. That'd assume that there can only ever be a single continuation buffer, which is true now but it's possible that we may want to make it per-cpu in the future. Sigh, the whole mess is caused by the fact that we could not extend struct printk_log easily. It would be much better if we could put fragid there. I finally understand why you need to reuse the dict. I've been thinking about it and using dict area for internal metadata is indeed quite messy. I think a better way to do it is declaring dict_len as a union w/ fragid. This'd limit the fragid to 16bit but that should be more than enough and we can do away with the string formatting and reading back. Another solution would be to allow to disable the continuous buffer via some boot option or /sys/kernel/debug entry if you want to debug such a problem and have problem with the partial flushing. It isn't really about debugging partial flushing itself but rather always being able to push out the messages before the printk invocation finishes. Thanks. -- tejun -- To unsubscribe from this list: send the line unsubscribe netdev in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 04/16] printk: implement support for extended console drivers
On Mon 2015-04-20 17:43:07, Petr Mladek wrote: On Thu 2015-04-16 19:03:41, Tejun Heo wrote: printk log_buf keeps various metadata for each message including its sequence number and timestamp. The metadata is currently available only through /dev/kmsg and stripped out before passed onto console drivers. We want this metadata to be available to console drivers too. Immediately, it's to implement reliable netconsole but may be useful for other console devices too. This patch implements support for extended console drivers. Consoles can indicate that they process extended messages by setting the new CON_EXTENDED flag and they'll fed messages formatted the same way as /dev/kmsg output as follows. level,sequnum,timestamp,contflag;message text One special case is fragments. Message fragments are output immediately to consoles to avoid losing them in case of crashes. For normal consoles, this is handled by later suppressing the assembled result and /dev/kmsg only shows fully assembled message; however, extended consoles would need both the fragments, to avoid losing message in case of a crash, and the assembled result, to tell how the fragments are assembled and which sequence number got assigned to it. To help matching up the fragments with the resulting message, fragments are emitted in the following format. level,-,timestamp,-,fragid=fragid;message fragment And later when the assembly is complete, the following is transmitted, level,sequnum,timestamp,contflag,fragid=fragid;message text * Extended message formatting for console drivers is enabled iff there [...] Sigh, it adds another twist into the already complex printk code. Another solution would be to allow to disable the continuous buffer via some boot option or /sys/kernel/debug entry if you want to debug such a problem and have problem with the partial flushing. Hmm, I wonder what are the typical values passed via dict and if we need to handle this entry such a special way. It would make sense to always print dict values to the ext consoles and handle this as a yet another normal dict value. It would allow us to remove some hacks at least. Another solution would be to always flush cont buffer when it is being printed to the console. Then the messages might by distinguished by the seqnum and fragid won't be needed. The question is if the cont buffer will still have any affect after this change. Best Regards, Petr -- To unsubscribe from this list: send the line unsubscribe netdev in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 04/16] printk: implement support for extended console drivers
On Thu 2015-04-16 19:03:41, Tejun Heo wrote:
printk log_buf keeps various metadata for each message including its
sequence number and timestamp. The metadata is currently available
only through /dev/kmsg and stripped out before passed onto console
drivers. We want this metadata to be available to console drivers
too. Immediately, it's to implement reliable netconsole but may be
useful for other console devices too.
This patch implements support for extended console drivers. Consoles
can indicate that they process extended messages by setting the new
CON_EXTENDED flag and they'll fed messages formatted the same way as
/dev/kmsg output as follows.
level,sequnum,timestamp,contflag;message text
One special case is fragments. Message fragments are output
immediately to consoles to avoid losing them in case of crashes. For
normal consoles, this is handled by later suppressing the assembled
result and /dev/kmsg only shows fully assembled message; however,
extended consoles would need both the fragments, to avoid losing
message in case of a crash, and the assembled result, to tell how the
fragments are assembled and which sequence number got assigned to it.
To help matching up the fragments with the resulting message,
fragments are emitted in the following format.
level,-,timestamp,-,fragid=fragid;message fragment
And later when the assembly is complete, the following is transmitted,
level,sequnum,timestamp,contflag,fragid=fragid;message text
* Extended message formatting for console drivers is enabled iff there
^^^
s/iff/if/
are registered extended consoles.
* Comment describing extended message formats updated to help
distinguishing variable with verbatim terms.
Signed-off-by: Tejun Heo t...@kernel.org
Cc: Kay Sievers k...@vrfy.org
Cc: Petr Mladek pmla...@suse.cz
---
include/linux/console.h | 1 +
kernel/printk/printk.c | 141
+---
2 files changed, 123 insertions(+), 19 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index 7571a16..04bbd09 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -115,6 +115,7 @@ static inline int con_debug_leave(void)
#define CON_BOOT (8)
#define CON_ANYTIME (16) /* Safe to call when cpu is offline */
#define CON_BRL (32) /* Used for a braille device */
+#define CON_EXTENDED (64) /* Use the extended output format a la /dev/kmsg */
struct console {
charname[16];
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 0175c46..349a37b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -84,6 +84,8 @@ static struct lockdep_map console_lock_dep_map = {
};
#endif
+static int nr_ext_console_drivers;
+
/*
* Helper macros to handle lockdep when locking/unlocking console_sem. We use
* macros instead of functions so that _RET_IP_ contains useful information.
@@ -195,14 +197,28 @@ static int console_may_schedule;
* need to be changed in the future, when the requirements change.
*
* /dev/kmsg exports the structured data in the following line format:
- * level,sequnum,timestamp;message text\n
+ * level,sequnum,timestamp,contflag;message text\n
*
* The optional key/value pairs are attached as continuation lines starting
* with a space character and terminated by a newline. All possible
* non-prinatable characters are escaped in the \xff notation.
*
* Users of the export format should ignore possible additional values
- * separated by ',', and find the message after the ';' character.
+ * separated by ',', and find the message after the ';' character. All
+ * optional header fields should have the form key=value.
+ *
+ * For consoles with CON_EXTENDED set, a message formatted like the
+ * following may also be printed. This is a continuation fragment which are
+ * being assembled and will be re-transmitted with a normal header once
+ * assembly finishes. The fragments are sent out immediately to avoid
+ * losing them over a crash.
+ * level,-,timestamp,-,fragid=fragid;message fragment\n
+ *
+ * On completion of assembly, the following is transmitted.
+ * level,sequnum,timestamp,contflag,fragid=fragid;message
text\n
+ *
+ * Extended consoles should identify and handle duplicates by matching the
+ * fragids of the fragments and assembled messages.
*/
enum log_flags {
@@ -210,6 +226,7 @@ enum log_flags {
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
+ LOG_DICT_META = 16, /* dict contains console meta information */
};
struct printk_log {
@@ -292,6 +309,12 @@ static char *log_dict(const struct printk_log *msg)
return (char *)msg +
[PATCH 04/16] printk: implement support for extended console drivers
printk log_buf keeps various metadata for each message including its
sequence number and timestamp. The metadata is currently available
only through /dev/kmsg and stripped out before passed onto console
drivers. We want this metadata to be available to console drivers
too. Immediately, it's to implement reliable netconsole but may be
useful for other console devices too.
This patch implements support for extended console drivers. Consoles
can indicate that they process extended messages by setting the new
CON_EXTENDED flag and they'll fed messages formatted the same way as
/dev/kmsg output as follows.
level,sequnum,timestamp,contflag;message text
One special case is fragments. Message fragments are output
immediately to consoles to avoid losing them in case of crashes. For
normal consoles, this is handled by later suppressing the assembled
result and /dev/kmsg only shows fully assembled message; however,
extended consoles would need both the fragments, to avoid losing
message in case of a crash, and the assembled result, to tell how the
fragments are assembled and which sequence number got assigned to it.
To help matching up the fragments with the resulting message,
fragments are emitted in the following format.
level,-,timestamp,-,fragid=fragid;message fragment
And later when the assembly is complete, the following is transmitted,
level,sequnum,timestamp,contflag,fragid=fragid;message text
* Extended message formatting for console drivers is enabled iff there
are registered extended consoles.
* Comment describing extended message formats updated to help
distinguishing variable with verbatim terms.
Signed-off-by: Tejun Heo t...@kernel.org
Cc: Kay Sievers k...@vrfy.org
Cc: Petr Mladek pmla...@suse.cz
---
include/linux/console.h | 1 +
kernel/printk/printk.c | 141 +---
2 files changed, 123 insertions(+), 19 deletions(-)
diff --git a/include/linux/console.h b/include/linux/console.h
index 7571a16..04bbd09 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -115,6 +115,7 @@ static inline int con_debug_leave(void)
#define CON_BOOT (8)
#define CON_ANYTIME(16) /* Safe to call when cpu is offline */
#define CON_BRL(32) /* Used for a braille device */
+#define CON_EXTENDED (64) /* Use the extended output format a la /dev/kmsg */
struct console {
charname[16];
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 0175c46..349a37b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -84,6 +84,8 @@ static struct lockdep_map console_lock_dep_map = {
};
#endif
+static int nr_ext_console_drivers;
+
/*
* Helper macros to handle lockdep when locking/unlocking console_sem. We use
* macros instead of functions so that _RET_IP_ contains useful information.
@@ -195,14 +197,28 @@ static int console_may_schedule;
* need to be changed in the future, when the requirements change.
*
* /dev/kmsg exports the structured data in the following line format:
- * level,sequnum,timestamp;message text\n
+ * level,sequnum,timestamp,contflag;message text\n
*
* The optional key/value pairs are attached as continuation lines starting
* with a space character and terminated by a newline. All possible
* non-prinatable characters are escaped in the \xff notation.
*
* Users of the export format should ignore possible additional values
- * separated by ',', and find the message after the ';' character.
+ * separated by ',', and find the message after the ';' character. All
+ * optional header fields should have the form key=value.
+ *
+ * For consoles with CON_EXTENDED set, a message formatted like the
+ * following may also be printed. This is a continuation fragment which are
+ * being assembled and will be re-transmitted with a normal header once
+ * assembly finishes. The fragments are sent out immediately to avoid
+ * losing them over a crash.
+ * level,-,timestamp,-,fragid=fragid;message fragment\n
+ *
+ * On completion of assembly, the following is transmitted.
+ * level,sequnum,timestamp,contflag,fragid=fragid;message
text\n
+ *
+ * Extended consoles should identify and handle duplicates by matching the
+ * fragids of the fragments and assembled messages.
*/
enum log_flags {
@@ -210,6 +226,7 @@ enum log_flags {
LOG_NEWLINE = 2,/* text ended with a newline */
LOG_PREFIX = 4,/* text started with a prefix */
LOG_CONT= 8,/* text is a fragment of a continuation line */
+ LOG_DICT_META = 16, /* dict contains console meta information */
};
struct printk_log {
@@ -292,6 +309,12 @@ static char *log_dict(const struct printk_log *msg)
return (char *)msg + sizeof(struct printk_log) + msg-text_len;
}
+/* if LOG_DICT_META is set, the dict buffer carries printk internal info */
+static size_t log_dict_len(const struct printk_log *msg)
+{
+ return (msg-flags
