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