fix #2178: endless loop on ipv6 extension headers
[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/signalfd.h>
33 #include <sys/types.h>
34 #include <sys/stat.h>
35 #include <fcntl.h>
36 #include <unistd.h>
37 #include <arpa/inet.h>
38 #include <sys/socket.h>
39 #include <sys/file.h>
40 #include <linux/netlink.h>
41 #include <libnfnetlink/libnfnetlink.h>
42 #include <libnetfilter_log/libnetfilter_log.h>
43 #include <libnetfilter_conntrack/libnetfilter_conntrack.h>
44 #include <netinet/ip.h>
45 #include <netinet/ip_icmp.h>
46 #include <netinet/ip6.h>
47 #include <netinet/icmp6.h>
48 #include <netinet/udp.h>
49 #include <netinet/tcp.h>
50 #include <netinet/if_ether.h>
51 #include <syslog.h>
52
53 #include <glib.h>
54
55 static struct nflog_handle *logh = NULL;
56 static struct nlif_handle *nlifh = NULL;
57 static struct nfct_handle *nfcth = NULL;
58 GMainLoop *main_loop;
59
60 gboolean foreground = FALSE;
61 gboolean debug = FALSE;
62 gboolean conntrack = FALSE;
63
64 /*
65
66 LOG FORMAT:
67
68 Special care was taken to allow fast parsing (and filer messages for a singl VM).
69
70 <VMID> <LOGLEVEL> <CHAIN> <TIME> <TIMEZONE> <MSG>
71
72 Example:
73
74 117 6 tap117i0-IN 14/Mar/2014:12:47:07 +0100 policy REJECT: IN=vmbr1 ...
75
76 */
77
78 #define LOGFILE "/var/log/pve-firewall.log"
79
80 #define LOCKFILE "/var/lock/pvefw-logger.lck"
81 #define PIDFILE "/var/run/pvefw-logger.pid"
82 #define LOG_CONNTRACK_FILE "/var/lib/pve-firewall/log_nf_conntrack"
83
84 #define LQ_LEN 512
85 #define LE_MAX (512 - 4) // try to fit into 512 bytes
86
87 #define MAX_CHAIN_LEN 28
88
89 struct log_entry {
90     guint32 len; // max LE_MAX chars
91     char buf[LE_MAX];
92 };
93
94 #define STATIC_ASSERT(cond) \
95     extern void pve_static_assert(int test[(cond) ? 1 : -1])
96
97 STATIC_ASSERT(sizeof(struct log_entry) == 512);
98
99 int outfd = -1;
100
101 gboolean terminate_threads = FALSE;
102
103 static gboolean write_pidfile(pid_t pid)
104 {
105     gboolean res;
106
107     char *strpid = g_strdup_printf("%d\n", pid);
108     res = g_file_set_contents(PIDFILE, strpid, strlen(strpid), NULL);
109     g_free(strpid);
110
111     return res;
112 }
113
114 static GAsyncQueue *queue;
115
116 ssize_t
117 safe_write(int fd, char *buf, size_t count)
118 {
119   ssize_t n;
120
121   do {
122     n = write(fd, buf, count);
123   } while (n < 0 && errno == EINTR);
124
125   return n;
126 }
127
128 static gpointer
129 log_writer_thread(gpointer data)
130 {
131     while (1) {
132         struct log_entry *le = (struct log_entry *)g_async_queue_timeout_pop(queue, 250000);
133         if (le == NULL) {
134             if (terminate_threads) {
135                 return NULL;
136             }
137             continue;
138         }
139
140         if (debug) fputs(le->buf, stdout);
141
142         int res = safe_write(outfd, le->buf, le->len);
143
144         g_free(le);
145
146         if (res < 0) {
147             syslog(3, "writing log failed, stopping daemon - %s", strerror (errno));
148             g_main_loop_quit(main_loop);
149             return NULL;
150         }
151     }
152
153     return NULL;
154 }
155
156 static int skipped_logs = 0;
157
158 static void log_status_message(guint loglevel, const char *fmt, ...);
159
160 static void
161 queue_log_entry(struct log_entry *le)
162 {
163     gint len = g_async_queue_length(queue);
164
165     if (skipped_logs > 0) {
166         if (len >= (LQ_LEN - 1)) {
167             skipped_logs++;
168         } else {
169             int skip_tmp = skipped_logs;
170             skipped_logs = 0; // clear before calling log_status_message()
171             log_status_message(3, "skipped %d log entries (queue full)", skip_tmp);
172             g_async_queue_push(queue, le);
173         }
174     } else {
175         if (len >= LQ_LEN) {
176             skipped_logs++;
177         } else {
178             g_async_queue_push(queue, le);
179         }
180     }
181 }
182
183
184 #define LEPRINTF(format, ...) \
185     do { \
186         if (le->len < LE_MAX) \
187             le->len += snprintf(le->buf + le->len, LE_MAX - le->len, format, ##__VA_ARGS__); \
188     } while (0)
189 #define LEPRINTTIME(sec) \
190     do { \
191         time_t tmp_sec = sec; \
192         if (le->len < (LE_MAX - 30)) \
193             le->len += strftime(le->buf + le->len, LE_MAX - le->len, "%d/%b/%Y:%H:%M:%S %z ", localtime(&tmp_sec)); \
194     } while (0)
195
196 static void
197 log_status_message(guint loglevel, const char *fmt, ...)
198 {
199     va_list ap, ap2;
200
201     if (loglevel > 7 ) loglevel = 7; // syslog defines level 0-7
202
203     struct log_entry *le = g_new0(struct log_entry, 1);
204
205     LEPRINTF("0 %d - ", loglevel);
206
207     LEPRINTTIME(time(NULL));
208
209     va_start(ap, fmt);
210     va_copy(ap2, ap);
211     le->len += vsnprintf(le->buf + le->len, LE_MAX - le->len, fmt, ap);
212     va_end(ap);
213
214     LEPRINTF("\n");
215
216     queue_log_entry(le);
217
218     // also log to syslog
219
220     vsyslog(loglevel, fmt, ap2);
221     va_end(ap2);
222 }
223
224 static int
225 print_tcp(struct log_entry *le, struct tcphdr *h, int payload_len)
226 {
227     LEPRINTF("PROTO=TCP ");
228
229     if (payload_len < sizeof(struct tcphdr)) {
230         LEPRINTF("LEN=%d ", payload_len);
231         LEPRINTF("INVALID=LEN ");
232         return -1;
233     }
234
235     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
236     LEPRINTF("SEQ=%u ACK=%u ", ntohl(h->seq), ntohl(h->ack_seq));
237     LEPRINTF("WINDOW=%u ", ntohs(h->window));
238
239     if (h->urg) LEPRINTF("URG ");
240     if (h->ack) LEPRINTF("ACK ");
241     if (h->psh) LEPRINTF("PSH ");
242     if (h->rst) LEPRINTF("RST ");
243     if (h->syn) LEPRINTF("SYN ");
244     if (h->fin) LEPRINTF("FIN ");
245
246     if (h->urg) LEPRINTF("URGP=%u ",ntohs(h->urg_ptr));
247
248     return 0;
249 }
250
251 static int
252 print_udp(struct log_entry *le, struct udphdr *h, int payload_len)
253 {
254     LEPRINTF("PROTO=UDP ");
255
256     if (payload_len < sizeof(struct udphdr)) {
257         LEPRINTF("LEN=%d ", payload_len);
258         LEPRINTF("INVALID=LEN ");
259         return -1;
260     }
261
262     LEPRINTF("SPT=%u DPT=%u LEN=%u", ntohs(h->source), ntohs(h->dest), ntohs(h->len));
263
264     return 0;
265 }
266
267 static int
268 print_icmp(struct log_entry *le, struct icmphdr *h, int payload_len)
269 {
270     char tmp[INET_ADDRSTRLEN];
271     u_int32_t gateway;
272
273     LEPRINTF("PROTO=ICMP ");
274
275     if (payload_len < sizeof(struct icmphdr)) {
276         LEPRINTF("LEN=%d ", payload_len);
277         LEPRINTF("INVALID=LEN ");
278         return -1;
279     }
280
281     LEPRINTF("TYPE=%u CODE=%u ", h->type, h->code);
282
283     switch (h->type) {
284     case ICMP_ECHO:
285     case ICMP_ECHOREPLY:
286         LEPRINTF("ID=%u SEQ=%u ", ntohs(h->un.echo.id), ntohs(h->un.echo.sequence));
287         break;
288     case ICMP_PARAMETERPROB:
289         LEPRINTF("PARAMETER=%u ", ntohl(h->un.gateway) >> 24);
290         break;
291     case ICMP_REDIRECT:
292         gateway = ntohl(h->un.gateway);
293         inet_ntop(AF_INET, &gateway, tmp, sizeof(tmp));
294         LEPRINTF("GATEWAY=%s ", tmp);
295         break;
296     case ICMP_DEST_UNREACH:
297         if (h->code == ICMP_FRAG_NEEDED) {
298             LEPRINTF("MTU=%u ", ntohs(h->un.frag.mtu));
299         }
300         break;
301     }
302
303     return 0;
304 }
305
306 /* Section 3.1.  SCTP Common Header Format */
307 typedef struct sctphdr {
308         __be16 source;
309         __be16 dest;
310         __be32 vtag;
311         __be32 checksum;
312 } __attribute__((packed)) sctp_sctphdr_t;
313
314 static int
315 print_sctp(struct log_entry *le, struct sctphdr *h, int payload_len)
316 {
317     LEPRINTF("PROTO=SCTP ");
318
319     if (payload_len < sizeof(struct sctphdr)) {
320         LEPRINTF("LEN=%d ", payload_len);
321         LEPRINTF("INVALID=LEN ");
322         return -1;
323     }
324
325     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
326
327     return 0;
328 }
329
330 static int
331 print_ipproto(struct log_entry *le, char * nexthdr, int payload_len, u_int8_t proto)
332 {
333     switch (proto) {
334     case IPPROTO_TCP:
335         print_tcp(le, (struct tcphdr *)nexthdr, payload_len);
336         break;
337     case IPPROTO_UDP:
338         print_udp(le, (struct udphdr *)nexthdr, payload_len);
339         break;
340     case IPPROTO_ICMP:
341         print_icmp(le, (struct icmphdr *)nexthdr, payload_len);
342         break;
343     case IPPROTO_SCTP:
344         print_sctp(le, (struct sctphdr *)nexthdr, payload_len);
345         break;
346     case IPPROTO_AH:
347         LEPRINTF("PROTO=AH ");
348         break;
349     case IPPROTO_ESP:
350         LEPRINTF("PROTO=ESP ");
351         break;
352     case IPPROTO_IGMP:
353         LEPRINTF("PROTO=IGMP ");
354         break;
355      default:
356         return -1;
357     }
358     return 0;
359 }
360
361 static int
362 print_iphdr(struct log_entry *le, char * payload, int payload_len)
363 {
364     if (payload_len < sizeof(struct iphdr)) {
365        LEPRINTF("LEN=%d ", payload_len);
366        LEPRINTF("INVALID=LEN ");
367        return -1;
368     }
369
370     struct iphdr *h = (struct iphdr *)payload;
371
372     if (payload_len <= (u_int32_t)(h->ihl * 4)) {
373         LEPRINTF("INVALID=IHL ");
374         return -1;
375     }
376
377     char tmp[INET_ADDRSTRLEN];
378
379     inet_ntop(AF_INET, &h->saddr, tmp, sizeof(tmp));
380     LEPRINTF("SRC=%s ", tmp);
381     inet_ntop(AF_INET, &h->daddr, tmp, sizeof(tmp));
382     LEPRINTF("DST=%s ", tmp);
383
384     LEPRINTF("LEN=%u TOS=0x%02X PREC=0x%02X TTL=%u ID=%u ",
385              ntohs(h->tot_len),  h->tos & IPTOS_TOS_MASK,
386              h->tos & IPTOS_PREC_MASK, h->ttl, ntohs(h->id));
387
388     short ip_off = ntohs(h->frag_off);
389     if (ip_off & IP_OFFMASK)
390         LEPRINTF("FRAG=%u ", ip_off & IP_OFFMASK);
391
392     if (ip_off & IP_DF) LEPRINTF("DF ");
393     if (ip_off & IP_MF) LEPRINTF("MF ");
394
395     void *nexthdr = (u_int32_t *)h + h->ihl;
396     payload_len -= h->ihl * 4;
397
398     if (print_ipproto(le, nexthdr, payload_len, h->protocol) < 0) {
399         LEPRINTF("PROTO=%u ", h->protocol);
400     }
401
402     return 0;
403 }
404
405 static int
406 print_routing(struct log_entry *le, struct ip6_rthdr *rthdr, int payload_len)
407 {
408     char tmp[INET6_ADDRSTRLEN];
409     LEPRINTF("TYPE=%u SEGMENTS=%u", rthdr->ip6r_type, rthdr->ip6r_segleft);
410
411     if (payload_len < sizeof(*rthdr) || payload_len < rthdr->ip6r_len*8) {
412         LEPRINTF("LEN=%d ", payload_len);
413         LEPRINTF("INVALID=LEN ");
414         return -1;
415     }
416
417     if (rthdr->ip6r_type == 0) {
418         /* Route via waypoints (deprecated), this contains a list of waypoints
419          * to visit. (RFC2460 (4.4))
420          */
421         struct ip6_rthdr0 *h = (struct ip6_rthdr0*)rthdr;
422         if (rthdr->ip6r_len*8 < sizeof(*h) + rthdr->ip6r_segleft * sizeof(struct in6_addr)) {
423             LEPRINTF("INVALID=SEGMENTS ");
424             return 0;
425         }
426         return 0;
427     } else if (rthdr->ip6r_type == 1) {
428         /* nimrod routing (RFC1992) */
429         return 0;
430     } else if (rthdr->ip6r_type == 2) {
431         /* RFC3375 (6.4), the layout is like type-0 but with exactly 1 address */
432         struct ip6_rthdr0 *h = (struct ip6_rthdr0*)rthdr;
433         if (rthdr->ip6r_len*8 < sizeof(*h) + sizeof(struct in6_addr)) {
434             LEPRINTF("LEN=%d ", payload_len);
435             LEPRINTF("INVALID=LEN ");
436             return -1;
437         }
438         inet_ntop(AF_INET6, &h->ip6r0_addr[0], tmp, sizeof(tmp));
439         LEPRINTF("HOME=%s ", tmp);
440         return 0;
441     }
442
443     return 0;
444 }
445
446 static int
447 print_fragment(struct log_entry *le, struct ip6_frag *frag, int payload_len)
448 {
449     u_int16_t offlg;
450
451     if (payload_len < sizeof(*frag)) {
452         LEPRINTF("LEN=%d ", payload_len);
453         LEPRINTF("INVALID=LEN ");
454         return -1;
455     }
456
457     offlg = ntohs(frag->ip6f_offlg);
458     LEPRINTF("FRAG=%d ID=%d ", (offlg&0x2FFF), ntohl(frag->ip6f_ident));
459     if (offlg>>15) {
460         LEPRINTF("MF ");
461     }
462     return 0;
463 }
464
465 static int
466 print_icmp6(struct log_entry *le, struct icmp6_hdr *h, int payload_len)
467 {
468     struct nd_router_advert *ra;
469     struct nd_neighbor_advert *na;
470     struct nd_redirect *re;
471     char tmp[INET6_ADDRSTRLEN];
472
473     if (payload_len < sizeof(struct icmp6_hdr)) {
474         LEPRINTF("LEN=%d ", payload_len);
475         LEPRINTF("INVALID=LEN ");
476         return -1;
477     }
478
479     LEPRINTF("TYPE=%u CODE=%u ", h->icmp6_type, h->icmp6_code);
480
481     switch (h->icmp6_type) {
482     case ICMP6_ECHO_REQUEST:
483     case ICMP6_ECHO_REPLY:
484         LEPRINTF("ID=%u SEQ=%u ", ntohs(h->icmp6_id), ntohs(h->icmp6_seq));
485         break;
486
487     case ND_ROUTER_SOLICIT:
488         /* can be followed by options, otherwise nothing to print */
489         break;
490
491     case ND_ROUTER_ADVERT:
492         ra = (struct nd_router_advert*)h;
493         LEPRINTF("HOPLIMIT=%d ", ra->nd_ra_curhoplimit);
494         /* nd_ra_flags_reserved is only 8 bit, so no swapping here as
495          * opposed to the neighbor advertisement flags (see below).
496          */
497         LEPRINTF("RA=%02x LIFETIME=%d REACHABLE=%d RETRANSMIT=%d ",
498                  ra->nd_ra_flags_reserved,
499                  ntohs(ra->nd_ra_router_lifetime),
500                  ntohl(ra->nd_ra_reachable),
501                  ntohl(ra->nd_ra_retransmit));
502         /* can be followed by options */
503         break;
504
505     case ND_NEIGHBOR_SOLICIT:
506         /* can be followed by options */
507         break;
508
509     case ND_NEIGHBOR_ADVERT:
510         na = (struct nd_neighbor_advert*)h;
511         LEPRINTF("NA=%08x ", ntohl(na->nd_na_flags_reserved));
512         /* can be followed by options */
513         break;
514
515     case ND_REDIRECT:
516         re = (struct nd_redirect*)h;
517         inet_ntop(AF_INET6, &re->nd_rd_target, tmp, sizeof(tmp));
518         LEPRINTF("TARGET=%s ", tmp);
519         inet_ntop(AF_INET6, &re->nd_rd_dst, tmp, sizeof(tmp));
520         LEPRINTF("GATEWAY=%s ", tmp);
521         /* can be followed by options */
522         break;
523
524     case ICMP6_DST_UNREACH:
525         /* CODE shows the type, no extra parameters available in ipv6 */
526         break;
527
528     case ICMP6_PACKET_TOO_BIG:
529         LEPRINTF("MTU=%u ", ntohl(h->icmp6_mtu));
530         break;
531
532     case ICMP6_TIME_EXCEEDED:
533         /* CODE shows the type (0 = hop limit, 1 = reassembly timed out) */
534         break;
535
536     case ICMP6_PARAM_PROB:
537         switch (ntohl(h->icmp6_pptr)) {
538         case ICMP6_PARAMPROB_HEADER:
539             LEPRINTF("PARAMETER=HEADER "); /* erroneous header */
540             break;
541         case ICMP6_PARAMPROB_NEXTHEADER:
542             LEPRINTF("PARAMETER=NEXTHEADER "); /* bad next-header field */
543             break;
544         case ICMP6_PARAMPROB_OPTION:
545             LEPRINTF("PARAMETER=OPTION "); /* bad ipv6 option (hop/dst header?) */
546             break;
547         default:
548             LEPRINTF("PARAMETER=%u ", ntohl(h->icmp6_pptr)); /* unknown */
549             break;
550         }
551         break;
552     }
553
554     return 0;
555 }
556
557 static int
558 check_ip6ext(struct log_entry *le, struct ip6_ext *exthdr, int payload_len)
559 {
560     if (payload_len < sizeof(*exthdr) ||
561         payload_len < exthdr->ip6e_len)
562     {
563         LEPRINTF("LEN=%d ", payload_len);
564         LEPRINTF("INVALID=LEN ");
565         return -1;
566     }
567     return 0;
568 }
569
570 static int
571 print_nexthdr(struct log_entry *le, char *hdr, int payload_len, u_int8_t proto)
572 {
573     while (1) {
574         if (print_ipproto(le, hdr, payload_len, proto) == 0)
575             return 0;
576
577         struct ip6_ext *exthdr = (struct ip6_ext*)hdr;
578         int ext_len = 0;
579
580         switch (proto) {
581         /* protocols (these return) */
582         case IPPROTO_ICMPV6:
583             LEPRINTF("PROTO=ICMPV6 ");
584             if (check_ip6ext(le, exthdr, payload_len) < 0)
585                 return -1;
586             if (print_icmp6(le, (struct icmp6_hdr*)(hdr + exthdr->ip6e_len),
587                             payload_len - exthdr->ip6e_len) < 0)
588             {
589                 return -1;
590             }
591             return 0;
592
593         /* extension headers (these break to keep iterating) */
594         case IPPROTO_ROUTING:
595             if (check_ip6ext(le, exthdr, payload_len) < 0)
596                 return -1;
597             if (print_routing(le, (struct ip6_rthdr*)hdr, payload_len) < 0)
598                 return -1;
599             break;
600         case IPPROTO_FRAGMENT:
601             if (check_ip6ext(le, exthdr, payload_len) < 0)
602                 return -1;
603             if (print_fragment(le, (struct ip6_frag*)hdr, payload_len) < 0)
604                 return -1;
605             ext_len = sizeof(struct ip6_frag);
606             break;
607         case IPPROTO_HOPOPTS:
608             LEPRINTF("NEXTHDR=HOPOPTS ");
609             if (check_ip6ext(le, exthdr, payload_len) < 0)
610                 return -1;
611             /* do we want to print these? */
612             break;
613         case IPPROTO_DSTOPTS:
614             LEPRINTF("NEXTHDR=DSTOPTS ");
615             if (check_ip6ext(le, exthdr, payload_len) < 0)
616                 return -1;
617             /* do we want to print these? */
618             break;
619         case IPPROTO_MH:
620             LEPRINTF("NEXTHDR=MH ");
621             if (check_ip6ext(le, exthdr, payload_len) < 0)
622                 return -1;
623             break;
624
625         /* unknown protocol */
626         default:
627             LEPRINTF("PROTO=%u ", proto);
628             return 0; /* bail */
629         }
630         /* next header: */
631         if (check_ip6ext(le, exthdr, payload_len) < 0)
632             return -1;
633         if(ext_len == 0) {
634             ext_len = (exthdr->ip6e_len+1) * 8;
635         }
636         hdr += ext_len;
637         payload_len -= ext_len;
638         proto = exthdr->ip6e_nxt;
639     }
640 }
641
642 static int
643 print_ip6hdr(struct log_entry *le, char * payload, int payload_len)
644 {
645     if (payload_len < sizeof(struct ip6_hdr)) {
646         LEPRINTF("LEN=%d ", payload_len);
647         LEPRINTF("INVALID=LEN ");
648         return -1;
649     }
650
651     struct ip6_hdr *h = (struct ip6_hdr*)payload;
652
653     char tmp[INET6_ADDRSTRLEN];
654     inet_ntop(AF_INET6, &h->ip6_src, tmp, sizeof(tmp));
655     LEPRINTF("SRC=%s ", tmp);
656     inet_ntop(AF_INET6, &h->ip6_dst, tmp, sizeof(tmp));
657     LEPRINTF("DST=%s ", tmp);
658
659     LEPRINTF("LEN=%u ", ntohs(h->ip6_plen));
660
661     u_int32_t flow = ntohl(h->ip6_flow);
662     LEPRINTF("TC=%d FLOWLBL=%d ", (flow>>20)&0xFF, flow&0xFFFFF);
663
664     LEPRINTF("HOPLIMIT=%d ", h->ip6_hlim);
665
666     return print_nexthdr(le, (char *)(h+1), payload_len - sizeof(*h), h->ip6_nxt);
667 }
668
669 // ebtables -I FORWARD --nflog --nflog-group 0
670 static int
671 print_arp(struct log_entry *le, struct ether_arp *h, int payload_len)
672 {
673     if (payload_len < sizeof(struct ether_arp)) {
674         LEPRINTF("LEN=%d ", payload_len);
675         LEPRINTF("INVALID=LEN ");
676         return -1;
677     }
678
679     LEPRINTF("SRC=%u.%u.%u.%u ", h->arp_spa[0], h->arp_spa[1],
680              h->arp_spa[2], h->arp_spa[3]);
681
682     LEPRINTF("DST=%u.%u.%u.%u ", h->arp_tpa[0], h->arp_tpa[1],
683              h->arp_tpa[2], h->arp_tpa[3]);
684
685     LEPRINTF("PROTO=ARP ");
686
687     unsigned short code = ntohs(h->arp_op);
688     switch (code) {
689     case ARPOP_REQUEST:
690         LEPRINTF("REQUEST ");
691         break;
692     case ARPOP_REPLY:
693         LEPRINTF("REPLY MAC=%02x:%02x:%02x:%02x:%02x:%02x ",
694                  h->arp_sha[0], h->arp_sha[1], h->arp_sha[2],
695                  h->arp_sha[3], h->arp_sha[4], h->arp_sha[5]);
696         break;
697     case ARPOP_NAK:
698         LEPRINTF("NAK ");
699         break;
700     default:
701         LEPRINTF("CODE=%u ", code);
702     }
703
704
705     // LEPRINTF("HTYPE=%u ", ntohs(h->arp_hrd));
706
707     // LEPRINTF("PTYPE=%u ", ntohs(h->arp_pro));
708
709     return 0;
710 }
711
712
713 static int print_pkt(struct log_entry *le, struct nflog_data *ldata, u_int8_t family)
714 {
715     u_int32_t mark = nflog_get_nfmark(ldata);
716     u_int32_t indev = nflog_get_indev(ldata);
717     u_int32_t outdev = nflog_get_outdev(ldata);
718     u_int32_t physindev = nflog_get_physindev(ldata);
719     u_int32_t physoutdev = nflog_get_physoutdev(ldata);
720
721     char *prefix = nflog_get_prefix(ldata);
722     char *payload;
723     char devname[256];
724
725     guint32 vmid = 0;
726
727     guint8 log_level = 6; // info
728
729     char *chain_name = "-";
730
731     if (prefix != NULL) {
732         // Note: parse ":$vmid:$loglevel:$chain: $msg"
733         if (prefix[0] == ':') {
734             char *p = prefix + 1;
735             guint32 tmpid = 0;
736             while(*p  >= '0' && *p <= '9') { tmpid *= 10; tmpid += *p - '0'; p++; }
737
738             if ((*p == ':') &&
739                 (p[1] >= '0' && p[1] <= '7') &&
740                 (p[2] == ':')) {
741
742                 guint8 tmp_level = p[1] - '0'; // store for later use
743                 char *chain_start = p + 3; // store for later use
744                 p = chain_start;
745                 while (*p && *p != ':' && *p != ' ') p++;
746                 int len = p - chain_start;
747
748                 if (*p == ':' && p[1] == ' ' && len && (len <= MAX_CHAIN_LEN)) {
749                     // parsing successful
750
751                     *p = 0; // terminate string
752
753                     vmid = tmpid;
754                     log_level = tmp_level;
755                     chain_name = chain_start;
756                     prefix = p + 2; // the rest
757                 }
758             }
759         }
760     }
761
762     LEPRINTF("%d ", vmid);
763
764     LEPRINTF("%d ", log_level);
765
766     LEPRINTF("%s ", chain_name);
767
768     struct timeval ts;
769     if (nflog_get_timestamp(ldata, &ts) == 0) {
770         LEPRINTTIME(ts.tv_sec);
771     } else {
772         LEPRINTTIME(time(NULL));
773     }
774
775     if (prefix != NULL) {
776         LEPRINTF("%s", prefix);
777     }
778
779     if (indev > 0) {
780         if (nlif_index2name(nlifh, indev, devname) != -1) {
781             LEPRINTF("IN=%s ", devname);
782         } else {
783             LEPRINTF("IN=%u ", indev);
784         }
785     }
786
787     if (outdev > 0) {
788         if (nlif_index2name(nlifh, outdev, devname) != -1) {
789             LEPRINTF("OUT=%s ", devname);
790         } else {
791             LEPRINTF("OUT=%u ", outdev);
792         }
793     }
794
795     if (physindev > 0) {
796         if (nlif_index2name(nlifh, physindev, devname) != -1) {
797             LEPRINTF("PHYSIN=%s ", devname);
798         } else {
799             LEPRINTF("PHYSIN=%u ", physindev);
800         }
801     }
802
803     if (physoutdev > 0) {
804         if (nlif_index2name(nlifh, physoutdev, devname) != -1) {
805             LEPRINTF("PHYSOUT=%s ", devname);
806         } else {
807             LEPRINTF("PHYSOUT=%u ", physoutdev);
808         }
809     }
810
811     int payload_len = nflog_get_payload(ldata, &payload);
812
813     int hwhdrlen = nflog_get_msg_packet_hwhdrlen(ldata);
814     if (hwhdrlen > 0) {
815         unsigned char *hwhdr = (unsigned char *)nflog_get_msg_packet_hwhdr(ldata);
816         if (hwhdr != NULL) {
817             int i;
818             LEPRINTF("MAC=");
819             for (i = 0; i < hwhdrlen; i++) {
820                 LEPRINTF("%02x", hwhdr[i]);
821                 if (i < (hwhdrlen -1 )) LEPRINTF(":");
822             }
823             LEPRINTF(" ");
824         }
825     }
826
827     u_int16_t hw_protocol = 0;
828     struct nfulnl_msg_packet_hdr *ph = NULL;
829
830     switch (family) {
831     case AF_INET:
832         print_iphdr(le, payload, payload_len);
833         break;
834     case AF_INET6:
835         print_ip6hdr(le, payload, payload_len);
836         break;
837     case AF_BRIDGE:
838         ph = nflog_get_msg_packet_hdr(ldata);
839         if (ph) hw_protocol = ntohs(ph->hw_protocol);
840
841         switch (hw_protocol) {
842         case ETH_P_IP:
843             print_iphdr(le, payload, payload_len);
844             break;
845         case ETH_P_IPV6:
846              print_ip6hdr(le, payload, payload_len);
847             break;
848         case ETH_P_ARP:
849             print_arp(le, (struct ether_arp *)payload, payload_len);
850             break;
851         }
852         break;
853     }
854
855     if (mark) LEPRINTF("mark=%u ", mark);
856
857
858     return 0;
859
860 }
861
862 static int
863 nflog_cb(struct nflog_g_handle *gh, struct nfgenmsg *nfmsg,
864                struct nflog_data *nfa, void *data)
865 {
866     struct log_entry *le = g_new0(struct log_entry, 1);
867
868     print_pkt(le, nfa, nfmsg->nfgen_family);
869
870     LEPRINTF("\n"); // add newline
871
872     queue_log_entry(le);
873
874     return 0;
875 }
876
877 static gboolean
878 nflog_read_cb(GIOChannel *source,
879               GIOCondition condition,
880               gpointer data)
881 {
882     int rv = 0;
883     gchar buf[8192];
884
885     int fd =  g_io_channel_unix_get_fd(source);
886
887     if ((rv = recv(fd, buf, sizeof(buf), 0)) && rv >= 0) {
888          nflog_handle_packet(logh, buf, rv);
889     }
890
891     return TRUE;
892 }
893
894 static gboolean
895 nlif_read_cb(GIOChannel *source,
896              GIOCondition condition,
897              gpointer data)
898 {
899     static int last_res = 0;
900     int res;
901
902     if ((res = nlif_catch(nlifh)) < 0) {
903         if (last_res == 0) { // only report once
904             log_status_message(3, "nlif_catch failed (res = %d)", res);
905         }
906         last_res = res;
907     } else {
908         last_res = 0;
909     }
910
911     return TRUE;
912 }
913
914 static gboolean
915 signal_read_cb(GIOChannel *source,
916                GIOCondition condition,
917                gpointer data)
918 {
919     int rv = 0;
920     struct signalfd_siginfo si;
921
922     int fd =  g_io_channel_unix_get_fd(source);
923
924     if ((rv = read(fd, &si, sizeof(si))) && rv >= 0) {
925         terminate_threads = TRUE;
926         log_status_message(5, "received terminate request (signal)");
927         g_main_loop_quit(main_loop);
928     }
929
930     return TRUE;
931 }
932
933 static int
934 nfct_cb(const struct nlmsghdr *nlh,
935         enum nf_conntrack_msg_type type,
936         struct nf_conntrack *ct,
937         void *data)
938 {
939     struct log_entry *le = g_new0(struct log_entry, 1);
940     int len = nfct_snprintf(&le->buf[le->len], LE_MAX - le->len,
941                             ct, type, NFCT_O_DEFAULT,
942                             NFCT_OF_SHOW_LAYER3|NFCT_OF_TIMESTAMP);
943     le->len += len;
944
945     if (le->len == LE_MAX) {
946         le->buf[le->len-1] = '\n';
947     } else { // le->len < LE_MAX
948         le->buf[le->len++] = '\n';
949     }
950
951     queue_log_entry(le);
952
953     return NFCT_CB_STOP;
954 }
955
956 static gboolean
957 nfct_read_cb(GIOChannel *source,
958              GIOCondition condition,
959              gpointer data)
960 {
961     int res;
962     if ((res = nfct_catch(nfcth)) < 0) {
963         if (errno == ENOBUFS) {
964             log_status_message(3, "nfct_catch returned ENOBUFS: conntrack information may be incomplete");
965         } else {
966             log_status_message(3, "error catching nfct: %s", strerror(errno));
967             return FALSE;
968         }
969     }
970     return TRUE;
971 }
972
973 int
974 main(int argc, char *argv[])
975 {
976     int lockfd = -1;
977     int sigfd = -1;
978
979     gboolean wrote_pidfile = FALSE;
980
981     openlog("pvefw-logger", LOG_CONS|LOG_PID, LOG_DAEMON);
982
983     GOptionContext *context;
984
985     GOptionEntry entries[] = {
986         { "debug", 'd', 0, G_OPTION_ARG_NONE, &debug, "Turn on debug messages", NULL },
987         { "foreground", 'f', 0, G_OPTION_ARG_NONE, &foreground, "Do not daemonize server", NULL },
988         { "conntrack", 0, 0, G_OPTION_ARG_NONE, &conntrack, "Add conntrack logging", NULL },
989         { NULL },
990     };
991
992     context = g_option_context_new("");
993     g_option_context_add_main_entries (context, entries, NULL);
994
995     GError *err = NULL;
996     if (!g_option_context_parse (context, &argc, &argv, &err)) {
997         fprintf(stderr, "error: %s\n", err->message);
998         fprintf(stderr, "%s", g_option_context_get_help(context, FALSE, NULL));
999         g_error_free (err);
1000         exit(-1);
1001     }
1002
1003     if (optind < argc) {
1004         fprintf(stderr, "error: too many arguments\n");
1005         fprintf(stderr, "%s", g_option_context_get_help(context, FALSE, NULL));
1006         exit(-1);
1007     }
1008
1009     g_option_context_free(context);
1010
1011     if (!conntrack) {
1012         int log_nf_conntrackfd = open(LOG_CONNTRACK_FILE, O_RDONLY);
1013         if (log_nf_conntrackfd == -1) {
1014             if (errno != ENOENT) {
1015                 fprintf(stderr, "error: failed to open "LOG_CONNTRACK_FILE": %s\n", strerror(errno));
1016             }
1017         } else {
1018             char c = '0';
1019             ssize_t bytes = read(log_nf_conntrackfd, &c, sizeof(c));
1020             if (bytes < 0) {
1021                 fprintf(stderr, "error: failed to read value in log_nf_conntrack: %s\n", strerror(errno));
1022             } else {
1023                 conntrack = (c == '1');
1024             }
1025         }
1026     }
1027
1028     if (debug) foreground = TRUE;
1029
1030     if ((lockfd = open(LOCKFILE, O_RDWR|O_CREAT|O_APPEND, 0644)) == -1) {
1031         fprintf(stderr, "unable to create lock '%s': %s\n", LOCKFILE, strerror (errno) );
1032         exit(-1);
1033     }
1034
1035     for (int i = 10; i >= 0; i--) {
1036         if (flock(lockfd, LOCK_EX|LOCK_NB) != 0) {
1037             if (!i) {
1038                 fprintf(stderr, "unable to aquire lock '%s': %s\n", LOCKFILE, strerror (errno));
1039                 exit(-1);
1040             }
1041             if (i == 10)
1042                 fprintf(stderr, "unable to aquire lock '%s' - trying again.\n", LOCKFILE);
1043
1044             sleep(1);
1045         }
1046     }
1047
1048     if ((outfd = open(LOGFILE, O_WRONLY|O_CREAT|O_APPEND, 0644)) == -1) {
1049         fprintf(stderr, "unable to open file '%s': %s\n", LOGFILE, strerror (errno));
1050         exit(-1);
1051     }
1052
1053     if ((logh = nflog_open())  == NULL) {
1054         fprintf(stderr, "unable to open nflog\n");
1055         exit(-1);
1056     }
1057
1058     if (nflog_bind_pf(logh, AF_INET) < 0) {
1059         fprintf(stderr, "nflog_bind_pf AF_INET failed\n");
1060         exit(-1);
1061     }
1062
1063 #if 0
1064     if (!nflog_bind_pf(logh, AF_INET6) <= 0) {
1065         fprintf(stderr, "nflog_bind_pf AF_INET6 failed\n");
1066         exit(-1);
1067     }
1068 #endif
1069
1070     if (nflog_bind_pf(logh, AF_BRIDGE) < 0) {
1071         fprintf(stderr, "nflog_bind_pf AF_BRIDGE failed\n");
1072         exit(-1);
1073     }
1074
1075     struct nflog_g_handle *qh = nflog_bind_group(logh, 0);
1076     if (!qh) {
1077         fprintf(stderr, "no nflog handle for group 0\n");
1078         exit(-1);
1079     }
1080
1081     if (nflog_set_mode(qh, NFULNL_COPY_PACKET, 0xffff) < 0) {
1082         fprintf(stderr, "can't set packet copy mode\n");
1083         exit(-1);
1084     }
1085
1086     if ((nlifh = nlif_open()) == NULL) {
1087         fprintf(stderr, "unable to open netlink interface handle\n");
1088         exit(-1);
1089     }
1090
1091     if (conntrack) {
1092         if ((nfcth = nfct_open(CONNTRACK, NF_NETLINK_CONNTRACK_NEW|NF_NETLINK_CONNTRACK_DESTROY)) == NULL) {
1093             fprintf(stderr, "unable to open netfilter conntrack\n");
1094             exit(-1);
1095         }
1096     }
1097
1098     sigset_t mask;
1099     sigemptyset(&mask);
1100     sigaddset(&mask, SIGINT);
1101     sigaddset(&mask, SIGTERM);
1102     
1103     sigprocmask(SIG_BLOCK, &mask, NULL);
1104
1105     if ((sigfd = signalfd(-1, &mask, SFD_NONBLOCK)) < 0) {
1106         fprintf(stderr, "unable to open signalfd: %s\n", strerror (errno));
1107         exit(-1);
1108     }
1109
1110     if (!foreground) {
1111         pid_t cpid = fork();
1112
1113         if (cpid == -1) {
1114             fprintf(stderr, "failed to daemonize program - %s\n", strerror (errno));
1115             exit(-1);
1116         } else if (cpid) {
1117             write_pidfile(cpid);
1118             _exit(0);
1119         } else {
1120             int nullfd;
1121
1122             if (chroot("/") != 0) fprintf(stderr, "chroot '/' failed - %s\n", strerror (errno));
1123
1124             if ((nullfd = open("/dev/null", O_RDWR, 0)) != -1) {
1125                 dup2(nullfd, 0);
1126                 dup2(nullfd, 1);
1127                 dup2(nullfd, 2);
1128                 if (nullfd > 2)
1129                     close (nullfd);
1130             }
1131
1132             setsid();
1133         }
1134     } else {
1135         write_pidfile(getpid());
1136     }
1137
1138     wrote_pidfile = TRUE;
1139
1140     nflog_callback_register(qh, &nflog_cb, logh);
1141
1142     queue = g_async_queue_new_full(g_free);
1143
1144     log_status_message(5, "starting pvefw logger");
1145
1146     nlif_query(nlifh);
1147
1148     GIOChannel *nlif_ch = g_io_channel_unix_new(nlif_fd(nlifh));
1149
1150     g_io_add_watch(nlif_ch, G_IO_IN, nlif_read_cb, NULL);
1151
1152     int logfd = nflog_fd(logh);
1153     GIOChannel *nflog_ch = g_io_channel_unix_new(logfd);
1154
1155     g_io_add_watch(nflog_ch, G_IO_IN, nflog_read_cb, NULL);
1156
1157     if (conntrack) {
1158         nfct_callback_register2(nfcth, NFCT_T_NEW|NFCT_T_DESTROY, &nfct_cb, NULL);
1159         int nfctfd = nfct_fd(nfcth);
1160         GIOChannel *nfct_ch = g_io_channel_unix_new(nfctfd);
1161         g_io_add_watch(nfct_ch, G_IO_IN, nfct_read_cb, NULL);
1162     }
1163
1164     GIOChannel *sig_ch = g_io_channel_unix_new(sigfd);
1165     if (!g_io_add_watch(sig_ch, G_IO_IN, signal_read_cb, NULL)) {
1166         exit(-1);
1167     }
1168
1169     GThread *wthread = g_thread_new("log_writer_thread", log_writer_thread, NULL);
1170
1171     main_loop = g_main_loop_new(NULL, TRUE);
1172
1173     g_main_loop_run(main_loop);
1174
1175     log_status_message(5, "stopping pvefw logger");
1176
1177     g_thread_join(wthread);
1178
1179     close(outfd);
1180
1181     if (conntrack) {
1182         nfct_callback_unregister2(nfcth);
1183         nfct_close(nfcth);
1184     }
1185
1186     nflog_close(logh);
1187
1188     if (wrote_pidfile)
1189         unlink(PIDFILE);
1190
1191     exit(0);
1192 }