public inbox for passt-dev@passt.top
 help / color / mirror / code / Atom feed
From: Stefano Brivio <sbrivio@redhat.com>
To: passt-dev@passt.top
Subject: [PATCH 01/24] conf, util, tap: Implement --trace option for extra verbose logging
Date: Fri, 25 Mar 2022 23:52:37 +0100	[thread overview]
Message-ID: <20220325225300.2803584-2-sbrivio@redhat.com> (raw)
In-Reply-To: <20220325225300.2803584-1-sbrivio@redhat.com>

[-- Attachment #1: Type: text/plain, Size: 8880 bytes --]

--debug can be a bit too noisy, especially as single packets or
socket messages are logged: implement a new option, --trace,
implying --debug, that enables all debug messages.

Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>
---
 conf.c         | 15 +++++++++++++++
 passt.1        |  5 +++++
 passt.c        |  3 ++-
 passt.h        |  2 ++
 tap.c          |  4 ++--
 test/README.md |  6 +++++-
 test/lib/setup | 10 ++++++++++
 util.c         |  6 ++++++
 util.h         |  8 ++++++++
 9 files changed, 55 insertions(+), 4 deletions(-)

diff --git a/conf.c b/conf.c
index 08f24be..5170163 100644
--- a/conf.c
+++ b/conf.c
@@ -558,6 +558,7 @@ static void usage(const char *name)
 	info("");
 
 	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");
 	info(   "  -f, --foreground	Don't run in background");
 	info(   "    default: run in background if started from a TTY");
@@ -829,6 +830,7 @@ void conf(struct ctx *c, int argc, char **argv)
 		{"no-dhcp-search", no_argument,		NULL,		8 },
 		{"dns-forward",	required_argument,	NULL,		9 },
 		{"no-netns-quit", no_argument,		NULL,		10 },
+		{"trace",	no_argument,		NULL,		11 },
 		{ 0 },
 	};
 	struct get_bound_ports_ns_arg ns_ports_arg = { .c = c };
@@ -960,6 +962,19 @@ void conf(struct ctx *c, int argc, char **argv)
 			}
 			c->no_netns_quit = 1;
 			break;
+		case 11:
+			if (c->trace) {
+				err("Multiple --trace options given");
+				usage(argv[0]);
+			}
+
+			if (c->quiet) {
+				err("Either --trace or --quiet");
+				usage(argv[0]);
+			}
+
+			c->trace = c->debug = c->foreground = 1;
+			break;
 		case 'd':
 			if (c->debug) {
 				err("Multiple --debug options given");
diff --git a/passt.1 b/passt.1
index 57cf745..0252fbb 100644
--- a/passt.1
+++ b/passt.1
@@ -74,6 +74,11 @@ for performance reasons.
 .BR \-d ", " \-\-debug
 Be verbose, don't run in background.
 
+.TP
+.BR \-\-trace
+Be extra verbose, show single packets, don't run in background. Implies
+\fB--debug\fR.
+
 .TP
 .BR \-q ", " \-\-quiet
 Don't print informational messages.
diff --git a/passt.c b/passt.c
index 40d3e57..5cd8f3b 100644
--- a/passt.c
+++ b/passt.c
@@ -96,7 +96,7 @@ char *ip_proto_str[IPPROTO_SCTP + 1] = {
 static void sock_handler(struct ctx *c, union epoll_ref ref, uint32_t events,
 			 struct timespec *now)
 {
-	debug("%s: %s packet from socket %i (events: 0x%08x)",
+	trace("%s: %s packet from socket %i (events: 0x%08x)",
 	      c->mode == MODE_PASST ? "passt" : "pasta",
 	      IP_PROTO_STR(ref.r.proto), ref.r.s, events);
 
@@ -351,6 +351,7 @@ int main(int argc, char **argv)
 	__setlogmask(LOG_MASK(LOG_EMERG));
 
 	conf(&c, argc, argv);
+	trace_init(c.trace);
 
 	if (!c.debug && (c.stderr || isatty(fileno(stdout))))
 		__openlog(log_name, LOG_PERROR, LOG_DAEMON);
diff --git a/passt.h b/passt.h
index 042f760..8344fca 100644
--- a/passt.h
+++ b/passt.h
@@ -92,6 +92,7 @@ enum passt_modes {
  * struct ctx - Execution context
  * @mode:		Operation mode, qemu/UNIX domain socket or namespace/tap
  * @debug:		Enable debug mode
+ * @trace:		Enable tracing (extra debug) mode
  * @quiet:		Don't print informational messages
  * @foreground:		Run in foreground, don't log to stderr by default
  * @stderr:		Force logging to stderr
@@ -153,6 +154,7 @@ enum passt_modes {
 struct ctx {
 	enum passt_modes mode;
 	int debug;
+	int trace;
 	int quiet;
 	int foreground;
 	int stderr;
diff --git a/tap.c b/tap.c
index 29fcd51..e1854fb 100644
--- a/tap.c
+++ b/tap.c
@@ -283,14 +283,14 @@ static void tap_packet_debug(struct iphdr *iph, struct ipv6hdr *ip6h,
 	}
 
 	if (proto == IPPROTO_TCP || proto == IPPROTO_UDP) {
-		debug("protocol %i from tap: %s:%i -> %s:%i (%i packet%s)",
+		trace("protocol %i from tap: %s:%i -> %s:%i (%i packet%s)",
 		      proto, seq4 ? buf4s : buf6s,
 		      ntohs(seq4 ? seq4->source : seq6->source),
 		      seq4 ? buf4d : buf6d,
 		      ntohs(seq4 ? seq4->dest : seq6->dest),
 		      count, count == 1 ? "" : "s");
 	} else {
-		debug("protocol %i from tap: %s -> %s (%i packet%s)",
+		trace("protocol %i from tap: %s -> %s (%i packet%s)",
 		      proto, iph ? buf4s : buf6s, iph ? buf4d : buf6d,
 		      count, count == 1 ? "" : "s");
 	}
diff --git a/test/README.md b/test/README.md
index 88270e8..cdf233b 100644
--- a/test/README.md
+++ b/test/README.md
@@ -63,7 +63,11 @@ Just issue:
 
     ./run
 
-from the `test` directory. Elevated privileges are not needed.
+from the `test` directory. Elevated privileges are not needed. Environment
+variable settings: DEBUG=1 enables debugging messages, TRACE=1 enables tracing
+(further debugging messages), PCAP=1 enables packet captures. Example:
+
+    PCAP=1 TRACE=1 ./run
 
 ## Continuous integration
 
diff --git a/test/lib/setup b/test/lib/setup
index f04949e..a39eb80 100755
--- a/test/lib/setup
+++ b/test/lib/setup
@@ -49,6 +49,8 @@ setup_passt() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/passt.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
+
 	pane_run PASST "./passt ${__opts} -f -t 10001 -u 10001"
 	sleep 1
 
@@ -90,6 +92,7 @@ setup_pasta() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/pasta.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 
 	pane_run PASST "./pasta ${__opts} -f -t 10002 -T 10003 -u 10002 -U 10003 ${__target_pid}"
 	sleep 1
@@ -118,6 +121,7 @@ setup_passt_in_ns() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/pasta_with_passt.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 
 	__pid_file="$(mktemp)"
 	pane_run PASST "./pasta ${__opts} -t 10001,10002,10011,10012 -T 10003,10013 -u 10001,10002,10011,10012 -U 10003,10013 -P ${__pid_file}"
@@ -145,6 +149,7 @@ setup_passt_in_ns() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/passt_in_pasta.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 
 	#pane_run PASST "valgrind --max-stackframe=3000000 ./passt -f ${__opts} -t 10001,10011,10021,10031 -u 10001,10011,10021,10031"
 	pane_run PASST "./passt -f ${__opts} -t 10001,10011,10021,10031 -u 10001,10011,10021,10031"
@@ -183,11 +188,13 @@ setup_two_guests() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/pasta_1.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 	pane_run PASST_1 "./pasta ${__opts} -P ${__pid1_file} -t 10001,10002 -T 10003,10004 -u 10001,10002 -U 10003,10004"
 
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/pasta_2.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 	pane_run PASST_2 "./pasta ${__opts} -P ${__pid2_file} -t 10004,10005 -T 10003,10001 -u 10004,10005 -U 10003,10001"
 
 	sleep 1
@@ -223,12 +230,15 @@ setup_two_guests() {
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/passt_1.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
+
 	pane_run PASST_1 "./passt -f ${__opts} -t 10001 -u 10001"
 	sleep 1
 
 	__opts=
 	[ ${PCAP} -eq 1 ] && __opts="${__opts} -p /tmp/passt_2.pcap"
 	[ ${DEBUG} -eq 1 ] && __opts="${__opts} -d"
+	[ ${TRACE} -eq 1 ] && __opts="${__opts} --trace"
 	pane_run PASST_2 "./passt -f ${__opts} -t 10004 -u 10004"
 
 	pane_run GUEST_2 'cp mbuto.img mbuto_2.img'
diff --git a/util.c b/util.c
index 90b5ab8..50b83db 100644
--- a/util.c
+++ b/util.c
@@ -45,6 +45,7 @@ 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, ...) {					\
@@ -77,6 +78,11 @@ 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)
diff --git a/util.h b/util.h
index b7852e9..bfab221 100644
--- a/util.h
+++ b/util.h
@@ -8,6 +8,14 @@ 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
-- 
@@ -8,6 +8,14 @@ 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
-- 
2.35.1


  reply	other threads:[~2022-03-25 22:52 UTC|newest]

Thread overview: 25+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2022-03-25 22:52 [PATCH 00/24] Boundary-checked "packets", TCP timerfd timeouts, assorted fixes Stefano Brivio
2022-03-25 22:52 ` Stefano Brivio [this message]
2022-03-25 22:52 ` [PATCH 02/24] pcap: Fix mistake in printed string Stefano Brivio
2022-03-25 22:52 ` [PATCH 03/24] util: Drop CHECK_SET_MIN_MAX{,_PROTO_FD} macros Stefano Brivio
2022-03-25 22:52 ` [PATCH 04/24] util: Use standard int types Stefano Brivio
2022-03-25 22:52 ` [PATCH 05/24] tcp: Refactor to use events instead of states, split out spliced implementation Stefano Brivio
2022-03-25 22:52 ` [PATCH 06/24] test/lib/video: Fill in href attributes of video shortcuts Stefano Brivio
2022-03-25 22:52 ` [PATCH 07/24] udp: Drop _splice from recv, send, sendto static buffer names Stefano Brivio
2022-03-25 22:52 ` [PATCH 08/24] udp: Split buffer queueing/writing parts of udp_sock_handler() Stefano Brivio
2022-03-25 22:52 ` [PATCH 09/24] dhcpv6, tap, tcp: Use IN6_ARE_ADDR_EQUAL instead of open-coded memcmp() Stefano Brivio
2022-03-25 22:52 ` [PATCH 10/24] udp: Use flags for local, loopback, and configured unicast binds Stefano Brivio
2022-03-25 22:52 ` [PATCH 11/24] Makefile: Enable a few hardening flags Stefano Brivio
2022-03-25 22:52 ` [PATCH 12/24] test: Add asciinema(1) as requirement for CI in README Stefano Brivio
2022-03-25 22:52 ` [PATCH 13/24] test, seccomp, Makefile: Switch to valgrind runs for passt functional tests Stefano Brivio
2022-03-25 22:52 ` [PATCH 14/24] tcp, udp, util: Enforce 24-bit limit on socket numbers Stefano Brivio
2022-03-25 22:52 ` [PATCH 15/24] tcp: Rework timers to use timerfd instead of periodic bitmap scan Stefano Brivio
2022-03-25 22:52 ` [PATCH 16/24] tcp_splice: Close sockets right away on high number of open files Stefano Brivio
2022-03-25 22:52 ` [PATCH 17/24] test/perf: Work-around for virtio_net hang before long streams from guest Stefano Brivio
2022-03-25 22:52 ` [PATCH 18/24] README: Avoid "here" links Stefano Brivio
2022-03-25 22:52 ` [PATCH 19/24] README: Update Interfaces and Availability sections Stefano Brivio
2022-03-25 22:52 ` [PATCH 20/24] tcp: Fit struct tcp_conn into a single 64-byte cacheline Stefano Brivio
2022-03-25 22:52 ` [PATCH 21/24] dhcp: Minimum option length implied by RFC 951 is 60 bytes, not 62 Stefano Brivio
2022-03-25 22:52 ` [PATCH 22/24] tcp, tcp_splice: Use less awkward syntax to swap in/out sockets from pools Stefano Brivio
2022-03-25 22:52 ` [PATCH 23/24] util: Fix function declaration style of write_pidfile() Stefano Brivio
2022-03-25 22:53 ` [PATCH 24/24] treewide: Packet abstraction with mandatory boundary checks Stefano Brivio

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20220325225300.2803584-2-sbrivio@redhat.com \
    --to=sbrivio@redhat.com \
    --cc=passt-dev@passt.top \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
Code repositories for project(s) associated with this public inbox

	https://passt.top/passt

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for IMAP folder(s).