diff --git a/Makefile b/Makefile index 74bbfeb..e4c64fe 100644 --- a/Makefile +++ b/Makefile @@ -41,7 +41,7 @@ SRCS = $(PASST_SRCS) $(QRAP_SRCS) MANPAGES = passt.1 pasta.1 qrap.1 PASST_HEADERS = arch.h arp.h checksum.h conf.h dhcp.h dhcpv6.h icmp.h \ - isolation.h lineread.h ndp.h netlink.h packet.h passt.h pasta.h \ + isolation.h lineread.h log.h ndp.h netlink.h packet.h passt.h pasta.h \ pcap.h port_fwd.h siphash.h tap.h tcp.h tcp_splice.h udp.h util.h HEADERS = $(PASST_HEADERS) seccomp.h @@ -90,6 +90,11 @@ ifeq ($(shell :|$(CC) -fstack-protector-strong -S -xc - -o - >/dev/null 2>&1; ec FLAGS += -fstack-protector-strong endif +C := \#define _GNU_SOURCE\n\#include \nx = FALLOC_FL_COLLAPSE_RANGE; +ifeq ($(shell printf "$(C)" | $(CC) -S -xc - -o - >/dev/null 2>&1; echo $$?),0) + EXTRA_SYSCALLS += fallocate +endif + prefix ?= /usr/local exec_prefix ?= $(prefix) bindir ?= $(exec_prefix)/bin @@ -110,7 +115,7 @@ static: FLAGS += -static -DGLIBC_NO_STATIC_NSS static: clean all seccomp.h: seccomp.sh $(PASST_SRCS) $(PASST_HEADERS) - @ EXTRA_SYSCALLS=$(EXTRA_SYSCALLS) ./seccomp.sh $(PASST_SRCS) $(PASST_HEADERS) + @ EXTRA_SYSCALLS="$(EXTRA_SYSCALLS)" ./seccomp.sh $(PASST_SRCS) $(PASST_HEADERS) passt: $(PASST_SRCS) $(HEADERS) $(CC) $(FLAGS) $(CFLAGS) $(PASST_SRCS) -o passt $(LDFLAGS) @@ -128,9 +133,9 @@ pasta.avx2 pasta.1 pasta: pasta%: passt% qrap: $(QRAP_SRCS) passt.h $(CC) $(FLAGS) $(CFLAGS) $(QRAP_SRCS) -o qrap $(LDFLAGS) -valgrind: EXTRA_SYSCALLS="rt_sigprocmask rt_sigtimedwait rt_sigaction \ - getpid gettid kill clock_gettime mmap munmap open \ - unlink gettimeofday futex" +valgrind: EXTRA_SYSCALLS += rt_sigprocmask rt_sigtimedwait rt_sigaction \ + getpid gettid kill clock_gettime mmap \ + munmap open unlink gettimeofday futex valgrind: FLAGS:=-g -O0 $(filter-out -O%,$(FLAGS)) valgrind: all diff --git a/README.md b/README.md index 2c522b2..3dc4fc5 100644 --- a/README.md +++ b/README.md @@ -289,7 +289,7 @@ speeding up local connections, and usually requiring NAT. _pasta_: * ✅ all capabilities dropped, other than `CAP_NET_BIND_SERVICE` (if granted) * ✅ with default options, user, mount, IPC, UTS, PID namespaces are detached * ✅ no external dependencies (other than a standard C library) -* ✅ restrictive seccomp profiles (26 syscalls allowed for _passt_, 40 for +* ✅ restrictive seccomp profiles (30 syscalls allowed for _passt_, 41 for _pasta_ on x86_64) * ✅ examples of [AppArmor](/passt/tree/contrib/apparmor) and [SELinux](/passt/tree/contrib/selinux) profiles available diff --git a/conf.c b/conf.c index e9cd4a7..f22940b 100644 --- a/conf.c +++ b/conf.c @@ -633,6 +633,9 @@ static void usage(const char *name) info( " default: run in background if started from a TTY"); info( " -e, --stderr Log to stderr too"); info( " default: log to system logger only if started from a TTY"); + info( " -l, --log-file PATH Log (only) to given file"); + info( " --log-size BYTES Maximum size of log file"); + info( " default: 1 MiB"); info( " --runas UID|UID:GID Run as given UID, GID, which can be"); info( " numeric, or login and group names"); info( " default: drop to user \"nobody\""); @@ -994,6 +997,7 @@ void conf(struct ctx *c, int argc, char **argv) {"quiet", no_argument, NULL, 'q' }, {"foreground", no_argument, NULL, 'f' }, {"stderr", no_argument, NULL, 'e' }, + {"log-file", required_argument, NULL, 'l' }, {"help", no_argument, NULL, 'h' }, {"socket", required_argument, NULL, 's' }, {"ns-ifname", required_argument, NULL, 'I' }, @@ -1034,26 +1038,28 @@ void conf(struct ctx *c, int argc, char **argv) {"no-netns-quit", no_argument, NULL, 10 }, {"trace", no_argument, NULL, 11 }, {"runas", required_argument, NULL, 12 }, + {"log-size", required_argument, NULL, 13 }, { 0 }, }; struct get_bound_ports_ns_arg ns_ports_arg = { .c = c }; char userns[PATH_MAX] = { 0 }, netns[PATH_MAX] = { 0 }; bool v4_only = false, v6_only = false; + char *runas = NULL, *logfile = NULL; struct in6_addr *dns6 = c->ip6.dns; struct fqdn *dnss = c->dns_search; uint32_t *dns4 = c->ip4.dns; int name, ret, mask, b, i; const char *optstring; unsigned int ifi = 0; - char *runas = NULL; + size_t logsize = 0; uid_t uid; gid_t gid; if (c->mode == MODE_PASTA) { c->no_dhcp_dns = c->no_dhcp_dns_search = 1; - optstring = "dqfehI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:"; + optstring = "dqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:"; } else { - optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:"; + optstring = "dqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:"; } c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0; @@ -1177,6 +1183,20 @@ void conf(struct ctx *c, int argc, char **argv) runas = optarg; break; + case 13: + if (logsize) { + err("Multiple --log-size options given"); + usage(argv[0]); + } + + errno = 0; + logsize = strtol(optarg, NULL, 0); + + if (logsize < LOGFILE_SIZE_MIN || errno) { + err("Invalid --log-size: %s", optarg); + usage(argv[0]); + } + break; case 'd': if (c->debug) { err("Multiple --debug options given"); @@ -1192,6 +1212,11 @@ void conf(struct ctx *c, int argc, char **argv) c->foreground = 1; break; case 'e': + if (logfile) { + err("Can't log to both file and stderr"); + usage(argv[0]); + } + if (c->stderr) { err("Multiple --stderr options given"); usage(argv[0]); @@ -1199,6 +1224,19 @@ void conf(struct ctx *c, int argc, char **argv) c->stderr = 1; break; + case 'l': + if (c->stderr) { + err("Can't log to both stderr and file"); + usage(argv[0]); + } + + if (logfile) { + err("Multiple --log-file options given"); + usage(argv[0]); + } + + logfile = optarg; + break; case 'q': if (c->quiet) { err("Multiple --quiet options given"); @@ -1460,6 +1498,11 @@ void conf(struct ctx *c, int argc, char **argv) if (ret) usage(argv[0]); + if (logfile) { + logfile_init(c->mode == MODE_PASST ? "passt" : "pasta", + logfile, logsize); + } + if (c->mode == MODE_PASTA) { if (conf_pasta_ns(&netns_only, userns, netns, optind, argc, argv) < 0) diff --git a/log.c b/log.c index 54a7cbb..d769a33 100644 --- a/log.c +++ b/log.c @@ -12,7 +12,12 @@ * Author: Stefano Brivio */ +#include +#include +#include +#include #include +#include #include #include #include @@ -20,36 +25,49 @@ #include #include #include -#include #include "log.h" +#include "util.h" +#include "passt.h" -/* For __openlog() and __setlogmask() wrappers, and passt_vsyslog() */ -static int log_mask; -static int log_sock = -1; -static char log_ident[BUFSIZ]; -static int log_opt; -static time_t log_debug_start; -int log_trace; +static int log_sock = -1; /* Optional socket to system logger */ +static char log_ident[BUFSIZ]; /* Identifier string for openlog() */ +static int log_mask; /* Current log priority mask */ +static int log_opt; /* Options for openlog() */ + +static int log_file = -1; /* Optional log file descriptor */ +static size_t log_size; /* Maximum log file size in bytes */ +static size_t log_written; /* Currently used bytes in log file */ +static size_t log_cut_size; /* Bytes to cut at start on rotation */ +static char log_header[BUFSIZ]; /* File header, written back on cuts */ + +static time_t log_start; /* Start timestamp */ +int log_trace; /* --trace mode enabled */ #define logfn(name, level) \ void name(const char *format, ...) { \ struct timespec tp; \ va_list args; \ \ - if (setlogmask(0) & LOG_MASK(LOG_DEBUG)) { \ + if (setlogmask(0) & LOG_MASK(LOG_DEBUG) && log_file == -1) { \ clock_gettime(CLOCK_REALTIME, &tp); \ fprintf(stderr, "%li.%04li: ", \ - tp.tv_sec - log_debug_start, \ + tp.tv_sec - log_start, \ tp.tv_nsec / (100L * 1000)); \ - } else { \ + } \ + \ + if ((LOG_MASK(LOG_PRI(level)) & log_mask) || \ + setlogmask(0) == LOG_MASK(LOG_EMERG)) { \ va_start(args, format); \ - passt_vsyslog(level, format, args); \ + if (log_file != -1) \ + logfile_write(level, format, args); \ + else if (!(setlogmask(0) & LOG_MASK(LOG_DEBUG))) \ + passt_vsyslog(level, format, args); \ va_end(args); \ } \ \ - if (setlogmask(0) & LOG_MASK(LOG_DEBUG) || \ - setlogmask(0) == LOG_MASK(LOG_EMERG)) { \ + if ((setlogmask(0) & LOG_MASK(LOG_DEBUG) || \ + setlogmask(0) == LOG_MASK(LOG_EMERG)) && log_file == -1) { \ va_start(args, format); \ (void)vfprintf(stderr, format, args); \ va_end(args); \ @@ -58,6 +76,16 @@ void name(const char *format, ...) { \ } \ } +/* Prefixes for log file messages, indexed by priority */ +const char *logfile_prefix[] = { + NULL, NULL, NULL, /* Unused: LOG_EMERG, LOG_ALERT, LOG_CRIT */ + "ERROR: ", + "WARNING: ", + NULL, /* Unused: LOG_NOTICE */ + "info: ", + " ", /* LOG_DEBUG */ +}; + logfn(err, LOG_ERR) logfn(warn, LOG_WARNING) logfn(info, LOG_INFO) @@ -79,7 +107,7 @@ void __openlog(const char *ident, int option, int facility) struct timespec tp; clock_gettime(CLOCK_REALTIME, &tp); - log_debug_start = tp.tv_sec; + log_start = tp.tv_sec; if (log_sock < 0) { struct sockaddr_un a = { .sun_family = AF_UNIX, }; @@ -124,9 +152,6 @@ void passt_vsyslog(int pri, const char *format, va_list ap) char buf[BUFSIZ]; int n; - if (!(LOG_MASK(LOG_PRI(pri)) & log_mask)) - return; - /* Send without name and timestamp, the system logger should add them */ n = snprintf(buf, BUFSIZ, "<%i> ", pri); @@ -141,3 +166,200 @@ void passt_vsyslog(int pri, const char *format, va_list ap) if (send(log_sock, buf, n, 0) != n) fprintf(stderr, "Failed to send %i bytes to syslog\n", n); } + +/** + * logfile_init() - Open log file and write header with PID and path + * @name: Identifier for header: passt or pasta + * @path: Path to log file + * @size: Maximum size of log file: log_cut_size is calculatd here + */ +void logfile_init(const char *name, const char *path, size_t size) +{ + char nl = '\n', exe[PATH_MAX] = { 0 }; + int n; + + if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0) { + perror("readlink /proc/self/exe"); + exit(EXIT_FAILURE); + } + + log_file = open(path, O_CREAT | O_TRUNC | O_APPEND | O_RDWR | O_CLOEXEC, + S_IRUSR | S_IWUSR); + if (log_file == -1) { + err("Couldn't open log file %s: %s", path, strerror(errno)); + exit(EXIT_FAILURE); + } + + log_size = size ? size : LOGFILE_SIZE_DEFAULT; + + n = snprintf(log_header, sizeof(log_header), "%s: %s (%i)", + name, exe, getpid()); + + if (write(log_file, log_header, n) <= 0 || + write(log_file, &nl, 1) <= 0) { + perror("Couldn't write to log file\n"); + exit(EXIT_FAILURE); + } + + /* For FALLOC_FL_COLLAPSE_RANGE: VFS block size can be up to one page */ + log_cut_size = ROUND_UP(log_size * LOGFILE_CUT_RATIO / 100, PAGE_SIZE); +} + +#ifdef FALLOC_FL_COLLAPSE_RANGE +/** + * logfile_rotate_fallocate() - Write header, set log_written after fallocate() + * @fd: Log file descriptor + * @ts: Current timestamp + * + * #syscalls lseek ppc64le:_llseek ppc64:_llseek armv6l:_llseek armv7l:_llseek + */ +static void logfile_rotate_fallocate(int fd, struct timespec *ts) +{ + char buf[BUFSIZ], *nl; + int n; + + if (lseek(fd, 0, SEEK_SET) == -1) + return; + if (read(fd, buf, BUFSIZ) == -1) + return; + + n = snprintf(buf, BUFSIZ, + "%s - log truncated at %li.%04li", log_header, + ts->tv_sec - log_start, ts->tv_nsec / (100L * 1000)); + + /* Avoid partial lines by padding the header with spaces */ + nl = memchr(buf + n + 1, '\n', BUFSIZ - n - 1); + if (nl) + memset(buf + n, ' ', nl - (buf + n)); + + if (lseek(fd, 0, SEEK_SET) == -1) + return; + if (write(fd, buf, BUFSIZ) == -1) + return; + + log_written -= log_cut_size; +} +#endif /* FALLOC_FL_COLLAPSE_RANGE */ + +/** + * logfile_rotate_move() - Fallback: move recent entries toward start, then cut + * @fd: Log file descriptor + * @ts: Current timestamp + * + * #syscalls lseek ppc64le:_llseek ppc64:_llseek armv6l:_llseek armv7l:_llseek + * #syscalls ftruncate + */ +static void logfile_rotate_move(int fd, struct timespec *ts) +{ + int header_len, write_offset, end, discard, n; + char buf[BUFSIZ], *nl; + + header_len = snprintf(buf, BUFSIZ, + "%s - log truncated at %li.%04li\n", log_header, + ts->tv_sec - log_start, + ts->tv_nsec / (100L * 1000)); + if (lseek(fd, 0, SEEK_SET) == -1) + return; + if (write(fd, buf, header_len) == -1) + return; + + end = write_offset = header_len; + discard = log_cut_size + header_len; + + /* Try to cut cleanly at newline */ + if (lseek(fd, discard, SEEK_SET) == -1) + goto out; + if ((n = read(fd, buf, BUFSIZ)) <= 0) + goto out; + if ((nl = memchr(buf, '\n', n))) + discard += (nl - buf) + 1; + + /* Go to first block to be moved */ + if (lseek(fd, discard, SEEK_SET) == -1) + goto out; + + while ((n = read(fd, buf, BUFSIZ)) > 0) { + end = header_len; + + if (lseek(fd, write_offset, SEEK_SET) == -1) + goto out; + if ((n = write(fd, buf, n)) == -1) + goto out; + write_offset += n; + + if ((n = lseek(fd, 0, SEEK_CUR)) == -1) + goto out; + + if (lseek(fd, discard - header_len, SEEK_CUR) == -1) + goto out; + + end = n; + } + +out: + if (ftruncate(fd, end)) + return; + + log_written = end; +} + +/** + * logfile_rotate() - "Rotate" log file once it's full + * @fd: Log file descriptor + * @ts: Current timestamp + * + * Return: 0 on success, negative error code on failure + * + * #syscalls fcntl + * + * fallocate() passed as EXTRA_SYSCALL only if FALLOC_FL_COLLAPSE_RANGE is there + */ +static int logfile_rotate(int fd, struct timespec *ts) +{ + if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */)) + return -errno; + +#ifdef FALLOC_FL_COLLAPSE_RANGE + /* Only for Linux >= 3.15, extent-based ext4 or XFS, glibc >= 2.18 */ + if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size)) + logfile_rotate_fallocate(fd, ts); + else +#endif + logfile_rotate_move(fd, ts); + + if (fcntl(fd, F_SETFL, O_RDWR | O_APPEND)) + return -errno; + + return 0; +} + +/** + * logfile_write() - Write entry to log file, trigger rotation if full + * @pri: Facility and level map, same as priority for vsyslog() + * @format: Same as vsyslog() format + * @ap: Same as vsyslog() ap + */ +void logfile_write(int pri, const char *format, va_list ap) +{ + struct timespec ts; + char buf[BUFSIZ]; + int n; + + if (clock_gettime(CLOCK_REALTIME, &ts)) + return; + + n = snprintf(buf, BUFSIZ, "%li.%04li: %s", + ts.tv_sec - log_start, ts.tv_nsec / (100L * 1000), + logfile_prefix[pri]); + + n += vsnprintf(buf + n, BUFSIZ - n, format, ap); + + if (format[strlen(format)] != '\n') + n += snprintf(buf + n, BUFSIZ - n, "\n"); + + if ((log_written + n >= log_size) && logfile_rotate(log_file, &ts)) + return; + + if ((n = write(log_file, buf, n)) >= 0) + log_written += n; +} diff --git a/log.h b/log.h index 70cad6f..f92394c 100644 --- a/log.h +++ b/log.h @@ -6,6 +6,10 @@ #ifndef LOG_H #define LOG_H +#define LOGFILE_SIZE_DEFAULT (1024 * 1024UL) +#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */ +#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE)) + void err(const char *format, ...); void warn(const char *format, ...); void info(const char *format, ...); @@ -20,7 +24,9 @@ void trace_init(int enable); } while (0) void __openlog(const char *ident, int option, int facility); +void logfile_init(const char *name, const char *path, size_t size); void passt_vsyslog(int pri, const char *format, va_list ap); +void logfile_write(int pri, const char *format, va_list ap); void __setlogmask(int mask); #endif /* LOG_H */ diff --git a/passt.1 b/passt.1 index 83395bc..64236b6 100644 --- a/passt.1 +++ b/passt.1 @@ -79,7 +79,7 @@ for performance reasons. .TP .BR \-d ", " \-\-debug -Be verbose, don't run in background. +Be verbose, don't run in background, don't log to the system logger. .TP .BR \-\-trace @@ -99,9 +99,19 @@ Default is to fork into background. .TP .BR \-e ", " \-\-stderr Log to standard error too. -Default is to log to system logger only, if started from an interactive +Default is to log to the system logger only, if started from an interactive terminal, and to both system logger and standard error otherwise. +.TP +.BR \-l ", " \-\-log-file " " \fIPATH\fR +Log to file \fIPATH\fR, not to standard error, and not to the system logger. + +.TP +.BR \-\-log-size " " \fISIZE\fR +Limit log file size to \fISIZE\fR bytes. When the log file is full, make room +for new entries by removing old ones at the beginning. This limit is mandatory. +Default is 1048576 (1 MiB). + .TP .BR \-\-runas " " \fIUID\fR|\fIUID:GID\fR|\fILOGIN\fR|\fILOGIN:GROUP\fR Attempt to change to given UID and corresponding group if UID is given, diff --git a/passt.c b/passt.c index 0c561b2..7589b05 100644 --- a/passt.c +++ b/passt.c @@ -220,6 +220,7 @@ int main(int argc, char **argv) __openlog(log_name, 0, LOG_DAEMON); + /* Meaning we don't know yet: log everything. LOG_EMERG is unused */ __setlogmask(LOG_MASK(LOG_EMERG)); c.epollfd = epoll_create1(EPOLL_CLOEXEC);