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