From: Kay Sievers <[email protected]>
Subject: kmsg: export printk records to the /dev/kmsg interface
Support for multiple concurrent readers of /dev/kmsg, with read(),
seek(), poll() support. Output of message sequence numbers, to allow
userspace log consumers to reliably reconnect and reconstruct their
state at any given time. After open("/dev/kmsg"), read() always
returns *all* buffered records. If only future messages should be
read, SEEK_END can be used. In case records get overwritten while
/dev/kmsg is held open, or records get faster overwritten than they
are read, the next read() will return -EPIPE and the current reading
position gets updated to the next available record. The passed
sequence numbers allow the log consumer to calculate the amount of
lost messages.
[root@mop ~]# cat /dev/kmsg
5,0,0;Linux version 3.4.0-rc1+ (kay@mop) (gcc version 4.7.0 20120315 ...
6,159,423091;ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
7,160,424069;pci_root PNP0A03:00: host bridge window [io 0x0000-0x0cf7] (ignored)
SUBSYSTEM=acpi
DEVICE=+acpi:PNP0A03:00
6,339,5140900;NET: Registered protocol family 10
30,340,5690716;udevd[80]: starting version 181
6,341,6081421;FDC 0 is a S82078B
6,345,6154686;microcode: CPU0 sig=0x623, pf=0x0, revision=0x0
7,346,6156968;sr 1:0:0:0: Attached scsi CD-ROM sr0
SUBSYSTEM=scsi
DEVICE=+scsi:1:0:0:0
6,347,6289375;microcode: CPU1 sig=0x623, pf=0x0, revision=0x0
Cc: Karel Zak <[email protected]>
Tested-by: William Douglas <[email protected]>
Signed-off-by: Kay Sievers <[email protected]>
---
drivers/char/mem.c | 61 ---------
include/linux/printk.h | 2
kernel/printk.c | 313 +++++++++++++++++++++++++++++++++++++++++++++++++
3 files changed, 316 insertions(+), 60 deletions(-)
--- a/drivers/char/mem.c
+++ b/drivers/char/mem.c
@@ -807,65 +807,6 @@ static const struct file_operations oldm
};
#endif
-static ssize_t kmsg_writev(struct kiocb *iocb, const struct iovec *iv,
- unsigned long count, loff_t pos)
-{
- char *buf, *line;
- int i;
- int level = default_message_loglevel;
- int facility = 1; /* LOG_USER */
- size_t len = iov_length(iv, count);
- ssize_t ret = len;
-
- if (len > 1024)
- return -EINVAL;
- buf = kmalloc(len+1, GFP_KERNEL);
- if (buf == NULL)
- return -ENOMEM;
-
- line = buf;
- for (i = 0; i < count; i++) {
- if (copy_from_user(line, iv[i].iov_base, iv[i].iov_len))
- goto out;
- line += iv[i].iov_len;
- }
-
- /*
- * Extract and skip the syslog prefix <[0-9]*>. Coming from userspace
- * the decimal value represents 32bit, the lower 3 bit are the log
- * level, the rest are the log facility.
- *
- * If no prefix or no userspace facility is specified, we
- * enforce LOG_USER, to be able to reliably distinguish
- * kernel-generated messages from userspace-injected ones.
- */
- line = buf;
- if (line[0] == '<') {
- char *endp = NULL;
-
- i = simple_strtoul(line+1, &endp, 10);
- if (endp && endp[0] == '>') {
- level = i & 7;
- if (i >> 3)
- facility = i >> 3;
- endp++;
- len -= endp - line;
- line = endp;
- }
- }
- line[len] = '\0';
-
- printk_emit(facility, level, NULL, 0, "%s", line);
-out:
- kfree(buf);
- return ret;
-}
-
-static const struct file_operations kmsg_fops = {
- .aio_write = kmsg_writev,
- .llseek = noop_llseek,
-};
-
static const struct memdev {
const char *name;
umode_t mode;
@@ -884,7 +825,7 @@ static const struct memdev {
[7] = { "full", 0666, &full_fops, NULL },
[8] = { "random", 0666, &random_fops, NULL },
[9] = { "urandom", 0666, &urandom_fops, NULL },
- [11] = { "kmsg", 0, &kmsg_fops, NULL },
+ [11] = { "kmsg", 0644, &kmsg_fops, NULL },
#ifdef CONFIG_CRASH_DUMP
[12] = { "oldmem", 0, &oldmem_fops, NULL },
#endif
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -300,6 +300,8 @@ extern void dump_stack(void) __cold;
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
+extern const struct file_operations kmsg_fops;
+
enum {
DUMP_PREFIX_NONE,
DUMP_PREFIX_ADDRESS,
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -41,6 +41,7 @@
#include <linux/cpu.h>
#include <linux/notifier.h>
#include <linux/rculist.h>
+#include <linux/poll.h>
#include <asm/uaccess.h>
@@ -149,6 +150,48 @@ static int console_may_schedule;
* length of the message text is stored in the header, the stored message
* is not terminated.
*
+ * Optionally, a message can carry a dictionary of properties (key/value pairs),
+ * to provide userspace with a machine-readable message context.
+ *
+ * Examples for well-defined, commonly used property names are:
+ * DEVICE=b12:8 device identifier
+ * b12:8 block dev_t
+ * c127:3 char dev_t
+ * n8 netdev ifindex
+ * +sound:card0 subsystem:devname
+ * SUBSYSTEM=pci driver-core subsystem name
+ *
+ * Valid characters in property names are [a-zA-Z0-9.-_]. The plain text value
+ * follows directly after a '=' character. Every property is terminated by
+ * a '\0' character. The last property is not terminated.
+ *
+ * Example of a message structure:
+ * 0000 ff 8f 00 00 00 00 00 00 monotonic time in nsec
+ * 0008 34 00 record is 52 bytes long
+ * 000a 0b 00 text is 11 bytes long
+ * 000c 1f 00 dictionary is 23 bytes long
+ * 000e 03 00 LOG_KERN (facility) LOG_ERR (level)
+ * 0010 69 74 27 73 20 61 20 6c "it's a l"
+ * 69 6e 65 "ine"
+ * 001b 44 45 56 49 43 "DEVIC"
+ * 45 3d 62 38 3a 32 00 44 "E=b8:2\0D"
+ * 52 49 56 45 52 3d 62 75 "RIVER=bu"
+ * 67 "g"
+ * 0032 00 00 00 padding to next message header
+ *
+ * The 'struct log' buffer header must never be directly exported to
+ * userspace, it is a kernel-private implementation detail that might
+ * 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"
+ *
+ * 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.
*/
struct log {
@@ -297,6 +340,276 @@ static void log_store(int facility, int
log_next_seq++;
}
+/* /dev/kmsg - userspace message inject/listen interface */
+struct devkmsg_user {
+ u64 seq;
+ u32 idx;
+ struct mutex lock;
+ char buf[8192];
+};
+
+static ssize_t devkmsg_writev(struct kiocb *iocb, const struct iovec *iv,
+ unsigned long count, loff_t pos)
+{
+ char *buf, *line;
+ int i;
+ int level = default_message_loglevel;
+ int facility = 1; /* LOG_USER */
+ size_t len = iov_length(iv, count);
+ ssize_t ret = len;
+
+ if (len > LOG_LINE_MAX)
+ return -EINVAL;
+ buf = kmalloc(len+1, GFP_KERNEL);
+ if (buf == NULL)
+ return -ENOMEM;
+
+ line = buf;
+ for (i = 0; i < count; i++) {
+ if (copy_from_user(line, iv[i].iov_base, iv[i].iov_len))
+ goto out;
+ line += iv[i].iov_len;
+ }
+
+ /*
+ * Extract and skip the syslog prefix <[0-9]*>. Coming from userspace
+ * the decimal value represents 32bit, the lower 3 bit are the log
+ * level, the rest are the log facility.
+ *
+ * If no prefix or no userspace facility is specified, we
+ * enforce LOG_USER, to be able to reliably distinguish
+ * kernel-generated messages from userspace-injected ones.
+ */
+ line = buf;
+ if (line[0] == '<') {
+ char *endp = NULL;
+
+ i = simple_strtoul(line+1, &endp, 10);
+ if (endp && endp[0] == '>') {
+ level = i & 7;
+ if (i >> 3)
+ facility = i >> 3;
+ endp++;
+ len -= endp - line;
+ line = endp;
+ }
+ }
+ line[len] = '\0';
+
+ printk_emit(facility, level, NULL, 0, "%s", line);
+out:
+ kfree(buf);
+ return ret;
+}
+
+static ssize_t devkmsg_read(struct file *file, char __user *buf,
+ size_t count, loff_t *ppos)
+{
+ struct devkmsg_user *user = file->private_data;
+ struct log *msg;
+ size_t i;
+ size_t len;
+ ssize_t ret;
+
+ if (!user)
+ return -EBADF;
+
+ mutex_lock(&user->lock);
+ raw_spin_lock(&logbuf_lock);
+ while (user->seq == log_next_seq) {
+ if (file->f_flags & O_NONBLOCK) {
+ ret = -EAGAIN;
+ raw_spin_unlock(&logbuf_lock);
+ goto out;
+ }
+
+ raw_spin_unlock(&logbuf_lock);
+ ret = wait_event_interruptible(log_wait,
+ user->seq != log_next_seq);
+ if (ret)
+ goto out;
+ raw_spin_lock(&logbuf_lock);
+ }
+
+ if (user->seq < log_first_seq) {
+ /* our last seen message is gone, return error and reset */
+ user->idx = log_first_idx;
+ user->seq = log_first_seq;
+ ret = -EPIPE;
+ raw_spin_unlock(&logbuf_lock);
+ goto out;
+ }
+
+ msg = log_from_idx(user->idx);
+ len = sprintf(user->buf, "%u,%llu,%llu;",
+ msg->level, user->seq, msg->ts_nsec / 1000);
+
+ /* escape non-printable characters */
+ for (i = 0; i < msg->text_len; i++) {
+ char c = log_text(msg)[i];
+
+ if (c < ' ' || c >= 128)
+ len += sprintf(user->buf + len, "\\x%02x", c);
+ else
+ user->buf[len++] = c;
+ }
+ user->buf[len++] = '\n';
+
+ if (msg->dict_len) {
+ bool line = true;
+
+ for (i = 0; i < msg->dict_len; i++) {
+ char c = log_dict(msg)[i];
+
+ if (line) {
+ user->buf[len++] = ' ';
+ line = false;
+ }
+
+ if (c == '\0') {
+ user->buf[len++] = '\n';
+ line = true;
+ continue;
+ }
+
+ if (c < ' ' || c >= 128) {
+ len += sprintf(user->buf + len, "\\x%02x", c);
+ continue;
+ }
+
+ user->buf[len++] = c;
+ }
+ user->buf[len++] = '\n';
+ }
+
+ user->idx = log_next(user->idx);
+ user->seq++;
+ raw_spin_unlock(&logbuf_lock);
+
+ if (len > count) {
+ ret = -EINVAL;
+ goto out;
+ }
+
+ if (copy_to_user(buf, user->buf, len)) {
+ ret = -EFAULT;
+ goto out;
+ }
+ ret = len;
+out:
+ mutex_unlock(&user->lock);
+ return ret;
+}
+
+static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
+{
+ struct devkmsg_user *user = file->private_data;
+ loff_t ret = 0;
+
+ if (!user)
+ return -EBADF;
+ if (offset)
+ return -ESPIPE;
+
+ raw_spin_lock(&logbuf_lock);
+ switch (whence) {
+ case SEEK_SET:
+ /* the first record */
+ user->idx = log_first_idx;
+ user->seq = log_first_seq;
+ break;
+ case SEEK_DATA:
+ /*
+ * The first record after the last SYSLOG_ACTION_CLEAR,
+ * like issued by 'dmesg -c'. Reading /dev/kmsg itself
+ * changes no global state, and does not clear anything.
+ */
+ user->idx = clear_idx;
+ user->seq = clear_seq;
+ break;
+ case SEEK_END:
+ /* after the last record */
+ user->idx = log_next_idx;
+ user->seq = log_next_seq;
+ break;
+ default:
+ ret = -EINVAL;
+ }
+ raw_spin_unlock(&logbuf_lock);
+ return ret;
+}
+
+static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
+{
+ struct devkmsg_user *user = file->private_data;
+ int ret = 0;
+
+ if (!user)
+ return POLLERR|POLLNVAL;
+
+ poll_wait(file, &log_wait, wait);
+
+ raw_spin_lock(&logbuf_lock);
+ if (user->seq < log_next_seq) {
+ /* return error when data has vanished underneath us */
+ if (user->seq < log_first_seq)
+ ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI;
+ ret = POLLIN|POLLRDNORM;
+ }
+ raw_spin_unlock(&logbuf_lock);
+
+ return ret;
+}
+
+static int devkmsg_open(struct inode *inode, struct file *file)
+{
+ struct devkmsg_user *user;
+ int err;
+
+ /* write-only does not need any file context */
+ if ((file->f_flags & O_ACCMODE) == O_WRONLY)
+ return 0;
+
+ err = security_syslog(SYSLOG_ACTION_READ_ALL);
+ if (err)
+ return err;
+
+ user = kmalloc(sizeof(struct devkmsg_user), GFP_KERNEL);
+ if (!user)
+ return -ENOMEM;
+
+ mutex_init(&user->lock);
+
+ raw_spin_lock(&logbuf_lock);
+ user->idx = log_first_idx;
+ user->seq = log_first_seq;
+ raw_spin_unlock(&logbuf_lock);
+
+ file->private_data = user;
+ return 0;
+}
+
+static int devkmsg_release(struct inode *inode, struct file *file)
+{
+ struct devkmsg_user *user = file->private_data;
+
+ if (!user)
+ return 0;
+
+ mutex_destroy(&user->lock);
+ kfree(user);
+ return 0;
+}
+
+const struct file_operations kmsg_fops = {
+ .open = devkmsg_open,
+ .read = devkmsg_read,
+ .aio_write = devkmsg_writev,
+ .llseek = devkmsg_llseek,
+ .poll = devkmsg_poll,
+ .release = devkmsg_release,
+};
+
#ifdef CONFIG_KEXEC
/*
* This appends the listed symbols to /proc/vmcoreinfo
On Thu, May 03, 2012 at 02:29:41AM +0200, Kay Sievers wrote:
> From: Kay Sievers <[email protected]>
> Subject: kmsg: export printk records to the /dev/kmsg interface
>
> Support for multiple concurrent readers of /dev/kmsg, with read(),
> seek(), poll() support. Output of message sequence numbers, to allow
> userspace log consumers to reliably reconnect and reconstruct their
> state at any given time. After open("/dev/kmsg"), read() always
> returns *all* buffered records. If only future messages should be
> read, SEEK_END can be used. In case records get overwritten while
> /dev/kmsg is held open, or records get faster overwritten than they
> are read, the next read() will return -EPIPE and the current reading
> position gets updated to the next available record. The passed
> sequence numbers allow the log consumer to calculate the amount of
> lost messages.
>
> [root@mop ~]# cat /dev/kmsg
> 5,0,0;Linux version 3.4.0-rc1+ (kay@mop) (gcc version 4.7.0 20120315 ...
> 6,159,423091;ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
> 7,160,424069;pci_root PNP0A03:00: host bridge window [io 0x0000-0x0cf7] (ignored)
> SUBSYSTEM=acpi
> DEVICE=+acpi:PNP0A03:00
> 6,339,5140900;NET: Registered protocol family 10
> 30,340,5690716;udevd[80]: starting version 181
> 6,341,6081421;FDC 0 is a S82078B
> 6,345,6154686;microcode: CPU0 sig=0x623, pf=0x0, revision=0x0
> 7,346,6156968;sr 1:0:0:0: Attached scsi CD-ROM sr0
> SUBSYSTEM=scsi
> DEVICE=+scsi:1:0:0:0
> 6,347,6289375;microcode: CPU1 sig=0x623, pf=0x0, revision=0x0
Can you add a file somwhere in Documentation (Documentatin/ABI?) that
documents the file format for this file?
Other than that, nice, I've queued all of these up.
thanks,
greg k-h
On Tue, May 8, 2012 at 2:28 AM, Greg Kroah-Hartmann <[email protected]> wrote:
> Can you add a file somwhere in Documentation (Documentatin/ABI?) that
> documents the file format for this file?
Something like that? Please let me know, what else might be useful here.
Thanks,
Kay
From: Kay Sievers <[email protected]>
Subject: kmsg - add Documentation/ABI/testing/dev-kmsg
Signed-off-by: Kay Sievers <[email protected]>
---
Documentation/ABI/testing/dev-kmsg | 90 +++++++++++++++++++++++++++++++++++++
Documentation/devices.txt | 3 -
2 files changed, 92 insertions(+), 1 deletion(-)
--- /dev/null
+++ b/Documentation/ABI/testing/dev-kmsg
@@ -0,0 +1,90 @@
+What: /dev/kmsg
+Date: Mai 2012
+KernelVersion: 3.4
+Contact: Kay Sievers <[email protected]>
+Description: The /dev/kmsg character device node provides userspace access
+ to the kernel's printk buffer.
+
+ Injecting messages:
+ Every write() to the opened device node places a log entry in
+ the kernel's printk buffer.
+
+ The logged line can be prefixed with a <N> syslog prefix, which
+ carries the syslog priority and facility. The single decimal
+ prefix number is composed of the 3 lowest bits being the syslog
+ priority and the higher bits the syslog facility number.
+
+ If no prefix is given, the priority number is the default kernel
+ log priority and the facility number is set to LOG_USER (1). It
+ is not possible to inject messages from userspace with the
+ facility number LOG_KERN (0), to make sure that the origin of
+ the messages can always be reliably determined.
+
+ Accessing the buffer:
+ Every read() from the opened device node receives one record
+ of the kernel's printk buffer.
+
+ The first read() directly following an open() always returns
+ first message in the buffer; there is no kernel-internal
+ persistent state; many readers can concurrently open the device
+ and read from it, without affecting other readers.
+
+ Every read() will receive the next available record. If no more
+ records are available read() will block, or if O_NONBLOCK is
+ used -EAGAIN returned.
+
+ Messages in the record ring buffer get overwritten as whole,
+ there are never partial messages received by read().
+
+ In case messages get overwritten in the circular buffer while
+ the device is kept open, the next read() will return -EPIPE,
+ and the seek position be updated to the next available record.
+ Subsequent reads() will return available records again.
+
+ Unlike the classic syslog() interface, the 64 bit record
+ sequence numbers allow to calculate the amount of lost
+ messages, in case the buffer gets overwritten. And they allow
+ to reconnect to the buffer and reconstruct the read position
+ if needed, without limiting the interface to a single reader.
+
+ The device supports seek with the following parameters:
+ SEEK_SET, 0
+ seek to the first entry in the buffer
+ SEEK_END, 0
+ seek after the last entry in the buffer
+ SEEK_DATA, 0
+ seek after the last record available at the time
+ the last SYSLOG_ACTION_CLEAR was issued.
+
+ The output format consists of a prefix carrying the syslog
+ prefix including priority and facility, the 64 bit message
+ sequence number and the monotonic timestamp in microseconds.
+ The values are separated by a ','. Future extensions might
+ add more comma separated values before the terminating ';'.
+ Unknown values should be gracefully ignored.
+
+ The human readable text string starts directly after the ';'
+ and is terminated by a '\n'. Untrusted values derived from
+ hardware or other facilities are printed, therefore
+ all non-printable characters in the log message are escaped
+ by "\x00" C-style hex encoding.
+
+ A line starting with ' ', is a continuation line, adding
+ key/value pairs to the log message, which provide the machine
+ readable context of the message, for reliable processing in
+ userspace.
+
+ Example:
+ 7,160,424069;pci_root PNP0A03:00: host bridge window [io 0x0000-0x0cf7] (ignored)
+ SUBSYSTEM=acpi
+ DEVICE=+acpi:PNP0A03:00
+ 6,339,5140900;NET: Registered protocol family 10
+ 30,340,5690716;udevd[80]: starting version 181
+
+ The DEVICE= key uniquely identifies devices the following way:
+ b12:8 - block dev_t
+ c127:3 - char dev_t
+ n8 - netdev ifindex
+ + sound:card0 - subsystem:devname
+
+Users: dmesg(1), userspace kernel log consumers
--- a/Documentation/devices.txt
+++ b/Documentation/devices.txt
@@ -98,7 +98,8 @@ Your cooperation is appreciated.
8 = /dev/random Nondeterministic random number gen.
9 = /dev/urandom Faster, less secure random number gen.
10 = /dev/aio Asynchronous I/O notification interface
- 11 = /dev/kmsg Writes to this come out as printk's
+ 11 = /dev/kmsg Writes to this come out as printk's, reads
+ export the buffered printk records.
12 = /dev/oldmem Used by crashdump kernels to access
the memory of the kernel that crashed.
On Tue, May 08, 2012 at 06:50:50PM +0200, Kay Sievers wrote:
> On Tue, May 8, 2012 at 2:28 AM, Greg Kroah-Hartmann <[email protected]> wrote:
>
> > Can you add a file somwhere in Documentation (Documentatin/ABI?) that
> > documents the file format for this file?
>
> Something like that? Please let me know, what else might be useful here.
This looks good to me, thanks.
greg k-h
On Thu, May 03, 2012 at 02:29:41AM +0200, Kay Sievers wrote:
> + /* escape non-printable characters */
> + for (i = 0; i < msg->text_len; i++) {
> + char c = log_text(msg)[i];
> +
> + if (c < ' ' || c >= 128)
Signed char type is never larger than 127.
> + len += sprintf(user->buf + len, "\\x%02x", c);
> + else
> + user->buf[len++] = c;
> + }
> + user->buf[len++] = '\n';
> +
> + if (msg->dict_len) {
> + bool line = true;
> +
> + for (i = 0; i < msg->dict_len; i++) {
> + char c = log_dict(msg)[i];
> +
> + if (line) {
> + user->buf[len++] = ' ';
> + line = false;
> + }
> +
> + if (c == '\0') {
> + user->buf[len++] = '\n';
> + line = true;
> + continue;
> + }
> +
> + if (c < ' ' || c >= 128) {
Same.
> + len += sprintf(user->buf + len, "\\x%02x", c);
> + continue;
> + }
> +
regards,
dan carpenter
On Thu, May 10, 2012 at 4:45 AM, Dan Carpenter <[email protected]> wrote:
> On Thu, May 03, 2012 at 02:29:41AM +0200, Kay Sievers wrote:
>> + ? ? /* escape non-printable characters */
>> + ? ? for (i = 0; i < msg->text_len; i++) {
>> + ? ? ? ? ? ? char c = log_text(msg)[i];
>> +
>> + ? ? ? ? ? ? if (c < ' ' || c >= 128)
>
> Signed char type is never larger than 127.
You don't know that it's signed.
The sign of "char" is implementation-defined, and there are indeed
architectures that Linux supports where it is unsigned (I think ARM is
one example).
So that comparison against 128 is actually required.
Or, better yet, the code should make 'c' *explicitly* signed (or
unsigned) so that this particular C language definition oddity is
avoided entirely.
Linus