Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1341926 > unrolled thread

[PATCH v6 0/8] Additional kmsg devices

Started byKazimierz Krosman <k.krosman@samsung.com>
First post2016-02-24 13:00 +0100
Last post2016-02-26 15:10 +0100
Articles 10 — 3 participants

Back to article view | Back to linux.kernel


Contents

  [PATCH v6 0/8] Additional kmsg devices Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-24 13:00 +0100
    [PATCH v6 4/8] kmsg: add additional buffers support to memory class Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-24 13:00 +0100
    [PATCH v6 7/8] kmsg: add ioctl for kmsg* devices operating on buffers Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-24 13:00 +0100
    [PATCH v6 5/8] kmsg: add function for adding and deleting additional  buffers Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-24 13:00 +0100
    [PATCH v6 2/8] printk: add one function for storing log in proper  format Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-24 13:00 +0100
    Re: [PATCH v6 0/8] Additional kmsg devices Tejun Heo <tj@kernel.org> - 2016-02-25 22:50 +0100
      Re: [PATCH v6 0/8] Additional kmsg devices Kazimierz Krosman <k.krosman@samsung.com> - 2016-02-26 14:30 +0100
        Re: [PATCH v6 0/8] Additional kmsg devices Petr Mladek <pmladek@suse.com> - 2016-02-26 15:50 +0100
          Re: [PATCH v6 0/8] Additional kmsg devices Tejun Heo <tj@kernel.org> - 2016-02-27 13:00 +0100
    Re: [PATCH v6 3/8] kmsg: introduce additional kmsg devices support Petr Mladek <pmladek@suse.com> - 2016-02-26 15:10 +0100

#1341926 — [PATCH v6 0/8] Additional kmsg devices

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-24 13:00 +0100
Subject[PATCH v6 0/8] Additional kmsg devices
Message-ID<r5GgO-3YX-3@gated-at.bofh.it>
Dear All,

This is the sixth iteration of Marcin Niesluchowski's series of patches
extending kmsg interface with ability to dynamically create (and destroy)
kmsg-like devices which can be used by userspace for logging,

Changed from v5:

 * ioctl that adds kmsg device with minor number higher than 255 returns
   with error. This is because of registering kmsg as character device with
   register_chrdev which creates 256 minor numbers for a given major.

 * minor fix for selftest- changed size of message to write.
   Previous value causes exceeding of LOG_LINE_MAX limits.

 * dropped RFC tag in subject.

 * rebased patches v5 on Linux v4.5-rc5.

Changes from v4:

 * selftests are rearranged to use kselftest.h API

 * a disputed patch "add predefined _PID, _TID, _COMM keywords to kmsg*
   log dict" is removed - no chance it will be ever accepted. It is not
   critical for this patchset as a whole.

Changes from v3:

 * fixes problems spotted by kbuild test robot

 * fiesed problem with inproper use of copy_from_user()

Changes from v2:

 * Extracted kmsg related functions from printk.c to a new file, kmsg.c

Changes from v1:

 * all occurences of '#ifdef CONFIG_PRINTK' removed from drivers/char/mem.c

 * printk related code moved to kernel/printk/printk.c

 * use of VMCOREINFO_STRUCT_SIZE

 * selftests for kmsg added (shape of testing infrastructure based on
   kdbus selftests)

We would like to share our opinion about this changes. We see following advantages
of the proposed extensions to kmsg interface:

1. kmsg device does not require maintenance by reader process side.
Multiple writers can write to a device and new records overwrite logs saved earlier.
When system crashes logs can be restored with pstore mechanism.

2. Using kmsg can cause lower CPU utilisation in the real-word use case than 
userspace logging mechanisms.
We created 2 tests: (1) 100 writer processes write to created kmsg buffer and
(2) 100 writers write to socket (stream)- there is one reader to protect
socket buffer against overflow. Tests show that cpu utilisation in case of first
test is about 2.3 times lower (39.1%) than it is in second case (87.7%) (measured
with top program; tests code is attached below). Tested on Odroid XU4.

Possible future enhancements:
1. It is possible to extend kmsg interface with ioctl that is blockingi read process
until the cyclic buffer is almost full (for example 3/4 of max size). This
modification can enable efficient read of records and prevents against cyclic buffer
overwriting.

2. Maybe we should consider to set some global and local limit for creating
additional buffer. In current version of patches it is possible to create buffers
as long as minor is below 256 and there is a free memory (ioctl fail if kmalloc fail).
It means that it is possible to allocate whole kernel memory for kmsg devices.

Best regards,
Kazimierz Krosman

Marcin Niesluchowski (6):
  printk: add one function for storing log in proper format
  kmsg: introduce additional kmsg devices support
  kmsg: add additional buffers support to memory class
  kmsg: add function for adding and deleting additional buffers
  kmsg: add ioctl for adding and deleting kmsg* devices
  kmsg: add ioctl for kmsg* devices operating on buffers

Paul Osmialowski (2):
  printk: extract kmsg-related routines from printk.c to kmsg.c
  kmsg: selftests

 Documentation/ioctl/ioctl-number.txt               |    1 +
 drivers/char/mem.c                                 |   27 +-
 fs/proc/kmsg.c                                     |    4 +-
 include/linux/printk.h                             |   48 +
 include/uapi/linux/Kbuild                          |    1 +
 include/uapi/linux/kmsg_ioctl.h                    |   45 +
 kernel/printk/Makefile                             |    1 +
 kernel/printk/kmsg.c                               | 1022 ++++++++++++++++
 kernel/printk/printk.c                             | 1255 +++++---------------
 kernel/printk/printk.h                             |  260 ++++
 samples/kmsg/kmsg-api.h                            |   44 +
 tools/testing/selftests/Makefile                   |    1 +
 tools/testing/selftests/kmsg/.gitignore            |    1 +
 tools/testing/selftests/kmsg/Makefile              |   30 +
 tools/testing/selftests/kmsg/kmsg-test.c           |  344 ++++++
 tools/testing/selftests/kmsg/kmsg-test.h           |   28 +
 tools/testing/selftests/kmsg/test-buffer-add-del.c |   78 ++
 .../kmsg/test-buffer-add-write-read-del.c          |  163 +++
 .../kmsg/test-buffer-buf-multithreaded-torture.c   |  201 ++++
 .../selftests/kmsg/test-buffer-buf-torture.c       |  141 +++
 20 files changed, 2725 insertions(+), 970 deletions(-)
 create mode 100644 include/uapi/linux/kmsg_ioctl.h
 create mode 100644 kernel/printk/kmsg.c
 create mode 100644 kernel/printk/printk.h
 create mode 100644 samples/kmsg/kmsg-api.h
 create mode 100644 tools/testing/selftests/kmsg/.gitignore
 create mode 100644 tools/testing/selftests/kmsg/Makefile
 create mode 100644 tools/testing/selftests/kmsg/kmsg-test.c
 create mode 100644 tools/testing/selftests/kmsg/kmsg-test.h
 create mode 100644 tools/testing/selftests/kmsg/test-buffer-add-del.c
 create mode 100644 tools/testing/selftests/kmsg/test-buffer-add-write-read-del.c
 create mode 100644 tools/testing/selftests/kmsg/test-buffer-buf-multithreaded-torture.c
 create mode 100644 tools/testing/selftests/kmsg/test-buffer-buf-torture.c

-- 
1.9.1

Attached Test programs:
(1) kmsg_test.c
#include <stdio.h>
#include <errno.h>
#include <string.h>
#include <sys/socket.h>
#include <sys/un.h>
#include <sys/types.h>
#include <unistd.h>
#include <sys/time.h>
#include <fcntl.h>
#include <unistd.h>
#include <stdlib.h>
#include <stdint.h>
#include <errno.h>
#include <sys/ioctl.h>
#include <linux/kmsg_ioctl.h>


enum { ARGS_NUM_MAX = 4};
int MSG_COUNT = 1024*102;
int MSG_SIZE = 256;
int KMSG_SIZE = 1024;
int WRITERS_NUM = 100;

int* args[ARGS_NUM_MAX] = {&KMSG_SIZE, &WRITERS_NUM, &MSG_SIZE, &MSG_COUNT};

int main_minor = 0;
int main_fd = 0;

static int print_help(char* name)
{
    printf( "Usage:  %s [KMSG_SIZE [WRITERS_NUM [MSG_SIZE [MSG_COUNT]]]]\n"
            "Example call: %s 1024 10 256 1048576\n"
            "\nOption description:\n"
            "\tKMSG_SIZE: size of buffer created with ioctl on /dev/kmsg\n"
            "\tWRITER_NUM: number of process that writes to created buffer\n"
            "\tMSG_SIZE: size of message\n"
            "\tMSG_COUNT: number of write() calls done by each writer\n"
            "\n\n", name, name
        );
}

static int kmsg_cmd_buffer_add(char* path)
{
    struct kmsg_cmd_buffer_add cmd;
    int ret;
    int fd = open("/dev/kmsg", O_RDWR);
    
    if (fd < 0) 
    {
        fprintf(stderr, "Cannot open /dev/kmsg: fd=%d, errno=%d\n", fd, errno);
        exit(EXIT_FAILURE);
    }
    cmd.size = KMSG_SIZE;
    cmd.mode = 0662;
    
    ret = ioctl(fd, KMSG_CMD_BUFFER_ADD, &cmd);
    if (ret < 0)
    {
        fprintf(stderr, "ioctl failed (size=%lld, mode=0%o) = return=%d, errno=%d\n", cmd.size, cmd.mode, ret, errno);
        exit(EXIT_FAILURE);
    }
    
    main_minor = cmd.minor;
    snprintf(path, 80, "/dev/kmsg%d", main_minor);
    printf("Created device: %s\n", path);
    main_fd = fd;
    return (ret < 0) ? (errno > 0 ? -errno : -EINVAL) : 0;
}

static void kmsg_cmd_buffer_del()
{
    int ret;
    ret = ioctl(main_fd, KMSG_CMD_BUFFER_DEL, &main_minor);
    printf("Deleted /dev/kmsg%d %d %d\n",  main_minor, ret, errno);
    close(main_fd);
}

static void fail()
{
    kmsg_cmd_buffer_del();
    exit(EXIT_FAILURE);
}

int main(int argc , char *argv[])
{
    char path[80];
    char buf[MSG_SIZE];
    size_t size;
    struct timeval start, end;
    int i, fd, forked, pid;
    forked = 0;

    if (argc > 1)
    {
        int i = 0;
        while ( i < ARGS_NUM_MAX  && i+1 < argc)
            *(args[i++]) = atoi(argv[i]);
    } else 
        print_help(argv[0]);

    printf("Test parameters: KMSG_SIZE=%d, WRITERS_NUM=%d, MSG_SIZE=%d, MSG_COUNT=%d\n", KMSG_SIZE, WRITERS_NUM, MSG_SIZE, MSG_COUNT);

    kmsg_cmd_buffer_add(path);

    if(argc == (ARGS_NUM_MAX+2))
    {
        fd = open(path, O_WRONLY);
        if (fd < 0)
        {
            fprintf(stderr, "open failed: %s (fd=%d, errno=%d)\n", path, fd, errno);
            fail();
        }

        return 0;
    }

    for (i = 0;i<WRITERS_NUM;i++)
    {
        if(!fork())
        {
            forked =1;
            break;
        }
    }

    if (!forked)
    {
        if (-1 == gettimeofday(&start, 0)) {
            fprintf(stderr, "gettimeofday failed\n");
            fail();
        }
        printf("%ld.%06ld\n", start.tv_sec, start.tv_usec);
    } else {
        fd = open(path, O_WRONLY);
        if (fd < 0)
        {
            fprintf(stderr, "open failed: %s (fd=%d, errno=%d)\n", path, fd, errno);
            exit(EXIT_FAILURE);
        }

        for(i=0; i<MSG_COUNT; i++)
            if (write(fd, buf, MSG_SIZE) < 0) {
                fprintf(stderr, "Write failed. %s\n", strerror(errno));
                exit(EXIT_FAILURE);
            }
        return 0;
    }

    while (pid = waitpid(-1, NULL, 0))
        if (errno == ECHILD)
            break;

    if (-1 == gettimeofday(&end, 0)) {
        fprintf(stderr, "gettimeofday failed\n");
        fail();
    }

    printf("%ld.%06ld\n", end.tv_sec, end.tv_usec);

    printf("Time: %ld us\n", (end.tv_sec-start.tv_sec)*1000000 + end.tv_usec - start.tv_usec);
    kmsg_cmd_buffer_del();
    return 0;
}
//-------------------------------------------------------------------------------------------
(2) stream_test.c
#include <stdio.h>
#include <errno.h>
#include <string.h>
#include <sys/socket.h>
#include <sys/un.h>
#include <sys/types.h>
#include <unistd.h>
#include <sys/time.h>
#include <fcntl.h>
#include <unistd.h>
#include <stdlib.h>
#include <sys/epoll.h>

#define SOCKET_PATH "/var/run/test_socket"
enum {MSG_MAX_SIZE  = 8192};
int WRT_NUM   = 100; //WRITERS_NUMBER
enum { ARGS_NUM_MAX = 3};
int MSG_COUNT = 1024*102;
int MSG_SIZE = 256;

char buf[MSG_MAX_SIZE];
int sd;

static int print_help(char* name)
{
    printf( "Usage:  %s [WRITERS_NUM [MSG_SIZE [MSG_COUNT]]]\n"
            "Example call: %s 10 256 1048576\n"
            "\nOption description:\n"
            "\tWRITERS_NUM: number of process that writes to created buffer\n"
            "\tMSG_SIZE: size of message\n"
            "\tMSG_COUNT: number of write() calls done by each writer\n"
            "\n\n", name, name
        );
}

void prepare_server()
{
    struct sockaddr_un server_addr;
    sd = socket(AF_UNIX, SOCK_STREAM, 0);
    if (sd == -1) {
        fprintf(stderr, "Could not create socket");
        exit(EXIT_FAILURE);
    }

    memset(&server_addr, 0, sizeof(server_addr));
    server_addr.sun_family = AF_UNIX;
    strcpy(server_addr.sun_path, SOCKET_PATH);
    unlink(server_addr.sun_path);

    if (bind(sd, (struct sockaddr*)&server_addr, sizeof(server_addr)) == -1) {
        fprintf(stderr, "Bind failed");
        exit(EXIT_FAILURE);
    }

    if (listen(sd, 5) == -1) {
        fprintf(stderr, "Listen failed");
        exit(EXIT_FAILURE);
    }

}


void do_server()
{
    struct sockaddr_un client_addr;
    long long int readed_size = 0;
    long long int to_read = (MSG_COUNT*MSG_SIZE*(long long int)WRT_NUM);
    int i = 0, conn_sock, epollfd, nfds, flags;
    unsigned int client_len = sizeof(client_addr);
    ssize_t size_one;
    struct epoll_event ev, events[WRT_NUM+1];

    epollfd = epoll_create1(0);
    if (epollfd == -1) {
        perror("epoll_create1");
        exit(EXIT_FAILURE);
    }

    ev.events = EPOLLIN;
    ev.data.fd = sd;
    if (epoll_ctl(epollfd, EPOLL_CTL_ADD, sd, &ev) == -1) {
        perror("epoll_ctl: listen_sock");
        exit(EXIT_FAILURE);
    }

    for (;;) {
        nfds = epoll_wait(epollfd, events, WRT_NUM+1, -1);
        if (nfds == -1) {
            perror("epoll_wait");
            exit(EXIT_FAILURE);
        }

        for (i=0; i < nfds; ++i) {
            if (events[i].data.fd == sd) {
                conn_sock = accept(sd,
                                    (struct sockaddr *) &client_addr, &client_len);
                if (conn_sock == -1) {
                    perror("accept");
                    exit(EXIT_FAILURE);
                }
                ev.events = EPOLLIN;
                ev.data.fd = conn_sock;
                flags = fcntl(conn_sock, F_GETFL, 0);
                fcntl(conn_sock, F_SETFL, flags | O_NONBLOCK);
                if (epoll_ctl(epollfd, EPOLL_CTL_ADD, conn_sock, &ev) == -1) {
                    perror("epoll_ctl: conn_sock");
                    exit(EXIT_FAILURE);
                }
            } else {
                size_one = read(events[i].data.fd, buf, MSG_MAX_SIZE);
                if (size_one == 0 && events[i].events & EPOLLHUP)
                    close(events[i].data.fd);
                readed_size += size_one;
            }
        }
        if (readed_size >= to_read)
            return;
    }
}

int main(int argc , char *argv[])
{
    int sd;
    struct sockaddr_un client_addr;
    size_t size;
    ssize_t size_one;
    struct timeval start;
    struct timeval end;
    int pid, i;
    int forked=0;

    int* args[ARGS_NUM_MAX] = {&WRT_NUM, &MSG_SIZE, &MSG_COUNT};

    if (argc > 1)
    {
        int i = 0;
        while ( i < ARGS_NUM_MAX  && i+1 < argc)
            *(args[i++]) = atoi(argv[i]);
    } else
        print_help(argv[0]);

    printf("Test parameters: WRITERS_NUM=%d, MSG_SIZE=%d, MSG_COUNT=%d\n", WRT_NUM, MSG_SIZE, MSG_COUNT);
    prepare_server();

    for (i=0;i<WRT_NUM;i++)
        if (!fork())
        {
            forked=1;
            break;
        }

    if (!forked)
    {
        if (-1 == gettimeofday(&start, 0)) {
            fprintf(stderr, "gettimeofday failed");
            exit(EXIT_FAILURE);
        }
        printf("%ld.%06ld\n", start.tv_sec, start.tv_usec);
    } else
    {
        sd = socket(AF_UNIX, SOCK_STREAM, 0);
        if (sd == -1) {
            fprintf(stderr, "Could not create socket");
            exit(EXIT_FAILURE);
        }

        memset(&client_addr, 0, sizeof(client_addr));
        client_addr.sun_family = AF_UNIX;
        strcpy(client_addr.sun_path, SOCKET_PATH);

        if (connect(sd, (struct sockaddr*)&client_addr, sizeof(client_addr)) == -1) {
            fprintf(stderr, "Connect failed");
            exit(EXIT_FAILURE);
        }

        for(i=0; i<MSG_COUNT; i++) {
            if (write(sd, buf, MSG_SIZE) < 0) {
                fprintf(stderr, "Write failed. %s", strerror(errno));
                exit(EXIT_FAILURE);
            }
        }
        return 0;
    }
    do_server();

    while (pid = waitpid(-1, NULL, 0))
        if (errno == ECHILD)
            break;

    if (-1 == gettimeofday(&end, 0)) {
        fprintf(stderr, "gettimeofday failed");
        exit(EXIT_FAILURE);
    }

    printf("%ld.%06ld\n", end.tv_sec, end.tv_usec);
    printf("Time: %ld us\n", (end.tv_sec-start.tv_sec)*1000000 + end.tv_usec - start.tv_usec);

    return 0;
}

[toc] | [next] | [standalone]


#1341927 — [PATCH v6 4/8] kmsg: add additional buffers support to memory class

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-24 13:00 +0100
Subject[PATCH v6 4/8] kmsg: add additional buffers support to memory class
Message-ID<r5GgP-3YX-29@gated-at.bofh.it>
In reply to#1341926
From: Marcin Niesluchowski <m.niesluchow@samsung.com>

Memory class does not support additional kmsg buffers.

Add additional kmsg buffers support to:
* devnode() callback of "mem" class
* file operations of major "mem" character device

Signed-off-by: Marcin Niesluchowski <m.niesluchow@samsung.com>
Signed-off-by: Paul Osmialowski <p.osmialowsk@samsung.com>
[Rebased kmsg patch v5 on Linux 4.5-rc5]
Signed-off-by: Kazimierz Krosman <k.krosman@samsung.com>
---
 drivers/char/mem.c     | 27 ++++++++++++++++++++-------
 include/linux/printk.h | 32 ++++++++++++++++++++++++++++++++
 kernel/printk/kmsg.c   | 42 ++++++++++++++++++++++++++++++++++++++++++
 kernel/printk/printk.c |  1 +
 kernel/printk/printk.h |  1 +
 5 files changed, 96 insertions(+), 7 deletions(-)

diff --git a/drivers/char/mem.c b/drivers/char/mem.c
index 4f6f94c..aa68923 100644
--- a/drivers/char/mem.c
+++ b/drivers/char/mem.c
@@ -799,9 +799,6 @@ static const struct memdev {
 	 [7] = { "full", 0666, &full_fops, 0 },
 	 [8] = { "random", 0666, &random_fops, 0 },
 	 [9] = { "urandom", 0666, &urandom_fops, 0 },
-#ifdef CONFIG_PRINTK
-	[11] = { "kmsg", 0644, &kmsg_fops, 0 },
-#endif
 };
 
 static int memory_open(struct inode *inode, struct file *filp)
@@ -811,7 +808,7 @@ static int memory_open(struct inode *inode, struct file *filp)
 
 	minor = iminor(inode);
 	if (minor >= ARRAY_SIZE(devlist))
-		return -ENXIO;
+		return kmsg_memory_open(inode, filp);
 
 	dev = &devlist[minor];
 	if (!dev->fops)
@@ -833,16 +830,28 @@ static const struct file_operations memory_fops = {
 
 static char *mem_devnode(struct device *dev, umode_t *mode)
 {
-	if (mode && devlist[MINOR(dev->devt)].mode)
-		*mode = devlist[MINOR(dev->devt)].mode;
+	int minor = MINOR(dev->devt);
+
+	if (!mode)
+		goto out;
+
+	if (minor >= ARRAY_SIZE(devlist)) {
+		kmsg_mode(minor, mode);
+		goto out;
+	}
+
+	if (devlist[minor].mode)
+		*mode = devlist[minor].mode;
+out:
 	return NULL;
 }
 
-static struct class *mem_class;
+struct class *mem_class;
 
 static int __init chr_dev_init(void)
 {
 	int minor;
+	struct device *kmsg;
 
 	if (register_chrdev(MEM_MAJOR, "mem", &memory_fops))
 		printk("unable to get major %d for memory devs\n", MEM_MAJOR);
@@ -866,6 +875,10 @@ static int __init chr_dev_init(void)
 			      NULL, devlist[minor].name);
 	}
 
+	kmsg = init_kmsg(KMSG_MINOR, 0644);
+	if (IS_ERR(kmsg))
+		return PTR_ERR(kmsg);
+
 	return tty_init();
 }
 
diff --git a/include/linux/printk.h b/include/linux/printk.h
index 9ccbdf2..342e9d0 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -417,8 +417,40 @@ do {									\
 	no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
 #endif
 
+#define KMSG_MINOR	11
+
+struct file;
+struct inode;
+
+#ifdef CONFIG_PRINTK
+
+extern struct class *mem_class;
+
 extern const struct file_operations kmsg_fops;
 
+extern struct device *init_kmsg(int minor, umode_t mode);
+extern int kmsg_memory_open(struct inode *inode, struct file *filp);
+extern int kmsg_mode(int minor, umode_t *mode);
+
+#else
+
+static inline struct device *init_kmsg(int minor, umode_t mode)
+{
+	return NULL;
+}
+
+static inline int kmsg_memory_open(struct inode *inode, struct file *filp)
+{
+	return -ENXIO;
+}
+
+static inline int kmsg_mode(int minor, umode_t *mode)
+{
+	return -ENXIO;
+}
+
+#endif
+
 enum {
 	DUMP_PREFIX_NONE,
 	DUMP_PREFIX_ADDRESS,
diff --git a/kernel/printk/kmsg.c b/kernel/printk/kmsg.c
index dbb4a6b..b5e07ff 100644
--- a/kernel/printk/kmsg.c
+++ b/kernel/printk/kmsg.c
@@ -16,6 +16,9 @@
 #include <linux/syslog.h>
 #include <linux/uio.h>
 #include <linux/wait.h>
+#include <linux/device.h>
+#include <linux/major.h>
+#include <linux/kdev_t.h>
 
 #include <asm/uaccess.h>
 
@@ -386,6 +389,45 @@ const struct file_operations kmsg_fops = {
 	.release = devkmsg_release,
 };
 
+/* Should be used for device registration */
+struct device *init_kmsg(int minor, umode_t mode)
+{
+	log_buf.minor = minor;
+	log_buf.mode = mode;
+	return device_create(mem_class, NULL, MKDEV(MEM_MAJOR, minor),
+			NULL, "kmsg");
+}
+
+int kmsg_memory_open(struct inode *inode, struct file *filp)
+{
+	filp->f_op = &kmsg_fops;
+
+	return kmsg_fops.open(inode, filp);
+}
+
+int kmsg_mode(int minor, umode_t *mode)
+{
+	int ret = -ENXIO;
+	struct log_buffer *log_b;
+
+	if (minor == log_buf.minor) {
+		*mode = log_buf.mode;
+		return 0;
+	}
+
+	rcu_read_lock();
+	list_for_each_entry_rcu(log_b, &log_buf.list, list) {
+		if (log_b->minor == minor) {
+			*mode = log_b->mode;
+			ret = 0;
+			break;
+		}
+	}
+	rcu_read_unlock();
+
+	return ret;
+}
+
 static DEFINE_SPINLOCK(dump_list_lock);
 static LIST_HEAD(dump_list);
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b99403b..d8626ee 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -177,6 +177,7 @@ struct log_buffer log_buf = {
 	.next_idx	= 0,
 	.clear_seq	= 0,
 	.clear_idx	= 0,
+	.mode		= 0,
 	.minor		= 0,
 };
 
diff --git a/kernel/printk/printk.h b/kernel/printk/printk.h
index 4eefde5..e5c8a46 100644
--- a/kernel/printk/printk.h
+++ b/kernel/printk/printk.h
@@ -130,6 +130,7 @@ struct log_buffer {
 	u64 clear_seq;
 	u32 clear_idx;
 
+	int mode;		/* mode of device */
 	int minor;		/* minor representing buffer device */
 #endif
 };
-- 
1.9.1

[toc] | [prev] | [next] | [standalone]


#1341928 — [PATCH v6 7/8] kmsg: add ioctl for kmsg* devices operating on buffers

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-24 13:00 +0100
Subject[PATCH v6 7/8] kmsg: add ioctl for kmsg* devices operating on buffers
Message-ID<r5GgP-3YX-23@gated-at.bofh.it>
In reply to#1341926
From: Marcin Niesluchowski <m.niesluchow@samsung.com>

There is no possibility to clear additional kmsg buffers,
get size of them or know what size should be passed to read
file operation (too small size causes it to retrun -EINVAL).

Add following ioctls which solve those issues:
* KMSG_CMD_GET_BUF_SIZE
* KMSG_CMD_GET_READ_SIZE_MAX
* KMSG_CMD_CLEAR

Signed-off-by: Marcin Niesluchowski <m.niesluchow@samsung.com>
Signed-off-by: Paul Osmialowski <p.osmialowsk@samsung.com>
[Rebased kmsg patch v5 on Linux 4.5-rc5]
Signed-off-by: Kazimierz Krosman <k.krosman@samsung.com>
---
 Documentation/ioctl/ioctl-number.txt |  2 +-
 include/uapi/linux/kmsg_ioctl.h      | 15 ++++++++++
 kernel/printk/kmsg.c                 | 57 ++++++++++++++++++++++++++++++++++--
 3 files changed, 71 insertions(+), 3 deletions(-)

diff --git a/Documentation/ioctl/ioctl-number.txt b/Documentation/ioctl/ioctl-number.txt
index 4949aac..c133fb2 100644
--- a/Documentation/ioctl/ioctl-number.txt
+++ b/Documentation/ioctl/ioctl-number.txt
@@ -319,7 +319,7 @@ Code  Seq#(hex)	Include File		Comments
 					<mailto:vgo@ratio.de>
 0xB1	00-1F	PPPoX			<mailto:mostrows@styx.uwaterloo.ca>
 0xB3	00	linux/mmc/ioctl.h
-0xBB	00-02	uapi/linux/kmsg_ioctl.h
+0xBB	00-83	uapi/linux/kmsg_ioctl.h
 0xC0	00-0F	linux/usb/iowarrior.h
 0xCA	00-0F	uapi/misc/cxl.h
 0xCA	80-8F	uapi/scsi/cxlflash_ioctl.h
diff --git a/include/uapi/linux/kmsg_ioctl.h b/include/uapi/linux/kmsg_ioctl.h
index 96e7930..bfd9cd3 100644
--- a/include/uapi/linux/kmsg_ioctl.h
+++ b/include/uapi/linux/kmsg_ioctl.h
@@ -27,4 +27,19 @@ struct kmsg_cmd_buffer_add {
 					      struct kmsg_cmd_buffer_add)
 #define KMSG_CMD_BUFFER_DEL		_IOW(KMSG_IOCTL_MAGIC, 0x01, int)
 
+/*
+ * A ioctl interface for kmsg* devices.
+ *
+ * KMSG_CMD_GET_BUF_SIZE:	Retrieve cyclic log buffer size associated with
+ *				device.
+ * KMSG_CMD_GET_READ_SIZE_MAX:	Retrieve max size of data read by kmsg read
+ *				operation.
+ * KMSG_CMD_CLEAR:		Clears cyclic log buffer. After that operation
+ *				there is no data to read from buffer unless
+ *				logs are written.
+ */
+#define KMSG_CMD_GET_BUF_SIZE		_IOR(KMSG_IOCTL_MAGIC, 0x80, __u32)
+#define KMSG_CMD_GET_READ_SIZE_MAX	_IOR(KMSG_IOCTL_MAGIC, 0x81, __u32)
+#define KMSG_CMD_CLEAR			_IO(KMSG_IOCTL_MAGIC, 0x82)
+
 #endif
diff --git a/kernel/printk/kmsg.c b/kernel/printk/kmsg.c
index 4bf36cd..9ba3989 100644
--- a/kernel/printk/kmsg.c
+++ b/kernel/printk/kmsg.c
@@ -247,8 +247,9 @@ static loff_t kmsg_llseek(struct log_buffer *log_b, struct file *file,
 		}
 		/*
 		 * 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.
+		 * like issued by 'dmesg -c' or KMSG_CMD_CLEAR ioctl
+		 * command. Reading /dev/kmsg itself changes no global
+		 * state, and does not clear anything.
 		 */
 		user->idx = log_b->clear_idx;
 		user->seq = log_b->clear_seq;
@@ -391,6 +392,56 @@ static int devkmsg_open(struct inode *inode, struct file *file)
 	return ret;
 }
 
+static long kmsg_ioctl(struct log_buffer *log_b, unsigned int cmd,
+		       unsigned long arg)
+{
+	void __user *argp = (void __user *)arg;
+	static const u32 read_size_max = CONSOLE_EXT_LOG_MAX;
+
+	switch (cmd) {
+	case KMSG_CMD_GET_BUF_SIZE:
+		if (copy_to_user(argp, &log_b->len, sizeof(u32)))
+			return -EFAULT;
+		break;
+	case KMSG_CMD_GET_READ_SIZE_MAX:
+		if (copy_to_user(argp, &read_size_max, sizeof(u32)))
+			return -EFAULT;
+		break;
+	case KMSG_CMD_CLEAR:
+		if (!capable(CAP_SYSLOG))
+			return -EPERM;
+		raw_spin_lock_irq(&log_b->lock);
+		log_b->clear_seq = log_b->next_seq;
+		log_b->clear_idx = log_b->next_idx;
+		raw_spin_unlock_irq(&log_b->lock);
+		break;
+	default:
+		return -ENOTTY;
+	}
+	return 0;
+}
+
+static long devkmsg_ioctl(struct file *file, unsigned int cmd,
+			  unsigned long arg)
+{
+	long ret = -ENXIO;
+	int minor = iminor(file->f_inode);
+	struct log_buffer *log_b;
+
+	if (minor == log_buf.minor)
+		return kmsg_ioctl(&log_buf, cmd, arg);
+
+	rcu_read_lock();
+	list_for_each_entry_rcu(log_b, &log_buf.list, list) {
+		if (log_b->minor == minor) {
+			ret = kmsg_ioctl(log_b, cmd, arg);
+			break;
+		}
+	}
+	rcu_read_unlock();
+	return ret;
+}
+
 static int devkmsg_release(struct inode *inode, struct file *file)
 {
 	struct devkmsg_user *user = file->private_data;
@@ -409,6 +460,8 @@ const struct file_operations kmsg_fops = {
 	.write_iter = devkmsg_write,
 	.llseek = devkmsg_llseek,
 	.poll = devkmsg_poll,
+	.unlocked_ioctl = devkmsg_ioctl,
+	.compat_ioctl = devkmsg_ioctl,
 	.release = devkmsg_release,
 };
 
-- 
1.9.1

[toc] | [prev] | [next] | [standalone]


#1341929 — [PATCH v6 5/8] kmsg: add function for adding and deleting additional buffers

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-24 13:00 +0100
Subject[PATCH v6 5/8] kmsg: add function for adding and deleting additional buffers
Message-ID<r5GgP-3YX-33@gated-at.bofh.it>
In reply to#1341926
From: Marcin Niesluchowski <m.niesluchow@samsung.com>

Additional kmsg buffers should be created and deleted dynamically.

Adding two functions
* kmsg_sys_buffer_add() creates additional kmsg buffer returning minor
* kmsg_sys_buffer_del() deletes one based on provided minor

Signed-off-by: Marcin Niesluchowski <m.niesluchow@samsung.com>
Signed-off-by: Paul Osmialowski <p.osmialowsk@samsung.com>
[Rebased kmsg patch v5 on Linux 4.5-rc5]
Signed-off-by: Kazimierz Krosman <k.krosman@samsung.com>
---
 include/linux/printk.h |   9 +++++
 kernel/printk/kmsg.c   | 107 +++++++++++++++++++++++++++++++++++++++++++++++--
 kernel/printk/printk.c |  12 ++++++
 kernel/printk/printk.h |   4 ++
 4 files changed, 129 insertions(+), 3 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 342e9d0..c146ee4 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -431,6 +431,8 @@ extern const struct file_operations kmsg_fops;
 extern struct device *init_kmsg(int minor, umode_t mode);
 extern int kmsg_memory_open(struct inode *inode, struct file *filp);
 extern int kmsg_mode(int minor, umode_t *mode);
+extern int kmsg_sys_buffer_add(size_t size, umode_t mode);
+extern void kmsg_sys_buffer_del(int minor);
 
 #else
 
@@ -449,6 +451,13 @@ static inline int kmsg_mode(int minor, umode_t *mode)
 	return -ENXIO;
 }
 
+static inline int kmsg_sys_buffer_add(size_t size, umode_t mode)
+{
+	return -ENXIO;
+}
+
+static inline void kmsg_sys_buffer_del(int minor) {}
+
 #endif
 
 enum {
diff --git a/kernel/printk/kmsg.c b/kernel/printk/kmsg.c
index b5e07ff..82bc282 100644
--- a/kernel/printk/kmsg.c
+++ b/kernel/printk/kmsg.c
@@ -19,6 +19,7 @@
 #include <linux/device.h>
 #include <linux/major.h>
 #include <linux/kdev_t.h>
+#include <linux/kref.h>
 
 #include <asm/uaccess.h>
 
@@ -141,8 +142,20 @@ static ssize_t kmsg_read(struct log_buffer *log_b, struct file *file,
 		}
 
 		raw_spin_unlock_irq(&log_b->lock);
-		ret = wait_event_interruptible(log_b->wait,
-					       user->seq != log_b->next_seq);
+		if (log_b == &log_buf) {
+			ret = wait_event_interruptible(log_b->wait,
+						user->seq != log_b->next_seq);
+		} else {
+			rcu_read_unlock();
+			kref_get(&log_b->refcount);
+			ret = wait_event_interruptible(log_b->wait,
+						user->seq != log_b->next_seq);
+			if (log_b->minor == -1)
+				ret = -ENXIO;
+			if (kref_put(&log_b->refcount, log_buf_release))
+				ret = -ENXIO;
+			rcu_read_lock();
+		}
 		if (ret)
 			goto out;
 		raw_spin_lock_irq(&log_b->lock);
@@ -311,8 +324,14 @@ static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
 	rcu_read_lock();
 	list_for_each_entry_rcu(log_b, &log_buf.list, list) {
 		if (log_b->minor == minor) {
+			kref_get(&log_b->refcount);
+			rcu_read_unlock();
+
 			ret = kmsg_poll(log_b, file, wait);
-			break;
+
+			if (kref_put(&log_b->refcount, log_buf_release))
+				return POLLERR|POLLNVAL;
+			return ret;
 		}
 	}
 	rcu_read_unlock();
@@ -428,6 +447,88 @@ int kmsg_mode(int minor, umode_t *mode)
 	return ret;
 }
 
+static DEFINE_SPINLOCK(kmsg_sys_list_lock);
+
+int kmsg_sys_buffer_add(size_t size, umode_t mode)
+{
+	unsigned long flags;
+	int minor = log_buf.minor;
+	struct log_buffer *log_b;
+	struct log_buffer *log_b_new;
+
+	if (size < LOG_LINE_MAX + PREFIX_MAX)
+		return -EINVAL;
+
+	log_b_new = kzalloc(sizeof(struct log_buffer), GFP_KERNEL);
+	if (!log_b_new)
+		return -ENOMEM;
+
+	log_b_new->buf = kmalloc(size, GFP_KERNEL);
+	if (!log_b_new->buf) {
+		kfree(log_b_new);
+		return -ENOMEM;
+	}
+
+	log_b_new->len = size;
+	log_b_new->lock = __RAW_SPIN_LOCK_UNLOCKED(log_b_new->lock);
+	init_waitqueue_head(&log_b_new->wait);
+	kref_init(&log_b_new->refcount);
+	log_b_new->mode = mode;
+
+	kref_get(&log_b_new->refcount);
+
+	spin_lock_irqsave(&kmsg_sys_list_lock, flags);
+
+	list_for_each_entry(log_b, &log_buf.list, list) {
+		if (log_b->minor - minor > 1)
+			break;
+
+		minor = log_b->minor;
+	}
+
+	if (!(minor & MINORMASK)) {
+		kref_put(&log_b->refcount, log_buf_release);
+		spin_unlock_irqrestore(&kmsg_sys_list_lock, flags);
+		return -ERANGE;
+	}
+
+	minor += 1;
+	log_b_new->minor = minor;
+
+	list_add_tail_rcu(&log_b_new->list, &log_b->list);
+
+	spin_unlock_irqrestore(&kmsg_sys_list_lock, flags);
+
+	return minor;
+}
+
+void kmsg_sys_buffer_del(int minor)
+{
+	unsigned long flags;
+	struct log_buffer *log_b;
+
+	spin_lock_irqsave(&kmsg_sys_list_lock, flags);
+
+	list_for_each_entry(log_b, &log_buf.list, list) {
+		if (log_b->minor == minor)
+			break;
+	}
+
+	if (log_b == &log_buf) {
+		spin_unlock_irqrestore(&kmsg_sys_list_lock, flags);
+		return;
+	}
+
+	list_del_rcu(&log_b->list);
+
+	spin_unlock_irqrestore(&kmsg_sys_list_lock, flags);
+
+	log_b->minor = -1;
+	wake_up_interruptible(&log_b->wait);
+
+	kref_put(&log_b->refcount, log_buf_release);
+}
+
 static DEFINE_SPINLOCK(dump_list_lock);
 static LIST_HEAD(dump_list);
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d8626ee..fd5991d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -42,6 +42,8 @@
 #include <linux/irq_work.h>
 #include <linux/utsname.h>
 #include <linux/ctype.h>
+#include <linux/kref.h>
+#include <linux/slab.h>
 
 #include <asm/uaccess.h>
 #include <asm-generic/sections.h>
@@ -171,6 +173,7 @@ struct log_buffer log_buf = {
 	.len		= __LOG_BUF_K_LEN,
 	.lock		= __RAW_SPIN_LOCK_UNLOCKED(log_buf.lock),
 	.wait		= __WAIT_QUEUE_HEAD_INITIALIZER(log_buf.wait),
+	.refcount	= { .refcount = { .counter = 0 } },
 	.first_seq	= 0,
 	.first_idx	= 0,
 	.next_seq	= 0,
@@ -216,6 +219,15 @@ u32 log_buf_len_get(void)
 	return log_buf.len;
 }
 
+void log_buf_release(struct kref *ref)
+{
+	struct log_buffer *log_b = container_of(ref, struct log_buffer,
+						refcount);
+
+	kfree(log_b->buf);
+	kfree(log_b);
+}
+
 /*
  * Check whether there is enough free space for the given message.
  *
diff --git a/kernel/printk/printk.h b/kernel/printk/printk.h
index e5c8a46..a873c27 100644
--- a/kernel/printk/printk.h
+++ b/kernel/printk/printk.h
@@ -5,6 +5,7 @@
 #include <linux/spinlock_types.h>
 #include <linux/types.h>
 #include <linux/wait.h>
+#include <linux/kref.h>
 
 #ifdef CONFIG_PRINTK
 
@@ -111,6 +112,7 @@ struct log_buffer {
 	char *buf;		/* cyclic log buffer */
 	u32 len;		/* buffer length */
 	wait_queue_head_t wait;	/* wait queue for kmsg buffer */
+	struct kref refcount;	/* refcount for kmsg_sys buffers */
 #endif
 /*
  * The lock protects kmsg buffer, indices, counters. This can be taken within
@@ -139,6 +141,8 @@ struct log_buffer {
 
 extern struct log_buffer log_buf;
 
+void log_buf_release(struct kref *ref);
+
 ssize_t msg_print_ext_header(char *buf, size_t size,
 				    struct printk_log *msg, u64 seq,
 				    enum log_flags prev_flags);
-- 
1.9.1

[toc] | [prev] | [next] | [standalone]


#1341931 — [PATCH v6 2/8] printk: add one function for storing log in proper format

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-24 13:00 +0100
Subject[PATCH v6 2/8] printk: add one function for storing log in proper format
Message-ID<r5GgQ-3YX-45@gated-at.bofh.it>
In reply to#1341926
From: Marcin Niesluchowski <m.niesluchow@samsung.com>

Preparation commit for future changes purpose.

Separate code responsible for storing log message in proper format
from operations on consoles by putting it in another function.

Signed-off-by: Marcin Niesluchowski <m.niesluchow@samsung.com>
Signed-off-by: Paul Osmialowski <p.osmialowsk@samsung.com>
[Rebased kmsg patch v5 on Linux 4.5-rc5]
Signed-off-by: Kazimierz Krosman <k.krosman@samsung.com>
---
 kernel/printk/printk.c | 222 ++++++++++++++++++++++++++-----------------------
 1 file changed, 119 insertions(+), 103 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2787bc7..3653a8e 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -179,6 +179,27 @@ static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
 static char *log_buf = __log_buf;
 static u32 log_buf_len = __LOG_BUF_LEN;
 
+/*
+ * Continuation lines are buffered, and not committed to the record buffer
+ * until the line is complete, or a race forces it. The line fragments
+ * though, are printed immediately to the consoles to ensure everything has
+ * reached the console in case of a kernel crash.
+ */
+static struct cont {
+	char buf[LOG_LINE_MAX];
+	size_t len;			/* length == 0 means unused buffer */
+	size_t cons;			/* bytes written to console */
+	struct task_struct *owner;	/* task of first print*/
+	u64 ts_nsec;			/* time of first print */
+	u8 level;			/* log level of first message */
+	u8 facility;			/* log facility of first message */
+	enum log_flags flags;		/* prefix, newline flags */
+	bool flushed:1;			/* buffer sealed and committed */
+} cont;
+
+static void cont_flush(enum log_flags flags);
+static bool cont_add(int facility, int level, const char *text, size_t len);
+
 /* Return log buffer address */
 char *log_buf_addr_get(void)
 {
@@ -330,6 +351,102 @@ static int log_store(int facility, int level,
 	return msg->text_len;
 }
 
+static int log_format_and_store(int facility, int level,
+				const char *dict, size_t dictlen,
+				const char *fmt, va_list args)
+{
+	static char textbuf[LOG_LINE_MAX];
+	char *text = textbuf;
+	size_t text_len = 0;
+	enum log_flags lflags = 0;
+	int printed_len = 0;
+
+	/*
+	 * The printf needs to come first; we need the syslog
+	 * prefix which might be passed-in as a parameter.
+	 */
+	text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
+
+	/* mark and strip a trailing newline */
+	if (text_len && text[text_len-1] == '\n') {
+		text_len--;
+		lflags |= LOG_NEWLINE;
+	}
+
+	/* strip kernel syslog prefix and extract log level or control flags */
+	if (facility == 0) {
+		int kern_level = printk_get_level(text);
+
+		if (kern_level) {
+			const char *end_of_header = printk_skip_level(text);
+
+			switch (kern_level) {
+			case '0' ... '7':
+				if (level == LOGLEVEL_DEFAULT)
+					level = kern_level - '0';
+				/* fallthrough */
+			case 'd':	/* KERN_DEFAULT */
+				lflags |= LOG_PREFIX;
+			}
+			/*
+			 * No need to check length here because vscnprintf
+			 * put '\0' at the end of the string. Only valid and
+			 * newly printed level is detected.
+			 */
+			text_len -= end_of_header - text;
+			text = (char *)end_of_header;
+		}
+	}
+
+	if (level == LOGLEVEL_DEFAULT)
+		level = default_message_loglevel;
+
+	if (dict)
+		lflags |= LOG_PREFIX|LOG_NEWLINE;
+
+	if (!(lflags & LOG_NEWLINE)) {
+		/*
+		 * Flush the conflicting buffer. An earlier newline was missing,
+		 * or another task also prints continuation lines.
+		 */
+		if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
+			cont_flush(LOG_NEWLINE);
+
+		/* buffer line if possible, otherwise store it right away */
+		if (cont_add(facility, level, text, text_len))
+			printed_len += text_len;
+		else
+			printed_len += log_store(facility, level,
+						 lflags | LOG_CONT, 0,
+						 dict, dictlen, text, text_len);
+	} else {
+		bool stored = false;
+
+		/*
+		 * If an earlier newline was missing and it was the same task,
+		 * either merge it with the current buffer and flush, or if
+		 * there was a race with interrupts (prefix == true) then just
+		 * flush it out and store this line separately.
+		 * If the preceding printk was from a different task and missed
+		 * a newline, flush and append the newline.
+		 */
+		if (cont.len) {
+			if (cont.owner == current && !(lflags & LOG_PREFIX))
+				stored = cont_add(facility, level, text,
+						  text_len);
+			cont_flush(LOG_NEWLINE);
+		}
+
+		if (stored)
+			printed_len += text_len;
+		else
+			printed_len += log_store(facility, level,
+						 lflags, 0, dict, dictlen,
+						 text, text_len);
+	}
+	return printed_len;
+}
+
 int dmesg_restrict = IS_ENABLED(CONFIG_SECURITY_DMESG_RESTRICT);
 
 static int syslog_action_restricted(int type)
@@ -1164,24 +1281,6 @@ static inline void printk_delay(void)
 	}
 }
 
-/*
- * Continuation lines are buffered, and not committed to the record buffer
- * until the line is complete, or a race forces it. The line fragments
- * though, are printed immediately to the consoles to ensure everything has
- * reached the console in case of a kernel crash.
- */
-static struct cont {
-	char buf[LOG_LINE_MAX];
-	size_t len;			/* length == 0 means unused buffer */
-	size_t cons;			/* bytes written to console */
-	struct task_struct *owner;	/* task of first print*/
-	u64 ts_nsec;			/* time of first print */
-	u8 level;			/* log level of first message */
-	u8 facility;			/* log facility of first message */
-	enum log_flags flags;		/* prefix, newline flags */
-	bool flushed:1;			/* buffer sealed and committed */
-} cont;
-
 static void cont_flush(enum log_flags flags)
 {
 	if (cont.flushed)
@@ -1277,10 +1376,6 @@ asmlinkage int vprintk_emit(int facility, int level,
 			    const char *fmt, va_list args)
 {
 	static bool recursion_bug;
-	static char textbuf[LOG_LINE_MAX];
-	char *text = textbuf;
-	size_t text_len = 0;
-	enum log_flags lflags = 0;
 	unsigned long flags;
 	int this_cpu;
 	int printed_len = 0;
@@ -1334,87 +1429,8 @@ asmlinkage int vprintk_emit(int facility, int level,
 					 strlen(recursion_msg));
 	}
 
-	/*
-	 * The printf needs to come first; we need the syslog
-	 * prefix which might be passed-in as a parameter.
-	 */
-	text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
-
-	/* mark and strip a trailing newline */
-	if (text_len && text[text_len-1] == '\n') {
-		text_len--;
-		lflags |= LOG_NEWLINE;
-	}
-
-	/* strip kernel syslog prefix and extract log level or control flags */
-	if (facility == 0) {
-		int kern_level = printk_get_level(text);
-
-		if (kern_level) {
-			const char *end_of_header = printk_skip_level(text);
-			switch (kern_level) {
-			case '0' ... '7':
-				if (level == LOGLEVEL_DEFAULT)
-					level = kern_level - '0';
-				/* fallthrough */
-			case 'd':	/* KERN_DEFAULT */
-				lflags |= LOG_PREFIX;
-			}
-			/*
-			 * No need to check length here because vscnprintf
-			 * put '\0' at the end of the string. Only valid and
-			 * newly printed level is detected.
-			 */
-			text_len -= end_of_header - text;
-			text = (char *)end_of_header;
-		}
-	}
-
-	if (level == LOGLEVEL_DEFAULT)
-		level = default_message_loglevel;
-
-	if (dict)
-		lflags |= LOG_PREFIX|LOG_NEWLINE;
-
-	if (!(lflags & LOG_NEWLINE)) {
-		/*
-		 * Flush the conflicting buffer. An earlier newline was missing,
-		 * or another task also prints continuation lines.
-		 */
-		if (cont.len && (lflags & LOG_PREFIX || cont.owner != current))
-			cont_flush(LOG_NEWLINE);
-
-		/* buffer line if possible, otherwise store it right away */
-		if (cont_add(facility, level, text, text_len))
-			printed_len += text_len;
-		else
-			printed_len += log_store(facility, level,
-						 lflags | LOG_CONT, 0,
-						 dict, dictlen, text, text_len);
-	} else {
-		bool stored = false;
-
-		/*
-		 * If an earlier newline was missing and it was the same task,
-		 * either merge it with the current buffer and flush, or if
-		 * there was a race with interrupts (prefix == true) then just
-		 * flush it out and store this line separately.
-		 * If the preceding printk was from a different task and missed
-		 * a newline, flush and append the newline.
-		 */
-		if (cont.len) {
-			if (cont.owner == current && !(lflags & LOG_PREFIX))
-				stored = cont_add(facility, level, text,
-						  text_len);
-			cont_flush(LOG_NEWLINE);
-		}
-
-		if (stored)
-			printed_len += text_len;
-		else
-			printed_len += log_store(facility, level, lflags, 0,
-						 dict, dictlen, text, text_len);
-	}
+	printed_len += log_format_and_store(facility, level, dict, dictlen,
+					    fmt, args);
 
 	logbuf_cpu = UINT_MAX;
 	raw_spin_unlock(&logbuf_lock);
-- 
1.9.1

[toc] | [prev] | [next] | [standalone]


#1343506

FromTejun Heo <tj@kernel.org>
Date2016-02-25 22:50 +0100
Message-ID<r6bXk-1x8-11@gated-at.bofh.it>
In reply to#1341926
Hello, Kazimierz.

On Wed, Feb 24, 2016 at 12:53:13PM +0100, Kazimierz Krosman wrote:
> 1. kmsg device does not require maintenance by reader process side.
> Multiple writers can write to a device and new records overwrite logs saved earlier.
> When system crashes logs can be restored with pstore mechanism.

I'm not sure this is the right layer to implement generic logging
facility.

> 2. Using kmsg can cause lower CPU utilisation in the real-word use case than 
> userspace logging mechanisms.
> We created 2 tests: (1) 100 writer processes write to created kmsg buffer and
> (2) 100 writers write to socket (stream)- there is one reader to protect
> socket buffer against overflow. Tests show that cpu utilisation in case of first
> test is about 2.3 times lower (39.1%) than it is in second case (87.7%) (measured
> with top program; tests code is attached below). Tested on Odroid XU4.

This sounds like a generic IPC problem than anything else.

Thanks.

-- 
tejun

[toc] | [prev] | [next] | [standalone]


#1344244

FromKazimierz Krosman <k.krosman@samsung.com>
Date2016-02-26 14:30 +0100
Message-ID<r6qCZ-3Sx-1@gated-at.bofh.it>
In reply to#1343506
On 02/25/2016 10:47 PM, Tejun Heo wrote:
> I'm not sure this is the right layer to implement generic logging
> facility.
In general this patches add only one feature- possibility of adding and 
deleting
new kmsg devices, so I think that it can be treated as kmsg upgrade.
>> 2. Using kmsg can cause lower CPU utilisation in the real-word use case than
>> >userspace logging mechanisms.
>> >We created 2 tests: (1) 100 writer processes write to created kmsg buffer and
>> >(2) 100 writers write to socket (stream)- there is one reader to protect
>> >socket buffer against overflow. Tests show that cpu utilisation in case of first
>> >test is about 2.3 times lower (39.1%) than it is in second case (87.7%) (measured
>> >with top program; tests code is attached below). Tested on Odroid XU4.
> This sounds like a generic IPC problem than anything else.

For the test purpose I've written two tests (attached in cover letter). 
I think that tests
show that in this use case (multiple writers) system with additional 
kmsg devices
consumes less CPU time than system which use sockets for logging. 
Logging system
based on sockets needs read process, that continuously reads socket and 
protects
against socket buffers overflow and messages drop. It is one of 
advantages of this
solution: no maintenance.

Could you explain in more detail what did you mean by IPC problems?

Thanks.

-- 
Kazimierz Krosman

Samsung R&D Institute Poland
Samsung Electronics
k.krosman@samsung.com

  

[toc] | [prev] | [next] | [standalone]


#1344315

FromPetr Mladek <pmladek@suse.com>
Date2016-02-26 15:50 +0100
Message-ID<r6rSq-4HT-11@gated-at.bofh.it>
In reply to#1344244
On Fri 2016-02-26 14:22:42, Kazimierz Krosman wrote:
> On 02/25/2016 10:47 PM, Tejun Heo wrote:
> >I'm not sure this is the right layer to implement generic logging
> >facility.
> In general this patches add only one feature- possibility of adding
> and deleting
> new kmsg devices, so I think that it can be treated as kmsg upgrade.
> >>2. Using kmsg can cause lower CPU utilisation in the real-word use case than
> >>>userspace logging mechanisms.
> >>>We created 2 tests: (1) 100 writer processes write to created kmsg buffer and
> >>>(2) 100 writers write to socket (stream)- there is one reader to protect
> >>>socket buffer against overflow. Tests show that cpu utilisation in case of first
> >>>test is about 2.3 times lower (39.1%) than it is in second case (87.7%) (measured
> >>>with top program; tests code is attached below). Tested on Odroid XU4.
> >This sounds like a generic IPC problem than anything else.
> 
> For the test purpose I've written two tests (attached in cover
> letter). I think that tests
> show that in this use case (multiple writers) system with additional
> kmsg devices
> consumes less CPU time than system which use sockets for logging.
> Logging system
> based on sockets needs read process, that continuously reads socket
> and protects
> against socket buffers overflow and messages drop. It is one of
> advantages of this
> solution: no maintenance.

Wait. The net addition of this patch set is 1755 lines out of it
526 lines seems to be in non-test code. You added another level
of complexity into the handling of the ring buffer(s). And it will
require no maintenance?


> Could you explain in more detail what did you mean by IPC problems?

I guess that the idea was to make IPC more effective in general.
You definitely could not move all functionality that needs IPC
into the kernel.

Best Regards,
Petr

[toc] | [prev] | [next] | [standalone]


#1345002

FromTejun Heo <tj@kernel.org>
Date2016-02-27 13:00 +0100
Message-ID<r6LHs-2pp-11@gated-at.bofh.it>
In reply to#1344315
Hello,

On Fri, Feb 26, 2016 at 03:47:18PM +0100, Petr Mladek wrote:
> > Could you explain in more detail what did you mean by IPC problems?
> 
> I guess that the idea was to make IPC more effective in general.
> You definitely could not move all functionality that needs IPC
> into the kernel.

1. There are multiple ways to do IPC and I don't think what was
   implemented as the comparison is optimal.

2. If that were optimal, we have an a lot larger general IPC problem
   than logging.  We can't possibly implement custom solution for each
   specific IPC use case in kernel.

Thanks.

-- 
tejun

[toc] | [prev] | [next] | [standalone]


#1344277 — Re: [PATCH v6 3/8] kmsg: introduce additional kmsg devices support

FromPetr Mladek <pmladek@suse.com>
Date2016-02-26 15:10 +0100
SubjectRe: [PATCH v6 3/8] kmsg: introduce additional kmsg devices support
Message-ID<r6rfI-4re-29@gated-at.bofh.it>
In reply to#1341926
On Wed 2016-02-24 12:53:16, Kazimierz Krosman wrote:
> From: Marcin Niesluchowski <m.niesluchow@samsung.com>
> 
> kmsg device provides operations on cyclic logging buffer used mainly
> by kernel but also in userspace by privileged processes.
> 
> Additional kmsg devices keep the same log format but may be added
> dynamically with custom size.
> 
> Signed-off-by: Marcin Niesluchowski <m.niesluchow@samsung.com>
> Signed-off-by: Paul Osmialowski <p.osmialowsk@samsung.com>
> [Rebased kmsg patch v5 on Linux 4.5-rc5]
> Signed-off-by: Kazimierz Krosman <k.krosman@samsung.com>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 3653a8e..b99403b 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -584,9 +595,11 @@ ssize_t msg_print_ext_body(char *buf, size_t size,
>  void log_buf_kexec_setup(void)
>  {
>  	VMCOREINFO_SYMBOL(log_buf);
> -	VMCOREINFO_SYMBOL(log_buf_len);
> -	VMCOREINFO_SYMBOL(log_first_idx);
> -	VMCOREINFO_SYMBOL(log_next_idx);
> +	VMCOREINFO_STRUCT_SIZE(log_buffer);
> +	VMCOREINFO_OFFSET(log_buffer, buf);
> +	VMCOREINFO_OFFSET(log_buffer, len);
> +	VMCOREINFO_OFFSET(log_buffer, first_idx);
> +	VMCOREINFO_OFFSET(log_buffer, next_idx);

This breaks makedumpfile, crash and possibly other tools
that use this information to access the log buffer.

Best Regards,
Petr

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web