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 }