source: ksyslog/trunk/ksyslog.c @ 241

/*
 * ksyslog: In-kernel syslog receiver 
 * Copyright(C) 2013 Atzm WATANABE All rights reserved
 * Distributed under the GPL
 */

#include <linux/module.h>
#include <linux/ip.h>
#include <linux/udp.h>
#include <linux/namei.h>
#include <net/udp.h>
#include "ksyslog.h"

static DEFINE_SPINLOCK(ksyslog_queue_lock);
static DEFINE_SPINLOCK(ksyslog_vfs_lock);

static struct socket *ksyslog_rcv_sk = NULL;

static struct delayed_work ksyslog_work;
static struct workqueue_struct *ksyslog_wq = NULL;

static struct ksyslog_queue ksyslog_queue;

#ifdef CONFIG_PROC_FS
static struct proc_dir_entry *ksyslog_procdir = NULL;
static struct proc_dir_entry *ksyslog_proc_queue = NULL;
static struct proc_dir_entry *ksyslog_proc_nr_queued = NULL;
static struct proc_dir_entry *ksyslog_proc_nr_written = NULL;
static struct proc_dir_entry *ksyslog_proc_nr_dropped = NULL;
#endif

static char *ksyslog_host = "0.0.0.0";
static ushort ksyslog_port = 514;
static char *ksyslog_path = "/var/log/ksyslog.log";
static ulong ksyslog_queue_length = 2048;
static ulong ksyslog_flush_interval = 45;  /* milliseconds */

module_param(ksyslog_host, charp, 0444);
module_param(ksyslog_port, ushort, 0444);
module_param(ksyslog_path, charp, 0644);
module_param(ksyslog_queue_length, ulong, 0644);
module_param(ksyslog_flush_interval, ulong, 0644);

static void
ksyslog_queue_init(struct ksyslog_queue *queue)
{
        memset(queue, 0, sizeof(*queue));
        INIT_LIST_HEAD(&queue->head);
        atomic64_set(&queue->nr_queued, 0);
        atomic64_set(&queue->nr_written, 0);
        atomic64_set(&queue->nr_dropped, 0);
}

static int
ksyslog_close(struct file *file)
{
        return filp_close(file, NULL);
}

static struct file *
ksyslog_open(const char *path)
{
        struct file *file;
        struct nameidata nd;
        mm_segment_t oldfs;

        oldfs = get_fs();
        set_fs(get_ds());

        if (unlikely(path_lookup(path, LOOKUP_OPEN|LOOKUP_FOLLOW, &nd)))
                file = filp_open(path, O_CREAT|O_WRONLY|O_APPEND|O_LARGEFILE, 0600);
        else
                file = filp_open(path, O_WRONLY|O_APPEND|O_LARGEFILE, 0);

        if (unlikely(IS_ERR(file)))
                goto out;

        if (unlikely(S_ISDIR(file->f_path.dentry->d_inode->i_mode))) {
                ksyslog_close(file);
                file = ERR_PTR(-EISDIR);
                goto out;
        }

        if (unlikely(file->f_pos < 0)) {
                ksyslog_close(file);
                file = ERR_PTR(-EIO);
                goto out;
        }

out:
        set_fs(oldfs);
        return file;
}

static int
ksyslog_write(struct file *file, const char *buf, const size_t length)
{
        int err;
        mm_segment_t oldfs;

        oldfs = get_fs();
        set_fs(get_ds());

        err = vfs_write(file, (__force void __user *)buf, length, &file->f_pos);

        set_fs(oldfs);
        return err;
}

static void
ksyslog_drop_warning(const struct ksyslog_entry *entry)
{
        pr_warn("dropped: %llu %s.%s %u.%u.%u.%u %.*s\n",
                timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
                ksyslog_facility_str(entry->facility),
                ksyslog_severity_str(entry->severity),
                entry->saddr.addr8[0], entry->saddr.addr8[1],
                entry->saddr.addr8[2], entry->saddr.addr8[3],
                (int)entry->length, entry->data);
}

static int
ksyslog_format(char **buf, const struct ksyslog_entry *entry)
{
        *buf = kzalloc(54 + entry->length + 2, GFP_ATOMIC);
        if (unlikely(*buf == NULL))
                return -ENOMEM;

        return sprintf(*buf, "%llu %s.%s %u.%u.%u.%u %.*s\n",
                       timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
                       ksyslog_facility_str(entry->facility),
                       ksyslog_severity_str(entry->severity),
                       entry->saddr.addr8[0], entry->saddr.addr8[1],
                       entry->saddr.addr8[2], entry->saddr.addr8[3],
                       (int)entry->length, entry->data);
}

static struct ksyslog_entry *
ksyslog_entry_create(const struct sk_buff *skb,
                     const struct iphdr *iph, const struct udphdr *udph)
{
        struct ksyslog_entry *entry;
        unsigned int priority, facility, severity, month, day, hour, minute, second;
        unsigned char *start, month_s[4];
        struct tm tm;
        int length, i;

        if (sscanf(skb->data, "<%3u>%3s %2u %2u:%2u:%2u ",
                   &priority, month_s, &day, &hour, &minute, &second) != 6)
                return ERR_PTR(-EINVAL);

        start = memchr(skb->data, '>', 5);
        if (start == NULL)
                return ERR_PTR(-EINVAL);
        start++;

        facility = priority >> 3;
        severity = priority & 7;

        if (facility >= __KSYSLOG_F_MAX)
                return ERR_PTR(-EINVAL);
        if (severity >= __KSYSLOG_S_MAX)
                return ERR_PTR(-EINVAL);

        month = ksyslog_month_num(month_s);
        if (!month)
                return ERR_PTR(-EINVAL);
        if (day > 31)
                return ERR_PTR(-EINVAL);
        if (hour > 23)
                return ERR_PTR(-EINVAL);
        if (minute > 59)
                return ERR_PTR(-EINVAL);
        if (second > 59)
                return ERR_PTR(-EINVAL);

        entry = kzalloc(sizeof(*entry), GFP_ATOMIC);
        if (unlikely(entry == NULL))
                return ERR_PTR(-ENOMEM);

        length = skb->len - (start - skb->data);
        entry->data = kzalloc(length, GFP_ATOMIC);
        if (unlikely(entry->data == NULL)) {
                kfree(entry);
                return ERR_PTR(-ENOMEM);
        }

        if (skb->tstamp.tv64)
                entry->tv = ktime_to_timeval(skb->tstamp);
        else
                do_gettimeofday(&entry->tv);

        time_to_tm(entry->tv.tv_sec, 0, &tm);
        entry->time = mktime(tm.tm_year + 1900, month, day, hour, minute, second);

        entry->priority = priority;
        entry->facility = facility;
        entry->severity = severity;

        entry->daddr.addr32 = iph->daddr;
        entry->saddr.addr32 = iph->saddr;

        entry->dport = udph->dest;
        entry->sport = udph->source;

        entry->length = length;
        memcpy(entry->data, start, length);

        for (i = 0; i < length; i++)
                if (unlikely(entry->data[i] == '\n'))
                        entry->data[i] = ' ';

        INIT_RCU_HEAD(&entry->rcu);
        return entry;
}

static void
ksyslog_entry_free(struct rcu_head *head)
{
        struct ksyslog_entry *entry = container_of(head, struct ksyslog_entry, rcu);
        kfree(entry->data);
        kfree(entry);
}

static int
ksyslog_entry_add(struct ksyslog_queue *queue, struct ksyslog_entry *entry)
{
        if (unlikely(atomic64_read(&queue->nr_queued) >= ksyslog_queue_length))
                return -ENOBUFS;
        list_add_tail_rcu(&entry->list, &queue->head);
        WARN_ON(atomic64_inc_return(&queue->nr_queued) > ksyslog_queue_length);
        return 0;
}

static void
ksyslog_entry_del(struct ksyslog_queue *queue, struct ksyslog_entry *entry, bool free)
{
        WARN_ON(atomic64_dec_return(&queue->nr_queued) < 0);
        list_del_rcu(&entry->list);
        if (free)
                call_rcu(&entry->rcu, ksyslog_entry_free);
}

static void
ksyslog_entry_destroy(struct ksyslog_queue *queue)
{
        struct ksyslog_entry *entry, *next;

        list_for_each_entry_safe(entry, next, &queue->head, list)
                ksyslog_entry_del(queue, entry, true);
}

static void
ksyslog_entry_migrate(struct ksyslog_queue *from, struct ksyslog_queue *to)
{
        struct ksyslog_entry *entry, *next;

        list_for_each_entry_safe(entry, next, &from->head, list) {
                ksyslog_entry_del(from, entry, false);
                if (unlikely(ksyslog_entry_add(to, entry))) {
                        atomic64_inc(&from->nr_dropped);
                        atomic64_inc(&to->nr_dropped);
                        ksyslog_drop_warning(entry);
                        call_rcu(&entry->rcu, ksyslog_entry_free);
                }
        }
}

static void
ksyslog_work_register(unsigned long timer)
{
        queue_delayed_work(ksyslog_wq, &ksyslog_work, timer * HZ / 1000);
}

static void
ksyslog_work_unregister(void)
{
        cancel_delayed_work_sync(&ksyslog_work);
}

static void
ksyslog_work_handler(struct work_struct *work)
{
        struct file *file = NULL;
        struct ksyslog_entry *entry, *next;
        struct ksyslog_queue write_queue;

        ksyslog_queue_init(&write_queue);

        spin_lock_bh(&ksyslog_queue_lock);
        ksyslog_entry_migrate(&ksyslog_queue, &write_queue);
        spin_unlock_bh(&ksyslog_queue_lock);

        if (atomic64_read(&write_queue.nr_queued) <= 0)
                goto out;

        spin_lock(&ksyslog_vfs_lock);

        file = ksyslog_open(ksyslog_path);
        if (unlikely(IS_ERR(file))) {
                spin_unlock(&ksyslog_vfs_lock);

                spin_lock_bh(&ksyslog_queue_lock);
                ksyslog_entry_migrate(&write_queue, &ksyslog_queue);
                spin_unlock_bh(&ksyslog_queue_lock);

                goto out;
        }

        list_for_each_entry_safe(entry, next, &write_queue.head, list) {
                int length;
                char *buf;

                ksyslog_entry_del(&write_queue, entry, false);

                length = ksyslog_format(&buf, entry);
                if (unlikely(length < 0))
                        goto restore;

                if (unlikely(ksyslog_write(file, buf, length) < 0)) {
                        kfree(buf);
                        goto restore;
                }

                atomic64_inc(&ksyslog_queue.nr_written);
                kfree(buf);
                call_rcu(&entry->rcu, ksyslog_entry_free);
                continue;

restore:
                spin_lock_bh(&ksyslog_queue_lock);
                if (unlikely(ksyslog_entry_add(&ksyslog_queue, entry))) {
                        atomic64_inc(&ksyslog_queue.nr_dropped);
                        ksyslog_drop_warning(entry);
                        call_rcu(&entry->rcu, ksyslog_entry_free);
                }
                spin_unlock_bh(&ksyslog_queue_lock);
        }

        ksyslog_close(file);
        spin_unlock(&ksyslog_vfs_lock);

out:
        ksyslog_work_register(ksyslog_flush_interval);
}

static int
ksyslog_rcv(struct sock *sk, struct sk_buff *skb)
{
        int err;
        struct iphdr *iph;
        struct udphdr *udph;
        struct ksyslog_entry *entry;

        if (unlikely(skb_linearize(skb)))
                goto err;

        iph = ip_hdr(skb);
        udph = udp_hdr(skb);

        if (unlikely(!skb_pull(skb, sizeof(*udph))))
                goto err;

        entry = ksyslog_entry_create(skb, iph, udph);
        if (unlikely(IS_ERR(entry)))
                goto err;

        spin_lock_bh(&ksyslog_queue_lock);
        err = ksyslog_entry_add(&ksyslog_queue, entry);
        spin_unlock_bh(&ksyslog_queue_lock);

        if (unlikely(err)) {
                ksyslog_drop_warning(entry);
                ksyslog_entry_free(&entry->rcu);
                goto err;
        }

out:
        consume_skb(skb);
        return 0;

err:
        atomic64_inc(&ksyslog_queue.nr_dropped);
        goto out;
}

#ifdef CONFIG_PROC_FS
static void *
ksyslog_rculist_seq_start(struct seq_file *seq, loff_t *pos)
{
        struct list_head *lh, *head = seq->private;
        loff_t ppos = *pos;

        rcu_read_lock();

        __list_for_each_rcu(lh, head)
                if (ppos-- == 0)
                        return lh;

        return NULL;
}

static void *
ksyslog_rculist_seq_next(struct seq_file *seq, void *v, loff_t *pos)
{
        struct list_head *lh = rcu_dereference(((struct list_head *)v)->next);
        ++(*pos);
        return lh == seq->private ? NULL : lh;
}

static void
ksyslog_rculist_seq_stop(struct seq_file *seq, void *v)
{
        rcu_read_unlock();
}

static int
ksyslog_queue_seq_show(struct seq_file *seq, void *v)
{
        const struct ksyslog_entry *entry = list_entry_rcu(v, struct ksyslog_entry, list);

        seq_printf(seq, "%llu %s.%s %u.%u.%u.%u %.*s\n",
                   timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
                   ksyslog_facility_str(entry->facility),
                   ksyslog_severity_str(entry->severity),
                   entry->saddr.addr8[0], entry->saddr.addr8[1],
                   entry->saddr.addr8[2], entry->saddr.addr8[3],
                   (int)entry->length, entry->data);

        return 0;
}

static struct seq_operations ksyslog_queue_seq_ops = {
        .start = ksyslog_rculist_seq_start,
        .next  = ksyslog_rculist_seq_next,
        .stop  = ksyslog_rculist_seq_stop,
        .show  = ksyslog_queue_seq_show,
};

static int
ksyslog_queue_seq_open(struct inode *inode, struct file *file)
{
        int err = seq_open(file, &ksyslog_queue_seq_ops);

        if (!err)
                ((struct seq_file *)file->private_data)->private = PDE(inode)->data;

        return err;
}

static struct file_operations ksyslog_queue_fops = {
        .owner   = THIS_MODULE,
        .open    = ksyslog_queue_seq_open,
        .read    = seq_read,
        .llseek  = seq_lseek,
        .release = seq_release,
};

static int
ksyslog_nr_queued_seq_show(struct seq_file *seq, void *v)
{
        seq_printf(seq, "%lu\n", atomic64_read(&ksyslog_queue.nr_queued));
        return 0;
}

static int
ksyslog_nr_queued_seq_open(struct inode *inode, struct file *file)
{
        return single_open(file, ksyslog_nr_queued_seq_show, PDE(inode)->data);
}

static int
ksyslog_nr_written_seq_show(struct seq_file *seq, void *v)
{
        seq_printf(seq, "%lu\n", atomic64_read(&ksyslog_queue.nr_written));
        return 0;
}

static int
ksyslog_nr_written_seq_open(struct inode *inode, struct file *file)
{
        return single_open(file, ksyslog_nr_written_seq_show, PDE(inode)->data);
}

static int
ksyslog_nr_dropped_seq_show(struct seq_file *seq, void *v)
{
        seq_printf(seq, "%lu\n", atomic64_read(&ksyslog_queue.nr_dropped));
        return 0;
}

static int
ksyslog_nr_dropped_seq_open(struct inode *inode, struct file *file)
{
        return single_open(file, ksyslog_nr_dropped_seq_show, PDE(inode)->data);
}

static struct file_operations ksyslog_nr_queued_fops = {
        .owner   = THIS_MODULE,
        .open    = ksyslog_nr_queued_seq_open,
        .read    = seq_read,
        .llseek  = seq_lseek,
        .release = single_release,
};

static struct file_operations ksyslog_nr_written_fops = {
        .owner   = THIS_MODULE,
        .open    = ksyslog_nr_written_seq_open,
        .read    = seq_read,
        .llseek  = seq_lseek,
        .release = single_release,
};

static struct file_operations ksyslog_nr_dropped_fops = {
        .owner   = THIS_MODULE,
        .open    = ksyslog_nr_dropped_seq_open,
        .read    = seq_read,
        .llseek  = seq_lseek,
        .release = single_release,
};

static void
ksyslog_proc_destroy(void)
{
        if (ksyslog_proc_queue)
                remove_proc_entry(ksyslog_proc_queue->name, ksyslog_proc_queue->parent);
        ksyslog_proc_queue = NULL;

        if (ksyslog_proc_nr_queued)
                remove_proc_entry(ksyslog_proc_nr_queued->name, ksyslog_proc_nr_queued->parent);
        ksyslog_proc_nr_queued = NULL;

        if (ksyslog_proc_nr_written)
                remove_proc_entry(ksyslog_proc_nr_written->name, ksyslog_proc_nr_written->parent);
        ksyslog_proc_nr_written = NULL;

        if (ksyslog_proc_nr_dropped)
                remove_proc_entry(ksyslog_proc_nr_dropped->name, ksyslog_proc_nr_dropped->parent);
        ksyslog_proc_nr_dropped = NULL;

        if (ksyslog_procdir)
                remove_proc_entry(ksyslog_procdir->name, ksyslog_procdir->parent);
        ksyslog_procdir = NULL;
}

static int
ksyslog_proc_init(void)
{
        ksyslog_procdir = proc_mkdir("ksyslog", NULL);
        if (ksyslog_procdir == NULL) {
                pr_err("proc_mkdir failed\n");
                goto err;
        }

        ksyslog_proc_queue = proc_create_data("queue", S_IRUGO, ksyslog_procdir,
                                              &ksyslog_queue_fops, &ksyslog_queue.head);
        if (ksyslog_proc_queue == NULL) {
                pr_err("proc_create(queue) failed\n");
                goto err;
        }

        ksyslog_proc_nr_queued = proc_create("nr_queued", S_IRUGO, ksyslog_procdir,
                                              &ksyslog_nr_queued_fops);
        if (ksyslog_proc_nr_queued == NULL) {
                pr_err("proc_create(nr_queued) failed\n");
                goto err;
        }

        ksyslog_proc_nr_written = proc_create("nr_written", S_IRUGO, ksyslog_procdir,
                                              &ksyslog_nr_written_fops);
        if (ksyslog_proc_nr_written == NULL) {
                pr_err("proc_create(nr_written) failed\n");
                goto err;
        }

        ksyslog_proc_nr_dropped = proc_create("nr_dropped", S_IRUGO, ksyslog_procdir,
                                              &ksyslog_nr_dropped_fops);
        if (ksyslog_proc_nr_dropped == NULL) {
                pr_err("proc_create(nr_dropped) failed\n");
                goto err;
        }

        return 0;

err:
        ksyslog_proc_destroy();
        return -ENOMEM;
}
#endif

static void
ksyslog_finish(void)
{
        if (ksyslog_rcv_sk)
                sock_release(ksyslog_rcv_sk);
        ksyslog_rcv_sk = NULL;

        if (ksyslog_wq) {
                ksyslog_work_unregister();
                destroy_workqueue(ksyslog_wq);
        }
        ksyslog_wq = NULL;

#ifdef CONFIG_PROC_FS
        ksyslog_proc_destroy();
#endif

        ksyslog_entry_destroy(&ksyslog_queue);
        rcu_barrier();
}

static int __init
ksyslog_init(void)
{
        int err;
        struct sockaddr_in sin;

        ksyslog_queue_init(&ksyslog_queue);

#ifdef CONFIG_PROC_FS
        err = ksyslog_proc_init();
        if (err)
                goto err;
#endif

        ksyslog_wq = create_singlethread_workqueue("ksyslog");
        if (ksyslog_wq == NULL) {
                pr_err("create_workqueue failed\n");
                err = -ENOMEM;
                goto err;
        }

        INIT_DELAYED_WORK(&ksyslog_work, ksyslog_work_handler);

        err = sock_create(AF_INET, SOCK_DGRAM, 0, &ksyslog_rcv_sk);
        if (err) {
                pr_err("sock_create failed\n");
                goto err;
        }

        sin.sin_family = AF_INET;
        sin.sin_addr.s_addr = in_aton(ksyslog_host);
        sin.sin_port = htons(ksyslog_port);

        err = kernel_bind(ksyslog_rcv_sk, (struct sockaddr *)&sin,
                          sizeof(struct sockaddr_in));
        if (err) {
                pr_err("kernel_bind failed\n");
                goto err;
        }

        udp_sk(ksyslog_rcv_sk->sk)->encap_type = UDP_ENCAP_KSYSLOG;
        udp_sk(ksyslog_rcv_sk->sk)->encap_rcv = ksyslog_rcv;

        ksyslog_work_register(ksyslog_flush_interval);

        return 0;

err:
        ksyslog_finish();
        return err;
}

static void __exit
ksyslog_exit(void)
{
        ksyslog_finish();
}

module_init(ksyslog_init);
module_exit(ksyslog_exit);

MODULE_AUTHOR("Atzm WATANABE");
MODULE_DESCRIPTION("In-kernel syslog receiver");
MODULE_LICENSE("GPL");