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/types.h>
  33 #include <sys/stat.h>
  34 #include <fcntl.h>
  35 #include <unistd.h>
  36 #include <arpa/inet.h>
  37 #include <sys/socket.h>
  38 #include <sys/file.h>
  39 #include <linux/netlink.h>
  40 #include <libnfnetlink/libnfnetlink.h>
  41 #include <libnetfilter_log/libnetfilter_log.h>
  42 #include <netinet/ip.h>
  43 #include <netinet/ip_icmp.h>
  44 #include <netinet/udp.h>
  45 #include <netinet/tcp.h>
  46 #include <netinet/if_ether.h>
  47
  48 #include <glib.h>
  49 #include <glib-unix.h>
  50
  51 static struct nflog_handle *logh = NULL;
  52 static struct nlif_handle *nlifh = NULL;
  53
  54 #define LOGFILE "/var/log/pve-firewall.log"
  55
  56 #define LOCKFILE "/var/lock/pvefw-logger.lck"
  57 #define PIDFILE "/var/run/pvefw-logger.pid"
  58
  59 #define LQ_LEN 512
  60 #define LE_MAX (512 - 16) // try to fit into 512 bytes
  61
  62 struct log_entry {
  63     guint32 len; // max LE_MAX chars
  64     char buf[LE_MAX];
  65 };
  66
  67 int outfd = -1;
  68
  69 gboolean terminate_threads = FALSE;
  70
  71 static gboolean write_pidfile(pid_t pid)
  72 {
  73     gboolean res;
  74
  75     char *strpid = g_strdup_printf("%d\n", pid);
  76     res = g_file_set_contents(PIDFILE, strpid, strlen(strpid), NULL);
  77     g_free(strpid);
  78
  79     return res;
  80 }
  81
  82 static GAsyncQueue *queue;
  83
  84 ssize_t
  85 safe_write(int fd, char *buf, size_t count)
  86 {
  87   ssize_t n;
  88
  89   do {
  90     n = write(fd, buf, count);
  91   } while (n < 0 && errno == EINTR);
  92
  93   return n;
  94 }
  95
  96 static gpointer
  97 log_writer_thread(gpointer data)
  98 {
  99     while (1) {
 100         struct log_entry *le = (struct log_entry *)g_async_queue_timeout_pop(queue, 250000);
 101         if (le == NULL) {
 102             if (terminate_threads) {
 103                 return NULL;
 104             }
 105             continue;
 106         }
 107
 108         int res = safe_write(outfd, le->buf, le->len);
 109
 110         g_free(le);
 111
 112         if (res < 0) {
 113             // printf("write failed\n"); // fixme??
 114         }
 115     }
 116
 117     return NULL;
 118 }
 119
 120 static int skipped_logs = 0;
 121
 122 static void log_status_message(const char *fmt, ...);
 123
 124 static void
 125 queue_log_entry(struct log_entry *le)
 126 {
 127     gint len = g_async_queue_length(queue);
 128
 129     if (skipped_logs > 0) {
 130         if (len >= (LQ_LEN - 1)) {
 131             skipped_logs++;
 132         } else {
 133             int skip_tmp = skipped_logs;
 134             skipped_logs = 0; // clear before calling log_status_message()
 135             log_status_message("skipped %d log entries (queue full)", skip_tmp);
 136             g_async_queue_push(queue, le);
 137         }
 138     } else {
 139         if (len >= LQ_LEN) {
 140             skipped_logs++;
 141         } else {
 142             g_async_queue_push(queue, le);
 143         }
 144     }
 145 }
 146
 147
 148 #define LEPRINTF(format, ...) { if (le->len < LE_MAX) le->len += snprintf(le->buf + le->len, LE_MAX - le->len, format, ##__VA_ARGS__); }
 149 #define LEPRINTTIME(sec) { time_t tmp_sec = sec; if (le->len < (LE_MAX - 30)) le->len += strftime(le->buf + le->len, LE_MAX - le->len, "%d/%b/%Y:%H:%M:%S %z ", localtime(&tmp_sec)); }
 150
 151 static void
 152 log_status_message(const char *fmt, ...)
 153 {
 154     va_list ap;
 155     va_start(ap, fmt);
 156
 157     struct log_entry *le = g_new0(struct log_entry, 1);
 158
 159     LEPRINTTIME(time(NULL));
 160
 161     le->len += vsnprintf(le->buf + le->len, LE_MAX - le->len, fmt, ap);
 162
 163     LEPRINTF("\n");
 164
 165     queue_log_entry(le);
 166 }
 167
 168 static int
 169 print_tcp(struct log_entry *le, struct tcphdr *h, int payload_len)
 170 {
 171     LEPRINTF("PROTO=TCP ");
 172
 173     if (payload_len < sizeof(struct tcphdr)) {
 174         LEPRINTF("LEN=%d ", payload_len);
 175         LEPRINTF("INVALID=LEN ");
 176         return -1;
 177     }
 178
 179     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
 180     LEPRINTF("SEQ=%u ACK=%u ", ntohl(h->seq), ntohl(h->ack_seq));
 181     LEPRINTF("WINDOW=%u ", ntohs(h->window));
 182
 183     if (h->urg) LEPRINTF("URG ");
 184     if (h->ack) LEPRINTF("ACK ");
 185     if (h->psh) LEPRINTF("PSH ");
 186     if (h->rst) LEPRINTF("RST ");
 187     if (h->syn) LEPRINTF("SYN ");
 188     if (h->fin) LEPRINTF("FIN ");
 189
 190     if (h->urg) LEPRINTF("URGP=%u ",ntohs(h->urg_ptr));
 191
 192     return 0;
 193 }
 194
 195 static int
 196 print_udp(struct log_entry *le, struct udphdr *h, int payload_len)
 197 {
 198     LEPRINTF("PROTO=UDP ");
 199
 200     if (payload_len < sizeof(struct udphdr)) {
 201         LEPRINTF("LEN=%d ", payload_len);
 202         LEPRINTF("INVALID=LEN ");
 203         return -1;
 204     }
 205
 206     LEPRINTF("SPT=%u DPT=%u LEN=%u", ntohs(h->source), ntohs(h->dest), ntohs(h->len));
 207
 208     return 0;
 209 }
 210
 211 static int
 212 print_icmp(struct log_entry *le, struct icmphdr *h, int payload_len)
 213 {
 214     char tmp[INET_ADDRSTRLEN];
 215     u_int32_t gateway;
 216
 217     LEPRINTF("PROTO=ICMP ");
 218
 219     if (payload_len < sizeof(struct icmphdr)) {
 220         LEPRINTF("LEN=%d ", payload_len);
 221         LEPRINTF("INVALID=LEN ");
 222         return -1;
 223     }
 224
 225     LEPRINTF("TYPE=%u CODE=%u ", h->type, h->code);
 226
 227     switch (h->type) {
 228     case ICMP_ECHO:
 229     case ICMP_ECHOREPLY:
 230         LEPRINTF("ID=%u SEQ=%u ", ntohs(h->un.echo.id), ntohs(h->un.echo.sequence));
 231         break;
 232     case ICMP_PARAMETERPROB:
 233         LEPRINTF("PARAMETER=%u ", ntohl(h->un.gateway) >> 24);
 234         break;
 235     case ICMP_REDIRECT:
 236         gateway = ntohl(h->un.gateway);
 237         inet_ntop(AF_INET, &gateway, tmp, sizeof(tmp));
 238         LEPRINTF("GATEWAY=%s ", tmp);
 239         break;
 240     case ICMP_DEST_UNREACH:
 241         if (h->code == ICMP_FRAG_NEEDED) {
 242             LEPRINTF("MTU=%u ", ntohs(h->un.frag.mtu));
 243         }
 244         break;
 245     }
 246
 247     return 0;
 248 }
 249
 250 /* Section 3.1.  SCTP Common Header Format */
 251 typedef struct sctphdr {
 252         __be16 source;
 253         __be16 dest;
 254         __be32 vtag;
 255         __be32 checksum;
 256 } __attribute__((packed)) sctp_sctphdr_t;
 257
 258 static int
 259 print_sctp(struct log_entry *le, struct sctphdr *h, int payload_len)
 260 {
 261     LEPRINTF("PROTO=SCTP ");
 262
 263     if (payload_len < sizeof(struct sctphdr)) {
 264         LEPRINTF("LEN=%d ", payload_len);
 265         LEPRINTF("INVALID=LEN ");
 266         return -1;
 267     }
 268
 269     LEPRINTF("SPT=%u DPT=%u ", ntohs(h->source), ntohs(h->dest));
 270
 271     return 0;
 272 }
 273
 274 static int
 275 print_iphdr(struct log_entry *le, char * payload, int payload_len)
 276 {
 277     if (payload_len < sizeof(struct iphdr)) {
 278        LEPRINTF("LEN=%d ", payload_len);
 279        LEPRINTF("INVALID=LEN ");
 280        return -1;
 281     }
 282
 283     struct iphdr *h = (struct iphdr *)payload;
 284
 285     if (payload_len <= (u_int32_t)(h->ihl * 4)) {
 286         LEPRINTF("INVALID=IHL ");
 287         return -1;
 288     }
 289
 290     char tmp[INET_ADDRSTRLEN];
 291
 292     inet_ntop(AF_INET, &h->saddr, tmp, sizeof(tmp));
 293     LEPRINTF("SRC=%s ", tmp);
 294     inet_ntop(AF_INET, &h->daddr, tmp, sizeof(tmp));
 295     LEPRINTF("DST=%s ", tmp);
 296
 297     LEPRINTF("LEN=%u TOS=0x%02X PREC=0x%02X TTL=%u ID=%u ",
 298              ntohs(h->tot_len),  h->tos & IPTOS_TOS_MASK,
 299              h->tos & IPTOS_PREC_MASK, h->ttl, ntohs(h->id));
 300
 301     short ip_off = ntohs(h->frag_off);
 302     if (ip_off & IP_OFFMASK)
 303         LEPRINTF("FRAG=%u ", ip_off & IP_OFFMASK);
 304
 305     if (ip_off & IP_DF) LEPRINTF("DF ");
 306     if (ip_off & IP_MF) LEPRINTF("MF ");
 307
 308     void *nexthdr = (u_int32_t *)h + h->ihl;
 309     payload_len -= h->ihl * 4;
 310
 311     switch (h->protocol) {
 312     case IPPROTO_TCP:
 313         print_tcp(le, (struct tcphdr *)nexthdr, payload_len);
 314         break;
 315     case IPPROTO_UDP:
 316         print_udp(le, (struct udphdr *)nexthdr, payload_len);
 317         break;
 318     case IPPROTO_ICMP:
 319         print_icmp(le, (struct icmphdr *)nexthdr, payload_len);
 320         break;
 321     case IPPROTO_SCTP:
 322         print_sctp(le, (struct sctphdr *)nexthdr, payload_len);
 323         break;
 324     case IPPROTO_AH:
 325         LEPRINTF("PROTO=AH ");
 326         break;
 327     case IPPROTO_ESP:
 328         LEPRINTF("PROTO=ESP ");
 329         break;
 330     case IPPROTO_IGMP:
 331         LEPRINTF("PROTO=IGMP ");
 332         break;
 333      default:
 334         LEPRINTF("PROTO=%u ", h->protocol);
 335     }
 336
 337     return 0;
 338 }
 339
 340 static int
 341 print_ip6hdr(struct log_entry *le, char * payload, int payload_len)
 342 {
 343     LEPRINTF("IPV6 logging not implemented ");
 344
 345     return 0;
 346 }
 347
 348 // ebtables -I FORWARD --nflog --nflog-group 0
 349 static int
 350 print_arp(struct log_entry *le, struct ether_arp *h, int payload_len)
 351 {
 352     if (payload_len < sizeof(struct ether_arp)) {
 353         LEPRINTF("LEN=%d ", payload_len);
 354         LEPRINTF("INVALID=LEN ");
 355         return -1;
 356     }
 357
 358     LEPRINTF("SRC=%u.%u.%u.%u ", h->arp_spa[0], h->arp_spa[1],
 359              h->arp_spa[2], h->arp_spa[3]);
 360
 361     LEPRINTF("DST=%u.%u.%u.%u ", h->arp_tpa[0], h->arp_tpa[1],
 362              h->arp_tpa[2], h->arp_tpa[3]);
 363
 364     LEPRINTF("PROTO=ARP ");
 365
 366     unsigned short code = ntohs(h->arp_op);
 367     switch (code) {
 368     case ARPOP_REQUEST:
 369         LEPRINTF("REQUEST ");
 370         break;
 371     case ARPOP_REPLY:
 372         LEPRINTF("REPLY MAC=%02x:%02x:%02x:%02x:%02x:%02x ",
 373                  h->arp_sha[0], h->arp_sha[1], h->arp_sha[2],
 374                  h->arp_sha[3], h->arp_sha[4], h->arp_sha[5]);
 375         break;
 376     case ARPOP_NAK:
 377         LEPRINTF("NAK ");
 378         break;
 379     default:
 380         LEPRINTF("CODE=%u ", code);
 381     }
 382
 383
 384     // LEPRINTF("HTYPE=%u ", ntohs(h->arp_hrd));
 385
 386     // LEPRINTF("PTYPE=%u ", ntohs(h->arp_pro));
 387
 388     return 0;
 389 }
 390
 391
 392 static int print_pkt(struct log_entry *le, struct nflog_data *ldata, u_int8_t family)
 393 {
 394     u_int32_t mark = nflog_get_nfmark(ldata);
 395     u_int32_t indev = nflog_get_indev(ldata);
 396     u_int32_t outdev = nflog_get_outdev(ldata);
 397     u_int32_t physindev = nflog_get_physindev(ldata);
 398     u_int32_t physoutdev = nflog_get_physoutdev(ldata);
 399
 400     char *prefix = nflog_get_prefix(ldata);
 401     char *payload;
 402     char devname[256];
 403
 404     struct timeval ts;
 405     nflog_get_timestamp(ldata, &ts);
 406
 407     LEPRINTTIME(ts.tv_sec);
 408
 409     //le->len += strftime(le->buf + le->len, LE_MAX - le->len, "%d/%b/%Y:%H:%M:%S %z ", localtime(&ts.tv_sec));
 410
 411     if (prefix != NULL) {
 412         LEPRINTF("%s", prefix);
 413     }
 414
 415     if ((indev > 0) && (nlif_index2name(nlifh, indev, devname) != -1)) {
 416         LEPRINTF("IN=%s ", devname);
 417     }
 418
 419     if ((outdev > 0) && (nlif_index2name(nlifh, outdev, devname) != -1)) {
 420         LEPRINTF("OUT=%s ", devname);
 421     }
 422
 423     if ((physindev > 0) && (nlif_index2name(nlifh, physindev, devname) != -1)) {
 424         LEPRINTF("PHYSIN=%s ", devname);
 425     }
 426
 427     if ((physoutdev > 0) &&  (nlif_index2name(nlifh, physoutdev, devname) != -1)) {
 428         LEPRINTF("PHYSOUT=%s ", devname);
 429     }
 430
 431     int payload_len = nflog_get_payload(ldata, &payload);
 432
 433     int hwhdrlen = nflog_get_msg_packet_hwhdrlen(ldata);
 434     if (hwhdrlen > 0) {
 435         unsigned char *hwhdr = (unsigned char *)nflog_get_msg_packet_hwhdr(ldata);
 436         if (hwhdr != NULL) {
 437             int i;
 438             LEPRINTF("MAC=");
 439             for (i = 0; i < hwhdrlen; i++) {
 440                 LEPRINTF("%02x", hwhdr[i]);
 441                 if (i < (hwhdrlen -1 )) LEPRINTF(":");
 442             }
 443             LEPRINTF(" ");
 444         }
 445     }
 446
 447     u_int16_t hw_protocol = 0;
 448     struct nfulnl_msg_packet_hdr *ph = NULL;
 449
 450     switch (family) {
 451     case AF_INET:
 452         print_iphdr(le, payload, payload_len);
 453         break;
 454     case AF_INET6:
 455         print_ip6hdr(le, payload, payload_len);
 456         break;
 457     case AF_BRIDGE:
 458         ph = nflog_get_msg_packet_hdr(ldata);
 459         if (ph) hw_protocol = ntohs(ph->hw_protocol);
 460
 461         switch (hw_protocol) {
 462         case ETH_P_IP:
 463             print_iphdr(le, payload, payload_len);
 464             break;
 465         case ETH_P_IPV6:
 466              print_ip6hdr(le, payload, payload_len);
 467             break;
 468         case ETH_P_ARP:
 469             print_arp(le, (struct ether_arp *)payload, payload_len);
 470             break;
 471         }
 472         break;
 473     }
 474
 475     if (mark) LEPRINTF("mark=%u ", mark);
 476
 477
 478     return 0;
 479
 480 }
 481
 482 static int
 483 nflog_cb(struct nflog_g_handle *gh, struct nfgenmsg *nfmsg,
 484                struct nflog_data *nfa, void *data)
 485 {
 486     struct log_entry *le = g_new0(struct log_entry, 1);
 487
 488     print_pkt(le, nfa, nfmsg->nfgen_family);
 489
 490     LEPRINTF("\n"); // add newline
 491
 492     queue_log_entry(le);
 493
 494     return 0;
 495 }
 496
 497 static gboolean
 498 nflog_read_cb(GIOChannel *source,
 499               GIOCondition condition,
 500               gpointer data)
 501 {
 502     int rv = 0;
 503     gchar buf[8192];
 504
 505     int fd =  g_io_channel_unix_get_fd(source);
 506
 507     if ((rv = recv(fd, buf, sizeof(buf), 0)) && rv >= 0) {
 508          nflog_handle_packet(logh, buf, rv);
 509     }
 510
 511     return TRUE;
 512 }
 513
 514 static gboolean
 515 nlif_read_cb(GIOChannel *source,
 516              GIOCondition condition,
 517              gpointer data)
 518 {
 519     nlif_catch(nlifh);
 520     // fixme: report  errors
 521     return TRUE;
 522 }
 523
 524 GMainLoop *main_loop;
 525
 526 static gboolean
 527 terminate_request(gpointer data)
 528 {
 529     terminate_threads = TRUE;
 530
 531     log_status_message("received terminate request (signal)");
 532
 533     g_main_loop_quit(main_loop);
 534
 535     return TRUE;
 536 }
 537
 538
 539 int
 540 main(int argc, char *argv[])
 541 {
 542     int lockfd = -1;
 543     gboolean foreground = FALSE;
 544     gboolean wrote_pidfile = FALSE;
 545
 546     g_thread_init(NULL);
 547
 548     if ((lockfd = open(LOCKFILE, O_RDWR|O_CREAT|O_APPEND, 0644)) == -1) {
 549         fprintf(stderr, "unable to create lock '%s': %s", LOCKFILE, strerror (errno));
 550         exit(-1);
 551     }
 552
 553     for (int i = 10; i >= 0; i--) {
 554         if (flock(lockfd, LOCK_EX|LOCK_NB) != 0) {
 555             if (!i) {
 556                 fprintf(stderr, "unable to aquire lock '%s': %s", LOCKFILE, strerror (errno));
 557                 exit(-1);
 558             }
 559             if (i == 10)
 560                 fprintf(stderr, "unable to aquire lock '%s' - trying again.\n", LOCKFILE);
 561
 562             sleep(1);
 563         }
 564     }
 565
 566     if ((outfd = open(LOGFILE, O_WRONLY|O_CREAT|O_APPEND, 0644)) == -1) {
 567         fprintf(stderr, "unable to open file '%s': %s", LOGFILE, strerror (errno));
 568         exit(-1);
 569     }
 570
 571     if ((logh = nflog_open())  == NULL) {
 572         fprintf(stderr, "unable to open nflog\n");
 573         exit(-1);
 574     }
 575
 576     if (!nflog_bind_pf(logh, AF_INET) <= 0) {
 577         fprintf(stderr, "nflog_bind_pf AF_INET failed\n");
 578         exit(-1);
 579     }
 580
 581 #if 0
 582     if (!nflog_bind_pf(logh, AF_INET6) <= 0) {
 583         fprintf(stderr, "nflog_bind_pf AF_INET6 failed\n");
 584         exit(-1);
 585     }
 586 #endif
 587
 588     if (!nflog_bind_pf(logh, AF_BRIDGE) <= 0) {
 589         fprintf(stderr, "nflog_bind_pf AF_BRIDGE failed\n");
 590         exit(-1);
 591     }
 592
 593     struct nflog_g_handle *qh = nflog_bind_group(logh, 0);
 594     if (!qh) {
 595         fprintf(stderr, "no handle for group 1\n");
 596         exit(-1);
 597     }
 598
 599     if (nflog_set_mode(qh, NFULNL_COPY_PACKET, 0xffff) < 0) {
 600         fprintf(stderr, "can't set packet copy mode\n");
 601         exit(-1);
 602     }
 603
 604     if ((nlifh = nlif_open()) == NULL) {
 605         fprintf(stderr, "unable to open netlink interface handle\n");
 606         exit(-1);
 607     }
 608
 609     if (!foreground) {
 610         pid_t cpid = fork();
 611
 612         if (cpid == -1) {
 613             fprintf(stderr, "failed to daemonize program - %s\n", strerror (errno));
 614             exit(-1);
 615         } else if (cpid) {
 616             write_pidfile(cpid);
 617             _exit(0);
 618         } else {
 619             int nullfd;
 620
 621             if (chroot("/") != 0) fprintf(stderr, "chroot '/' failed - %s\n", strerror (errno));
 622
 623             if ((nullfd = open("/dev/null", O_RDWR, 0)) != -1) {
 624                 dup2(nullfd, 0);
 625                 dup2(nullfd, 1);
 626                 dup2(nullfd, 2);
 627                 if (nullfd > 2)
 628                     close (nullfd);
 629             }
 630
 631             setsid();
 632         }
 633     } else {
 634         write_pidfile(getpid());
 635     }
 636
 637     wrote_pidfile = TRUE;
 638
 639     nflog_callback_register(qh, &nflog_cb, logh);
 640
 641     queue = g_async_queue_new_full(g_free);
 642
 643     log_status_message("starting pvefw logger");
 644
 645     nlif_query(nlifh);
 646
 647     GIOChannel *nlif_ch = g_io_channel_unix_new(nlif_fd(nlifh));
 648
 649     g_io_add_watch(nlif_ch, G_IO_IN, nlif_read_cb, NULL);
 650
 651     int logfd = nflog_fd(logh);
 652     GIOChannel *nflog_ch = g_io_channel_unix_new(logfd);
 653
 654     g_io_add_watch(nflog_ch, G_IO_IN, nflog_read_cb, NULL);
 655
 656     GThread *wthread = g_thread_new("log_writer_thread", log_writer_thread, NULL);
 657
 658     main_loop = g_main_loop_new(NULL, TRUE);
 659
 660     g_unix_signal_add(SIGINT, terminate_request, NULL);
 661     g_unix_signal_add(SIGTERM, terminate_request, NULL);
 662
 663     g_main_loop_run(main_loop);
 664
 665     log_status_message("stopping pvefw logger");
 666
 667     g_thread_join(wthread);
 668
 669     close(outfd);
 670
 671     nflog_close(logh);
 672
 673     if (wrote_pidfile)
 674         unlink(PIDFILE);
 675
 676     exit(0);
 677 }