3 Copyright (C) 2014 Proxmox Server Solutions GmbH
5 This software is written by Proxmox Server Solutions GmbH <support@proxmox.com>
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.
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.
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/>.
20 Author: Dietmar Maurer <dietmar@proxmox.com>
32 #include <sys/signalfd.h>
33 #include <sys/types.h>
37 #include <arpa/inet.h>
38 #include <sys/socket.h>
40 #include <linux/netlink.h>
41 #include <libnfnetlink/libnfnetlink.h>
42 #include <libnetfilter_log/libnetfilter_log.h>
43 #include <netinet/ip.h>
44 #include <netinet/ip_icmp.h>
45 #include <netinet/udp.h>
46 #include <netinet/tcp.h>
47 #include <netinet/if_ether.h>
52 static struct nflog_handle
*logh
= NULL
;
53 static struct nlif_handle
*nlifh
= NULL
;
56 gboolean foreground
= FALSE
;
57 gboolean debug
= FALSE
;
63 Special care was taken to allow fast parsing (and filer messages for a singl VM).
65 <VMID> <LOGLEVEL> <CHAIN> <TIME> <TIMEZONE> <MSG>
69 117 6 tap117i0-IN 14/Mar/2014:12:47:07 +0100 policy REJECT: IN=vmbr1 ...
73 #define LOGFILE "/var/log/pve-firewall.log"
75 #define LOCKFILE "/var/lock/pvefw-logger.lck"
76 #define PIDFILE "/var/run/pvefw-logger.pid"
79 #define LE_MAX (512 - 4) // try to fit into 512 bytes
81 #define MAX_CHAIN_LEN 28
84 guint32 len
; // max LE_MAX chars
88 #define STATIC_ASSERT(cond) \
89 extern void pve_static_assert(int test[(cond) ? 1 : -1])
91 STATIC_ASSERT(sizeof(struct log_entry
) == 512);
95 gboolean terminate_threads
= FALSE
;
97 static gboolean
write_pidfile(pid_t pid
)
101 char *strpid
= g_strdup_printf("%d\n", pid
);
102 res
= g_file_set_contents(PIDFILE
, strpid
, strlen(strpid
), NULL
);
108 static GAsyncQueue
*queue
;
111 safe_write(int fd
, char *buf
, size_t count
)
116 n
= write(fd
, buf
, count
);
117 } while (n
< 0 && errno
== EINTR
);
123 log_writer_thread(gpointer data
)
126 struct log_entry
*le
= (struct log_entry
*)g_async_queue_timeout_pop(queue
, 250000);
128 if (terminate_threads
) {
134 if (debug
) fputs(le
->buf
, stdout
);
136 int res
= safe_write(outfd
, le
->buf
, le
->len
);
141 syslog(3, "writing log failed, stopping daemon - %s", strerror (errno
));
142 g_main_loop_quit(main_loop
);
150 static int skipped_logs
= 0;
152 static void log_status_message(guint loglevel
, const char *fmt
, ...);
155 queue_log_entry(struct log_entry
*le
)
157 gint len
= g_async_queue_length(queue
);
159 if (skipped_logs
> 0) {
160 if (len
>= (LQ_LEN
- 1)) {
163 int skip_tmp
= skipped_logs
;
164 skipped_logs
= 0; // clear before calling log_status_message()
165 log_status_message(3, "skipped %d log entries (queue full)", skip_tmp
);
166 g_async_queue_push(queue
, le
);
172 g_async_queue_push(queue
, le
);
178 #define LEPRINTF(format, ...) { if (le->len < LE_MAX) le->len += snprintf(le->buf + le->len, LE_MAX - le->len, format, ##__VA_ARGS__); }
179 #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)); }
182 log_status_message(guint loglevel
, const char *fmt
, ...)
187 if (loglevel
> 7 ) loglevel
= 7; // syslog defines level 0-7
189 struct log_entry
*le
= g_new0(struct log_entry
, 1);
191 LEPRINTF("0 %d - ", loglevel
);
193 LEPRINTTIME(time(NULL
));
195 le
->len
+= vsnprintf(le
->buf
+ le
->len
, LE_MAX
- le
->len
, fmt
, ap
);
201 // also log to syslog
203 vsyslog(loglevel
, fmt
, ap
);
207 print_tcp(struct log_entry
*le
, struct tcphdr
*h
, int payload_len
)
209 LEPRINTF("PROTO=TCP ");
211 if (payload_len
< sizeof(struct tcphdr
)) {
212 LEPRINTF("LEN=%d ", payload_len
);
213 LEPRINTF("INVALID=LEN ");
217 LEPRINTF("SPT=%u DPT=%u ", ntohs(h
->source
), ntohs(h
->dest
));
218 LEPRINTF("SEQ=%u ACK=%u ", ntohl(h
->seq
), ntohl(h
->ack_seq
));
219 LEPRINTF("WINDOW=%u ", ntohs(h
->window
));
221 if (h
->urg
) LEPRINTF("URG ");
222 if (h
->ack
) LEPRINTF("ACK ");
223 if (h
->psh
) LEPRINTF("PSH ");
224 if (h
->rst
) LEPRINTF("RST ");
225 if (h
->syn
) LEPRINTF("SYN ");
226 if (h
->fin
) LEPRINTF("FIN ");
228 if (h
->urg
) LEPRINTF("URGP=%u ",ntohs(h
->urg_ptr
));
234 print_udp(struct log_entry
*le
, struct udphdr
*h
, int payload_len
)
236 LEPRINTF("PROTO=UDP ");
238 if (payload_len
< sizeof(struct udphdr
)) {
239 LEPRINTF("LEN=%d ", payload_len
);
240 LEPRINTF("INVALID=LEN ");
244 LEPRINTF("SPT=%u DPT=%u LEN=%u", ntohs(h
->source
), ntohs(h
->dest
), ntohs(h
->len
));
250 print_icmp(struct log_entry
*le
, struct icmphdr
*h
, int payload_len
)
252 char tmp
[INET_ADDRSTRLEN
];
255 LEPRINTF("PROTO=ICMP ");
257 if (payload_len
< sizeof(struct icmphdr
)) {
258 LEPRINTF("LEN=%d ", payload_len
);
259 LEPRINTF("INVALID=LEN ");
263 LEPRINTF("TYPE=%u CODE=%u ", h
->type
, h
->code
);
268 LEPRINTF("ID=%u SEQ=%u ", ntohs(h
->un
.echo
.id
), ntohs(h
->un
.echo
.sequence
));
270 case ICMP_PARAMETERPROB
:
271 LEPRINTF("PARAMETER=%u ", ntohl(h
->un
.gateway
) >> 24);
274 gateway
= ntohl(h
->un
.gateway
);
275 inet_ntop(AF_INET
, &gateway
, tmp
, sizeof(tmp
));
276 LEPRINTF("GATEWAY=%s ", tmp
);
278 case ICMP_DEST_UNREACH
:
279 if (h
->code
== ICMP_FRAG_NEEDED
) {
280 LEPRINTF("MTU=%u ", ntohs(h
->un
.frag
.mtu
));
288 /* Section 3.1. SCTP Common Header Format */
289 typedef struct sctphdr
{
294 } __attribute__((packed
)) sctp_sctphdr_t
;
297 print_sctp(struct log_entry
*le
, struct sctphdr
*h
, int payload_len
)
299 LEPRINTF("PROTO=SCTP ");
301 if (payload_len
< sizeof(struct sctphdr
)) {
302 LEPRINTF("LEN=%d ", payload_len
);
303 LEPRINTF("INVALID=LEN ");
307 LEPRINTF("SPT=%u DPT=%u ", ntohs(h
->source
), ntohs(h
->dest
));
313 print_iphdr(struct log_entry
*le
, char * payload
, int payload_len
)
315 if (payload_len
< sizeof(struct iphdr
)) {
316 LEPRINTF("LEN=%d ", payload_len
);
317 LEPRINTF("INVALID=LEN ");
321 struct iphdr
*h
= (struct iphdr
*)payload
;
323 if (payload_len
<= (u_int32_t
)(h
->ihl
* 4)) {
324 LEPRINTF("INVALID=IHL ");
328 char tmp
[INET_ADDRSTRLEN
];
330 inet_ntop(AF_INET
, &h
->saddr
, tmp
, sizeof(tmp
));
331 LEPRINTF("SRC=%s ", tmp
);
332 inet_ntop(AF_INET
, &h
->daddr
, tmp
, sizeof(tmp
));
333 LEPRINTF("DST=%s ", tmp
);
335 LEPRINTF("LEN=%u TOS=0x%02X PREC=0x%02X TTL=%u ID=%u ",
336 ntohs(h
->tot_len
), h
->tos
& IPTOS_TOS_MASK
,
337 h
->tos
& IPTOS_PREC_MASK
, h
->ttl
, ntohs(h
->id
));
339 short ip_off
= ntohs(h
->frag_off
);
340 if (ip_off
& IP_OFFMASK
)
341 LEPRINTF("FRAG=%u ", ip_off
& IP_OFFMASK
);
343 if (ip_off
& IP_DF
) LEPRINTF("DF ");
344 if (ip_off
& IP_MF
) LEPRINTF("MF ");
346 void *nexthdr
= (u_int32_t
*)h
+ h
->ihl
;
347 payload_len
-= h
->ihl
* 4;
349 switch (h
->protocol
) {
351 print_tcp(le
, (struct tcphdr
*)nexthdr
, payload_len
);
354 print_udp(le
, (struct udphdr
*)nexthdr
, payload_len
);
357 print_icmp(le
, (struct icmphdr
*)nexthdr
, payload_len
);
360 print_sctp(le
, (struct sctphdr
*)nexthdr
, payload_len
);
363 LEPRINTF("PROTO=AH ");
366 LEPRINTF("PROTO=ESP ");
369 LEPRINTF("PROTO=IGMP ");
372 LEPRINTF("PROTO=%u ", h
->protocol
);
379 print_ip6hdr(struct log_entry
*le
, char * payload
, int payload_len
)
381 LEPRINTF("IPV6 logging not implemented ");
386 // ebtables -I FORWARD --nflog --nflog-group 0
388 print_arp(struct log_entry
*le
, struct ether_arp
*h
, int payload_len
)
390 if (payload_len
< sizeof(struct ether_arp
)) {
391 LEPRINTF("LEN=%d ", payload_len
);
392 LEPRINTF("INVALID=LEN ");
396 LEPRINTF("SRC=%u.%u.%u.%u ", h
->arp_spa
[0], h
->arp_spa
[1],
397 h
->arp_spa
[2], h
->arp_spa
[3]);
399 LEPRINTF("DST=%u.%u.%u.%u ", h
->arp_tpa
[0], h
->arp_tpa
[1],
400 h
->arp_tpa
[2], h
->arp_tpa
[3]);
402 LEPRINTF("PROTO=ARP ");
404 unsigned short code
= ntohs(h
->arp_op
);
407 LEPRINTF("REQUEST ");
410 LEPRINTF("REPLY MAC=%02x:%02x:%02x:%02x:%02x:%02x ",
411 h
->arp_sha
[0], h
->arp_sha
[1], h
->arp_sha
[2],
412 h
->arp_sha
[3], h
->arp_sha
[4], h
->arp_sha
[5]);
418 LEPRINTF("CODE=%u ", code
);
422 // LEPRINTF("HTYPE=%u ", ntohs(h->arp_hrd));
424 // LEPRINTF("PTYPE=%u ", ntohs(h->arp_pro));
430 static int print_pkt(struct log_entry
*le
, struct nflog_data
*ldata
, u_int8_t family
)
432 u_int32_t mark
= nflog_get_nfmark(ldata
);
433 u_int32_t indev
= nflog_get_indev(ldata
);
434 u_int32_t outdev
= nflog_get_outdev(ldata
);
435 u_int32_t physindev
= nflog_get_physindev(ldata
);
436 u_int32_t physoutdev
= nflog_get_physoutdev(ldata
);
438 char *prefix
= nflog_get_prefix(ldata
);
444 guint8 log_level
= 6; // info
446 char *chain_name
= "-";
448 if (prefix
!= NULL
) {
449 // Note: parse ":$vmid:$loglevel:$chain: $msg"
450 if (prefix
[0] == ':') {
451 char *p
= prefix
+ 1;
453 while(*p
>= '0' && *p
<= '9') { tmpid
*= 10; tmpid
+= *p
- '0'; p
++; }
456 (p
[1] >= '0' && p
[1] <= '7') &&
459 guint8 tmp_level
= p
[1] - '0'; // store for later use
460 char *chain_start
= p
+ 3; // store for later use
462 while (*p
&& *p
!= ':' && *p
!= ' ') p
++;
463 int len
= p
- chain_start
;
465 if (*p
== ':' && p
[1] == ' ' && len
&& (len
<= MAX_CHAIN_LEN
)) {
466 // parsing successful
468 *p
= 0; // terminate string
471 log_level
= tmp_level
;
472 chain_name
= chain_start
;
473 prefix
= p
+ 2; // the rest
479 LEPRINTF("%d ", vmid
);
481 LEPRINTF("%d ", log_level
);
483 LEPRINTF("%s ", chain_name
);
486 nflog_get_timestamp(ldata
, &ts
);
488 LEPRINTTIME(ts
.tv_sec
);
490 if (prefix
!= NULL
) {
491 LEPRINTF("%s", prefix
);
495 if (nlif_index2name(nlifh
, indev
, devname
) != -1) {
496 LEPRINTF("IN=%s ", devname
);
498 LEPRINTF("IN=%u ", indev
);
503 if (nlif_index2name(nlifh
, outdev
, devname
) != -1) {
504 LEPRINTF("OUT=%s ", devname
);
506 LEPRINTF("OUT=%u ", outdev
);
511 if (nlif_index2name(nlifh
, physindev
, devname
) != -1) {
512 LEPRINTF("PHYSIN=%s ", devname
);
514 LEPRINTF("PHYSIN=%u ", physindev
);
518 if (physoutdev
> 0) {
519 if (nlif_index2name(nlifh
, physoutdev
, devname
) != -1) {
520 LEPRINTF("PHYSOUT=%s ", devname
);
522 LEPRINTF("PHYSOUT=%u ", physoutdev
);
526 int payload_len
= nflog_get_payload(ldata
, &payload
);
528 int hwhdrlen
= nflog_get_msg_packet_hwhdrlen(ldata
);
530 unsigned char *hwhdr
= (unsigned char *)nflog_get_msg_packet_hwhdr(ldata
);
534 for (i
= 0; i
< hwhdrlen
; i
++) {
535 LEPRINTF("%02x", hwhdr
[i
]);
536 if (i
< (hwhdrlen
-1 )) LEPRINTF(":");
542 u_int16_t hw_protocol
= 0;
543 struct nfulnl_msg_packet_hdr
*ph
= NULL
;
547 print_iphdr(le
, payload
, payload_len
);
550 print_ip6hdr(le
, payload
, payload_len
);
553 ph
= nflog_get_msg_packet_hdr(ldata
);
554 if (ph
) hw_protocol
= ntohs(ph
->hw_protocol
);
556 switch (hw_protocol
) {
558 print_iphdr(le
, payload
, payload_len
);
561 print_ip6hdr(le
, payload
, payload_len
);
564 print_arp(le
, (struct ether_arp
*)payload
, payload_len
);
570 if (mark
) LEPRINTF("mark=%u ", mark
);
578 nflog_cb(struct nflog_g_handle
*gh
, struct nfgenmsg
*nfmsg
,
579 struct nflog_data
*nfa
, void *data
)
581 struct log_entry
*le
= g_new0(struct log_entry
, 1);
583 print_pkt(le
, nfa
, nfmsg
->nfgen_family
);
585 LEPRINTF("\n"); // add newline
593 nflog_read_cb(GIOChannel
*source
,
594 GIOCondition condition
,
600 int fd
= g_io_channel_unix_get_fd(source
);
602 if ((rv
= recv(fd
, buf
, sizeof(buf
), 0)) && rv
>= 0) {
603 nflog_handle_packet(logh
, buf
, rv
);
610 nlif_read_cb(GIOChannel
*source
,
611 GIOCondition condition
,
614 static int last_res
= 0;
617 if ((res
= nlif_catch(nlifh
)) < 0) {
618 if (last_res
== 0) { // only report once
619 log_status_message(3, "nlif_catch failed (res = %d)", res
);
630 signal_read_cb(GIOChannel
*source
,
631 GIOCondition condition
,
635 struct signalfd_siginfo si
;
637 int fd
= g_io_channel_unix_get_fd(source
);
639 if ((rv
= read(fd
, &si
, sizeof(si
))) && rv
>= 0) {
640 terminate_threads
= TRUE
;
641 log_status_message(5, "received terminate request (signal)");
642 g_main_loop_quit(main_loop
);
649 main(int argc
, char *argv
[])
654 gboolean wrote_pidfile
= FALSE
;
658 openlog("pvepw-logger", LOG_CONS
|LOG_PID
, LOG_DAEMON
);
660 GOptionContext
*context
;
662 GOptionEntry entries
[] = {
663 { "debug", 'd', 0, G_OPTION_ARG_NONE
, &debug
, "Turn on debug messages", NULL
},
664 { "foreground", 'f', 0, G_OPTION_ARG_NONE
, &foreground
, "Do not daemonize server", NULL
},
668 context
= g_option_context_new("");
669 g_option_context_add_main_entries (context
, entries
, NULL
);
672 if (!g_option_context_parse (context
, &argc
, &argv
, &err
)) {
673 fprintf(stderr
, "error: %s\n", err
->message
);
674 fprintf(stderr
, "%s", g_option_context_get_help(context
, FALSE
, NULL
));
680 fprintf(stderr
, "error: too many arguments\n");
681 fprintf(stderr
, "%s", g_option_context_get_help(context
, FALSE
, NULL
));
685 g_option_context_free(context
);
687 if (debug
) foreground
= TRUE
;
689 if ((lockfd
= open(LOCKFILE
, O_RDWR
|O_CREAT
|O_APPEND
, 0644)) == -1) {
690 fprintf(stderr
, "unable to create lock '%s': %s\n", LOCKFILE
, strerror (errno
) );
694 for (int i
= 10; i
>= 0; i
--) {
695 if (flock(lockfd
, LOCK_EX
|LOCK_NB
) != 0) {
697 fprintf(stderr
, "unable to aquire lock '%s': %s\n", LOCKFILE
, strerror (errno
));
701 fprintf(stderr
, "unable to aquire lock '%s' - trying again.\n", LOCKFILE
);
707 if ((outfd
= open(LOGFILE
, O_WRONLY
|O_CREAT
|O_APPEND
, 0644)) == -1) {
708 fprintf(stderr
, "unable to open file '%s': %s\n", LOGFILE
, strerror (errno
));
712 if ((logh
= nflog_open()) == NULL
) {
713 fprintf(stderr
, "unable to open nflog\n");
717 if (!nflog_bind_pf(logh
, AF_INET
) <= 0) {
718 fprintf(stderr
, "nflog_bind_pf AF_INET failed\n");
723 if (!nflog_bind_pf(logh
, AF_INET6
) <= 0) {
724 fprintf(stderr
, "nflog_bind_pf AF_INET6 failed\n");
729 if (!nflog_bind_pf(logh
, AF_BRIDGE
) <= 0) {
730 fprintf(stderr
, "nflog_bind_pf AF_BRIDGE failed\n");
734 struct nflog_g_handle
*qh
= nflog_bind_group(logh
, 0);
736 fprintf(stderr
, "no nflog handle for group 0\n");
740 if (nflog_set_mode(qh
, NFULNL_COPY_PACKET
, 0xffff) < 0) {
741 fprintf(stderr
, "can't set packet copy mode\n");
745 if ((nlifh
= nlif_open()) == NULL
) {
746 fprintf(stderr
, "unable to open netlink interface handle\n");
752 sigaddset(&mask
, SIGINT
);
753 sigaddset(&mask
, SIGTERM
);
755 sigprocmask(SIG_BLOCK
, &mask
, NULL
);
757 if ((sigfd
= signalfd(-1, &mask
, SFD_NONBLOCK
)) < 0) {
758 fprintf(stderr
, "unable to open signalfd: %s\n", strerror (errno
));
766 fprintf(stderr
, "failed to daemonize program - %s\n", strerror (errno
));
774 if (chroot("/") != 0) fprintf(stderr
, "chroot '/' failed - %s\n", strerror (errno
));
776 if ((nullfd
= open("/dev/null", O_RDWR
, 0)) != -1) {
787 write_pidfile(getpid());
790 wrote_pidfile
= TRUE
;
792 nflog_callback_register(qh
, &nflog_cb
, logh
);
794 queue
= g_async_queue_new_full(g_free
);
796 log_status_message(5, "starting pvefw logger");
800 GIOChannel
*nlif_ch
= g_io_channel_unix_new(nlif_fd(nlifh
));
802 g_io_add_watch(nlif_ch
, G_IO_IN
, nlif_read_cb
, NULL
);
804 int logfd
= nflog_fd(logh
);
805 GIOChannel
*nflog_ch
= g_io_channel_unix_new(logfd
);
807 g_io_add_watch(nflog_ch
, G_IO_IN
, nflog_read_cb
, NULL
);
809 GIOChannel
*sig_ch
= g_io_channel_unix_new(sigfd
);
810 if (!g_io_add_watch(sig_ch
, G_IO_IN
, signal_read_cb
, NULL
)) {
814 GThread
*wthread
= g_thread_new("log_writer_thread", log_writer_thread
, NULL
);
816 main_loop
= g_main_loop_new(NULL
, TRUE
);
818 g_main_loop_run(main_loop
);
820 log_status_message(5, "stopping pvefw logger");
822 g_thread_join(wthread
);