* [PATCH 1/8] Move logging functions to a new file, log.c
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:13 ` David Gibson
2022-10-07 0:47 ` [PATCH 2/8] conf: Drop duplicate, diverging optstring assignments Stefano Brivio
` (6 subsequent siblings)
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 14808 bytes --]
Logging to file is going to add some further complexity that we don't
want to squeeze into util.c.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
Makefile | 4 +-
conf.c | 1 +
dhcp.c | 1 +
dhcpv6.c | 1 +
icmp.c | 1 +
isolation.c | 1 +
log.c | 143 +++++++++++++++++++++++++++++++++++++++++++++++++++
log.h | 26 ++++++++++
ndp.c | 1 +
netlink.c | 1 +
packet.c | 1 +
passt.c | 1 +
pasta.c | 1 +
pcap.c | 1 +
tap.c | 1 +
tcp.c | 1 +
tcp_splice.c | 1 +
udp.c | 1 +
util.c | 121 +------------------------------------------
util.h | 16 ------
20 files changed, 187 insertions(+), 138 deletions(-)
create mode 100644 log.c
create mode 100644 log.h
diff --git a/Makefile b/Makefile
index d4b623f..74bbfeb 100644
--- a/Makefile
+++ b/Makefile
@@ -33,8 +33,8 @@ FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
FLAGS += -DARCH=\"$(TARGET_ARCH)\"
PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
- isolation.c lineread.c mld.c ndp.c netlink.c packet.c passt.c pasta.c \
- pcap.c siphash.c tap.c tcp.c tcp_splice.c udp.c util.c
+ isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
+ pasta.c pcap.c siphash.c tap.c tcp.c tcp_splice.c udp.c util.c
QRAP_SRCS = qrap.c
SRCS = $(PASST_SRCS) $(QRAP_SRCS)
diff --git a/conf.c b/conf.c
index 1537dbf..ba1d8de 100644
--- a/conf.c
+++ b/conf.c
@@ -40,6 +40,7 @@
#include "pasta.h"
#include "lineread.h"
#include "isolation.h"
+#include "log.h"
/**
* get_bound_ports() - Get maps of ports with bound sockets
diff --git a/dhcp.c b/dhcp.c
index 7ad1319..7f0cc0b 100644
--- a/dhcp.c
+++ b/dhcp.c
@@ -29,6 +29,7 @@
#include "packet.h"
#include "passt.h"
#include "tap.h"
+#include "log.h"
#include "dhcp.h"
/**
diff --git a/dhcpv6.c b/dhcpv6.c
index 8a1d4a6..e7640ce 100644
--- a/dhcpv6.c
+++ b/dhcpv6.c
@@ -30,6 +30,7 @@
#include "util.h"
#include "passt.h"
#include "tap.h"
+#include "log.h"
/**
* struct opt_hdr - DHCPv6 option header
diff --git a/icmp.c b/icmp.c
index 29170aa..f02f89f 100644
--- a/icmp.c
+++ b/icmp.c
@@ -35,6 +35,7 @@
#include "util.h"
#include "passt.h"
#include "tap.h"
+#include "log.h"
#include "icmp.h"
#define ICMP_ECHO_TIMEOUT 60 /* s, timeout for ICMP socket activity */
diff --git a/isolation.c b/isolation.c
index 124dea4..b54c325 100644
--- a/isolation.c
+++ b/isolation.c
@@ -42,6 +42,7 @@
#include "util.h"
#include "seccomp.h"
#include "passt.h"
+#include "log.h"
#include "isolation.h"
/**
diff --git a/log.c b/log.c
new file mode 100644
index 0000000..54a7cbb
--- /dev/null
+++ b/log.c
@@ -0,0 +1,143 @@
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+/* PASST - Plug A Simple Socket Transport
+ * for qemu/UNIX domain socket mode
+ *
+ * PASTA - Pack A Subtle Tap Abstraction
+ * for network namespace/tap device mode
+ *
+ * log.c - Logging functions
+ *
+ * Copyright (c) 2020-2022 Red Hat GmbH
+ * Author: Stefano Brivio <sbrivio(a)redhat.com>
+ */
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <unistd.h>
+#include <string.h>
+#include <time.h>
+#include <syslog.h>
+#include <stdarg.h>
+#include <sys/socket.h>
+#include <sys/un.h>
+
+#include "log.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;
+
+#define logfn(name, level) \
+void name(const char *format, ...) { \
+ struct timespec tp; \
+ va_list args; \
+ \
+ if (setlogmask(0) & LOG_MASK(LOG_DEBUG)) { \
+ clock_gettime(CLOCK_REALTIME, &tp); \
+ fprintf(stderr, "%li.%04li: ", \
+ tp.tv_sec - log_debug_start, \
+ tp.tv_nsec / (100L * 1000)); \
+ } else { \
+ va_start(args, format); \
+ passt_vsyslog(level, format, args); \
+ va_end(args); \
+ } \
+ \
+ if (setlogmask(0) & LOG_MASK(LOG_DEBUG) || \
+ setlogmask(0) == LOG_MASK(LOG_EMERG)) { \
+ va_start(args, format); \
+ (void)vfprintf(stderr, format, args); \
+ va_end(args); \
+ if (format[strlen(format)] != '\n') \
+ fprintf(stderr, "\n"); \
+ } \
+}
+
+logfn(err, LOG_ERR)
+logfn(warn, LOG_WARNING)
+logfn(info, LOG_INFO)
+logfn(debug, LOG_DEBUG)
+
+void trace_init(int enable)
+{
+ log_trace = enable;
+}
+
+/**
+ * __openlog() - Non-optional openlog() wrapper, to allow custom vsyslog()
+ * @ident: openlog() identity (program name)
+ * @option: openlog() options
+ * @facility: openlog() facility (LOG_DAEMON)
+ */
+void __openlog(const char *ident, int option, int facility)
+{
+ struct timespec tp;
+
+ clock_gettime(CLOCK_REALTIME, &tp);
+ log_debug_start = tp.tv_sec;
+
+ if (log_sock < 0) {
+ struct sockaddr_un a = { .sun_family = AF_UNIX, };
+
+ log_sock = socket(AF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0);
+ if (log_sock < 0)
+ return;
+
+ strncpy(a.sun_path, _PATH_LOG, sizeof(a.sun_path));
+ if (connect(log_sock, (const struct sockaddr *)&a, sizeof(a))) {
+ close(log_sock);
+ log_sock = -1;
+ return;
+ }
+ }
+
+ log_mask |= facility;
+ strncpy(log_ident, ident, sizeof(log_ident) - 1);
+ log_opt = option;
+
+ openlog(ident, option, facility);
+}
+
+/**
+ * __setlogmask() - setlogmask() wrapper, to allow custom vsyslog()
+ * @mask: Same as setlogmask() mask
+ */
+void __setlogmask(int mask)
+{
+ log_mask = mask;
+ setlogmask(mask);
+}
+
+/**
+ * passt_vsyslog() - vsyslog() implementation not using heap memory
+ * @pri: Facility and level map, same as priority for vsyslog()
+ * @format: Same as vsyslog() format
+ * @ap: Same as vsyslog() ap
+ */
+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);
+
+ n += vsnprintf(buf + n, BUFSIZ - n, format, ap);
+
+ if (format[strlen(format)] != '\n')
+ n += snprintf(buf + n, BUFSIZ - n, "\n");
+
+ if (log_opt & LOG_PERROR)
+ fprintf(stderr, "%s", buf + sizeof("<0>"));
+
+ if (send(log_sock, buf, n, 0) != n)
+ fprintf(stderr, "Failed to send %i bytes to syslog\n", n);
+}
diff --git a/log.h b/log.h
new file mode 100644
index 0000000..70cad6f
--- /dev/null
+++ b/log.h
@@ -0,0 +1,26 @@
+/* SPDX-License-Identifier: AGPL-3.0-or-later
+ * Copyright (c) 2022 Red Hat GmbH
+ * Author: Stefano Brivio <sbrivio(a)redhat.com>
+ */
+
+#ifndef LOG_H
+#define LOG_H
+
+void err(const char *format, ...);
+void warn(const char *format, ...);
+void info(const char *format, ...);
+void debug(const char *format, ...);
+
+extern int log_trace;
+void trace_init(int enable);
+#define trace(format, ...) \
+ do { \
+ if (log_trace) \
+ debug(format, ##__VA_ARGS__); \
+ } while (0)
+
+void __openlog(const char *ident, int option, int facility);
+void passt_vsyslog(int pri, const char *format, va_list ap);
+void __setlogmask(int mask);
+
+#endif /* LOG_H */
diff --git a/ndp.c b/ndp.c
index 29c4b14..dec36a9 100644
--- a/ndp.c
+++ b/ndp.c
@@ -30,6 +30,7 @@
#include "util.h"
#include "passt.h"
#include "tap.h"
+#include "log.h"
#define RS 133
#define RA 134
diff --git a/netlink.c b/netlink.c
index 15ce213..9719e91 100644
--- a/netlink.c
+++ b/netlink.c
@@ -30,6 +30,7 @@
#include "util.h"
#include "passt.h"
+#include "log.h"
#include "netlink.h"
/* Socket in init, in target namespace, sequence (just needs to be monotonic) */
diff --git a/packet.c b/packet.c
index 6d10ec1..3f82e84 100644
--- a/packet.c
+++ b/packet.c
@@ -20,6 +20,7 @@
#include "packet.h"
#include "util.h"
+#include "log.h"
/**
* packet_add_do() - Add data as packet descriptor to given pool
diff --git a/passt.c b/passt.c
index 2c4a986..0c561b2 100644
--- a/passt.c
+++ b/passt.c
@@ -44,6 +44,7 @@
#include "conf.h"
#include "pasta.h"
#include "arch.h"
+#include "log.h"
#define EPOLL_EVENTS 8
diff --git a/pasta.c b/pasta.c
index 1dd8267..1887dd2 100644
--- a/pasta.c
+++ b/pasta.c
@@ -44,6 +44,7 @@
#include "passt.h"
#include "isolation.h"
#include "netlink.h"
+#include "log.h"
/* PID of child, in case we created a namespace */
static int pasta_child_pid;
diff --git a/pcap.c b/pcap.c
index 7a48baf..836688d 100644
--- a/pcap.c
+++ b/pcap.c
@@ -30,6 +30,7 @@
#include "util.h"
#include "passt.h"
+#include "log.h"
#define PCAP_VERSION_MINOR 4
diff --git a/tap.c b/tap.c
index 5540c18..bdcc161 100644
--- a/tap.c
+++ b/tap.c
@@ -52,6 +52,7 @@
#include "netlink.h"
#include "pasta.h"
#include "packet.h"
+#include "log.h"
/* IPv4 (plus ARP) and IPv6 message batches from tap/guest to IP handlers */
static PACKET_POOL_NOINIT(pool_tap4, TAP_MSGS, pkt_buf);
diff --git a/tcp.c b/tcp.c
index 8ec991c..830dc88 100644
--- a/tcp.c
+++ b/tcp.c
@@ -298,6 +298,7 @@
#include "pcap.h"
#include "conf.h"
#include "tcp_splice.h"
+#include "log.h"
#define TCP_FRAMES_MEM 128
#define TCP_FRAMES \
diff --git a/tcp_splice.c b/tcp_splice.c
index edbcfd4..4a015d0 100644
--- a/tcp_splice.c
+++ b/tcp_splice.c
@@ -47,6 +47,7 @@
#include "util.h"
#include "passt.h"
+#include "log.h"
#define MAX_PIPE_SIZE (8UL * 1024 * 1024)
#define TCP_SPLICE_MAX_CONNS (128 * 1024)
diff --git a/udp.c b/udp.c
index d1be622..5422fdd 100644
--- a/udp.c
+++ b/udp.c
@@ -116,6 +116,7 @@
#include "passt.h"
#include "tap.h"
#include "pcap.h"
+#include "log.h"
#define UDP_CONN_TIMEOUT 180 /* s, timeout for ephemeral or local bind */
#define UDP_SPLICE_FRAMES 32
diff --git a/util.c b/util.c
index 6b86ead..b366167 100644
--- a/util.c
+++ b/util.c
@@ -19,8 +19,6 @@
#include <net/ethernet.h>
#include <sys/epoll.h>
#include <fcntl.h>
-#include <syslog.h>
-#include <stdarg.h>
#include <string.h>
#include <time.h>
#include <errno.h>
@@ -29,124 +27,7 @@
#include "passt.h"
#include "packet.h"
#include "lineread.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;
-
-#define logfn(name, level) \
-void name(const char *format, ...) { \
- struct timespec tp; \
- va_list args; \
- \
- if (setlogmask(0) & LOG_MASK(LOG_DEBUG)) { \
- clock_gettime(CLOCK_REALTIME, &tp); \
- fprintf(stderr, "%li.%04li: ", \
- tp.tv_sec - log_debug_start, \
- tp.tv_nsec / (100L * 1000)); \
- } else { \
- va_start(args, format); \
- passt_vsyslog(level, format, args); \
- va_end(args); \
- } \
- \
- if (setlogmask(0) & LOG_MASK(LOG_DEBUG) || \
- setlogmask(0) == LOG_MASK(LOG_EMERG)) { \
- va_start(args, format); \
- (void)vfprintf(stderr, format, args); \
- va_end(args); \
- if (format[strlen(format)] != '\n') \
- fprintf(stderr, "\n"); \
- } \
-}
-
-logfn(err, LOG_ERR)
-logfn(warn, LOG_WARNING)
-logfn(info, LOG_INFO)
-logfn(debug, LOG_DEBUG)
-
-void trace_init(int enable)
-{
- log_trace = enable;
-}
-
-/**
- * __openlog() - Non-optional openlog() wrapper, to allow custom vsyslog()
- * @ident: openlog() identity (program name)
- * @option: openlog() options
- * @facility: openlog() facility (LOG_DAEMON)
- */
-void __openlog(const char *ident, int option, int facility)
-{
- struct timespec tp;
-
- clock_gettime(CLOCK_REALTIME, &tp);
- log_debug_start = tp.tv_sec;
-
- if (log_sock < 0) {
- struct sockaddr_un a = { .sun_family = AF_UNIX, };
-
- log_sock = socket(AF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0);
- if (log_sock < 0)
- return;
-
- strncpy(a.sun_path, _PATH_LOG, sizeof(a.sun_path));
- if (connect(log_sock, (const struct sockaddr *)&a, sizeof(a))) {
- close(log_sock);
- log_sock = -1;
- return;
- }
- }
-
- log_mask |= facility;
- strncpy(log_ident, ident, sizeof(log_ident) - 1);
- log_opt = option;
-
- openlog(ident, option, facility);
-}
-
-/**
- * __setlogmask() - setlogmask() wrapper, to allow custom vsyslog()
- * @mask: Same as setlogmask() mask
- */
-void __setlogmask(int mask)
-{
- log_mask = mask;
- setlogmask(mask);
-}
-
-/**
- * passt_vsyslog() - vsyslog() implementation not using heap memory
- * @pri: Facility and level map, same as priority for vsyslog()
- * @format: Same as vsyslog() format
- * @ap: Same as vsyslog() ap
- */
-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);
-
- n += vsnprintf(buf + n, BUFSIZ - n, format, ap);
-
- if (format[strlen(format)] != '\n')
- n += snprintf(buf + n, BUFSIZ - n, "\n");
-
- if (log_opt & LOG_PERROR)
- fprintf(stderr, "%s", buf + sizeof("<0>"));
-
- if (send(log_sock, buf, n, 0) != n)
- fprintf(stderr, "Failed to send %i bytes to syslog\n", n);
-}
+#include "log.h"
#define IPV6_NH_OPT(nh) \
((nh) == 0 || (nh) == 43 || (nh) == 44 || (nh) == 50 || \
diff --git a/util.h b/util.h
index 0c06e34..1adbf04 100644
--- a/util.h
+++ b/util.h
@@ -6,19 +6,6 @@
#ifndef UTIL_H
#define UTIL_H
-void err(const char *format, ...);
-void warn(const char *format, ...);
-void info(const char *format, ...);
-void debug(const char *format, ...);
-
-extern int log_trace;
-void trace_init(int enable);
-#define trace(format, ...) \
- do { \
- if (log_trace) \
- debug(format, ##__VA_ARGS__); \
- } while (0)
-
#ifndef SECCOMP_RET_KILL_PROCESS
#define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
#endif
@@ -196,9 +183,6 @@ struct ipv6_opt_hdr {
/* cppcheck-suppress funcArgNamesDifferent */
__attribute__ ((weak)) int ffsl(long int i) { return __builtin_ffsl(i); }
-void __openlog(const char *ident, int option, int facility);
-void passt_vsyslog(int pri, const char *format, va_list ap);
-void __setlogmask(int mask);
char *ipv6_l4hdr(const struct pool *p, int index, size_t offset, uint8_t *proto,
size_t *dlen);
int sock_l4(const struct ctx *c, int af, uint8_t proto,
--
@@ -6,19 +6,6 @@
#ifndef UTIL_H
#define UTIL_H
-void err(const char *format, ...);
-void warn(const char *format, ...);
-void info(const char *format, ...);
-void debug(const char *format, ...);
-
-extern int log_trace;
-void trace_init(int enable);
-#define trace(format, ...) \
- do { \
- if (log_trace) \
- debug(format, ##__VA_ARGS__); \
- } while (0)
-
#ifndef SECCOMP_RET_KILL_PROCESS
#define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
#endif
@@ -196,9 +183,6 @@ struct ipv6_opt_hdr {
/* cppcheck-suppress funcArgNamesDifferent */
__attribute__ ((weak)) int ffsl(long int i) { return __builtin_ffsl(i); }
-void __openlog(const char *ident, int option, int facility);
-void passt_vsyslog(int pri, const char *format, va_list ap);
-void __setlogmask(int mask);
char *ipv6_l4hdr(const struct pool *p, int index, size_t offset, uint8_t *proto,
size_t *dlen);
int sock_l4(const struct ctx *c, int af, uint8_t proto,
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 1/8] Move logging functions to a new file, log.c
2022-10-07 0:47 ` [PATCH 1/8] Move logging functions to a new file, log.c Stefano Brivio
@ 2022-10-07 6:13 ` David Gibson
0 siblings, 0 replies; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:13 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 16273 bytes --]
On Fri, Oct 07, 2022 at 02:47:35AM +0200, Stefano Brivio wrote:
> Logging to file is going to add some further complexity that we don't
> want to squeeze into util.c.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au>
> ---
> Makefile | 4 +-
> conf.c | 1 +
> dhcp.c | 1 +
> dhcpv6.c | 1 +
> icmp.c | 1 +
> isolation.c | 1 +
> log.c | 143 +++++++++++++++++++++++++++++++++++++++++++++++++++
> log.h | 26 ++++++++++
> ndp.c | 1 +
> netlink.c | 1 +
> packet.c | 1 +
> passt.c | 1 +
> pasta.c | 1 +
> pcap.c | 1 +
> tap.c | 1 +
> tcp.c | 1 +
> tcp_splice.c | 1 +
> udp.c | 1 +
> util.c | 121 +------------------------------------------
> util.h | 16 ------
> 20 files changed, 187 insertions(+), 138 deletions(-)
> create mode 100644 log.c
> create mode 100644 log.h
>
> diff --git a/Makefile b/Makefile
> index d4b623f..74bbfeb 100644
> --- a/Makefile
> +++ b/Makefile
> @@ -33,8 +33,8 @@ FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
> FLAGS += -DARCH=\"$(TARGET_ARCH)\"
>
> PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
> - isolation.c lineread.c mld.c ndp.c netlink.c packet.c passt.c pasta.c \
> - pcap.c siphash.c tap.c tcp.c tcp_splice.c udp.c util.c
> + isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
> + pasta.c pcap.c siphash.c tap.c tcp.c tcp_splice.c udp.c util.c
> QRAP_SRCS = qrap.c
> SRCS = $(PASST_SRCS) $(QRAP_SRCS)
>
> diff --git a/conf.c b/conf.c
> index 1537dbf..ba1d8de 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -40,6 +40,7 @@
> #include "pasta.h"
> #include "lineread.h"
> #include "isolation.h"
> +#include "log.h"
>
> /**
> * get_bound_ports() - Get maps of ports with bound sockets
> diff --git a/dhcp.c b/dhcp.c
> index 7ad1319..7f0cc0b 100644
> --- a/dhcp.c
> +++ b/dhcp.c
> @@ -29,6 +29,7 @@
> #include "packet.h"
> #include "passt.h"
> #include "tap.h"
> +#include "log.h"
> #include "dhcp.h"
>
> /**
> diff --git a/dhcpv6.c b/dhcpv6.c
> index 8a1d4a6..e7640ce 100644
> --- a/dhcpv6.c
> +++ b/dhcpv6.c
> @@ -30,6 +30,7 @@
> #include "util.h"
> #include "passt.h"
> #include "tap.h"
> +#include "log.h"
>
> /**
> * struct opt_hdr - DHCPv6 option header
> diff --git a/icmp.c b/icmp.c
> index 29170aa..f02f89f 100644
> --- a/icmp.c
> +++ b/icmp.c
> @@ -35,6 +35,7 @@
> #include "util.h"
> #include "passt.h"
> #include "tap.h"
> +#include "log.h"
> #include "icmp.h"
>
> #define ICMP_ECHO_TIMEOUT 60 /* s, timeout for ICMP socket activity */
> diff --git a/isolation.c b/isolation.c
> index 124dea4..b54c325 100644
> --- a/isolation.c
> +++ b/isolation.c
> @@ -42,6 +42,7 @@
> #include "util.h"
> #include "seccomp.h"
> #include "passt.h"
> +#include "log.h"
> #include "isolation.h"
>
> /**
> diff --git a/log.c b/log.c
> new file mode 100644
> index 0000000..54a7cbb
> --- /dev/null
> +++ b/log.c
> @@ -0,0 +1,143 @@
> +// SPDX-License-Identifier: AGPL-3.0-or-later
> +
> +/* PASST - Plug A Simple Socket Transport
> + * for qemu/UNIX domain socket mode
> + *
> + * PASTA - Pack A Subtle Tap Abstraction
> + * for network namespace/tap device mode
> + *
> + * log.c - Logging functions
> + *
> + * Copyright (c) 2020-2022 Red Hat GmbH
> + * Author: Stefano Brivio <sbrivio(a)redhat.com>
> + */
> +
> +#include <stdio.h>
> +#include <stdlib.h>
> +#include <unistd.h>
> +#include <string.h>
> +#include <time.h>
> +#include <syslog.h>
> +#include <stdarg.h>
> +#include <sys/socket.h>
> +#include <sys/un.h>
> +
> +#include "log.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;
> +
> +#define logfn(name, level) \
> +void name(const char *format, ...) { \
> + struct timespec tp; \
> + va_list args; \
> + \
> + if (setlogmask(0) & LOG_MASK(LOG_DEBUG)) { \
> + clock_gettime(CLOCK_REALTIME, &tp); \
> + fprintf(stderr, "%li.%04li: ", \
> + tp.tv_sec - log_debug_start, \
> + tp.tv_nsec / (100L * 1000)); \
> + } else { \
> + va_start(args, format); \
> + passt_vsyslog(level, format, args); \
> + va_end(args); \
> + } \
> + \
> + if (setlogmask(0) & LOG_MASK(LOG_DEBUG) || \
> + setlogmask(0) == LOG_MASK(LOG_EMERG)) { \
> + va_start(args, format); \
> + (void)vfprintf(stderr, format, args); \
> + va_end(args); \
> + if (format[strlen(format)] != '\n') \
> + fprintf(stderr, "\n"); \
> + } \
> +}
> +
> +logfn(err, LOG_ERR)
> +logfn(warn, LOG_WARNING)
> +logfn(info, LOG_INFO)
> +logfn(debug, LOG_DEBUG)
> +
> +void trace_init(int enable)
> +{
> + log_trace = enable;
> +}
> +
> +/**
> + * __openlog() - Non-optional openlog() wrapper, to allow custom vsyslog()
> + * @ident: openlog() identity (program name)
> + * @option: openlog() options
> + * @facility: openlog() facility (LOG_DAEMON)
> + */
> +void __openlog(const char *ident, int option, int facility)
> +{
> + struct timespec tp;
> +
> + clock_gettime(CLOCK_REALTIME, &tp);
> + log_debug_start = tp.tv_sec;
> +
> + if (log_sock < 0) {
> + struct sockaddr_un a = { .sun_family = AF_UNIX, };
> +
> + log_sock = socket(AF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0);
> + if (log_sock < 0)
> + return;
> +
> + strncpy(a.sun_path, _PATH_LOG, sizeof(a.sun_path));
> + if (connect(log_sock, (const struct sockaddr *)&a, sizeof(a))) {
> + close(log_sock);
> + log_sock = -1;
> + return;
> + }
> + }
> +
> + log_mask |= facility;
> + strncpy(log_ident, ident, sizeof(log_ident) - 1);
> + log_opt = option;
> +
> + openlog(ident, option, facility);
> +}
> +
> +/**
> + * __setlogmask() - setlogmask() wrapper, to allow custom vsyslog()
> + * @mask: Same as setlogmask() mask
> + */
> +void __setlogmask(int mask)
> +{
> + log_mask = mask;
> + setlogmask(mask);
> +}
> +
> +/**
> + * passt_vsyslog() - vsyslog() implementation not using heap memory
> + * @pri: Facility and level map, same as priority for vsyslog()
> + * @format: Same as vsyslog() format
> + * @ap: Same as vsyslog() ap
> + */
> +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);
> +
> + n += vsnprintf(buf + n, BUFSIZ - n, format, ap);
> +
> + if (format[strlen(format)] != '\n')
> + n += snprintf(buf + n, BUFSIZ - n, "\n");
> +
> + if (log_opt & LOG_PERROR)
> + fprintf(stderr, "%s", buf + sizeof("<0>"));
> +
> + if (send(log_sock, buf, n, 0) != n)
> + fprintf(stderr, "Failed to send %i bytes to syslog\n", n);
> +}
> diff --git a/log.h b/log.h
> new file mode 100644
> index 0000000..70cad6f
> --- /dev/null
> +++ b/log.h
> @@ -0,0 +1,26 @@
> +/* SPDX-License-Identifier: AGPL-3.0-or-later
> + * Copyright (c) 2022 Red Hat GmbH
> + * Author: Stefano Brivio <sbrivio(a)redhat.com>
> + */
> +
> +#ifndef LOG_H
> +#define LOG_H
> +
> +void err(const char *format, ...);
> +void warn(const char *format, ...);
> +void info(const char *format, ...);
> +void debug(const char *format, ...);
> +
> +extern int log_trace;
> +void trace_init(int enable);
> +#define trace(format, ...) \
> + do { \
> + if (log_trace) \
> + debug(format, ##__VA_ARGS__); \
> + } while (0)
> +
> +void __openlog(const char *ident, int option, int facility);
> +void passt_vsyslog(int pri, const char *format, va_list ap);
> +void __setlogmask(int mask);
> +
> +#endif /* LOG_H */
> diff --git a/ndp.c b/ndp.c
> index 29c4b14..dec36a9 100644
> --- a/ndp.c
> +++ b/ndp.c
> @@ -30,6 +30,7 @@
> #include "util.h"
> #include "passt.h"
> #include "tap.h"
> +#include "log.h"
>
> #define RS 133
> #define RA 134
> diff --git a/netlink.c b/netlink.c
> index 15ce213..9719e91 100644
> --- a/netlink.c
> +++ b/netlink.c
> @@ -30,6 +30,7 @@
>
> #include "util.h"
> #include "passt.h"
> +#include "log.h"
> #include "netlink.h"
>
> /* Socket in init, in target namespace, sequence (just needs to be monotonic) */
> diff --git a/packet.c b/packet.c
> index 6d10ec1..3f82e84 100644
> --- a/packet.c
> +++ b/packet.c
> @@ -20,6 +20,7 @@
>
> #include "packet.h"
> #include "util.h"
> +#include "log.h"
>
> /**
> * packet_add_do() - Add data as packet descriptor to given pool
> diff --git a/passt.c b/passt.c
> index 2c4a986..0c561b2 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -44,6 +44,7 @@
> #include "conf.h"
> #include "pasta.h"
> #include "arch.h"
> +#include "log.h"
>
> #define EPOLL_EVENTS 8
>
> diff --git a/pasta.c b/pasta.c
> index 1dd8267..1887dd2 100644
> --- a/pasta.c
> +++ b/pasta.c
> @@ -44,6 +44,7 @@
> #include "passt.h"
> #include "isolation.h"
> #include "netlink.h"
> +#include "log.h"
>
> /* PID of child, in case we created a namespace */
> static int pasta_child_pid;
> diff --git a/pcap.c b/pcap.c
> index 7a48baf..836688d 100644
> --- a/pcap.c
> +++ b/pcap.c
> @@ -30,6 +30,7 @@
>
> #include "util.h"
> #include "passt.h"
> +#include "log.h"
>
> #define PCAP_VERSION_MINOR 4
>
> diff --git a/tap.c b/tap.c
> index 5540c18..bdcc161 100644
> --- a/tap.c
> +++ b/tap.c
> @@ -52,6 +52,7 @@
> #include "netlink.h"
> #include "pasta.h"
> #include "packet.h"
> +#include "log.h"
>
> /* IPv4 (plus ARP) and IPv6 message batches from tap/guest to IP handlers */
> static PACKET_POOL_NOINIT(pool_tap4, TAP_MSGS, pkt_buf);
> diff --git a/tcp.c b/tcp.c
> index 8ec991c..830dc88 100644
> --- a/tcp.c
> +++ b/tcp.c
> @@ -298,6 +298,7 @@
> #include "pcap.h"
> #include "conf.h"
> #include "tcp_splice.h"
> +#include "log.h"
>
> #define TCP_FRAMES_MEM 128
> #define TCP_FRAMES \
> diff --git a/tcp_splice.c b/tcp_splice.c
> index edbcfd4..4a015d0 100644
> --- a/tcp_splice.c
> +++ b/tcp_splice.c
> @@ -47,6 +47,7 @@
>
> #include "util.h"
> #include "passt.h"
> +#include "log.h"
>
> #define MAX_PIPE_SIZE (8UL * 1024 * 1024)
> #define TCP_SPLICE_MAX_CONNS (128 * 1024)
> diff --git a/udp.c b/udp.c
> index d1be622..5422fdd 100644
> --- a/udp.c
> +++ b/udp.c
> @@ -116,6 +116,7 @@
> #include "passt.h"
> #include "tap.h"
> #include "pcap.h"
> +#include "log.h"
>
> #define UDP_CONN_TIMEOUT 180 /* s, timeout for ephemeral or local bind */
> #define UDP_SPLICE_FRAMES 32
> diff --git a/util.c b/util.c
> index 6b86ead..b366167 100644
> --- a/util.c
> +++ b/util.c
> @@ -19,8 +19,6 @@
> #include <net/ethernet.h>
> #include <sys/epoll.h>
> #include <fcntl.h>
> -#include <syslog.h>
> -#include <stdarg.h>
> #include <string.h>
> #include <time.h>
> #include <errno.h>
> @@ -29,124 +27,7 @@
> #include "passt.h"
> #include "packet.h"
> #include "lineread.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;
> -
> -#define logfn(name, level) \
> -void name(const char *format, ...) { \
> - struct timespec tp; \
> - va_list args; \
> - \
> - if (setlogmask(0) & LOG_MASK(LOG_DEBUG)) { \
> - clock_gettime(CLOCK_REALTIME, &tp); \
> - fprintf(stderr, "%li.%04li: ", \
> - tp.tv_sec - log_debug_start, \
> - tp.tv_nsec / (100L * 1000)); \
> - } else { \
> - va_start(args, format); \
> - passt_vsyslog(level, format, args); \
> - va_end(args); \
> - } \
> - \
> - if (setlogmask(0) & LOG_MASK(LOG_DEBUG) || \
> - setlogmask(0) == LOG_MASK(LOG_EMERG)) { \
> - va_start(args, format); \
> - (void)vfprintf(stderr, format, args); \
> - va_end(args); \
> - if (format[strlen(format)] != '\n') \
> - fprintf(stderr, "\n"); \
> - } \
> -}
> -
> -logfn(err, LOG_ERR)
> -logfn(warn, LOG_WARNING)
> -logfn(info, LOG_INFO)
> -logfn(debug, LOG_DEBUG)
> -
> -void trace_init(int enable)
> -{
> - log_trace = enable;
> -}
> -
> -/**
> - * __openlog() - Non-optional openlog() wrapper, to allow custom vsyslog()
> - * @ident: openlog() identity (program name)
> - * @option: openlog() options
> - * @facility: openlog() facility (LOG_DAEMON)
> - */
> -void __openlog(const char *ident, int option, int facility)
> -{
> - struct timespec tp;
> -
> - clock_gettime(CLOCK_REALTIME, &tp);
> - log_debug_start = tp.tv_sec;
> -
> - if (log_sock < 0) {
> - struct sockaddr_un a = { .sun_family = AF_UNIX, };
> -
> - log_sock = socket(AF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0);
> - if (log_sock < 0)
> - return;
> -
> - strncpy(a.sun_path, _PATH_LOG, sizeof(a.sun_path));
> - if (connect(log_sock, (const struct sockaddr *)&a, sizeof(a))) {
> - close(log_sock);
> - log_sock = -1;
> - return;
> - }
> - }
> -
> - log_mask |= facility;
> - strncpy(log_ident, ident, sizeof(log_ident) - 1);
> - log_opt = option;
> -
> - openlog(ident, option, facility);
> -}
> -
> -/**
> - * __setlogmask() - setlogmask() wrapper, to allow custom vsyslog()
> - * @mask: Same as setlogmask() mask
> - */
> -void __setlogmask(int mask)
> -{
> - log_mask = mask;
> - setlogmask(mask);
> -}
> -
> -/**
> - * passt_vsyslog() - vsyslog() implementation not using heap memory
> - * @pri: Facility and level map, same as priority for vsyslog()
> - * @format: Same as vsyslog() format
> - * @ap: Same as vsyslog() ap
> - */
> -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);
> -
> - n += vsnprintf(buf + n, BUFSIZ - n, format, ap);
> -
> - if (format[strlen(format)] != '\n')
> - n += snprintf(buf + n, BUFSIZ - n, "\n");
> -
> - if (log_opt & LOG_PERROR)
> - fprintf(stderr, "%s", buf + sizeof("<0>"));
> -
> - if (send(log_sock, buf, n, 0) != n)
> - fprintf(stderr, "Failed to send %i bytes to syslog\n", n);
> -}
> +#include "log.h"
>
> #define IPV6_NH_OPT(nh) \
> ((nh) == 0 || (nh) == 43 || (nh) == 44 || (nh) == 50 || \
> diff --git a/util.h b/util.h
> index 0c06e34..1adbf04 100644
> --- a/util.h
> +++ b/util.h
> @@ -6,19 +6,6 @@
> #ifndef UTIL_H
> #define UTIL_H
>
> -void err(const char *format, ...);
> -void warn(const char *format, ...);
> -void info(const char *format, ...);
> -void debug(const char *format, ...);
> -
> -extern int log_trace;
> -void trace_init(int enable);
> -#define trace(format, ...) \
> - do { \
> - if (log_trace) \
> - debug(format, ##__VA_ARGS__); \
> - } while (0)
> -
> #ifndef SECCOMP_RET_KILL_PROCESS
> #define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
> #endif
> @@ -196,9 +183,6 @@ struct ipv6_opt_hdr {
>
> /* cppcheck-suppress funcArgNamesDifferent */
> __attribute__ ((weak)) int ffsl(long int i) { return __builtin_ffsl(i); }
> -void __openlog(const char *ident, int option, int facility);
> -void passt_vsyslog(int pri, const char *format, va_list ap);
> -void __setlogmask(int mask);
> char *ipv6_l4hdr(const struct pool *p, int index, size_t offset, uint8_t *proto,
> size_t *dlen);
> int sock_l4(const struct ctx *c, int af, uint8_t proto,
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 2/8] conf: Drop duplicate, diverging optstring assignments
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
2022-10-07 0:47 ` [PATCH 1/8] Move logging functions to a new file, log.c Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:20 ` David Gibson
2022-10-07 0:47 ` [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration Stefano Brivio
` (5 subsequent siblings)
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1889 bytes --]
This originated as a result of copy and paste to introduce a second
stage for processing options related to port forwarding, has already
bitten David in the past, and just gave me hours of fun.
As a matter of fact, the second set of optstring assignments was
already incorrect, but it didn't matter because the first one was
more restrictive, not allowing optional arguments for -P, -D, -S.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
conf.c | 20 ++++++--------------
1 file changed, 6 insertions(+), 14 deletions(-)
diff --git a/conf.c b/conf.c
index ba1d8de..e9cd4a7 100644
--- a/conf.c
+++ b/conf.c
@@ -1043,25 +1043,23 @@ void conf(struct ctx *c, int argc, char **argv)
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;
uid_t uid;
gid_t gid;
- if (c->mode == MODE_PASTA)
+ 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:";
+ } else {
+ optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
+ }
c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
c->udp.fwd_in.f.mode = c->udp.fwd_out.f.mode = 0;
do {
- const char *optstring;
-
- if (c->mode == MODE_PASST)
- optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
- else
- optstring = "dqfehI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
-
name = getopt_long(argc, argv, optstring, options, NULL);
switch (name) {
@@ -1505,12 +1503,6 @@ void conf(struct ctx *c, int argc, char **argv)
optind = 1;
do {
struct port_fwd *fwd = NULL;
- const char *optstring;
-
- if (c->mode == MODE_PASST)
- optstring = "dqfehs:p::P:m:a:n:M:g:i:D::S::46t:u:";
- else
- optstring = "dqfehI:p::P:m:a:n:M:g:i:D::S::46t:u:T:U:";
name = getopt_long(argc, argv, optstring, options, NULL);
switch (name) {
--
@@ -1043,25 +1043,23 @@ void conf(struct ctx *c, int argc, char **argv)
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;
uid_t uid;
gid_t gid;
- if (c->mode == MODE_PASTA)
+ 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:";
+ } else {
+ optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
+ }
c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
c->udp.fwd_in.f.mode = c->udp.fwd_out.f.mode = 0;
do {
- const char *optstring;
-
- if (c->mode == MODE_PASST)
- optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
- else
- optstring = "dqfehI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
-
name = getopt_long(argc, argv, optstring, options, NULL);
switch (name) {
@@ -1505,12 +1503,6 @@ void conf(struct ctx *c, int argc, char **argv)
optind = 1;
do {
struct port_fwd *fwd = NULL;
- const char *optstring;
-
- if (c->mode == MODE_PASST)
- optstring = "dqfehs:p::P:m:a:n:M:g:i:D::S::46t:u:";
- else
- optstring = "dqfehI:p::P:m:a:n:M:g:i:D::S::46t:u:T:U:";
name = getopt_long(argc, argv, optstring, options, NULL);
switch (name) {
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 2/8] conf: Drop duplicate, diverging optstring assignments
2022-10-07 0:47 ` [PATCH 2/8] conf: Drop duplicate, diverging optstring assignments Stefano Brivio
@ 2022-10-07 6:20 ` David Gibson
0 siblings, 0 replies; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:20 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 2315 bytes --]
On Fri, Oct 07, 2022 at 02:47:36AM +0200, Stefano Brivio wrote:
> This originated as a result of copy and paste to introduce a second
> stage for processing options related to port forwarding, has already
> bitten David in the past, and just gave me hours of fun.
>
> As a matter of fact, the second set of optstring assignments was
> already incorrect, but it didn't matter because the first one was
> more restrictive, not allowing optional arguments for -P, -D, -S.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au>
> ---
> conf.c | 20 ++++++--------------
> 1 file changed, 6 insertions(+), 14 deletions(-)
>
> diff --git a/conf.c b/conf.c
> index ba1d8de..e9cd4a7 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -1043,25 +1043,23 @@ void conf(struct ctx *c, int argc, char **argv)
> 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;
> uid_t uid;
> gid_t gid;
>
> - if (c->mode == MODE_PASTA)
> + 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:";
> + } else {
> + optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> + }
>
> c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
> c->udp.fwd_in.f.mode = c->udp.fwd_out.f.mode = 0;
>
> do {
> - const char *optstring;
> -
> - if (c->mode == MODE_PASST)
> - optstring = "dqfehs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> - else
> - optstring = "dqfehI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> -
> name = getopt_long(argc, argv, optstring, options, NULL);
>
> switch (name) {
> @@ -1505,12 +1503,6 @@ void conf(struct ctx *c, int argc, char **argv)
> optind = 1;
> do {
> struct port_fwd *fwd = NULL;
> - const char *optstring;
> -
> - if (c->mode == MODE_PASST)
> - optstring = "dqfehs:p::P:m:a:n:M:g:i:D::S::46t:u:";
> - else
> - optstring = "dqfehI:p::P:m:a:n:M:g:i:D::S::46t:u:T:U:";
>
> name = getopt_long(argc, argv, optstring, options, NULL);
> switch (name) {
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
2022-10-07 0:47 ` [PATCH 1/8] Move logging functions to a new file, log.c Stefano Brivio
2022-10-07 0:47 ` [PATCH 2/8] conf: Drop duplicate, diverging optstring assignments Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:23 ` David Gibson
2022-10-07 0:47 ` [PATCH 4/8] log, conf: Add support for logging to file Stefano Brivio
` (4 subsequent siblings)
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 495 bytes --]
This saves some hassle when including passt.h, as we need ETH_ALEN
there.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
passt.h | 2 ++
1 file changed, 2 insertions(+)
diff --git a/passt.h b/passt.h
index 48e1096..de79e7b 100644
--- a/passt.h
+++ b/passt.h
@@ -133,6 +133,8 @@ struct ip6_ctx {
struct in6_addr dns_fwd;
};
+#include <netinet/if_ether.h>
+
/**
* struct ctx - Execution context
* @mode: Operation mode, qemu/UNIX domain socket or namespace/tap
--
@@ -133,6 +133,8 @@ struct ip6_ctx {
struct in6_addr dns_fwd;
};
+#include <netinet/if_ether.h>
+
/**
* struct ctx - Execution context
* @mode: Operation mode, qemu/UNIX domain socket or namespace/tap
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration
2022-10-07 0:47 ` [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration Stefano Brivio
@ 2022-10-07 6:23 ` David Gibson
2022-10-07 7:44 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:23 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1337 bytes --]
On Fri, Oct 07, 2022 at 02:47:37AM +0200, Stefano Brivio wrote:
> This saves some hassle when including passt.h, as we need ETH_ALEN
> there.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
Hrm. So I had the impression that passt was using the convention that
it's the top level files responsibility to include all the
dependencies for a header before including the header, rather than
having headers include other headers they need. Was I mistaken? I'm
ok with either model, they each have their advantages, but I find
sticking to one or the other is generally better than a mix of both.
That is, it would be helpful to me for you to clarify the policy, but
for this specific patch
Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au>
> ---
> passt.h | 2 ++
> 1 file changed, 2 insertions(+)
>
> diff --git a/passt.h b/passt.h
> index 48e1096..de79e7b 100644
> --- a/passt.h
> +++ b/passt.h
> @@ -133,6 +133,8 @@ struct ip6_ctx {
> struct in6_addr dns_fwd;
> };
>
> +#include <netinet/if_ether.h>
> +
> /**
> * struct ctx - Execution context
> * @mode: Operation mode, qemu/UNIX domain socket or namespace/tap
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration
2022-10-07 6:23 ` David Gibson
@ 2022-10-07 7:44 ` Stefano Brivio
2022-10-07 8:40 ` David Gibson
0 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 7:44 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1256 bytes --]
On Fri, 7 Oct 2022 17:23:30 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 02:47:37AM +0200, Stefano Brivio wrote:
> > This saves some hassle when including passt.h, as we need ETH_ALEN
> > there.
> >
> > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
>
> Hrm. So I had the impression that passt was using the convention that
> it's the top level files responsibility to include all the
> dependencies for a header before including the header, rather than
> having headers include other headers they need. Was I mistaken? I'm
> ok with either model, they each have their advantages, but I find
> sticking to one or the other is generally better than a mix of both.
That was my original idea, but it's a bit of a disaster, because it
turns out we need <netinet/if_ether.h> and a few others pretty much
everywhere, even though the file at hand will never see an Ethernet
header. :(
Does this indicate that it's time to move struct ctx out of passt.h
(and similarly with other structs here and there)?
Or that we should switch to the other way around? I don't really have
an answer.
If you have some ideas for a possible guideline/policy, I'd be happy to
refactor includes based on that...
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread
* Re: [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration
2022-10-07 7:44 ` Stefano Brivio
@ 2022-10-07 8:40 ` David Gibson
2022-10-07 11:36 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 8:40 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1659 bytes --]
On Fri, Oct 07, 2022 at 09:44:17AM +0200, Stefano Brivio wrote:
> On Fri, 7 Oct 2022 17:23:30 +1100
> David Gibson <david(a)gibson.dropbear.id.au> wrote:
>
> > On Fri, Oct 07, 2022 at 02:47:37AM +0200, Stefano Brivio wrote:
> > > This saves some hassle when including passt.h, as we need ETH_ALEN
> > > there.
> > >
> > > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> >
> > Hrm. So I had the impression that passt was using the convention that
> > it's the top level files responsibility to include all the
> > dependencies for a header before including the header, rather than
> > having headers include other headers they need. Was I mistaken? I'm
> > ok with either model, they each have their advantages, but I find
> > sticking to one or the other is generally better than a mix of both.
>
> That was my original idea, but it's a bit of a disaster, because it
> turns out we need <netinet/if_ether.h> and a few others pretty much
> everywhere, even though the file at hand will never see an Ethernet
> header. :(
>
> Does this indicate that it's time to move struct ctx out of passt.h
> (and similarly with other structs here and there)?
Well.. really we want to break struct ctx up so it's not globals by
another name, but that's not news.
> Or that we should switch to the other way around? I don't really have
> an answer.
>
> If you have some ideas for a possible guideline/policy, I'd be happy to
> refactor includes based on that...
>
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread
* Re: [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration
2022-10-07 8:40 ` David Gibson
@ 2022-10-07 11:36 ` Stefano Brivio
0 siblings, 0 replies; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 11:36 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1793 bytes --]
On Fri, 7 Oct 2022 19:40:43 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 09:44:17AM +0200, Stefano Brivio wrote:
> > On Fri, 7 Oct 2022 17:23:30 +1100
> > David Gibson <david(a)gibson.dropbear.id.au> wrote:
> >
> > > On Fri, Oct 07, 2022 at 02:47:37AM +0200, Stefano Brivio wrote:
> > > > This saves some hassle when including passt.h, as we need ETH_ALEN
> > > > there.
> > > >
> > > > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > >
> > > Hrm. So I had the impression that passt was using the convention that
> > > it's the top level files responsibility to include all the
> > > dependencies for a header before including the header, rather than
> > > having headers include other headers they need. Was I mistaken? I'm
> > > ok with either model, they each have their advantages, but I find
> > > sticking to one or the other is generally better than a mix of both.
> >
> > That was my original idea, but it's a bit of a disaster, because it
> > turns out we need <netinet/if_ether.h> and a few others pretty much
> > everywhere, even though the file at hand will never see an Ethernet
> > header. :(
> >
> > Does this indicate that it's time to move struct ctx out of passt.h
> > (and similarly with other structs here and there)?
>
> Well.. really we want to break struct ctx up so it's not globals by
> another name, but that's not news.
Okay, that sounds reasonable, and at that point we can probably go back
to the original idea, which has a few advantages especially when
headers don't have include guards.
Until then I would say we could be flexible with it -- including
netinet/if_ether.h everywhere looks bad, but if we have an extra
include for stdint.h somewhere I don't see it as a drama.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 4/8] log, conf: Add support for logging to file
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
` (2 preceding siblings ...)
2022-10-07 0:47 ` [PATCH 3/8] passt.h: Include netinet/if_ether.h before struct ctx declaration Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:51 ` David Gibson
2022-10-07 0:47 ` [PATCH 5/8] log: Add missing function comment for trace_init() Stefano Brivio
` (3 subsequent siblings)
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 17549 bytes --]
In some environments, such as KubeVirt pods, we might not have a
system logger available. We could choose to run in foreground, but
this takes away the convenient synchronisation mechanism derived from
forking to background when interfaces are ready.
Add optional logging to file with -l/--log-file and --log-size.
Unfortunately, this means we need to duplicate features that are more
appropriately implemented by a system logger, such as rotation. Keep
that reasonably simple, by using fallocate() with range collapsing
where supported (Linux kernel >= 3.15, extent-based ext4 and XFS) and
falling back to an unsophisticated block-by-block moving of entries
toward the beginning of the file once we reach the (mandatory) size
limit.
While at it, clarify the role of LOG_EMERG in passt.c.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
Makefile | 2 +-
README.md | 2 +-
conf.c | 49 ++++++++++-
log.c | 251 ++++++++++++++++++++++++++++++++++++++++++++++++++----
log.h | 6 ++
passt.1 | 14 ++-
passt.c | 1 +
7 files changed, 300 insertions(+), 25 deletions(-)
diff --git a/Makefile b/Makefile
index 74bbfeb..fafb024 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
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..1e405e3 100644
--- a/log.c
+++ b/log.c
@@ -12,7 +12,12 @@
* Author: Stefano Brivio <sbrivio(a)redhat.com>
*/
+#include <arpa/inet.h>
+#include <limits.h>
+#include <errno.h>
+#include <fcntl.h>
#include <stdio.h>
+#include <stdint.h>
#include <stdlib.h>
#include <unistd.h>
#include <string.h>
@@ -20,36 +25,49 @@
#include <syslog.h>
#include <stdarg.h>
#include <sys/socket.h>
-#include <sys/un.h>
#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,193 @@ 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);
+}
+
+/**
+ * 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;
+}
+
+/**
+ * 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;
+ end = n;
+
+ if (lseek(fd, discard - header_len, SEEK_CUR) == -1)
+ goto out;
+ }
+
+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 fallocate fcntl
+ */
+static int logfile_rotate(int fd, struct timespec *ts)
+{
+ if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */))
+ return -errno;
+
+ /* Collapsing only for Linux kernel >= 3.15, extent-based ext4 or XFS */
+ if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size))
+ logfile_rotate_fallocate(fd, ts);
+ else
+ 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..ed71cd7 100644
--- a/log.h
+++ b/log.h
@@ -6,6 +6,10 @@
#ifndef LOG_H
#define LOG_H
+#define LOGFILE_SIZE_DEFAULT 1E6
+#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);
--
@@ -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);
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 4/8] log, conf: Add support for logging to file
2022-10-07 0:47 ` [PATCH 4/8] log, conf: Add support for logging to file Stefano Brivio
@ 2022-10-07 6:51 ` David Gibson
2022-10-07 8:11 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:51 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 19538 bytes --]
On Fri, Oct 07, 2022 at 02:47:38AM +0200, Stefano Brivio wrote:
> In some environments, such as KubeVirt pods, we might not have a
> system logger available. We could choose to run in foreground, but
> this takes away the convenient synchronisation mechanism derived from
> forking to background when interfaces are ready.
>
> Add optional logging to file with -l/--log-file and --log-size.
>
> Unfortunately, this means we need to duplicate features that are more
> appropriately implemented by a system logger, such as rotation. Keep
> that reasonably simple, by using fallocate() with range collapsing
> where supported (Linux kernel >= 3.15, extent-based ext4 and XFS) and
> falling back to an unsophisticated block-by-block moving of entries
> toward the beginning of the file once we reach the (mandatory) size
> limit.
>
> While at it, clarify the role of LOG_EMERG in passt.c.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> ---
> Makefile | 2 +-
> README.md | 2 +-
> conf.c | 49 ++++++++++-
> log.c | 251 ++++++++++++++++++++++++++++++++++++++++++++++++++----
> log.h | 6 ++
> passt.1 | 14 ++-
> passt.c | 1 +
> 7 files changed, 300 insertions(+), 25 deletions(-)
>
> diff --git a/Makefile b/Makefile
> index 74bbfeb..fafb024 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
>
> 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)
That's a pity, but I guess we need it.
> * ✅ 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..1e405e3 100644
> --- a/log.c
> +++ b/log.c
> @@ -12,7 +12,12 @@
> * Author: Stefano Brivio <sbrivio(a)redhat.com>
> */
>
> +#include <arpa/inet.h>
> +#include <limits.h>
> +#include <errno.h>
> +#include <fcntl.h>
> #include <stdio.h>
> +#include <stdint.h>
> #include <stdlib.h>
> #include <unistd.h>
> #include <string.h>
> @@ -20,36 +25,49 @@
> #include <syslog.h>
> #include <stdarg.h>
> #include <sys/socket.h>
> -#include <sys/un.h>
>
> #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,193 @@ 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);
Do
> + 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);
> +}
> +
> +/**
> + * 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)
Have you tested this path? I thought with O_APPEND, this write would
go at the end, regardless of the lseek() above.
> + return;
> +
> + log_written -= log_cut_size;
> +}
> +
> +/**
> + * 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));
A common helper for the truncation header seems like it would be a
good idea.
> + 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;
Hrm.. so errors in this section will throw away everything except the header.
> +
> + 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;
> + end = n;
But errors after here will just throw away what we haven't moved so
far. Seems a bit inconsistent.
> +
> + if (lseek(fd, discard - header_len, SEEK_CUR) == -1)
> + goto out;
> + }
I wonder if those whole function would be made simpler using pread()
and pwrite() instead of lseek()s all over the place.
> +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 fallocate fcntl
> + */
> +static int logfile_rotate(int fd, struct timespec *ts)
> +{
> + if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */))
> + return -errno;
> +
> + /* Collapsing only for Linux kernel >= 3.15, extent-based ext4 or XFS */
> + if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size))
> + logfile_rotate_fallocate(fd, ts);
> + else
> + 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..ed71cd7 100644
> --- a/log.h
> +++ b/log.h
> @@ -6,6 +6,10 @@
> #ifndef LOG_H
> #define LOG_H
>
> +#define LOGFILE_SIZE_DEFAULT 1E6
Wouldn't a multiple of the block size make more sense?
> +#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);
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 4/8] log, conf: Add support for logging to file
2022-10-07 6:51 ` David Gibson
@ 2022-10-07 8:11 ` Stefano Brivio
2022-10-07 8:57 ` David Gibson
0 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 8:11 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 19720 bytes --]
On Fri, 7 Oct 2022 17:51:52 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 02:47:38AM +0200, Stefano Brivio wrote:
> > In some environments, such as KubeVirt pods, we might not have a
> > system logger available. We could choose to run in foreground, but
> > this takes away the convenient synchronisation mechanism derived from
> > forking to background when interfaces are ready.
> >
> > Add optional logging to file with -l/--log-file and --log-size.
> >
> > Unfortunately, this means we need to duplicate features that are more
> > appropriately implemented by a system logger, such as rotation. Keep
> > that reasonably simple, by using fallocate() with range collapsing
> > where supported (Linux kernel >= 3.15, extent-based ext4 and XFS) and
> > falling back to an unsophisticated block-by-block moving of entries
> > toward the beginning of the file once we reach the (mandatory) size
> > limit.
> >
> > While at it, clarify the role of LOG_EMERG in passt.c.
> >
> > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > ---
> > Makefile | 2 +-
> > README.md | 2 +-
> > conf.c | 49 ++++++++++-
> > log.c | 251 ++++++++++++++++++++++++++++++++++++++++++++++++++----
> > log.h | 6 ++
> > passt.1 | 14 ++-
> > passt.c | 1 +
> > 7 files changed, 300 insertions(+), 25 deletions(-)
> >
> > diff --git a/Makefile b/Makefile
> > index 74bbfeb..fafb024 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
> >
> > 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)
>
> That's a pity, but I guess we need it.
Yeah :( I started having thoughts about adding some granularity to
seccomp profiles based on what arguments are passed, but it still looked
a bit overkill just for this.
> > * ✅ 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..1e405e3 100644
> > --- a/log.c
> > +++ b/log.c
> > @@ -12,7 +12,12 @@
> > * Author: Stefano Brivio <sbrivio(a)redhat.com>
> > */
> >
> > +#include <arpa/inet.h>
> > +#include <limits.h>
> > +#include <errno.h>
> > +#include <fcntl.h>
> > #include <stdio.h>
> > +#include <stdint.h>
> > #include <stdlib.h>
> > #include <unistd.h>
> > #include <string.h>
> > @@ -20,36 +25,49 @@
> > #include <syslog.h>
> > #include <stdarg.h>
> > #include <sys/socket.h>
> > -#include <sys/un.h>
> >
> > #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,193 @@ 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);
>
> Do
?
> > + 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);
> > +}
> > +
> > +/**
> > + * 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)
>
> Have you tested this path? I thought with O_APPEND, this write would
> go at the end, regardless of the lseek() above.
With O_APPEND, it would, that's why the caller drops it before we enter
this function.
> > + return;
> > +
> > + log_written -= log_cut_size;
> > +}
> > +
> > +/**
> > + * 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));
>
> A common helper for the truncation header seems like it would be a
> good idea.
There's a newline here, but not in the other case, because here we
don't need any padding, given that we're not affected by the alignment
of FALLOC_FL_COLLAPSE_RANGE.
I tried to have this in a common path, and it invariably leads to
splitting into two writes (header plus newline, or header plus
padding), which looks worse than the alternative...
> > + 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;
>
> Hrm.. so errors in this section will throw away everything except the header.
>
> > +
> > + 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;
> > + end = n;
>
> But errors after here will just throw away what we haven't moved so
> far. Seems a bit inconsistent.
Um, right, I should move this assignment to the end of the loop, after
the lseek() below.
> > +
> > + if (lseek(fd, discard - header_len, SEEK_CUR) == -1)
> > + goto out;
> > + }
>
> I wonder if those whole function would be made simpler using pread()
> and pwrite() instead of lseek()s all over the place.
Yes, definitely, but I'm afraid we need to keep at least a couple of
lseek()s too (see BUGS in the man page of pread() implying I need to
switch O_APPEND on and off), and that would mean enabling three
additional syscalls, instead of just one.
And even if I manage to drop all the lseek()s, would this be worth two
additional syscalls instead of one? I'm not sure...
> > +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 fallocate fcntl
> > + */
> > +static int logfile_rotate(int fd, struct timespec *ts)
> > +{
> > + if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */))
> > + return -errno;
> > +
> > + /* Collapsing only for Linux kernel >= 3.15, extent-based ext4 or XFS */
> > + if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size))
> > + logfile_rotate_fallocate(fd, ts);
> > + else
> > + 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..ed71cd7 100644
> > --- a/log.h
> > +++ b/log.h
> > @@ -6,6 +6,10 @@
> > #ifndef LOG_H
> > #define LOG_H
> >
> > +#define LOGFILE_SIZE_DEFAULT 1E6
>
> Wouldn't a multiple of the block size make more sense?
In practice, that's already the case for most archs, with this being
256 pages in the vast majority of cases. If I make it explicit, though,
I can't report a default value in the man page, which I feel is an
important information to have there.
Also... does it really matter? fallocate(), here, just cares about
blocks we drop from the beginning, not blocks we use in total.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 4/8] log, conf: Add support for logging to file
2022-10-07 8:11 ` Stefano Brivio
@ 2022-10-07 8:57 ` David Gibson
2022-10-07 10:27 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 8:57 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 21240 bytes --]
On Fri, Oct 07, 2022 at 10:11:45AM +0200, Stefano Brivio wrote:
> On Fri, 7 Oct 2022 17:51:52 +1100
> David Gibson <david(a)gibson.dropbear.id.au> wrote:
>
> > On Fri, Oct 07, 2022 at 02:47:38AM +0200, Stefano Brivio wrote:
> > > In some environments, such as KubeVirt pods, we might not have a
> > > system logger available. We could choose to run in foreground, but
> > > this takes away the convenient synchronisation mechanism derived from
> > > forking to background when interfaces are ready.
> > >
> > > Add optional logging to file with -l/--log-file and --log-size.
> > >
> > > Unfortunately, this means we need to duplicate features that are more
> > > appropriately implemented by a system logger, such as rotation. Keep
> > > that reasonably simple, by using fallocate() with range collapsing
> > > where supported (Linux kernel >= 3.15, extent-based ext4 and XFS) and
> > > falling back to an unsophisticated block-by-block moving of entries
> > > toward the beginning of the file once we reach the (mandatory) size
> > > limit.
> > >
> > > While at it, clarify the role of LOG_EMERG in passt.c.
> > >
> > > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > > ---
> > > Makefile | 2 +-
> > > README.md | 2 +-
> > > conf.c | 49 ++++++++++-
> > > log.c | 251 ++++++++++++++++++++++++++++++++++++++++++++++++++----
> > > log.h | 6 ++
> > > passt.1 | 14 ++-
> > > passt.c | 1 +
> > > 7 files changed, 300 insertions(+), 25 deletions(-)
> > >
> > > diff --git a/Makefile b/Makefile
> > > index 74bbfeb..fafb024 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
> > >
> > > 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)
> >
> > That's a pity, but I guess we need it.
>
> Yeah :( I started having thoughts about adding some granularity to
> seccomp profiles based on what arguments are passed, but it still looked
> a bit overkill just for this.
>
> > > * ✅ 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..1e405e3 100644
> > > --- a/log.c
> > > +++ b/log.c
> > > @@ -12,7 +12,12 @@
> > > * Author: Stefano Brivio <sbrivio(a)redhat.com>
> > > */
> > >
> > > +#include <arpa/inet.h>
> > > +#include <limits.h>
> > > +#include <errno.h>
> > > +#include <fcntl.h>
> > > #include <stdio.h>
> > > +#include <stdint.h>
> > > #include <stdlib.h>
> > > #include <unistd.h>
> > > #include <string.h>
> > > @@ -20,36 +25,49 @@
> > > #include <syslog.h>
> > > #include <stdarg.h>
> > > #include <sys/socket.h>
> > > -#include <sys/un.h>
> > >
> > > #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,193 @@ 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);
> >
> > Do
>
> ?
>
> > > + 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);
> > > +}
> > > +
> > > +/**
> > > + * 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)
> >
> > Have you tested this path? I thought with O_APPEND, this write would
> > go at the end, regardless of the lseek() above.
>
> With O_APPEND, it would, that's why the caller drops it before we enter
> this function.
Duh, sorry. I completely missed those fcntl()s.
> > > + return;
> > > +
> > > + log_written -= log_cut_size;
> > > +}
> > > +
> > > +/**
> > > + * 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));
> >
> > A common helper for the truncation header seems like it would be a
> > good idea.
>
> There's a newline here, but not in the other case, because here we
> don't need any padding, given that we're not affected by the alignment
> of FALLOC_FL_COLLAPSE_RANGE.
Ah, ok.
> I tried to have this in a common path, and it invariably leads to
> splitting into two writes (header plus newline, or header plus
> padding), which looks worse than the alternative...
>
> > > + 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;
> >
> > Hrm.. so errors in this section will throw away everything except the header.
> >
> > > +
> > > + 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;
> > > + end = n;
> >
> > But errors after here will just throw away what we haven't moved so
> > far. Seems a bit inconsistent.
>
> Um, right, I should move this assignment to the end of the loop, after
> the lseek() below.
>
> > > +
> > > + if (lseek(fd, discard - header_len, SEEK_CUR) == -1)
> > > + goto out;
> > > + }
> >
> > I wonder if those whole function would be made simpler using pread()
> > and pwrite() instead of lseek()s all over the place.
>
> Yes, definitely, but I'm afraid we need to keep at least a couple of
> lseek()s too (see BUGS in the man page of pread() implying I need to
> switch O_APPEND on and off), and that would mean enabling three
> additional syscalls, instead of just one.
>
> And even if I manage to drop all the lseek()s, would this be worth two
> additional syscalls instead of one? I'm not sure...
>
> > > +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 fallocate fcntl
> > > + */
> > > +static int logfile_rotate(int fd, struct timespec *ts)
> > > +{
> > > + if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */))
> > > + return -errno;
> > > +
> > > + /* Collapsing only for Linux kernel >= 3.15, extent-based ext4 or XFS */
> > > + if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size))
> > > + logfile_rotate_fallocate(fd, ts);
> > > + else
> > > + 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..ed71cd7 100644
> > > --- a/log.h
> > > +++ b/log.h
> > > @@ -6,6 +6,10 @@
> > > #ifndef LOG_H
> > > #define LOG_H
> > >
> > > +#define LOGFILE_SIZE_DEFAULT 1E6
> >
> > Wouldn't a multiple of the block size make more sense?
>
> In practice, that's already the case for most archs, with this being
> 256 pages in the vast majority of cases. If I make it explicit, though,
> I can't report a default value in the man page, which I feel is an
> important information to have there.
Uh.. I must be forgetting my obscure C literal syntax. I assumed 1E6
was 1000000.
> Also... does it really matter? fallocate(), here, just cares about
> blocks we drop from the beginning, not blocks we use in total.
I guess so.
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 4/8] log, conf: Add support for logging to file
2022-10-07 8:57 ` David Gibson
@ 2022-10-07 10:27 ` Stefano Brivio
0 siblings, 0 replies; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 10:27 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 22334 bytes --]
On Fri, 7 Oct 2022 19:57:19 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 10:11:45AM +0200, Stefano Brivio wrote:
> > On Fri, 7 Oct 2022 17:51:52 +1100
> > David Gibson <david(a)gibson.dropbear.id.au> wrote:
> >
> > > On Fri, Oct 07, 2022 at 02:47:38AM +0200, Stefano Brivio wrote:
> > > > In some environments, such as KubeVirt pods, we might not have a
> > > > system logger available. We could choose to run in foreground, but
> > > > this takes away the convenient synchronisation mechanism derived from
> > > > forking to background when interfaces are ready.
> > > >
> > > > Add optional logging to file with -l/--log-file and --log-size.
> > > >
> > > > Unfortunately, this means we need to duplicate features that are more
> > > > appropriately implemented by a system logger, such as rotation. Keep
> > > > that reasonably simple, by using fallocate() with range collapsing
> > > > where supported (Linux kernel >= 3.15, extent-based ext4 and XFS) and
> > > > falling back to an unsophisticated block-by-block moving of entries
> > > > toward the beginning of the file once we reach the (mandatory) size
> > > > limit.
> > > >
> > > > While at it, clarify the role of LOG_EMERG in passt.c.
> > > >
> > > > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > > > ---
> > > > Makefile | 2 +-
> > > > README.md | 2 +-
> > > > conf.c | 49 ++++++++++-
> > > > log.c | 251 ++++++++++++++++++++++++++++++++++++++++++++++++++----
> > > > log.h | 6 ++
> > > > passt.1 | 14 ++-
> > > > passt.c | 1 +
> > > > 7 files changed, 300 insertions(+), 25 deletions(-)
> > > >
> > > > diff --git a/Makefile b/Makefile
> > > > index 74bbfeb..fafb024 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
> > > >
> > > > 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)
> > >
> > > That's a pity, but I guess we need it.
> >
> > Yeah :( I started having thoughts about adding some granularity to
> > seccomp profiles based on what arguments are passed, but it still looked
> > a bit overkill just for this.
> >
> > > > * ✅ 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..1e405e3 100644
> > > > --- a/log.c
> > > > +++ b/log.c
> > > > @@ -12,7 +12,12 @@
> > > > * Author: Stefano Brivio <sbrivio(a)redhat.com>
> > > > */
> > > >
> > > > +#include <arpa/inet.h>
> > > > +#include <limits.h>
> > > > +#include <errno.h>
> > > > +#include <fcntl.h>
> > > > #include <stdio.h>
> > > > +#include <stdint.h>
> > > > #include <stdlib.h>
> > > > #include <unistd.h>
> > > > #include <string.h>
> > > > @@ -20,36 +25,49 @@
> > > > #include <syslog.h>
> > > > #include <stdarg.h>
> > > > #include <sys/socket.h>
> > > > -#include <sys/un.h>
> > > >
> > > > #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,193 @@ 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);
> > >
> > > Do
> >
> > ?
> >
> > > > + 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);
> > > > +}
> > > > +
> > > > +/**
> > > > + * 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)
> > >
> > > Have you tested this path? I thought with O_APPEND, this write would
> > > go at the end, regardless of the lseek() above.
> >
> > With O_APPEND, it would, that's why the caller drops it before we enter
> > this function.
>
> Duh, sorry. I completely missed those fcntl()s.
>
> > > > + return;
> > > > +
> > > > + log_written -= log_cut_size;
> > > > +}
> > > > +
> > > > +/**
> > > > + * 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));
> > >
> > > A common helper for the truncation header seems like it would be a
> > > good idea.
> >
> > There's a newline here, but not in the other case, because here we
> > don't need any padding, given that we're not affected by the alignment
> > of FALLOC_FL_COLLAPSE_RANGE.
>
> Ah, ok.
>
> > I tried to have this in a common path, and it invariably leads to
> > splitting into two writes (header plus newline, or header plus
> > padding), which looks worse than the alternative...
> >
> > > > + 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;
> > >
> > > Hrm.. so errors in this section will throw away everything except the header.
> > >
> > > > +
> > > > + 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;
> > > > + end = n;
> > >
> > > But errors after here will just throw away what we haven't moved so
> > > far. Seems a bit inconsistent.
> >
> > Um, right, I should move this assignment to the end of the loop, after
> > the lseek() below.
> >
> > > > +
> > > > + if (lseek(fd, discard - header_len, SEEK_CUR) == -1)
> > > > + goto out;
> > > > + }
> > >
> > > I wonder if those whole function would be made simpler using pread()
> > > and pwrite() instead of lseek()s all over the place.
> >
> > Yes, definitely, but I'm afraid we need to keep at least a couple of
> > lseek()s too (see BUGS in the man page of pread() implying I need to
> > switch O_APPEND on and off), and that would mean enabling three
> > additional syscalls, instead of just one.
> >
> > And even if I manage to drop all the lseek()s, would this be worth two
> > additional syscalls instead of one? I'm not sure...
> >
> > > > +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 fallocate fcntl
> > > > + */
> > > > +static int logfile_rotate(int fd, struct timespec *ts)
> > > > +{
> > > > + if (fcntl(fd, F_SETFL, O_RDWR /* Drop O_APPEND: explicit lseek() */))
> > > > + return -errno;
> > > > +
> > > > + /* Collapsing only for Linux kernel >= 3.15, extent-based ext4 or XFS */
> > > > + if (!fallocate(fd, FALLOC_FL_COLLAPSE_RANGE, 0, log_cut_size))
> > > > + logfile_rotate_fallocate(fd, ts);
> > > > + else
> > > > + 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..ed71cd7 100644
> > > > --- a/log.h
> > > > +++ b/log.h
> > > > @@ -6,6 +6,10 @@
> > > > #ifndef LOG_H
> > > > #define LOG_H
> > > >
> > > > +#define LOGFILE_SIZE_DEFAULT 1E6
> > >
> > > Wouldn't a multiple of the block size make more sense?
> >
> > In practice, that's already the case for most archs, with this being
> > 256 pages in the vast majority of cases. If I make it explicit, though,
> > I can't report a default value in the man page, which I feel is an
> > important information to have there.
>
> Uh.. I must be forgetting my obscure C literal syntax. I assumed 1E6
> was 1000000.
Whoops, it actually is (of course, it's powers of 10!). I'll change
this to (1024 * 1024), even if it doesn't really matter for fallocate()
purposes.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 5/8] log: Add missing function comment for trace_init()
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
` (3 preceding siblings ...)
2022-10-07 0:47 ` [PATCH 4/8] log, conf: Add support for logging to file Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:52 ` David Gibson
2022-10-07 0:47 ` [PATCH 6/8] conf, log, Makefile: Add versioning information Stefano Brivio
` (2 subsequent siblings)
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 477 bytes --]
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
log.c | 4 ++++
1 file changed, 4 insertions(+)
diff --git a/log.c b/log.c
index 1e405e3..85b13fe 100644
--- a/log.c
+++ b/log.c
@@ -91,6 +91,10 @@ logfn(warn, LOG_WARNING)
logfn(info, LOG_INFO)
logfn(debug, LOG_DEBUG)
+/**
+ * trace_init() - Set log_trace depending on trace (debug) mode
+ * @enable: Tracing debug mode enabled if non-zero
+ */
void trace_init(int enable)
{
log_trace = enable;
--
@@ -91,6 +91,10 @@ logfn(warn, LOG_WARNING)
logfn(info, LOG_INFO)
logfn(debug, LOG_DEBUG)
+/**
+ * trace_init() - Set log_trace depending on trace (debug) mode
+ * @enable: Tracing debug mode enabled if non-zero
+ */
void trace_init(int enable)
{
log_trace = enable;
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 5/8] log: Add missing function comment for trace_init()
2022-10-07 0:47 ` [PATCH 5/8] log: Add missing function comment for trace_init() Stefano Brivio
@ 2022-10-07 6:52 ` David Gibson
0 siblings, 0 replies; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:52 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 819 bytes --]
On Fri, Oct 07, 2022 at 02:47:39AM +0200, Stefano Brivio wrote:
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au>
> ---
> log.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/log.c b/log.c
> index 1e405e3..85b13fe 100644
> --- a/log.c
> +++ b/log.c
> @@ -91,6 +91,10 @@ logfn(warn, LOG_WARNING)
> logfn(info, LOG_INFO)
> logfn(debug, LOG_DEBUG)
>
> +/**
> + * trace_init() - Set log_trace depending on trace (debug) mode
> + * @enable: Tracing debug mode enabled if non-zero
> + */
> void trace_init(int enable)
> {
> log_trace = enable;
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 6/8] conf, log, Makefile: Add versioning information
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
` (4 preceding siblings ...)
2022-10-07 0:47 ` [PATCH 5/8] log: Add missing function comment for trace_init() Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:57 ` David Gibson
2022-10-07 0:47 ` [PATCH 7/8] util: Check return value of lseek() while reading bound ports from procfs Stefano Brivio
2022-10-07 0:47 ` [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup Stefano Brivio
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 4388 bytes --]
Now that we can log to file, this might start to be relevant.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
Makefile | 3 +++
conf.c | 12 ++++++++++--
log.c | 4 ++--
passt.1 | 4 ++++
util.h | 8 ++++++++
5 files changed, 27 insertions(+), 4 deletions(-)
diff --git a/Makefile b/Makefile
index fafb024..f7ddb84 100644
--- a/Makefile
+++ b/Makefile
@@ -9,6 +9,8 @@
# Copyright (c) 2021 Red Hat GmbH
# Author: Stefano Brivio <sbrivio(a)redhat.com>
+VERSION ?= $(shell git describe --tags HEAD || echo "unknown\ version")
+
RLIMIT_STACK_VAL := $(shell /bin/sh -c 'ulimit -s')
ifeq ($(RLIMIT_STACK_VAL),unlimited)
RLIMIT_STACK_VAL := 1024
@@ -31,6 +33,7 @@ FLAGS += -DNETNS_RUN_DIR=\"/run/netns\"
FLAGS += -DPASST_AUDIT_ARCH=AUDIT_ARCH_$(AUDIT_ARCH)
FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
FLAGS += -DARCH=\"$(TARGET_ARCH)\"
+FLAGS += -DVERSION=\"$(VERSION)\"
PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
diff --git a/conf.c b/conf.c
index f22940b..4ec3153 100644
--- a/conf.c
+++ b/conf.c
@@ -626,6 +626,8 @@ static void usage(const char *name)
}
info("");
+
+ info( " -v, --version Show version and exit");
info( " -d, --debug Be verbose, don't run in background");
info( " --trace Be extra verbose, implies --debug");
info( " -q, --quiet Don't print informational messages");
@@ -993,6 +995,7 @@ void conf(struct ctx *c, int argc, char **argv)
{
int netns_only = 0;
struct option options[] = {
+ {"version", no_argument, NULL, 'v' },
{"debug", no_argument, NULL, 'd' },
{"quiet", no_argument, NULL, 'q' },
{"foreground", no_argument, NULL, 'f' },
@@ -1057,9 +1060,9 @@ void conf(struct ctx *c, int argc, char **argv)
if (c->mode == MODE_PASTA) {
c->no_dhcp_dns = c->no_dhcp_dns_search = 1;
- optstring = "dqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
+ optstring = "vdqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
} else {
- optstring = "dqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
+ optstring = "vdqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
}
c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
@@ -1197,6 +1200,11 @@ void conf(struct ctx *c, int argc, char **argv)
usage(argv[0]);
}
break;
+ case 'v':
+ fprintf(stdout,
+ c->mode == MODE_PASST ? "passt " : "pasta ");
+ fprintf(stdout, VERSION_BLOB);
+ exit(EXIT_SUCCESS);
case 'd':
if (c->debug) {
err("Multiple --debug options given");
diff --git a/log.c b/log.c
index 85b13fe..2b088c4 100644
--- a/log.c
+++ b/log.c
@@ -172,7 +172,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
}
/**
- * logfile_init() - Open log file and write header with PID and path
+ * logfile_init() - Open log file and write header with PID, version, 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
@@ -196,7 +196,7 @@ void logfile_init(const char *name, const char *path, size_t size)
log_size = size ? size : LOGFILE_SIZE_DEFAULT;
- n = snprintf(log_header, sizeof(log_header), "%s: %s (%i)",
+ n = snprintf(log_header, sizeof(log_header), "%s " VERSION ": %s (%i)",
name, exe, getpid());
if (write(log_file, log_header, n) <= 0 ||
diff --git a/passt.1 b/passt.1
index 64236b6..c63a439 100644
--- a/passt.1
+++ b/passt.1
@@ -77,6 +77,10 @@ for performance reasons.
.SH OPTIONS
+.TP
+.BR \-v ", " \-\-version
+Show version and exit.
+
.TP
.BR \-d ", " \-\-debug
Be verbose, don't run in background, don't log to the system logger.
diff --git a/util.h b/util.h
index 1adbf04..e8f99b6 100644
--- a/util.h
+++ b/util.h
@@ -6,6 +6,14 @@
#ifndef UTIL_H
#define UTIL_H
+#define VERSION_BLOB \
+ VERSION "\n" \
+ "Copyright (C) 2020-2022 Red Hat\n" \
+ "GNU Affero GPL version 3 or later " \
+ "<https://www.gnu.org/licenses/agpl-3.0.html>\n" \
+ "This is free software: you are free to change and redistribute it.\n" \
+ "There is NO WARRANTY, to the extent permitted by law.\n\n"
+
#ifndef SECCOMP_RET_KILL_PROCESS
#define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
#endif
--
@@ -6,6 +6,14 @@
#ifndef UTIL_H
#define UTIL_H
+#define VERSION_BLOB \
+ VERSION "\n" \
+ "Copyright (C) 2020-2022 Red Hat\n" \
+ "GNU Affero GPL version 3 or later " \
+ "<https://www.gnu.org/licenses/agpl-3.0.html>\n" \
+ "This is free software: you are free to change and redistribute it.\n" \
+ "There is NO WARRANTY, to the extent permitted by law.\n\n"
+
#ifndef SECCOMP_RET_KILL_PROCESS
#define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
#endif
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 6/8] conf, log, Makefile: Add versioning information
2022-10-07 0:47 ` [PATCH 6/8] conf, log, Makefile: Add versioning information Stefano Brivio
@ 2022-10-07 6:57 ` David Gibson
2022-10-07 8:15 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:57 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 5296 bytes --]
On Fri, Oct 07, 2022 at 02:47:40AM +0200, Stefano Brivio wrote:
> Now that we can log to file, this might start to be relevant.
Uh... I dont' understand the connection here.
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> ---
> Makefile | 3 +++
> conf.c | 12 ++++++++++--
> log.c | 4 ++--
> passt.1 | 4 ++++
> util.h | 8 ++++++++
> 5 files changed, 27 insertions(+), 4 deletions(-)
>
> diff --git a/Makefile b/Makefile
> index fafb024..f7ddb84 100644
> --- a/Makefile
> +++ b/Makefile
> @@ -9,6 +9,8 @@
> # Copyright (c) 2021 Red Hat GmbH
> # Author: Stefano Brivio <sbrivio(a)redhat.com>
>
> +VERSION ?= $(shell git describe --tags HEAD || echo "unknown\ version")
> +
> RLIMIT_STACK_VAL := $(shell /bin/sh -c 'ulimit -s')
> ifeq ($(RLIMIT_STACK_VAL),unlimited)
> RLIMIT_STACK_VAL := 1024
> @@ -31,6 +33,7 @@ FLAGS += -DNETNS_RUN_DIR=\"/run/netns\"
> FLAGS += -DPASST_AUDIT_ARCH=AUDIT_ARCH_$(AUDIT_ARCH)
> FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
> FLAGS += -DARCH=\"$(TARGET_ARCH)\"
> +FLAGS += -DVERSION=\"$(VERSION)\"
>
> PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
> isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
> diff --git a/conf.c b/conf.c
> index f22940b..4ec3153 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -626,6 +626,8 @@ static void usage(const char *name)
> }
> info("");
>
> +
Extraneous blank line.
> + info( " -v, --version Show version and exit");
I'd suggest just '--version'. '-v' is "verbose" more often than it is
"version".
> info( " -d, --debug Be verbose, don't run in background");
> info( " --trace Be extra verbose, implies --debug");
> info( " -q, --quiet Don't print informational messages");
> @@ -993,6 +995,7 @@ void conf(struct ctx *c, int argc, char **argv)
> {
> int netns_only = 0;
> struct option options[] = {
> + {"version", no_argument, NULL, 'v' },
> {"debug", no_argument, NULL, 'd' },
> {"quiet", no_argument, NULL, 'q' },
> {"foreground", no_argument, NULL, 'f' },
> @@ -1057,9 +1060,9 @@ void conf(struct ctx *c, int argc, char **argv)
>
> if (c->mode == MODE_PASTA) {
> c->no_dhcp_dns = c->no_dhcp_dns_search = 1;
> - optstring = "dqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> + optstring = "vdqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> } else {
> - optstring = "dqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> + optstring = "vdqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> }
>
> c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
> @@ -1197,6 +1200,11 @@ void conf(struct ctx *c, int argc, char **argv)
> usage(argv[0]);
> }
> break;
> + case 'v':
> + fprintf(stdout,
> + c->mode == MODE_PASST ? "passt " : "pasta ");
> + fprintf(stdout, VERSION_BLOB);
> + exit(EXIT_SUCCESS);
> case 'd':
> if (c->debug) {
> err("Multiple --debug options given");
> diff --git a/log.c b/log.c
> index 85b13fe..2b088c4 100644
> --- a/log.c
> +++ b/log.c
> @@ -172,7 +172,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
> }
>
> /**
> - * logfile_init() - Open log file and write header with PID and path
> + * logfile_init() - Open log file and write header with PID, version, 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
> @@ -196,7 +196,7 @@ void logfile_init(const char *name, const char *path, size_t size)
>
> log_size = size ? size : LOGFILE_SIZE_DEFAULT;
>
> - n = snprintf(log_header, sizeof(log_header), "%s: %s (%i)",
> + n = snprintf(log_header, sizeof(log_header), "%s " VERSION ": %s (%i)",
> name, exe, getpid());
>
> if (write(log_file, log_header, n) <= 0 ||
> diff --git a/passt.1 b/passt.1
> index 64236b6..c63a439 100644
> --- a/passt.1
> +++ b/passt.1
> @@ -77,6 +77,10 @@ for performance reasons.
>
> .SH OPTIONS
>
> +.TP
> +.BR \-v ", " \-\-version
> +Show version and exit.
> +
> .TP
> .BR \-d ", " \-\-debug
> Be verbose, don't run in background, don't log to the system logger.
> diff --git a/util.h b/util.h
> index 1adbf04..e8f99b6 100644
> --- a/util.h
> +++ b/util.h
> @@ -6,6 +6,14 @@
> #ifndef UTIL_H
> #define UTIL_H
>
> +#define VERSION_BLOB \
> + VERSION "\n" \
> + "Copyright (C) 2020-2022 Red Hat\n" \
Fwiw, I believe Red Hat legal suggests simply "Copyright Red Hat".
AIUI the "(C)" thing is legally meaningless (unlike the word
"copyright" or the actual © symbol), and the years are unnecessary and
tend to get out of date.
> + "GNU Affero GPL version 3 or later " \
> + "<https://www.gnu.org/licenses/agpl-3.0.html>\n" \
> + "This is free software: you are free to change and redistribute it.\n" \
> + "There is NO WARRANTY, to the extent permitted by law.\n\n"
> +
> #ifndef SECCOMP_RET_KILL_PROCESS
> #define SECCOMP_RET_KILL_PROCESS SECCOMP_RET_KILL
> #endif
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 6/8] conf, log, Makefile: Add versioning information
2022-10-07 6:57 ` David Gibson
@ 2022-10-07 8:15 ` Stefano Brivio
2022-10-07 9:03 ` David Gibson
0 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 8:15 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 5369 bytes --]
On Fri, 7 Oct 2022 17:57:43 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 02:47:40AM +0200, Stefano Brivio wrote:
> > Now that we can log to file, this might start to be relevant.
>
> Uh... I dont' understand the connection here.
Because we might have a pile of log files collected somewhere (or
logs shared by users) and this adds the version to the log file.
> > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > ---
> > Makefile | 3 +++
> > conf.c | 12 ++++++++++--
> > log.c | 4 ++--
> > passt.1 | 4 ++++
> > util.h | 8 ++++++++
> > 5 files changed, 27 insertions(+), 4 deletions(-)
> >
> > diff --git a/Makefile b/Makefile
> > index fafb024..f7ddb84 100644
> > --- a/Makefile
> > +++ b/Makefile
> > @@ -9,6 +9,8 @@
> > # Copyright (c) 2021 Red Hat GmbH
> > # Author: Stefano Brivio <sbrivio(a)redhat.com>
> >
> > +VERSION ?= $(shell git describe --tags HEAD || echo "unknown\ version")
> > +
> > RLIMIT_STACK_VAL := $(shell /bin/sh -c 'ulimit -s')
> > ifeq ($(RLIMIT_STACK_VAL),unlimited)
> > RLIMIT_STACK_VAL := 1024
> > @@ -31,6 +33,7 @@ FLAGS += -DNETNS_RUN_DIR=\"/run/netns\"
> > FLAGS += -DPASST_AUDIT_ARCH=AUDIT_ARCH_$(AUDIT_ARCH)
> > FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
> > FLAGS += -DARCH=\"$(TARGET_ARCH)\"
> > +FLAGS += -DVERSION=\"$(VERSION)\"
> >
> > PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
> > isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
> > diff --git a/conf.c b/conf.c
> > index f22940b..4ec3153 100644
> > --- a/conf.c
> > +++ b/conf.c
> > @@ -626,6 +626,8 @@ static void usage(const char *name)
> > }
> > info("");
> >
> > +
>
> Extraneous blank line.
Oops.
> > + info( " -v, --version Show version and exit");
>
> I'd suggest just '--version'. '-v' is "verbose" more often than it is
> "version".
Um, yes, I'll drop -v.
> > info( " -d, --debug Be verbose, don't run in background");
> > info( " --trace Be extra verbose, implies --debug");
> > info( " -q, --quiet Don't print informational messages");
> > @@ -993,6 +995,7 @@ void conf(struct ctx *c, int argc, char **argv)
> > {
> > int netns_only = 0;
> > struct option options[] = {
> > + {"version", no_argument, NULL, 'v' },
> > {"debug", no_argument, NULL, 'd' },
> > {"quiet", no_argument, NULL, 'q' },
> > {"foreground", no_argument, NULL, 'f' },
> > @@ -1057,9 +1060,9 @@ void conf(struct ctx *c, int argc, char **argv)
> >
> > if (c->mode == MODE_PASTA) {
> > c->no_dhcp_dns = c->no_dhcp_dns_search = 1;
> > - optstring = "dqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> > + optstring = "vdqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> > } else {
> > - optstring = "dqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> > + optstring = "vdqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> > }
> >
> > c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
> > @@ -1197,6 +1200,11 @@ void conf(struct ctx *c, int argc, char **argv)
> > usage(argv[0]);
> > }
> > break;
> > + case 'v':
> > + fprintf(stdout,
> > + c->mode == MODE_PASST ? "passt " : "pasta ");
> > + fprintf(stdout, VERSION_BLOB);
> > + exit(EXIT_SUCCESS);
> > case 'd':
> > if (c->debug) {
> > err("Multiple --debug options given");
> > diff --git a/log.c b/log.c
> > index 85b13fe..2b088c4 100644
> > --- a/log.c
> > +++ b/log.c
> > @@ -172,7 +172,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
> > }
> >
> > /**
> > - * logfile_init() - Open log file and write header with PID and path
> > + * logfile_init() - Open log file and write header with PID, version, 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
> > @@ -196,7 +196,7 @@ void logfile_init(const char *name, const char *path, size_t size)
> >
> > log_size = size ? size : LOGFILE_SIZE_DEFAULT;
> >
> > - n = snprintf(log_header, sizeof(log_header), "%s: %s (%i)",
> > + n = snprintf(log_header, sizeof(log_header), "%s " VERSION ": %s (%i)",
> > name, exe, getpid());
> >
> > if (write(log_file, log_header, n) <= 0 ||
> > diff --git a/passt.1 b/passt.1
> > index 64236b6..c63a439 100644
> > --- a/passt.1
> > +++ b/passt.1
> > @@ -77,6 +77,10 @@ for performance reasons.
> >
> > .SH OPTIONS
> >
> > +.TP
> > +.BR \-v ", " \-\-version
> > +Show version and exit.
> > +
> > .TP
> > .BR \-d ", " \-\-debug
> > Be verbose, don't run in background, don't log to the system logger.
> > diff --git a/util.h b/util.h
> > index 1adbf04..e8f99b6 100644
> > --- a/util.h
> > +++ b/util.h
> > @@ -6,6 +6,14 @@
> > #ifndef UTIL_H
> > #define UTIL_H
> >
> > +#define VERSION_BLOB \
> > + VERSION "\n" \
> > + "Copyright (C) 2020-2022 Red Hat\n" \
>
> Fwiw, I believe Red Hat legal suggests simply "Copyright Red Hat".
> AIUI the "(C)" thing is legally meaningless (unlike the word
> "copyright" or the actual © symbol), and the years are unnecessary and
> tend to get out of date.
I just checked coreutils and gcc, but I see both points, I'll change
this.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 6/8] conf, log, Makefile: Add versioning information
2022-10-07 8:15 ` Stefano Brivio
@ 2022-10-07 9:03 ` David Gibson
2022-10-07 10:12 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 9:03 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 6044 bytes --]
On Fri, Oct 07, 2022 at 10:15:25AM +0200, Stefano Brivio wrote:
> On Fri, 7 Oct 2022 17:57:43 +1100
> David Gibson <david(a)gibson.dropbear.id.au> wrote:
>
> > On Fri, Oct 07, 2022 at 02:47:40AM +0200, Stefano Brivio wrote:
> > > Now that we can log to file, this might start to be relevant.
> >
> > Uh... I dont' understand the connection here.
>
> Because we might have a pile of log files collected somewhere (or
> logs shared by users) and this adds the version to the log file.
But how is that different with a system logger?
> > > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > > ---
> > > Makefile | 3 +++
> > > conf.c | 12 ++++++++++--
> > > log.c | 4 ++--
> > > passt.1 | 4 ++++
> > > util.h | 8 ++++++++
> > > 5 files changed, 27 insertions(+), 4 deletions(-)
> > >
> > > diff --git a/Makefile b/Makefile
> > > index fafb024..f7ddb84 100644
> > > --- a/Makefile
> > > +++ b/Makefile
> > > @@ -9,6 +9,8 @@
> > > # Copyright (c) 2021 Red Hat GmbH
> > > # Author: Stefano Brivio <sbrivio(a)redhat.com>
> > >
> > > +VERSION ?= $(shell git describe --tags HEAD || echo "unknown\ version")
> > > +
> > > RLIMIT_STACK_VAL := $(shell /bin/sh -c 'ulimit -s')
> > > ifeq ($(RLIMIT_STACK_VAL),unlimited)
> > > RLIMIT_STACK_VAL := 1024
> > > @@ -31,6 +33,7 @@ FLAGS += -DNETNS_RUN_DIR=\"/run/netns\"
> > > FLAGS += -DPASST_AUDIT_ARCH=AUDIT_ARCH_$(AUDIT_ARCH)
> > > FLAGS += -DRLIMIT_STACK_VAL=$(RLIMIT_STACK_VAL)
> > > FLAGS += -DARCH=\"$(TARGET_ARCH)\"
> > > +FLAGS += -DVERSION=\"$(VERSION)\"
> > >
> > > PASST_SRCS = arch.c arp.c checksum.c conf.c dhcp.c dhcpv6.c icmp.c igmp.c \
> > > isolation.c lineread.c log.c mld.c ndp.c netlink.c packet.c passt.c \
> > > diff --git a/conf.c b/conf.c
> > > index f22940b..4ec3153 100644
> > > --- a/conf.c
> > > +++ b/conf.c
> > > @@ -626,6 +626,8 @@ static void usage(const char *name)
> > > }
> > > info("");
> > >
> > > +
> >
> > Extraneous blank line.
>
> Oops.
>
> > > + info( " -v, --version Show version and exit");
> >
> > I'd suggest just '--version'. '-v' is "verbose" more often than it is
> > "version".
>
> Um, yes, I'll drop -v.
>
> > > info( " -d, --debug Be verbose, don't run in background");
> > > info( " --trace Be extra verbose, implies --debug");
> > > info( " -q, --quiet Don't print informational messages");
> > > @@ -993,6 +995,7 @@ void conf(struct ctx *c, int argc, char **argv)
> > > {
> > > int netns_only = 0;
> > > struct option options[] = {
> > > + {"version", no_argument, NULL, 'v' },
> > > {"debug", no_argument, NULL, 'd' },
> > > {"quiet", no_argument, NULL, 'q' },
> > > {"foreground", no_argument, NULL, 'f' },
> > > @@ -1057,9 +1060,9 @@ void conf(struct ctx *c, int argc, char **argv)
> > >
> > > if (c->mode == MODE_PASTA) {
> > > c->no_dhcp_dns = c->no_dhcp_dns_search = 1;
> > > - optstring = "dqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> > > + optstring = "vdqfel:hI:p:P:m:a:n:M:g:i:D:S:46t:u:T:U:";
> > > } else {
> > > - optstring = "dqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> > > + optstring = "vdqfel:hs:p:P:m:a:n:M:g:i:D:S:46t:u:";
> > > }
> > >
> > > c->tcp.fwd_in.mode = c->tcp.fwd_out.mode = 0;
> > > @@ -1197,6 +1200,11 @@ void conf(struct ctx *c, int argc, char **argv)
> > > usage(argv[0]);
> > > }
> > > break;
> > > + case 'v':
> > > + fprintf(stdout,
> > > + c->mode == MODE_PASST ? "passt " : "pasta ");
> > > + fprintf(stdout, VERSION_BLOB);
> > > + exit(EXIT_SUCCESS);
> > > case 'd':
> > > if (c->debug) {
> > > err("Multiple --debug options given");
> > > diff --git a/log.c b/log.c
> > > index 85b13fe..2b088c4 100644
> > > --- a/log.c
> > > +++ b/log.c
> > > @@ -172,7 +172,7 @@ void passt_vsyslog(int pri, const char *format, va_list ap)
> > > }
> > >
> > > /**
> > > - * logfile_init() - Open log file and write header with PID and path
> > > + * logfile_init() - Open log file and write header with PID, version, 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
> > > @@ -196,7 +196,7 @@ void logfile_init(const char *name, const char *path, size_t size)
> > >
> > > log_size = size ? size : LOGFILE_SIZE_DEFAULT;
> > >
> > > - n = snprintf(log_header, sizeof(log_header), "%s: %s (%i)",
> > > + n = snprintf(log_header, sizeof(log_header), "%s " VERSION ": %s (%i)",
> > > name, exe, getpid());
> > >
> > > if (write(log_file, log_header, n) <= 0 ||
> > > diff --git a/passt.1 b/passt.1
> > > index 64236b6..c63a439 100644
> > > --- a/passt.1
> > > +++ b/passt.1
> > > @@ -77,6 +77,10 @@ for performance reasons.
> > >
> > > .SH OPTIONS
> > >
> > > +.TP
> > > +.BR \-v ", " \-\-version
> > > +Show version and exit.
> > > +
> > > .TP
> > > .BR \-d ", " \-\-debug
> > > Be verbose, don't run in background, don't log to the system logger.
> > > diff --git a/util.h b/util.h
> > > index 1adbf04..e8f99b6 100644
> > > --- a/util.h
> > > +++ b/util.h
> > > @@ -6,6 +6,14 @@
> > > #ifndef UTIL_H
> > > #define UTIL_H
> > >
> > > +#define VERSION_BLOB \
> > > + VERSION "\n" \
> > > + "Copyright (C) 2020-2022 Red Hat\n" \
> >
> > Fwiw, I believe Red Hat legal suggests simply "Copyright Red Hat".
> > AIUI the "(C)" thing is legally meaningless (unlike the word
> > "copyright" or the actual © symbol), and the years are unnecessary and
> > tend to get out of date.
>
> I just checked coreutils and gcc, but I see both points, I'll change
> this.
Yeah.. developer copyright statements have an awful lot of cargo culting.
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 6/8] conf, log, Makefile: Add versioning information
2022-10-07 9:03 ` David Gibson
@ 2022-10-07 10:12 ` Stefano Brivio
0 siblings, 0 replies; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 10:12 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 835 bytes --]
On Fri, 7 Oct 2022 20:03:52 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 10:15:25AM +0200, Stefano Brivio wrote:
> > On Fri, 7 Oct 2022 17:57:43 +1100
> > David Gibson <david(a)gibson.dropbear.id.au> wrote:
> >
> > > On Fri, Oct 07, 2022 at 02:47:40AM +0200, Stefano Brivio wrote:
> > > > Now that we can log to file, this might start to be relevant.
> > >
> > > Uh... I dont' understand the connection here.
> >
> > Because we might have a pile of log files collected somewhere (or
> > logs shared by users) and this adds the version to the log file.
>
> But how is that different with a system logger?
Files tend to pile up in random places, at least for me. :) The syslog
goes away, and nobody is going to share that with me. Anyway, fine, I
can rephrase this.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 7/8] util: Check return value of lseek() while reading bound ports from procfs
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
` (5 preceding siblings ...)
2022-10-07 0:47 ` [PATCH 6/8] conf, log, Makefile: Add versioning information Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 6:58 ` David Gibson
2022-10-07 0:47 ` [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup Stefano Brivio
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 959 bytes --]
Coverity now noticed we're checking most lseek() return values, but
not this. Not really relevant, but it doesn't hurt to check we can
actually seek before reading lines.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
util.c | 10 +++++++---
1 file changed, 7 insertions(+), 3 deletions(-)
diff --git a/util.c b/util.c
index b366167..5b1e08a 100644
--- a/util.c
+++ b/util.c
@@ -311,10 +311,14 @@ void procfs_scan_listen(struct ctx *c, uint8_t proto, int ip_version, int ns,
path = "/proc/net/udp6";
}
- if (*fd != -1)
- lseek(*fd, 0, SEEK_SET);
- else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0)
+ if (*fd != -1) {
+ if (lseek(*fd, 0, SEEK_SET)) {
+ warn("lseek() failed on %s: %s", path, strerror(errno));
+ return;
+ }
+ } else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0) {
return;
+ }
lineread_init(&lr, *fd);
lineread_get(&lr, &line); /* throw away header */
--
@@ -311,10 +311,14 @@ void procfs_scan_listen(struct ctx *c, uint8_t proto, int ip_version, int ns,
path = "/proc/net/udp6";
}
- if (*fd != -1)
- lseek(*fd, 0, SEEK_SET);
- else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0)
+ if (*fd != -1) {
+ if (lseek(*fd, 0, SEEK_SET)) {
+ warn("lseek() failed on %s: %s", path, strerror(errno));
+ return;
+ }
+ } else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0) {
return;
+ }
lineread_init(&lr, *fd);
lineread_get(&lr, &line); /* throw away header */
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 7/8] util: Check return value of lseek() while reading bound ports from procfs
2022-10-07 0:47 ` [PATCH 7/8] util: Check return value of lseek() while reading bound ports from procfs Stefano Brivio
@ 2022-10-07 6:58 ` David Gibson
0 siblings, 0 replies; 29+ messages in thread
From: David Gibson @ 2022-10-07 6:58 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 1330 bytes --]
On Fri, Oct 07, 2022 at 02:47:41AM +0200, Stefano Brivio wrote:
> Coverity now noticed we're checking most lseek() return values, but
> not this. Not really relevant, but it doesn't hurt to check we can
> actually seek before reading lines.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
Reviewed-by: David Gibson <david(a)gibson.dropbear.id.au>
> ---
> util.c | 10 +++++++---
> 1 file changed, 7 insertions(+), 3 deletions(-)
>
> diff --git a/util.c b/util.c
> index b366167..5b1e08a 100644
> --- a/util.c
> +++ b/util.c
> @@ -311,10 +311,14 @@ void procfs_scan_listen(struct ctx *c, uint8_t proto, int ip_version, int ns,
> path = "/proc/net/udp6";
> }
>
> - if (*fd != -1)
> - lseek(*fd, 0, SEEK_SET);
> - else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0)
> + if (*fd != -1) {
> + if (lseek(*fd, 0, SEEK_SET)) {
> + warn("lseek() failed on %s: %s", path, strerror(errno));
> + return;
> + }
> + } else if ((*fd = open(path, O_RDONLY | O_CLOEXEC)) < 0) {
> return;
> + }
>
> lineread_init(&lr, *fd);
> lineread_get(&lr, &line); /* throw away header */
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread
* [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup
2022-10-07 0:47 [PATCH 0/8] Add support for log file, version display, and tests Stefano Brivio
` (6 preceding siblings ...)
2022-10-07 0:47 ` [PATCH 7/8] util: Check return value of lseek() while reading bound ports from procfs Stefano Brivio
@ 2022-10-07 0:47 ` Stefano Brivio
2022-10-07 8:37 ` David Gibson
7 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 0:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 7997 bytes --]
To test log files on a tmpfs mount, we need to unshare the mount
namespace, which means using a context for the passt pane is not
really practical at the moment, as we can't open a shell there, so
we would have to encapsulate all the commands under 'unshare -rUm',
plus the "inner" pasta command, running in turn a tcp_rr server.
It might be worth fixing this by e.g. detecting we are trying to
spawn an interactive shell and adding a special path in the context
setup with some form of stdin redirection -- I'm not sure it's doable
though.
For this reason, add a new layout, using a context only for the host
pane, while keeping the old command dispatch mechanism for the passt
pane.
We also need a new setup function that doesn't start pasta: we want
to start and restart it with different options.
Further, we need a 'pint' directive, to send an interrupt to the
passt pane: add that in lib/test.
All the tests before the one involving tmpfs and a detached mount
namespace were also tested with the context mechanism. To make an
eventual conversion easier, pass tcp_crr directly as a command on
pasta's command line where feasible.
While at it, fix the comment to the teardown_pasta() function.
The new test set can be semi-conveniently run as:
./run pasta_options/log_to_file
and it checks basic log creation, size of the log file after flooding
it with debug entries, rotations, and basic consistency after
rotations, on both an existing filesystem and a tmpfs, chosen as
it doesn't support collapsing data ranges via fallocate(), hence
triggering the fall-back mechanism for logging rotation.
Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
test/lib/layout | 39 +++++++++++++++
test/lib/setup | 15 +++++-
test/lib/test | 3 ++
test/pasta_options/log_to_file | 90 ++++++++++++++++++++++++++++++++++
test/run | 4 ++
5 files changed, 150 insertions(+), 1 deletion(-)
create mode 100644 test/pasta_options/log_to_file
diff --git a/test/lib/layout b/test/lib/layout
index 79a6c80..fcd1db4 100644
--- a/test/lib/layout
+++ b/test/lib/layout
@@ -43,6 +43,45 @@ layout_host() {
sleep 1
}
+# layout_pasta_simple() - Panes for host and pasta
+layout_pasta_simple() {
+ sleep 3
+
+ tmux kill-pane -a -t 0
+ cmd_write 0 clear
+
+ tmux split-window -v -t passt_test
+ tmux split-window -h -t passt_test
+
+ PANE_PASST=0
+ PANE_HOST=1
+ PANE_INFO=2
+
+ get_info_cols
+
+ tmux send-keys -l -t ${PANE_INFO} 'while cat '"$STATEBASE/log_pipe"'; do :; done'
+ tmux send-keys -t ${PANE_INFO} -N 100 C-m
+ tmux select-pane -t ${PANE_INFO} -T "test log"
+
+ if context_exists host; then
+ pane_watch_contexts ${PANE_HOST} host host
+ else
+ tmux pipe-pane -O -t ${PANE_HOST} "cat >> ${LOGDIR}/pane_host.log"
+ tmux select-pane -t ${PANE_HOST} -T "host"
+ fi
+
+ if context_exists passt; then
+ pane_watch_contexts ${PANE_PASST} host host
+ else
+ tmux pipe-pane -O -t ${PANE_PASST} "cat >> ${LOGDIR}/pane_passt.log"
+ tmux select-pane -t ${PANE_PASST} -T "pasta"
+ fi
+
+ info_layout "single pasta instance"
+
+ sleep 1
+}
+
# layout_pasta() - Panes for host, pasta, and separate one for namespace
layout_pasta() {
sleep 3
diff --git a/test/lib/setup b/test/lib/setup
index 071e11d..e2d0ff0 100755
--- a/test/lib/setup
+++ b/test/lib/setup
@@ -106,6 +106,13 @@ setup_pasta() {
wait_for [ -f "${STATESETUP}/passt.pid" ]
}
+# setup_pasta_options() - Set up layout and host context without starting pasta
+setup_pasta_options() {
+ context_setup_host host
+
+ layout_pasta_simple
+}
+
# setup_passt_in_ns() - Set up namespace (with pasta), run qemu and passt into it
setup_passt_in_ns() {
context_setup_host host
@@ -294,7 +301,7 @@ teardown_passt() {
teardown_context_watch ${PANE_GUEST} qemu guest
}
-# teardown_passt() - Exit namespace, kill pasta process
+# teardown_pasta() - Exit namespace, kill pasta process
teardown_pasta() {
${NSHOLDER} "${STATESETUP}/ns.hold" stop
context_wait unshare
@@ -304,6 +311,12 @@ teardown_pasta() {
teardown_context_watch ${PANE_NS} unshare ns
}
+# teardown_pasta_options() - Tear down pasta and host context, no namespace
+teardown_pasta_options() {
+ teardown_context_watch ${PANE_HOST} host
+ teardown_context_watch ${PANE_PASST} passt
+}
+
# teardown_passt_in_ns() - Exit namespace, kill qemu and pasta, remove pid file
teardown_passt_in_ns() {
context_run ns kill $(cat "${STATESETUP}/qemu.pid")
diff --git a/test/lib/test b/test/lib/test
index 558d0f0..4c271a5 100755
--- a/test/lib/test
+++ b/test/lib/test
@@ -137,6 +137,9 @@ test_one_line() {
"passtw")
pane_or_context_wait passt || TEST_ONE_nok=1
;;
+ "pint")
+ tmux send-keys -t ${PANE_PASST} "C-c"
+ ;;
"pout")
__varname="${__arg%% *}"
__output="$(pane_or_context_output passt "${__arg#* }")"
diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
new file mode 100644
index 0000000..587bf8e
--- /dev/null
+++ b/test/pasta_options/log_to_file
@@ -0,0 +1,90 @@
+# SPDX-License-Identifier: AGPL-3.0-or-later
+#
+# PASST - Plug A Simple Socket Transport
+# for qemu/UNIX domain socket mode
+#
+# PASTA - Pack A Subtle Tap Abstraction
+# for network namespace/tap device mode
+#
+# test/pasta_options/log_to_file - Check log creation, rotations and consistency
+#
+# Copyright (c) 2022 Red Hat GmbH
+# Author: Stefano Brivio <sbrivio(a)redhat.com>
+
+htools wc tcp_rr tail cut tr sort
+
+def flood_log_server
+passtb tcp_crr --nolog -P 10001 -C 10002 -6
+sleep 1
+endef
+
+def flood_log_client
+host tcp_crr --nolog -P 10001 -C 10002 -6 -c -H ::1
+endef
+
+def check_log_size_mountns
+pout SIZE cat __LOG_FILE__ | wc -c
+check [ __SIZE__ -gt $((50 * 1024)) ]
+check [ __SIZE__ -lt $((100 * 1024)) ]
+endef
+
+test Log creation
+
+set PORTS -t 10001,10002 -u 10001,10002
+set LOG_FILE __STATEDIR__/pasta.log
+
+passt ./pasta -l __LOG_FILE__
+passt exit
+check [ -s __LOG_FILE__ ]
+
+test Log truncated on creation
+passt ./pasta -l __LOG_FILE__
+passt exit
+check [ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
+
+test Maximum log size
+passtb ./pasta --config-net -d -f -l __LOG_FILE__ --log-size $((100 * 1024)) -- sh -c 'while true; do tcp_crr --nolog -P 10001 -C 10002 -6; done'
+sleep 1
+
+flood_log_client
+check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
+check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
+
+flood_log_client
+check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
+check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
+
+flood_log_client
+check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
+check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
+
+pint
+
+test Timestamp consistency after rotations
+check tail -n +2 __LOG_FILE__ | cut -f1 -d' ' | tr -d [.:] | sort -c
+
+test Maximum log size on tmpfs (no FALLOC_FL_COLLAPSE_RANGE)
+passt unshare -rUm
+passt mkdir __STATEDIR__/t
+passt mount -t tmpfs none __STATEDIR__/t
+set LOG_FILE __STATEDIR__/t/log
+passt ./pasta --config-net -d -l __LOG_FILE__ --log-size $((100 * 1024))
+
+flood_log_server
+flood_log_client
+check_log_size_mountns
+
+flood_log_server
+flood_log_client
+check_log_size_mountns
+
+flood_log_server
+flood_log_client
+check_log_size_mountns
+
+test Timestamp consistency after rotations (no FALLOC_FL_COLLAPSE_RANGE)
+check tail -n +2 __LOG_FILE__ | cut -f1 -d' ' | tr -d [.:] | sort -c
+
+passt exit
+passt umount __STATEDIR__/t
+passt exit
diff --git a/test/run b/test/run
index 1ae270e..0bf79d4 100755
--- a/test/run
+++ b/test/run
@@ -80,6 +80,10 @@ run() {
test passt/shutdown
teardown pasta
+ setup pasta_options
+ test pasta_options/log_to_file
+ teardown pasta_options
+
setup passt
test passt/ndp
test passt/dhcp
--
@@ -80,6 +80,10 @@ run() {
test passt/shutdown
teardown pasta
+ setup pasta_options
+ test pasta_options/log_to_file
+ teardown pasta_options
+
setup passt
test passt/ndp
test passt/dhcp
--
2.35.1
^ permalink raw reply related [flat|nested] 29+ messages in thread* Re: [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup
2022-10-07 0:47 ` [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup Stefano Brivio
@ 2022-10-07 8:37 ` David Gibson
2022-10-07 9:47 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: David Gibson @ 2022-10-07 8:37 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 9749 bytes --]
On Fri, Oct 07, 2022 at 02:47:42AM +0200, Stefano Brivio wrote:
> To test log files on a tmpfs mount, we need to unshare the mount
> namespace, which means using a context for the passt pane is not
> really practical at the moment, as we can't open a shell there, so
> we would have to encapsulate all the commands under 'unshare -rUm',
> plus the "inner" pasta command, running in turn a tcp_rr server.
>
> It might be worth fixing this by e.g. detecting we are trying to
> spawn an interactive shell and adding a special path in the context
> setup with some form of stdin redirection -- I'm not sure it's doable
> though.
>
> For this reason, add a new layout, using a context only for the host
> pane, while keeping the old command dispatch mechanism for the passt
> pane.
Blecch. I really hate going backwards with the test mechanisms like
this. .. and I don't think you need to, though it will require a
slight rearrangement.
AIUI, you want to run basically the same tests against a logfile on
the main fs (probably ext4 or xfs) and on tmpfs. So, I'd suggest one
test file that does the core tests, with two different setup functions
for the two cases. For the normal fs test, set the passt context to
be a second host context, for the tmpfs test, set the passt context to
nsenter an unshare -rUm.
I don't think you need another context to run things within the pasta
environment, because AFAICT you can just use a fixed command for each
pasta invocation rather than a shell (see details below).
> We also need a new setup function that doesn't start pasta: we want
> to start and restart it with different options.
>
> Further, we need a 'pint' directive, to send an interrupt to the
> passt pane: add that in lib/test.
>
> All the tests before the one involving tmpfs and a detached mount
> namespace were also tested with the context mechanism. To make an
> eventual conversion easier, pass tcp_crr directly as a command on
> pasta's command line where feasible.
>
> While at it, fix the comment to the teardown_pasta() function.
>
> The new test set can be semi-conveniently run as:
>
> ./run pasta_options/log_to_file
>
> and it checks basic log creation, size of the log file after flooding
> it with debug entries, rotations, and basic consistency after
> rotations, on both an existing filesystem and a tmpfs, chosen as
> it doesn't support collapsing data ranges via fallocate(), hence
> triggering the fall-back mechanism for logging rotation.
>
> Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> ---
> test/lib/layout | 39 +++++++++++++++
> test/lib/setup | 15 +++++-
> test/lib/test | 3 ++
> test/pasta_options/log_to_file | 90 ++++++++++++++++++++++++++++++++++
> test/run | 4 ++
> 5 files changed, 150 insertions(+), 1 deletion(-)
> create mode 100644 test/pasta_options/log_to_file
>
> diff --git a/test/lib/layout b/test/lib/layout
> index 79a6c80..fcd1db4 100644
> --- a/test/lib/layout
> +++ b/test/lib/layout
> @@ -43,6 +43,45 @@ layout_host() {
> sleep 1
> }
>
> +# layout_pasta_simple() - Panes for host and pasta
> +layout_pasta_simple() {
> + sleep 3
> +
> + tmux kill-pane -a -t 0
> + cmd_write 0 clear
> +
> + tmux split-window -v -t passt_test
> + tmux split-window -h -t passt_test
> +
> + PANE_PASST=0
> + PANE_HOST=1
> + PANE_INFO=2
> +
> + get_info_cols
> +
> + tmux send-keys -l -t ${PANE_INFO} 'while cat '"$STATEBASE/log_pipe"'; do :; done'
> + tmux send-keys -t ${PANE_INFO} -N 100 C-m
> + tmux select-pane -t ${PANE_INFO} -T "test log"
> +
> + if context_exists host; then
> + pane_watch_contexts ${PANE_HOST} host host
> + else
> + tmux pipe-pane -O -t ${PANE_HOST} "cat >> ${LOGDIR}/pane_host.log"
> + tmux select-pane -t ${PANE_HOST} -T "host"
> + fi
> +
> + if context_exists passt; then
> + pane_watch_contexts ${PANE_PASST} host host
> + else
> + tmux pipe-pane -O -t ${PANE_PASST} "cat >> ${LOGDIR}/pane_passt.log"
> + tmux select-pane -t ${PANE_PASST} -T "pasta"
> + fi
> +
> + info_layout "single pasta instance"
> +
> + sleep 1
> +}
> +
> # layout_pasta() - Panes for host, pasta, and separate one for namespace
> layout_pasta() {
> sleep 3
> diff --git a/test/lib/setup b/test/lib/setup
> index 071e11d..e2d0ff0 100755
> --- a/test/lib/setup
> +++ b/test/lib/setup
> @@ -106,6 +106,13 @@ setup_pasta() {
> wait_for [ -f "${STATESETUP}/passt.pid" ]
> }
>
> +# setup_pasta_options() - Set up layout and host context without starting pasta
> +setup_pasta_options() {
> + context_setup_host host
> +
> + layout_pasta_simple
> +}
> +
> # setup_passt_in_ns() - Set up namespace (with pasta), run qemu and passt into it
> setup_passt_in_ns() {
> context_setup_host host
> @@ -294,7 +301,7 @@ teardown_passt() {
> teardown_context_watch ${PANE_GUEST} qemu guest
> }
>
> -# teardown_passt() - Exit namespace, kill pasta process
> +# teardown_pasta() - Exit namespace, kill pasta process
> teardown_pasta() {
> ${NSHOLDER} "${STATESETUP}/ns.hold" stop
> context_wait unshare
> @@ -304,6 +311,12 @@ teardown_pasta() {
> teardown_context_watch ${PANE_NS} unshare ns
> }
>
> +# teardown_pasta_options() - Tear down pasta and host context, no namespace
> +teardown_pasta_options() {
> + teardown_context_watch ${PANE_HOST} host
> + teardown_context_watch ${PANE_PASST} passt
> +}
> +
> # teardown_passt_in_ns() - Exit namespace, kill qemu and pasta, remove pid file
> teardown_passt_in_ns() {
> context_run ns kill $(cat "${STATESETUP}/qemu.pid")
> diff --git a/test/lib/test b/test/lib/test
> index 558d0f0..4c271a5 100755
> --- a/test/lib/test
> +++ b/test/lib/test
> @@ -137,6 +137,9 @@ test_one_line() {
> "passtw")
> pane_or_context_wait passt || TEST_ONE_nok=1
> ;;
> + "pint")
> + tmux send-keys -t ${PANE_PASST} "C-c"
> + ;;
> "pout")
> __varname="${__arg%% *}"
> __output="$(pane_or_context_output passt "${__arg#* }")"
> diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
> new file mode 100644
> index 0000000..587bf8e
> --- /dev/null
> +++ b/test/pasta_options/log_to_file
> @@ -0,0 +1,90 @@
> +# SPDX-License-Identifier: AGPL-3.0-or-later
> +#
> +# PASST - Plug A Simple Socket Transport
> +# for qemu/UNIX domain socket mode
> +#
> +# PASTA - Pack A Subtle Tap Abstraction
> +# for network namespace/tap device mode
> +#
> +# test/pasta_options/log_to_file - Check log creation, rotations and consistency
> +#
> +# Copyright (c) 2022 Red Hat GmbH
> +# Author: Stefano Brivio <sbrivio(a)redhat.com>
> +
> +htools wc tcp_rr tail cut tr sort
> +
> +def flood_log_server
> +passtb tcp_crr --nolog -P 10001 -C 10002 -6
> +sleep 1
> +endef
> +
> +def flood_log_client
> +host tcp_crr --nolog -P 10001 -C 10002 -6 -c -H ::1
> +endef
> +
> +def check_log_size_mountns
> +pout SIZE cat __LOG_FILE__ | wc -c
> +check [ __SIZE__ -gt $((50 * 1024)) ]
> +check [ __SIZE__ -lt $((100 * 1024)) ]
> +endef
> +
> +test Log creation
> +
> +set PORTS -t 10001,10002 -u 10001,10002
> +set LOG_FILE __STATEDIR__/pasta.log
> +
> +passt ./pasta -l __LOG_FILE__
Here you can use 'true' instead of starting a shell then exiting.
> +passt exit
> +check [ -s __LOG_FILE__ ]
> +
> +test Log truncated on creation
> +passt ./pasta -l __LOG_FILE__
> +passt exit
Same here.
> +check [ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
> +
> +test Maximum log size
> +passtb ./pasta --config-net -d -f -l __LOG_FILE__ --log-size $((100 * 1024)) -- sh -c 'while true; do tcp_crr --nolog -P 10001 -C 10002 -6; done'
Here you're already using a command.
> +sleep 1
> +
> +flood_log_client
> +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> +
> +flood_log_client
> +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> +
> +flood_log_client
> +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> +
> +pint
> +
> +test Timestamp consistency after rotations
> +check tail -n +2 __LOG_FILE__ | cut -f1 -d' ' | tr -d [.:] | sort -c
> +
> +test Maximum log size on tmpfs (no FALLOC_FL_COLLAPSE_RANGE)
> +passt unshare -rUm
> +passt mkdir __STATEDIR__/t
> +passt mount -t tmpfs none __STATEDIR__/t
> +set LOG_FILE __STATEDIR__/t/log
> +passt ./pasta --config-net -d -l __LOG_FILE__ --log-size $((100 * 1024))
Here I think you can use the same while true trick as above, rather
than starting the server repeatedly.
> +flood_log_server
> +flood_log_client
> +check_log_size_mountns
> +
> +flood_log_server
> +flood_log_client
> +check_log_size_mountns
> +
> +flood_log_server
> +flood_log_client
> +check_log_size_mountns
> +
> +test Timestamp consistency after rotations (no FALLOC_FL_COLLAPSE_RANGE)
> +check tail -n +2 __LOG_FILE__ | cut -f1 -d' ' | tr -d [.:] | sort -c
> +
> +passt exit
> +passt umount __STATEDIR__/t
> +passt exit
> diff --git a/test/run b/test/run
> index 1ae270e..0bf79d4 100755
> --- a/test/run
> +++ b/test/run
> @@ -80,6 +80,10 @@ run() {
> test passt/shutdown
> teardown pasta
>
> + setup pasta_options
> + test pasta_options/log_to_file
> + teardown pasta_options
> +
> setup passt
> test passt/ndp
> test passt/dhcp
--
David Gibson | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you. NOT _the_ _other_
| _way_ _around_!
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup
2022-10-07 8:37 ` David Gibson
@ 2022-10-07 9:47 ` Stefano Brivio
2022-10-24 21:00 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-07 9:47 UTC (permalink / raw)
To: passt-dev
[-- Attachment #1: Type: text/plain, Size: 10801 bytes --]
On Fri, 7 Oct 2022 19:37:49 +1100
David Gibson <david(a)gibson.dropbear.id.au> wrote:
> On Fri, Oct 07, 2022 at 02:47:42AM +0200, Stefano Brivio wrote:
> > To test log files on a tmpfs mount, we need to unshare the mount
> > namespace, which means using a context for the passt pane is not
> > really practical at the moment, as we can't open a shell there, so
> > we would have to encapsulate all the commands under 'unshare -rUm',
> > plus the "inner" pasta command, running in turn a tcp_rr server.
> >
> > It might be worth fixing this by e.g. detecting we are trying to
> > spawn an interactive shell and adding a special path in the context
> > setup with some form of stdin redirection -- I'm not sure it's doable
> > though.
> >
> > For this reason, add a new layout, using a context only for the host
> > pane, while keeping the old command dispatch mechanism for the passt
> > pane.
>
> Blecch. I really hate going backwards with the test mechanisms like
> this. .. and I don't think you need to, though it will require a
> slight rearrangement.
>
> AIUI, you want to run basically the same tests against a logfile on
> the main fs (probably ext4 or xfs) and on tmpfs. So, I'd suggest one
> test file that does the core tests, with two different setup functions
> for the two cases. For the normal fs test, set the passt context to
> be a second host context, for the tmpfs test, set the passt context to
> nsenter an unshare -rUm.
Sure, I can do it, but I wonder: wouldn't it be worth to eventually try
and allow spawning an interactive shell from contexts, so that I can
have a single setup function -- which looks definitely better to me,
especially given the premises of the patch enabling test selection I
just posted?
Because, if that's feasible, I would rather keep this temporary
regression, for simplicity.
> I don't think you need another context to run things within the pasta
> environment, because AFAICT you can just use a fixed command for each
> pasta invocation rather than a shell (see details below).
Of course, I tried, and:
> > We also need a new setup function that doesn't start pasta: we want
> > to start and restart it with different options.
> >
> > Further, we need a 'pint' directive, to send an interrupt to the
> > passt pane: add that in lib/test.
> >
> > All the tests before the one involving tmpfs and a detached mount
> > namespace were also tested with the context mechanism. To make an
> > eventual conversion easier, pass tcp_crr directly as a command on
> > pasta's command line where feasible.
> >
> > While at it, fix the comment to the teardown_pasta() function.
> >
> > The new test set can be semi-conveniently run as:
> >
> > ./run pasta_options/log_to_file
> >
> > and it checks basic log creation, size of the log file after flooding
> > it with debug entries, rotations, and basic consistency after
> > rotations, on both an existing filesystem and a tmpfs, chosen as
> > it doesn't support collapsing data ranges via fallocate(), hence
> > triggering the fall-back mechanism for logging rotation.
> >
> > Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
> > ---
> > test/lib/layout | 39 +++++++++++++++
> > test/lib/setup | 15 +++++-
> > test/lib/test | 3 ++
> > test/pasta_options/log_to_file | 90 ++++++++++++++++++++++++++++++++++
> > test/run | 4 ++
> > 5 files changed, 150 insertions(+), 1 deletion(-)
> > create mode 100644 test/pasta_options/log_to_file
> >
> > diff --git a/test/lib/layout b/test/lib/layout
> > index 79a6c80..fcd1db4 100644
> > --- a/test/lib/layout
> > +++ b/test/lib/layout
> > @@ -43,6 +43,45 @@ layout_host() {
> > sleep 1
> > }
> >
> > +# layout_pasta_simple() - Panes for host and pasta
> > +layout_pasta_simple() {
> > + sleep 3
> > +
> > + tmux kill-pane -a -t 0
> > + cmd_write 0 clear
> > +
> > + tmux split-window -v -t passt_test
> > + tmux split-window -h -t passt_test
> > +
> > + PANE_PASST=0
> > + PANE_HOST=1
> > + PANE_INFO=2
> > +
> > + get_info_cols
> > +
> > + tmux send-keys -l -t ${PANE_INFO} 'while cat '"$STATEBASE/log_pipe"'; do :; done'
> > + tmux send-keys -t ${PANE_INFO} -N 100 C-m
> > + tmux select-pane -t ${PANE_INFO} -T "test log"
> > +
> > + if context_exists host; then
> > + pane_watch_contexts ${PANE_HOST} host host
> > + else
> > + tmux pipe-pane -O -t ${PANE_HOST} "cat >> ${LOGDIR}/pane_host.log"
> > + tmux select-pane -t ${PANE_HOST} -T "host"
> > + fi
> > +
> > + if context_exists passt; then
> > + pane_watch_contexts ${PANE_PASST} host host
> > + else
> > + tmux pipe-pane -O -t ${PANE_PASST} "cat >> ${LOGDIR}/pane_passt.log"
> > + tmux select-pane -t ${PANE_PASST} -T "pasta"
> > + fi
> > +
> > + info_layout "single pasta instance"
> > +
> > + sleep 1
> > +}
> > +
> > # layout_pasta() - Panes for host, pasta, and separate one for namespace
> > layout_pasta() {
> > sleep 3
> > diff --git a/test/lib/setup b/test/lib/setup
> > index 071e11d..e2d0ff0 100755
> > --- a/test/lib/setup
> > +++ b/test/lib/setup
> > @@ -106,6 +106,13 @@ setup_pasta() {
> > wait_for [ -f "${STATESETUP}/passt.pid" ]
> > }
> >
> > +# setup_pasta_options() - Set up layout and host context without starting pasta
> > +setup_pasta_options() {
> > + context_setup_host host
> > +
> > + layout_pasta_simple
> > +}
> > +
> > # setup_passt_in_ns() - Set up namespace (with pasta), run qemu and passt into it
> > setup_passt_in_ns() {
> > context_setup_host host
> > @@ -294,7 +301,7 @@ teardown_passt() {
> > teardown_context_watch ${PANE_GUEST} qemu guest
> > }
> >
> > -# teardown_passt() - Exit namespace, kill pasta process
> > +# teardown_pasta() - Exit namespace, kill pasta process
> > teardown_pasta() {
> > ${NSHOLDER} "${STATESETUP}/ns.hold" stop
> > context_wait unshare
> > @@ -304,6 +311,12 @@ teardown_pasta() {
> > teardown_context_watch ${PANE_NS} unshare ns
> > }
> >
> > +# teardown_pasta_options() - Tear down pasta and host context, no namespace
> > +teardown_pasta_options() {
> > + teardown_context_watch ${PANE_HOST} host
> > + teardown_context_watch ${PANE_PASST} passt
> > +}
> > +
> > # teardown_passt_in_ns() - Exit namespace, kill qemu and pasta, remove pid file
> > teardown_passt_in_ns() {
> > context_run ns kill $(cat "${STATESETUP}/qemu.pid")
> > diff --git a/test/lib/test b/test/lib/test
> > index 558d0f0..4c271a5 100755
> > --- a/test/lib/test
> > +++ b/test/lib/test
> > @@ -137,6 +137,9 @@ test_one_line() {
> > "passtw")
> > pane_or_context_wait passt || TEST_ONE_nok=1
> > ;;
> > + "pint")
> > + tmux send-keys -t ${PANE_PASST} "C-c"
> > + ;;
> > "pout")
> > __varname="${__arg%% *}"
> > __output="$(pane_or_context_output passt "${__arg#* }")"
> > diff --git a/test/pasta_options/log_to_file b/test/pasta_options/log_to_file
> > new file mode 100644
> > index 0000000..587bf8e
> > --- /dev/null
> > +++ b/test/pasta_options/log_to_file
> > @@ -0,0 +1,90 @@
> > +# SPDX-License-Identifier: AGPL-3.0-or-later
> > +#
> > +# PASST - Plug A Simple Socket Transport
> > +# for qemu/UNIX domain socket mode
> > +#
> > +# PASTA - Pack A Subtle Tap Abstraction
> > +# for network namespace/tap device mode
> > +#
> > +# test/pasta_options/log_to_file - Check log creation, rotations and consistency
> > +#
> > +# Copyright (c) 2022 Red Hat GmbH
> > +# Author: Stefano Brivio <sbrivio(a)redhat.com>
> > +
> > +htools wc tcp_rr tail cut tr sort
> > +
> > +def flood_log_server
> > +passtb tcp_crr --nolog -P 10001 -C 10002 -6
> > +sleep 1
> > +endef
> > +
> > +def flood_log_client
> > +host tcp_crr --nolog -P 10001 -C 10002 -6 -c -H ::1
> > +endef
> > +
> > +def check_log_size_mountns
> > +pout SIZE cat __LOG_FILE__ | wc -c
> > +check [ __SIZE__ -gt $((50 * 1024)) ]
> > +check [ __SIZE__ -lt $((100 * 1024)) ]
> > +endef
> > +
> > +test Log creation
> > +
> > +set PORTS -t 10001,10002 -u 10001,10002
> > +set LOG_FILE __STATEDIR__/pasta.log
> > +
> > +passt ./pasta -l __LOG_FILE__
>
> Here you can use 'true' instead of starting a shell then exiting.
Sure. This is not even a problem actually, the shell will terminate and
I have my small log file.
> > +passt exit
> > +check [ -s __LOG_FILE__ ]
> > +
> > +test Log truncated on creation
> > +passt ./pasta -l __LOG_FILE__
> > +passt exit
>
> Same here.
Same here.
> > +check [ $(cat __LOG_FILE__ | wc -l) -eq 1 ]
> > +
> > +test Maximum log size
> > +passtb ./pasta --config-net -d -f -l __LOG_FILE__ --log-size $((100 * 1024)) -- sh -c 'while true; do tcp_crr --nolog -P 10001 -C 10002 -6; done'
>
> Here you're already using a command.
Yes, and it works with the context approach, I tested it until this
point.
> > +sleep 1
> > +
> > +flood_log_client
> > +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> > +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> > +
> > +flood_log_client
> > +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> > +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> > +
> > +flood_log_client
> > +check [ $(cat __LOG_FILE__ | wc -c) -gt $((50 * 1024)) ]
> > +check [ $(cat __LOG_FILE__ | wc -c) -lt $((100 * 1024)) ]
> > +
> > +pint
> > +
> > +test Timestamp consistency after rotations
> > +check tail -n +2 __LOG_FILE__ | cut -f1 -d' ' | tr -d [.:] | sort -c
> > +
> > +test Maximum log size on tmpfs (no FALLOC_FL_COLLAPSE_RANGE)
> > +passt unshare -rUm
> > +passt mkdir __STATEDIR__/t
> > +passt mount -t tmpfs none __STATEDIR__/t
> > +set LOG_FILE __STATEDIR__/t/log
> > +passt ./pasta --config-net -d -l __LOG_FILE__ --log-size $((100 * 1024))
>
> Here I think you can use the same while true trick as above, rather
> than starting the server repeatedly.
Not really, because I want to check the size of the log file several
times during the test, and I can't do it from outside the mount
namespace, hence this:
pout SIZE cat __LOG_FILE__ | wc -c
in check_log_size_mountns. This would be solved by a separate
setup function like the one you mentioned, though. Having a separate
context/pane to just check that looks a bit bad for usability (in terms
of showing what's going on).
So the question here is really if we can avoid having a separate setup
function, by means of adapting the context mechanism to enable
interactive shells. If we can't, fine.
But if we can, I'd leave this as a temporary hack, because it's more
usable than the alternative -- for example, I don't have to select two
separate tests for this.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread* Re: [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup
2022-10-07 9:47 ` Stefano Brivio
@ 2022-10-24 21:00 ` Stefano Brivio
2022-10-26 7:26 ` Stefano Brivio
0 siblings, 1 reply; 29+ messages in thread
From: Stefano Brivio @ 2022-10-24 21:00 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev
Hello,
On Fri, 7 Oct 2022 11:47:00 +0200
Stefano Brivio <sbrivio@redhat.com> wrote:
> But if we can, I'd leave this as a temporary hack, because it's more
> usable than the alternative -- for example, I don't have to select two
> separate tests for this.
As predictable, neither of us had the time to figure out a
comprehensive solution for this so far, and I just sent a patch that
would need one more instance of this type of test.
So... how bad is it, really, if I just go ahead and merge this, and
then add another test using the same setup function? It looks quite
clean to revert, too, the day we find a way to have a context-style
setup function that can start a usable interactive shell.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread
* Re: [PATCH 8/8] test: Add log file tests for pasta plus corresponding layout and setup
2022-10-24 21:00 ` Stefano Brivio
@ 2022-10-26 7:26 ` Stefano Brivio
0 siblings, 0 replies; 29+ messages in thread
From: Stefano Brivio @ 2022-10-26 7:26 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev
On Mon, 24 Oct 2022 23:00:31 +0200
Stefano Brivio <sbrivio@redhat.com> wrote:
> Hello,
>
> On Fri, 7 Oct 2022 11:47:00 +0200
> Stefano Brivio <sbrivio@redhat.com> wrote:
>
> > But if we can, I'd leave this as a temporary hack, because it's more
> > usable than the alternative -- for example, I don't have to select two
> > separate tests for this.
>
> As predictable, neither of us had the time to figure out a
> comprehensive solution for this so far, and I just sent a patch that
> would need one more instance of this type of test.
>
> So... how bad is it, really, if I just go ahead and merge this, and
> then add another test using the same setup function? It looks quite
> clean to revert, too, the day we find a way to have a context-style
> setup function that can start a usable interactive shell.
I just merged it. As I'm going through the bug tracker and filing a
number of items, I'll track this there as well.
--
Stefano
^ permalink raw reply [flat|nested] 29+ messages in thread