source: ksyslog/trunk/ksyslog.c @ 250

Revision 250, 16.4 KB checked in by atzm, 11 years ago (diff)

optimize stats

Line 
1/*
2 * ksyslog: In-kernel syslog receiver
3 * Copyright(C) 2013 Atzm WATANABE All rights reserved
4 * Distributed under the GPL
5 */
6
7#include <linux/version.h>
8#include <linux/module.h>
9#include <linux/inet.h>
10#include <linux/ip.h>
11#include <linux/udp.h>
12#include <linux/namei.h>
13#include <linux/proc_fs.h>
14#include <linux/u64_stats_sync.h>
15#include <linux/percpu.h>
16#include <net/udp.h>
17#include "compat.h"
18#include "ksyslog.h"
19
20static DEFINE_SPINLOCK(ksyslog_vfs_lock);
21
22static struct ksyslog_queue ksyslog_queue;
23static struct socket *ksyslog_rcv_sk = NULL;
24
25static struct delayed_work ksyslog_work;
26static struct workqueue_struct *ksyslog_wq = NULL;
27
28#ifdef CONFIG_PROC_FS
29static struct proc_dir_entry *ksyslog_procdir = NULL;
30static struct proc_dir_entry *ksyslog_proc_queue = NULL;
31static struct proc_dir_entry *ksyslog_proc_size = NULL;
32static struct proc_dir_entry *ksyslog_proc_stats = NULL;
33#endif
34
35static char *ksyslog_host = "0.0.0.0";
36static ushort ksyslog_port = 514;
37static char *ksyslog_path = "/var/log/ksyslog.log";
38static ulong ksyslog_queue_size_max = 4096;
39static ulong ksyslog_flush_interval = 45;  /* milliseconds */
40
41module_param(ksyslog_host, charp, 0444);
42module_param(ksyslog_port, ushort, 0444);
43module_param(ksyslog_path, charp, 0644);
44module_param(ksyslog_queue_size_max, ulong, 0644);
45module_param(ksyslog_flush_interval, ulong, 0644);
46
47static int
48ksyslog_queue_init(struct ksyslog_queue *queue)
49{
50        memset(queue, 0, sizeof(*queue));
51        INIT_LIST_HEAD(&queue->head);
52        spin_lock_init(&queue->lock);
53        atomic64_set(&queue->size, 0);
54        queue->stats = alloc_percpu(struct ksyslog_stats);
55        if (unlikely(queue->stats == NULL))
56                return -ENOMEM;
57        return 0;
58}
59
60static void
61ksyslog_queue_uninit(struct ksyslog_queue *queue)
62{
63        if (likely(queue->stats))
64                free_percpu(queue->stats);
65        queue->stats = NULL;
66}
67
68static int
69ksyslog_close(struct file *file)
70{
71        return filp_close(file, NULL);
72}
73
74static struct file *
75ksyslog_open(const char *path)
76{
77        struct file *file;
78        struct path ppath;
79        mm_segment_t oldfs;
80
81        oldfs = get_fs();
82        set_fs(get_ds());
83
84        if (unlikely(kern_path(path, LOOKUP_OPEN|LOOKUP_FOLLOW, &ppath)))
85                file = filp_open(path, O_CREAT|O_WRONLY|O_APPEND|O_LARGEFILE, 0600);
86        else
87                file = filp_open(path, O_WRONLY|O_APPEND|O_LARGEFILE, 0);
88
89        if (unlikely(IS_ERR(file)))
90                goto out;
91
92        if (unlikely(S_ISDIR(file->f_path.dentry->d_inode->i_mode))) {
93                ksyslog_close(file);
94                file = ERR_PTR(-EISDIR);
95                goto out;
96        }
97
98        if (unlikely(file->f_pos < 0)) {
99                ksyslog_close(file);
100                file = ERR_PTR(-EIO);
101                goto out;
102        }
103
104out:
105        set_fs(oldfs);
106        return file;
107}
108
109static int
110ksyslog_write(struct file *file, const char *buf, const size_t length)
111{
112        int err;
113        mm_segment_t oldfs;
114
115        oldfs = get_fs();
116        set_fs(get_ds());
117
118        err = vfs_write(file, (__force void __user *)buf, length, &file->f_pos);
119
120        set_fs(oldfs);
121        return err;
122}
123
124static void
125ksyslog_drop_warning(const struct ksyslog_entry *entry)
126{
127        pr_warn("ksyslog: dropped: %llu %s.%s %u.%u.%u.%u %.*s\n",
128                timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
129                ksyslog_facility_str(entry->facility),
130                ksyslog_severity_str(entry->severity),
131                entry->saddr.addr8[0], entry->saddr.addr8[1],
132                entry->saddr.addr8[2], entry->saddr.addr8[3],
133                (int)entry->length, entry->data);
134}
135
136static int
137ksyslog_format(char **buf, const struct ksyslog_entry *entry)
138{
139        *buf = kzalloc(54 + entry->length + 2, GFP_ATOMIC);
140        if (unlikely(*buf == NULL))
141                return -ENOMEM;
142
143        return sprintf(*buf, "%llu %s.%s %u.%u.%u.%u %.*s\n",
144                       timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
145                       ksyslog_facility_str(entry->facility),
146                       ksyslog_severity_str(entry->severity),
147                       entry->saddr.addr8[0], entry->saddr.addr8[1],
148                       entry->saddr.addr8[2], entry->saddr.addr8[3],
149                       (int)entry->length, entry->data);
150}
151
152static struct ksyslog_entry *
153ksyslog_entry_create(const struct sk_buff *skb,
154                     const struct iphdr *iph, const struct udphdr *udph)
155{
156        struct ksyslog_entry *entry;
157        unsigned int priority, facility, severity, month, day, hour, minute, second;
158        unsigned char *start, month_s[4];
159        struct tm tm;
160        int length, i;
161
162        if (sscanf(skb->data, "<%3u>%3s %2u %2u:%2u:%2u ",
163                   &priority, month_s, &day, &hour, &minute, &second) != 6)
164                return ERR_PTR(-EINVAL);
165
166        start = memchr(skb->data, '>', 5);
167        if (start == NULL)
168                return ERR_PTR(-EINVAL);
169        start++;
170
171        facility = priority >> 3;
172        severity = priority & 7;
173
174        if (facility >= __KSYSLOG_F_MAX)
175                return ERR_PTR(-EINVAL);
176        if (severity >= __KSYSLOG_S_MAX)
177                return ERR_PTR(-EINVAL);
178
179        month = ksyslog_month_num(month_s);
180        if (!month)
181                return ERR_PTR(-EINVAL);
182        if (day > 31)
183                return ERR_PTR(-EINVAL);
184        if (hour > 23)
185                return ERR_PTR(-EINVAL);
186        if (minute > 59)
187                return ERR_PTR(-EINVAL);
188        if (second > 59)
189                return ERR_PTR(-EINVAL);
190
191        entry = kzalloc(sizeof(*entry), GFP_ATOMIC);
192        if (unlikely(entry == NULL))
193                return ERR_PTR(-ENOMEM);
194
195        length = skb->len - (start - skb->data);
196        entry->data = kzalloc(length, GFP_ATOMIC);
197        if (unlikely(entry->data == NULL)) {
198                kfree(entry);
199                return ERR_PTR(-ENOMEM);
200        }
201
202        if (skb->tstamp.tv64)
203                entry->tv = ktime_to_timeval(skb->tstamp);
204        else
205                do_gettimeofday(&entry->tv);
206
207        time_to_tm(entry->tv.tv_sec, 0, &tm);
208        entry->time = mktime(tm.tm_year + 1900, month, day, hour, minute, second);
209
210        entry->priority = priority;
211        entry->facility = facility;
212        entry->severity = severity;
213
214        entry->daddr.addr32 = iph->daddr;
215        entry->saddr.addr32 = iph->saddr;
216
217        entry->dport = udph->dest;
218        entry->sport = udph->source;
219
220        entry->length = length;
221        memcpy(entry->data, start, length);
222
223        for (i = 0; i < length; i++)
224                if (unlikely(entry->data[i] == '\n'))
225                        entry->data[i] = ' ';
226
227        return entry;
228}
229
230static void
231ksyslog_entry_free(struct rcu_head *head)
232{
233        struct ksyslog_entry *entry = container_of(head, struct ksyslog_entry, rcu);
234        kfree(entry->data);
235        kfree(entry);
236}
237
238static int
239ksyslog_entry_add(struct ksyslog_queue *queue, struct ksyslog_entry *entry)
240{
241        if (unlikely(atomic64_read(&queue->size) >= ksyslog_queue_size_max))
242                return -ENOBUFS;
243        list_add_tail_rcu(&entry->list, &queue->head);
244        WARN_ON(atomic64_inc_return(&queue->size) > ksyslog_queue_size_max);
245        return 0;
246}
247
248static void
249ksyslog_entry_del(struct ksyslog_queue *queue, struct ksyslog_entry *entry, bool free)
250{
251        WARN_ON(atomic64_dec_return(&queue->size) < 0);
252        list_del_rcu(&entry->list);
253        if (free)
254                call_rcu(&entry->rcu, ksyslog_entry_free);
255}
256
257static void
258ksyslog_entry_destroy(struct ksyslog_queue *queue)
259{
260        struct ksyslog_entry *entry, *next;
261
262        list_for_each_entry_safe(entry, next, &queue->head, list)
263                ksyslog_entry_del(queue, entry, true);
264}
265
266static void
267ksyslog_entry_migrate(struct ksyslog_queue *from, struct ksyslog_queue *to)
268{
269        struct ksyslog_entry *entry, *next;
270
271        list_for_each_entry_safe(entry, next, &from->head, list) {
272                ksyslog_entry_del(from, entry, false);
273                if (unlikely(ksyslog_entry_add(to, entry))) {
274                        ksyslog_stats_add_drop(from, entry->length);
275                        ksyslog_stats_add_drop(to, entry->length);
276                        ksyslog_drop_warning(entry);
277                        call_rcu(&entry->rcu, ksyslog_entry_free);
278                }
279        }
280}
281
282static void
283ksyslog_work_register(unsigned long timer)
284{
285        queue_delayed_work(ksyslog_wq, &ksyslog_work, timer * HZ / 1000);
286}
287
288static void
289ksyslog_work_unregister(void)
290{
291        cancel_delayed_work_sync(&ksyslog_work);
292}
293
294static void
295ksyslog_work_handler(struct work_struct *work)
296{
297        struct file *file = NULL;
298        struct ksyslog_entry *entry, *next;
299        struct ksyslog_queue write_queue;
300
301        if (ksyslog_queue_init(&write_queue))
302                goto out;
303
304        spin_lock_bh(&ksyslog_queue.lock);
305        ksyslog_entry_migrate(&ksyslog_queue, &write_queue);
306        spin_unlock_bh(&ksyslog_queue.lock);
307
308        if (atomic64_read(&write_queue.size) <= 0)
309                goto out;
310
311        spin_lock(&ksyslog_vfs_lock);
312
313        file = ksyslog_open(ksyslog_path);
314        if (unlikely(IS_ERR(file))) {
315                spin_unlock(&ksyslog_vfs_lock);
316
317                spin_lock_bh(&ksyslog_queue.lock);
318                ksyslog_entry_migrate(&write_queue, &ksyslog_queue);
319                spin_unlock_bh(&ksyslog_queue.lock);
320
321                goto out;
322        }
323
324        list_for_each_entry_safe(entry, next, &write_queue.head, list) {
325                int length;
326                char *buf;
327
328                ksyslog_entry_del(&write_queue, entry, false);
329
330                length = ksyslog_format(&buf, entry);
331                if (unlikely(length < 0))
332                        goto restore;
333
334                if (unlikely(ksyslog_write(file, buf, length) != length)) {
335                        kfree(buf);
336                        goto restore;
337                }
338
339                ksyslog_stats_add_write(&ksyslog_queue, entry->length);
340                kfree(buf);
341                call_rcu(&entry->rcu, ksyslog_entry_free);
342                continue;
343
344restore:
345                spin_lock_bh(&ksyslog_queue.lock);
346                if (unlikely(ksyslog_entry_add(&ksyslog_queue, entry))) {
347                        ksyslog_stats_add_drop(&ksyslog_queue, entry->length);
348                        ksyslog_drop_warning(entry);
349                        call_rcu(&entry->rcu, ksyslog_entry_free);
350                }
351                spin_unlock_bh(&ksyslog_queue.lock);
352        }
353
354        ksyslog_close(file);
355        spin_unlock(&ksyslog_vfs_lock);
356
357out:
358        ksyslog_queue_uninit(&write_queue);
359        ksyslog_work_register(ksyslog_flush_interval);
360}
361
362static int
363ksyslog_rcv(struct sock *sk, struct sk_buff *skb)
364{
365        int err;
366        struct iphdr *iph;
367        struct udphdr *udph;
368        struct ksyslog_entry *entry;
369
370        if (unlikely(skb_linearize(skb))) {
371                ksyslog_stats_add_drop(&ksyslog_queue, skb->len);
372                goto out;
373        }
374
375        iph = ip_hdr(skb);
376        udph = udp_hdr(skb);
377
378        if (unlikely(!skb_pull(skb, sizeof(*udph)))) {
379                ksyslog_stats_add_drop(&ksyslog_queue, skb->len);
380                goto out;
381        }
382
383        entry = ksyslog_entry_create(skb, iph, udph);
384        if (unlikely(IS_ERR(entry))) {
385                if (PTR_ERR(entry) == -EINVAL) {
386                        ksyslog_stats_add_discard(&ksyslog_queue, skb->len);
387                        goto out;
388                }
389
390                ksyslog_stats_add_drop(&ksyslog_queue, skb->len);
391                goto out;
392        }
393
394        spin_lock_bh(&ksyslog_queue.lock);
395        err = ksyslog_entry_add(&ksyslog_queue, entry);
396        spin_unlock_bh(&ksyslog_queue.lock);
397
398        if (unlikely(err)) {
399                ksyslog_stats_add_drop(&ksyslog_queue, entry->length);
400                ksyslog_drop_warning(entry);
401                ksyslog_entry_free(&entry->rcu);
402                goto out;
403        }
404
405out:
406        consume_skb(skb);
407        return 0;
408}
409
410#ifdef CONFIG_PROC_FS
411static void *
412ksyslog_rculist_seq_start(struct seq_file *seq, loff_t *pos)
413{
414        struct list_head *lh, *head = seq->private;
415        loff_t ppos = *pos;
416
417        rcu_read_lock();
418
419        __list_for_each_rcu(lh, head)
420                if (ppos-- == 0)
421                        return lh;
422
423        return NULL;
424}
425
426static void *
427ksyslog_rculist_seq_next(struct seq_file *seq, void *v, loff_t *pos)
428{
429        struct list_head *lh = rcu_dereference(((struct list_head *)v)->next);
430        ++(*pos);
431        return lh == seq->private ? NULL : lh;
432}
433
434static void
435ksyslog_rculist_seq_stop(struct seq_file *seq, void *v)
436{
437        rcu_read_unlock();
438}
439
440static int
441ksyslog_queue_seq_show(struct seq_file *seq, void *v)
442{
443        const struct ksyslog_entry *entry = list_entry_rcu(v, struct ksyslog_entry, list);
444
445        seq_printf(seq, "%llu %s.%s %u.%u.%u.%u %.*s\n",
446                   timeval_to_ns(&entry->tv) / 1000 / 1000 / 1000,
447                   ksyslog_facility_str(entry->facility),
448                   ksyslog_severity_str(entry->severity),
449                   entry->saddr.addr8[0], entry->saddr.addr8[1],
450                   entry->saddr.addr8[2], entry->saddr.addr8[3],
451                   (int)entry->length, entry->data);
452
453        return 0;
454}
455
456static struct seq_operations ksyslog_queue_seq_ops = {
457        .start = ksyslog_rculist_seq_start,
458        .next  = ksyslog_rculist_seq_next,
459        .stop  = ksyslog_rculist_seq_stop,
460        .show  = ksyslog_queue_seq_show,
461};
462
463static int
464ksyslog_queue_seq_open(struct inode *inode, struct file *file)
465{
466        int err = seq_open(file, &ksyslog_queue_seq_ops);
467
468        if (!err)
469                ((struct seq_file *)file->private_data)->private = PDE_DATA(inode);
470
471        return err;
472}
473
474static struct file_operations ksyslog_queue_fops = {
475        .owner   = THIS_MODULE,
476        .open    = ksyslog_queue_seq_open,
477        .read    = seq_read,
478        .llseek  = seq_lseek,
479        .release = seq_release,
480};
481
482static int
483ksyslog_size_seq_show(struct seq_file *seq, void *v)
484{
485        seq_printf(seq, "%lu\n", atomic64_read(&ksyslog_queue.size));
486        return 0;
487}
488
489static int
490ksyslog_size_seq_open(struct inode *inode, struct file *file)
491{
492        return single_open(file, ksyslog_size_seq_show, PDE_DATA(inode));
493}
494
495static int
496ksyslog_stats_seq_show(struct seq_file *seq, void *v)
497{
498        int i;
499        struct ksyslog_stats stats;
500
501        memset(&stats, 0, sizeof(stats));
502
503        for_each_possible_cpu(i) {
504                const struct ksyslog_stats *percpu_stats;
505                struct ksyslog_stats local_stats;
506                unsigned int start;
507
508                percpu_stats = per_cpu_ptr(ksyslog_queue.stats, i);
509
510                do {
511                        start = u64_stats_fetch_begin_bh(&percpu_stats->sync);
512                        local_stats = *percpu_stats;
513                } while (u64_stats_fetch_retry_bh(&percpu_stats->sync, start));
514
515                stats.write_bytes += local_stats.write_bytes;
516                stats.write_packets += local_stats.write_packets;
517                stats.drop_bytes += local_stats.drop_bytes;
518                stats.drop_packets += local_stats.drop_packets;
519                stats.discard_bytes += local_stats.discard_bytes;
520                stats.discard_packets += local_stats.discard_packets;
521        }
522
523        seq_puts(seq,   "{\n");
524        seq_puts(seq,   \"write\": {\n");
525        seq_printf(seq, "    \"bytes\":   \"%llu\",\n", stats.write_bytes);
526        seq_printf(seq, "    \"packets\": \"%llu\"\n", stats.write_packets);
527        seq_puts(seq,   "  },\n");
528        seq_puts(seq,   \"drop\": {\n");
529        seq_printf(seq, "    \"bytes\":   \"%llu\",\n", stats.drop_bytes);
530        seq_printf(seq, "    \"packets\": \"%llu\"\n", stats.drop_packets);
531        seq_puts(seq,   "  },\n");
532        seq_puts(seq,   \"discard\": {\n");
533        seq_printf(seq, "    \"bytes\":   \"%llu\",\n", stats.discard_bytes);
534        seq_printf(seq, "    \"packets\": \"%llu\"\n", stats.discard_packets);
535        seq_puts(seq,   "  }\n");
536        seq_puts(seq,   "}\n");
537
538        return 0;
539}
540
541static int
542ksyslog_stats_seq_open(struct inode *inode, struct file *file)
543{
544        return single_open(file, ksyslog_stats_seq_show, PDE_DATA(inode));
545}
546
547static struct file_operations ksyslog_size_fops = {
548        .owner   = THIS_MODULE,
549        .open    = ksyslog_size_seq_open,
550        .read    = seq_read,
551        .llseek  = seq_lseek,
552        .release = single_release,
553};
554
555static struct file_operations ksyslog_stats_fops = {
556        .owner   = THIS_MODULE,
557        .open    = ksyslog_stats_seq_open,
558        .read    = seq_read,
559        .llseek  = seq_lseek,
560        .release = single_release,
561};
562
563static void
564ksyslog_proc_destroy(void)
565{
566        if (ksyslog_proc_queue)
567                remove_proc_entry("queue", ksyslog_procdir);
568        ksyslog_proc_queue = NULL;
569
570        if (ksyslog_proc_size)
571                remove_proc_entry("size", ksyslog_procdir);
572        ksyslog_proc_size = NULL;
573
574        if (ksyslog_proc_stats)
575                remove_proc_entry("stats", ksyslog_procdir);
576        ksyslog_proc_stats = NULL;
577
578        if (ksyslog_procdir)
579                remove_proc_entry("ksyslog", NULL);
580        ksyslog_procdir = NULL;
581}
582
583static int
584ksyslog_proc_init(void)
585{
586        ksyslog_procdir = proc_mkdir("ksyslog", NULL);
587        if (ksyslog_procdir == NULL) {
588                pr_err("ksyslog: proc_mkdir failed\n");
589                goto err;
590        }
591
592        ksyslog_proc_queue = proc_create_data("queue", S_IRUGO, ksyslog_procdir,
593                                              &ksyslog_queue_fops, &ksyslog_queue.head);
594        if (ksyslog_proc_queue == NULL) {
595                pr_err("ksyslog: proc_create(queue) failed\n");
596                goto err;
597        }
598
599        ksyslog_proc_size = proc_create("size", S_IRUGO, ksyslog_procdir,
600                                        &ksyslog_size_fops);
601        if (ksyslog_proc_size == NULL) {
602                pr_err("ksyslog: proc_create(size) failed\n");
603                goto err;
604        }
605
606        ksyslog_proc_stats = proc_create("stats", S_IRUGO, ksyslog_procdir,
607                                         &ksyslog_stats_fops);
608        if (ksyslog_proc_stats == NULL) {
609                pr_err("ksyslog: proc_create(stats) failed\n");
610                goto err;
611        }
612
613        return 0;
614
615err:
616        ksyslog_proc_destroy();
617        return -ENOMEM;
618}
619#endif
620
621static void
622ksyslog_finish(void)
623{
624        if (ksyslog_rcv_sk)
625                sock_release(ksyslog_rcv_sk);
626        ksyslog_rcv_sk = NULL;
627
628        if (ksyslog_wq) {
629                ksyslog_work_unregister();
630                destroy_workqueue(ksyslog_wq);
631        }
632        ksyslog_wq = NULL;
633
634#ifdef CONFIG_PROC_FS
635        ksyslog_proc_destroy();
636#endif
637
638        ksyslog_entry_destroy(&ksyslog_queue);
639        rcu_barrier();
640
641        ksyslog_queue_uninit(&ksyslog_queue);
642}
643
644static int __init
645ksyslog_init(void)
646{
647        int err;
648        struct sockaddr_in sin;
649
650        err = ksyslog_queue_init(&ksyslog_queue);
651        if (err)
652                goto err;
653
654#ifdef CONFIG_PROC_FS
655        err = ksyslog_proc_init();
656        if (err)
657                goto err;
658#endif
659
660        ksyslog_wq = create_singlethread_workqueue("ksyslog");
661        if (ksyslog_wq == NULL) {
662                pr_err("ksyslog: create_workqueue failed\n");
663                err = -ENOMEM;
664                goto err;
665        }
666
667        INIT_DELAYED_WORK(&ksyslog_work, ksyslog_work_handler);
668
669        err = sock_create(AF_INET, SOCK_DGRAM, 0, &ksyslog_rcv_sk);
670        if (err) {
671                pr_err("ksyslog: sock_create failed\n");
672                goto err;
673        }
674
675        sin.sin_family = AF_INET;
676        sin.sin_addr.s_addr = in_aton(ksyslog_host);
677        sin.sin_port = htons(ksyslog_port);
678
679        err = kernel_bind(ksyslog_rcv_sk, (struct sockaddr *)&sin,
680                          sizeof(struct sockaddr_in));
681        if (err) {
682                pr_err("ksyslog: kernel_bind failed\n");
683                goto err;
684        }
685
686        ksyslog_work_register(ksyslog_flush_interval);
687
688        udp_sk(ksyslog_rcv_sk->sk)->encap_type = UDP_ENCAP_KSYSLOG;
689        udp_sk(ksyslog_rcv_sk->sk)->encap_rcv = ksyslog_rcv;
690        udp_encap_enable();
691
692        return 0;
693
694err:
695        ksyslog_finish();
696        return err;
697}
698
699static void __exit
700ksyslog_exit(void)
701{
702        ksyslog_finish();
703}
704
705module_init(ksyslog_init);
706module_exit(ksyslog_exit);
707
708MODULE_AUTHOR("Atzm WATANABE");
709MODULE_DESCRIPTION("In-kernel syslog receiver");
710MODULE_LICENSE("GPL");
Note: See TracBrowser for help on using the repository browser.