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 &lt;sbrivio(a)redhat.com&gt;
 + */
 +
 +#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

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

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

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

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 &lt;sbrivio(a)redhat.com&gt;
   */
  
 +#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

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 &lt;sbrivio(a)redhat.com&gt;
   */
  
 +#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

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

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

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

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

On Mon, 24 Oct 2022 23:00:31 +0200
Stefano Brivio <sbrivio(a)redhat.com> wrote:

...
  Hello,
 
 On Fri, 7 Oct 2022 11:47:00 +0200
 Stefano Brivio <sbrivio(a)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