add simple nflog daemon
[pve-firewall.git] / src / pvefw-logger.c
1 /*
2
3   Copyright (C) 2014 Proxmox Server Solutions GmbH
4
5   This software is written by Proxmox Server Solutions GmbH <support@proxmox.com>
6
7   This program is free software: you can redistribute it and/or modify
8   it under the terms of the GNU Affero General Public License as published by
9   the Free Software Foundation, either version 3 of the License, or
10   (at your option) any later version.
11
12   This program is distributed in the hope that it will be useful,
13   but WITHOUT ANY WARRANTY; without even the implied warranty of
14   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15   GNU Affero General Public License for more details.
16
17   You should have received a copy of the GNU Affero General Public License
18   along with this program.  If not, see <http://www.gnu.org/licenses/>.
19
20   Author: Dietmar Maurer <dietmar@proxmox.com>
21
22 */
23
24 #define _GNU_SOURCE
25
26 #include <stdlib.h>
27 #include <stdio.h>
28 #include <errno.h>
29 #include <stdarg.h>
30 #include <string.h>
31 #include <signal.h>
32 #include <sys/types.h> 
33 #include <sys/stat.h>
34 #include <fcntl.h>
35 #include <unistd.h>
36 #include <arpa/inet.h>
37 #include <sys/socket.h>
38 #include <sys/file.h>
39 #include <linux/netlink.h>
40 #include <libnfnetlink/libnfnetlink.h>
41 #include <libnetfilter_log/libnetfilter_log.h>
42 #include <netinet/ip.h>
43 #include <netinet/ip_icmp.h>
44 #include <netinet/udp.h>
45 #include <netinet/tcp.h>
46 #include <netinet/if_ether.h>
47
48 #include <glib.h>
49 #include <glib-unix.h>
50
51 static struct nflog_handle *logh = NULL;
52 static struct nlif_handle *nlifh = NULL;
53
54 #define LOGFILE "/var/log/pve-firewall.log"
55
56 #define LOCKFILE "/var/lock/pvefw-logger.lck"
57 #define PIDFILE "/var/run/pvefw-logger.pid"
58
59 #define LQ_LEN 512
60 #define LE_MAX (512 - 16) // try to fit into 512 bytes
61
62 struct log_entry { 
63     guint32 len; // max LE_MAX chars
64     char buf[LE_MAX];
65 };
66
67 int outfd = -1;
68
69 gboolean terminate_threads = FALSE;
70
71 static gboolean write_pidfile(pid_t pid)
72 {
73     gboolean res;
74
75     char *strpid = g_strdup_printf("%d\n", pid);
76     res = g_file_set_contents(PIDFILE, strpid, strlen(strpid), NULL);
77     g_free(strpid);
78
79     return res;
80 }
81
82 static GAsyncQueue *queue;
83
84 ssize_t 
85 safe_write(int fd, char *buf, size_t count)
86 {
87   ssize_t n;
88
89   do {
90     n = write(fd, buf, count);
91   } while (n < 0 && errno == EINTR);
92
93   return n;
94 }
95
96 static gpointer
97 log_writer_thread(gpointer data) 
98 {
99     while (1) {
100         struct log_entry *le = (struct log_entry *)g_async_queue_timeout_pop(queue, 250000);
101         if (le == NULL) {
102             if (terminate_threads) {
103                 return NULL;
104             }
105             continue;
106         }
107  
108         int res = safe_write(outfd, le->buf, le->len);
109
110         g_free(le);
111
112         if (res < 0) {
113             // printf("write failed\n"); // fixme??
114         }
115     }
116
117     return NULL;
118 }
119
120 static int skipped_logs = 0;
121
122 static void log_status_message(const char *fmt, ...);
123  
124 static void
125 queue_log_entry(struct log_entry *le)
126 {
127     gint len = g_async_queue_length(queue);
128
129     if (skipped_logs > 0) {
130         if (len >= (LQ_LEN - 1)) {
131             skipped_logs++;
132         } else {
133             int skip_tmp = skipped_logs; 
134             skipped_logs = 0; // clear before calling log_status_message()
135             log_status_message("skipped %d log entries (queue full)", skip_tmp);
136             g_async_queue_push(queue, le);
137         }
138     } else {
139         if (len >= LQ_LEN) {
140             skipped_logs++;
141         } else {
142             g_async_queue_push(queue, le);
143         }
144     }
145 }
146
147
148 #define LEPRINTF(format, ...) { if (le->len < LE_MAX) le->len += snprintf(le->buf + le->len, LE_MAX - le->len, format, ##__VA_ARGS__); }
149 #define LEPRINTTIME(sec) { time_t tmp_sec = sec; if (le->len < (LE_MAX - 30)) le->len += strftime(le->buf + le->len, LE_MAX - le->len, "%d/%b/%Y:%H:%M:%S %z ", localtime(&tmp_sec)); }
150
151 static void 
152 log_status_message(const char *fmt, ...) 
153 {
154     va_list ap;
155     va_start(ap, fmt);
156     
157     struct log_entry *le = g_new0(struct log_entry, 1);
158
159     LEPRINTTIME(time(NULL));
160
161     le->len += vsnprintf(le->buf + le->len, LE_MAX - le->len, fmt, ap);
162
163     LEPRINTF("\n");
164
165     queue_log_entry(le);
166 }
167
168 static int 
169 print_tcp(struct log_entry *le, struct tcphdr *h, int payload_len)
170 {
171     LEPRINTF("PROTO=TCP ");
172
173     if (payload_len < sizeof(struct tcphdr)) {
174         LEPRINTF("LEN=%d ", payload_len);
175         LEPRINTF("INVALID=LEN ");
176         return -1;
177     }
178
179     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
180     LEPRINTF("SEQ=%u ACK=%u ", ntohl(h->seq), ntohl(h->ack_seq));
181     LEPRINTF("WINDOW=%u ", ntohs(h->window));
182
183     if (h->urg) LEPRINTF("URG ");
184     if (h->ack) LEPRINTF("ACK ");
185     if (h->psh) LEPRINTF("PSH ");
186     if (h->rst) LEPRINTF("RST ");
187     if (h->syn) LEPRINTF("SYN ");
188     if (h->fin) LEPRINTF("FIN ");
189
190     if (h->urg) LEPRINTF("URGP=%u ",ntohs(h->urg_ptr));
191
192     return 0;
193 }
194
195 static int 
196 print_udp(struct log_entry *le, struct udphdr *h, int payload_len)
197 {
198     LEPRINTF("PROTO=UDP ");
199
200     if (payload_len < sizeof(struct udphdr)) {
201         LEPRINTF("LEN=%d ", payload_len);
202         LEPRINTF("INVALID=LEN ");
203         return -1;
204     }
205
206     LEPRINTF("SPT=%u DPT=%u LEN=%u", ntohs(h->source), ntohs(h->dest), ntohs(h->len));
207
208     return 0;
209 }
210
211 static int 
212 print_icmp(struct log_entry *le, struct icmphdr *h, int payload_len)
213 {
214     char tmp[INET_ADDRSTRLEN];
215     u_int32_t gateway;
216
217     LEPRINTF("PROTO=ICMP ");
218
219     if (payload_len < sizeof(struct icmphdr)) {
220         LEPRINTF("LEN=%d ", payload_len);
221         LEPRINTF("INVALID=LEN ");
222         return -1;
223     }
224
225     LEPRINTF("TYPE=%u CODE=%u ", h->type, h->code);
226
227     switch (h->type) {
228     case ICMP_ECHO:
229     case ICMP_ECHOREPLY:
230         LEPRINTF("ID=%u SEQ=%u ", ntohs(h->un.echo.id), ntohs(h->un.echo.sequence));
231         break;
232     case ICMP_PARAMETERPROB:
233         LEPRINTF("PARAMETER=%u ", ntohl(h->un.gateway) >> 24);
234         break;
235     case ICMP_REDIRECT:
236         gateway = ntohl(h->un.gateway);
237         inet_ntop(AF_INET, &gateway, tmp, sizeof(tmp));                
238         LEPRINTF("GATEWAY=%s ", tmp);
239         break;
240     case ICMP_DEST_UNREACH:
241         if (h->code == ICMP_FRAG_NEEDED) {
242             LEPRINTF("MTU=%u ", ntohs(h->un.frag.mtu));
243         }
244         break;
245     }
246
247     return 0;
248 }
249
250 /* Section 3.1.  SCTP Common Header Format */
251 typedef struct sctphdr {
252         __be16 source;
253         __be16 dest;
254         __be32 vtag;
255         __be32 checksum;
256 } __attribute__((packed)) sctp_sctphdr_t;
257
258 static int 
259 print_sctp(struct log_entry *le, struct sctphdr *h, int payload_len)
260 {
261     LEPRINTF("PROTO=SCTP ");
262
263     if (payload_len < sizeof(struct sctphdr)) {
264         LEPRINTF("LEN=%d ", payload_len);
265         LEPRINTF("INVALID=LEN ");
266         return -1;
267     }
268
269     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
270
271     return 0;
272 }
273
274 static int 
275 print_iphdr(struct log_entry *le, char * payload, int payload_len)
276 {
277     if (payload_len < sizeof(struct iphdr)) {
278        LEPRINTF("LEN=%d ", payload_len);
279        LEPRINTF("INVALID=LEN ");
280        return -1;
281     }
282
283     struct iphdr *h = (struct iphdr *)payload;
284  
285     if (payload_len <= (u_int32_t)(h->ihl * 4)) {
286         LEPRINTF("INVALID=IHL ");
287         return -1;
288     }
289
290     char tmp[INET_ADDRSTRLEN];
291    
292     inet_ntop(AF_INET, &h->saddr, tmp, sizeof(tmp));                
293     LEPRINTF("SRC=%s ", tmp);
294     inet_ntop(AF_INET, &h->daddr, tmp, sizeof(tmp));                
295     LEPRINTF("DST=%s ", tmp);
296
297     LEPRINTF("LEN=%u TOS=0x%02X PREC=0x%02X TTL=%u ID=%u ",
298              ntohs(h->tot_len),  h->tos & IPTOS_TOS_MASK,
299              h->tos & IPTOS_PREC_MASK, h->ttl, ntohs(h->id));
300                 
301     short ip_off = ntohs(h->frag_off);
302     if (ip_off & IP_OFFMASK) 
303         LEPRINTF("FRAG=%u ", ip_off & IP_OFFMASK);
304
305     if (ip_off & IP_DF) LEPRINTF("DF ");
306     if (ip_off & IP_MF) LEPRINTF("MF ");
307
308     void *nexthdr = (u_int32_t *)h + h->ihl;
309     payload_len -= h->ihl * 4;
310
311     switch (h->protocol) {
312     case IPPROTO_TCP:
313         print_tcp(le, (struct tcphdr *)nexthdr, payload_len);
314         break;
315     case IPPROTO_UDP:
316         print_udp(le, (struct udphdr *)nexthdr, payload_len);
317         break;
318     case IPPROTO_ICMP:
319         print_icmp(le, (struct icmphdr *)nexthdr, payload_len);
320         break;
321     case IPPROTO_SCTP:
322         print_sctp(le, (struct sctphdr *)nexthdr, payload_len);
323         break;
324     case IPPROTO_AH:
325         LEPRINTF("PROTO=AH ");
326         break;
327     case IPPROTO_ESP:
328         LEPRINTF("PROTO=ESP ");
329         break;
330     case IPPROTO_IGMP:
331         LEPRINTF("PROTO=IGMP ");
332         break;
333      default:
334         LEPRINTF("PROTO=%u ", h->protocol);
335     }
336
337     return 0;
338 }
339
340 static int 
341 print_ip6hdr(struct log_entry *le, char * payload, int payload_len)
342 {
343     LEPRINTF("IPV6 logging not implemented ");
344
345     return 0;
346 }
347
348 // ebtables -I FORWARD --nflog --nflog-group 0
349 static int 
350 print_arp(struct log_entry *le, struct ether_arp *h, int payload_len)
351 {
352     if (payload_len < sizeof(struct ether_arp)) {
353         LEPRINTF("LEN=%d ", payload_len);
354         LEPRINTF("INVALID=LEN ");
355         return -1;
356     }
357
358     LEPRINTF("SRC=%u.%u.%u.%u ", h->arp_spa[0], h->arp_spa[1],
359              h->arp_spa[2], h->arp_spa[3]);
360
361     LEPRINTF("DST=%u.%u.%u.%u ", h->arp_tpa[0], h->arp_tpa[1],
362              h->arp_tpa[2], h->arp_tpa[3]);
363
364     LEPRINTF("PROTO=ARP ");
365
366     unsigned short code = ntohs(h->arp_op);
367     switch (code) {
368     case ARPOP_REQUEST:
369         LEPRINTF("REQUEST ");
370         break;
371     case ARPOP_REPLY:
372         LEPRINTF("REPLY MAC=%02x:%02x:%02x:%02x:%02x:%02x ", 
373                  h->arp_sha[0], h->arp_sha[1], h->arp_sha[2], 
374                  h->arp_sha[3], h->arp_sha[4], h->arp_sha[5]);
375         break;
376     case ARPOP_NAK:
377         LEPRINTF("NAK ");
378         break;
379     default:
380         LEPRINTF("CODE=%u ", code);
381     }
382
383
384     // LEPRINTF("HTYPE=%u ", ntohs(h->arp_hrd));
385
386     // LEPRINTF("PTYPE=%u ", ntohs(h->arp_pro));
387
388     return 0;
389 }
390
391
392 static int print_pkt(struct log_entry *le, struct nflog_data *ldata, u_int8_t family)
393 {
394     u_int32_t mark = nflog_get_nfmark(ldata);
395     u_int32_t indev = nflog_get_indev(ldata);
396     u_int32_t outdev = nflog_get_outdev(ldata);
397     u_int32_t physindev = nflog_get_physindev(ldata);
398     u_int32_t physoutdev = nflog_get_physoutdev(ldata);
399
400     char *prefix = nflog_get_prefix(ldata);
401     char *payload;
402     char devname[256];
403     
404     struct timeval ts;
405     nflog_get_timestamp(ldata, &ts);
406
407     LEPRINTTIME(ts.tv_sec);
408
409     //le->len += strftime(le->buf + le->len, LE_MAX - le->len, "%d/%b/%Y:%H:%M:%S %z ", localtime(&ts.tv_sec));
410
411     if (prefix != NULL) {
412         LEPRINTF("%s", prefix);
413     }
414     
415     if ((indev > 0) && (nlif_index2name(nlifh, indev, devname) != -1)) {
416         LEPRINTF("IN=%s ", devname); 
417     }
418
419     if ((outdev > 0) && (nlif_index2name(nlifh, outdev, devname) != -1)) {
420         LEPRINTF("OUT=%s ", devname);
421     }
422
423     if ((physindev > 0) && (nlif_index2name(nlifh, physindev, devname) != -1)) {
424         LEPRINTF("PHYSIN=%s ", devname);
425     }
426          
427     if ((physoutdev > 0) &&  (nlif_index2name(nlifh, physoutdev, devname) != -1)) {
428         LEPRINTF("PHYSOUT=%s ", devname);
429     }
430
431     int payload_len = nflog_get_payload(ldata, &payload);
432
433     int hwhdrlen = nflog_get_msg_packet_hwhdrlen(ldata);
434     if (hwhdrlen > 0) {
435         unsigned char *hwhdr = (unsigned char *)nflog_get_msg_packet_hwhdr(ldata);
436         if (hwhdr != NULL) {
437             int i;
438             LEPRINTF("MAC=");
439             for (i = 0; i < hwhdrlen; i++) {
440                 LEPRINTF("%02x", hwhdr[i]);
441                 if (i < (hwhdrlen -1 )) LEPRINTF(":");
442             }
443             LEPRINTF(" ");
444         }
445     }
446
447     u_int16_t hw_protocol = 0;
448     struct nfulnl_msg_packet_hdr *ph = NULL;
449
450     switch (family) {
451     case AF_INET: 
452         print_iphdr(le, payload, payload_len);
453         break;
454     case AF_INET6:
455         print_ip6hdr(le, payload, payload_len);
456         break;
457     case AF_BRIDGE:
458         ph = nflog_get_msg_packet_hdr(ldata);
459         if (ph) hw_protocol = ntohs(ph->hw_protocol);
460
461         switch (hw_protocol) {
462         case ETH_P_IP:
463             print_iphdr(le, payload, payload_len);
464             break;
465         case ETH_P_IPV6:
466              print_ip6hdr(le, payload, payload_len);
467             break;
468         case ETH_P_ARP:
469             print_arp(le, (struct ether_arp *)payload, payload_len);
470             break;
471         }
472         break;
473     }
474
475     if (mark) LEPRINTF("mark=%u ", mark);
476
477
478     return 0;
479
480 }
481
482 static int 
483 nflog_cb(struct nflog_g_handle *gh, struct nfgenmsg *nfmsg,
484                struct nflog_data *nfa, void *data)
485 {
486     struct log_entry *le = g_new0(struct log_entry, 1);
487  
488     print_pkt(le, nfa, nfmsg->nfgen_family);
489
490     LEPRINTF("\n"); // add newline
491
492     queue_log_entry(le);
493
494     return 0;
495 }
496
497 static gboolean
498 nflog_read_cb(GIOChannel *source,
499               GIOCondition condition,
500               gpointer data)
501 {
502     int rv = 0;
503     gchar buf[8192];
504
505     int fd =  g_io_channel_unix_get_fd(source);
506    
507     if ((rv = recv(fd, buf, sizeof(buf), 0)) && rv >= 0) {
508          nflog_handle_packet(logh, buf, rv);
509     }
510
511     return TRUE;
512 }
513
514 static gboolean
515 nlif_read_cb(GIOChannel *source,
516              GIOCondition condition,
517              gpointer data)
518 {
519     nlif_catch(nlifh);
520     // fixme: report  errors
521     return TRUE; 
522 }
523
524 GMainLoop *main_loop;
525
526 static gboolean
527 terminate_request(gpointer data) 
528 {
529     terminate_threads = TRUE;
530
531     log_status_message("received terminate request (signal)");
532
533     g_main_loop_quit(main_loop);
534     
535     return TRUE;
536 }
537                 
538
539 int
540 main(int argc, char *argv[])
541 {
542     int lockfd = -1;
543     gboolean foreground = FALSE;
544     gboolean wrote_pidfile = FALSE;
545
546     g_thread_init(NULL);
547
548     if ((lockfd = open(LOCKFILE, O_RDWR|O_CREAT|O_APPEND, 0644)) == -1) {
549         fprintf(stderr, "unable to create lock '%s': %s", LOCKFILE, strerror (errno));
550         exit(-1);
551     }
552
553     for (int i = 10; i >= 0; i--) {
554         if (flock(lockfd, LOCK_EX|LOCK_NB) != 0) {
555             if (!i) {
556                 fprintf(stderr, "unable to aquire lock '%s': %s", LOCKFILE, strerror (errno));
557                 exit(-1);
558             }
559             if (i == 10)
560                 fprintf(stderr, "unable to aquire lock '%s' - trying again.\n", LOCKFILE);
561             
562             sleep(1);
563         }
564     }
565
566     if ((outfd = open(LOGFILE, O_WRONLY|O_CREAT|O_APPEND, 0644)) == -1) {
567         fprintf(stderr, "unable to open file '%s': %s", LOGFILE, strerror (errno));
568         exit(-1);
569     }
570
571     if ((logh = nflog_open())  == NULL) {
572         fprintf(stderr, "unable to open nflog\n");
573         exit(-1);
574     }
575
576     if (!nflog_bind_pf(logh, AF_INET) <= 0) {
577         fprintf(stderr, "nflog_bind_pf AF_INET failed\n");
578         exit(-1);
579     }
580
581 #if 0
582     if (!nflog_bind_pf(logh, AF_INET6) <= 0) {
583         fprintf(stderr, "nflog_bind_pf AF_INET6 failed\n");
584         exit(-1);
585     }
586 #endif
587     
588     if (!nflog_bind_pf(logh, AF_BRIDGE) <= 0) {
589         fprintf(stderr, "nflog_bind_pf AF_BRIDGE failed\n");
590         exit(-1);
591     }
592
593     struct nflog_g_handle *qh = nflog_bind_group(logh, 0);
594     if (!qh) {
595         fprintf(stderr, "no handle for group 1\n");
596         exit(-1);
597     }
598  
599     if (nflog_set_mode(qh, NFULNL_COPY_PACKET, 0xffff) < 0) {
600         fprintf(stderr, "can't set packet copy mode\n");
601         exit(-1);
602     }
603
604     if ((nlifh = nlif_open()) == NULL) {
605         fprintf(stderr, "unable to open netlink interface handle\n");
606         exit(-1);
607     }
608
609     if (!foreground) {
610         pid_t cpid = fork();
611
612         if (cpid == -1) {
613             fprintf(stderr, "failed to daemonize program - %s\n", strerror (errno));
614             exit(-1);
615         } else if (cpid) {
616             write_pidfile(cpid);
617             _exit(0);
618         } else {
619             int nullfd;
620
621             if (chroot("/") != 0) fprintf(stderr, "chroot '/' failed - %s\n", strerror (errno));
622
623             if ((nullfd = open("/dev/null", O_RDWR, 0)) != -1) {
624                 dup2(nullfd, 0);
625                 dup2(nullfd, 1);
626                 dup2(nullfd, 2);
627                 if (nullfd > 2)
628                     close (nullfd);
629             }
630
631             setsid();
632         }
633     } else {
634         write_pidfile(getpid());
635     }
636
637     wrote_pidfile = TRUE;
638
639     nflog_callback_register(qh, &nflog_cb, logh);
640
641     queue = g_async_queue_new_full(g_free);
642
643     log_status_message("starting pvefw logger");
644
645     nlif_query(nlifh);
646
647     GIOChannel *nlif_ch = g_io_channel_unix_new(nlif_fd(nlifh));
648
649     g_io_add_watch(nlif_ch, G_IO_IN, nlif_read_cb, NULL);
650
651     int logfd = nflog_fd(logh);
652     GIOChannel *nflog_ch = g_io_channel_unix_new(logfd);
653
654     g_io_add_watch(nflog_ch, G_IO_IN, nflog_read_cb, NULL);
655
656     GThread *wthread = g_thread_new("log_writer_thread", log_writer_thread, NULL);
657     
658     main_loop = g_main_loop_new(NULL, TRUE);
659     
660     g_unix_signal_add(SIGINT, terminate_request, NULL);
661     g_unix_signal_add(SIGTERM, terminate_request, NULL);
662     
663     g_main_loop_run(main_loop);
664
665     log_status_message("stopping pvefw logger");
666
667     g_thread_join(wthread);
668
669     close(outfd);
670
671     nflog_close(logh);
672
673     if (wrote_pidfile)
674         unlink(PIDFILE);
675
676     exit(0);
677 }