* [PATCH 0/6] Fixes for early logging/prints and related cleanups
@ 2024-06-17 12:03 Stefano Brivio
2024-06-17 12:03 ` [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it Stefano Brivio
` (5 more replies)
0 siblings, 6 replies; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
The most apparent issue fixed by this series is the one from 3/6: with
a log file configured, we wouldn't print to standard error anymore,
during initialisation, which means that users such as libvirt lost
the ability to report meaningful error messages that occurred during
initialisation, in that case.
Stefano Brivio (6):
conf, passt: Don't try to log to stderr after we close it
conf, log: Introduce internal log flags, instead of abusing log levels
log, passt: Always print to stderr before initialisation is complete
log: Add _perror() logging function variants
treewide: Replace perror() calls with calls to logging functions
treewide: Replace strerror() calls
arch.c | 10 ++++----
conf.c | 45 ++++++++++++++++++----------------
fwd.c | 2 +-
isolation.c | 46 +++++++++++++++--------------------
log.c | 57 +++++++++++++++++++++++++++++++------------
log.h | 26 +++++++++++++++++---
netlink.c | 4 +--
passt.1 | 3 ++-
passt.c | 70 +++++++++++++++++++++++------------------------------
pasta.c | 41 +++++++++++++++----------------
pcap.c | 8 +++---
tap.c | 14 +++++------
tcp.c | 24 ++++++------------
util.c | 12 ++++-----
14 files changed, 189 insertions(+), 173 deletions(-)
--
2.43.0
^ permalink raw reply [flat|nested] 27+ messages in thread
* [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:36 ` David Gibson
2024-06-17 12:03 ` [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels Stefano Brivio
` (4 subsequent siblings)
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
If we don't run in foreground, we close standard error as we
daemonise, so it makes no sense to check if the controlling terminal
is an interactive terminal or if --force-stderr was given, to decide
if we want to log to standard error.
Make --force-stderr depend on --foreground.
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
conf.c | 3 +++
passt.c | 2 +-
2 files changed, 4 insertions(+), 1 deletion(-)
diff --git a/conf.c b/conf.c
index 94b3ed6..dbdbb62 100644
--- a/conf.c
+++ b/conf.c
@@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
conf_ugid(runas, &uid, &gid);
+ if (!c->foreground && c->force_stderr)
+ die("Can't log to standard error if not running in foreground");
+
if (logfile) {
logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
logfile, logsize);
diff --git a/passt.c b/passt.c
index a5e2c5a..aa9648a 100644
--- a/passt.c
+++ b/passt.c
@@ -302,7 +302,7 @@ int main(int argc, char **argv)
if (isolate_prefork(&c))
die("Failed to sandbox process, exiting");
- if (!c.force_stderr && !isatty(fileno(stderr)))
+ if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
__openlog(log_name, 0, LOG_DAEMON);
if (!c.foreground)
--
@@ -302,7 +302,7 @@ int main(int argc, char **argv)
if (isolate_prefork(&c))
die("Failed to sandbox process, exiting");
- if (!c.force_stderr && !isatty(fileno(stderr)))
+ if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
__openlog(log_name, 0, LOG_DAEMON);
if (!c.foreground)
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
2024-06-17 12:03 ` [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:39 ` David Gibson
2024-06-17 12:03 ` [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete Stefano Brivio
` (3 subsequent siblings)
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
We currently use a LOG_EMERG log mask to represent the fact that we
don't know yet what the mask resulting from configuration should be,
before the command line is parsed.
However, we have the necessity of representing another phase as well,
that is, configuration is parsed but we didn't daemonise yet, or
we're not ready for operation yet. The next patch will add that
notion explicitly.
Mapping these cases to further log levels isn't really practical.
Introduce internal log flags to represent them, instead of abusing
log priorities.
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
conf.c | 5 ++---
log.c | 18 +++++++++++++-----
log.h | 4 ++++
3 files changed, 19 insertions(+), 8 deletions(-)
diff --git a/conf.c b/conf.c
index dbdbb62..0b76da9 100644
--- a/conf.c
+++ b/conf.c
@@ -1701,9 +1701,6 @@ void conf(struct ctx *c, int argc, char **argv)
logfile, logsize);
}
- /* Once the log mask is not LOG_EARLY, we will no longer log to stderr
- * if there was a log file specified.
- */
if (c->debug)
__setlogmask(LOG_UPTO(LOG_DEBUG));
else if (c->quiet)
@@ -1711,6 +1708,8 @@ void conf(struct ctx *c, int argc, char **argv)
else
__setlogmask(LOG_UPTO(LOG_INFO));
+ log_set_flag(LOG_FLAG_CONF_PARSED); /* Stop printing everything */
+
nl_sock_init(c, false);
if (!v6_only)
c->ifi4 = conf_ip4(ifi4, &c->ip4, c->mac);
diff --git a/log.c b/log.c
index aaf2beb..3b5a1c6 100644
--- a/log.c
+++ b/log.c
@@ -30,14 +30,13 @@
#include "util.h"
#include "passt.h"
-/* LOG_EARLY means we don't know yet: log everything. LOG_EMERG is unused */
-#define LOG_EARLY LOG_MASK(LOG_EMERG)
-
static int log_sock = -1; /* Optional socket to system logger */
static char log_ident[BUFSIZ]; /* Identifier string for openlog() */
-static int log_mask = LOG_EARLY; /* Current log priority mask */
+static int log_mask; /* Current log priority mask */
static int log_opt; /* Options for openlog() */
+static uint8_t log_flags; /* Internal, see LOG_FLAG_* in log.h */
+
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 */
@@ -50,7 +49,7 @@ int log_trace; /* --trace mode enabled */
void vlogmsg(int pri, const char *format, va_list ap)
{
bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
- bool early_print = LOG_PRI(log_mask) == LOG_EARLY;
+ bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
struct timespec tp;
if (debug_print) {
@@ -150,6 +149,15 @@ void __setlogmask(int mask)
setlogmask(mask);
}
+/**
+ * log_set_flag() - Set an internal log flag
+ * @flag: Flag as defined by LOG_FLAG_* in log.h
+ */
+void log_set_flag(uint8_t flag)
+{
+ log_flags |= flag;
+}
+
/**
* passt_vsyslog() - vsyslog() implementation not using heap memory
* @pri: Facility and level map, same as priority for vsyslog()
diff --git a/log.h b/log.h
index e0aab5a..6a3224a 100644
--- a/log.h
+++ b/log.h
@@ -6,8 +6,11 @@
#ifndef LOG_H
#define LOG_H
+#include <stdint.h>
#include <syslog.h>
+#define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
+
#define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
@@ -40,5 +43,6 @@ 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);
+void log_set_flag(uint8_t flag);
#endif /* LOG_H */
--
@@ -6,8 +6,11 @@
#ifndef LOG_H
#define LOG_H
+#include <stdint.h>
#include <syslog.h>
+#define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
+
#define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
@@ -40,5 +43,6 @@ 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);
+void log_set_flag(uint8_t flag);
#endif /* LOG_H */
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
2024-06-17 12:03 ` [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it Stefano Brivio
2024-06-17 12:03 ` [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:44 ` David Gibson
2024-06-17 12:03 ` [PATCH 4/6] log: Add _perror() logging function variants Stefano Brivio
` (2 subsequent siblings)
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
After commit 15001b39ef1d ("conf: set the log level much earlier"), we
had a phase during initialisation when messages wouldn't be printed to
standard error anymore.
Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
stderr until we detach") fixed that, but only for the case where no
log files are given.
If a log file is configured, vlogmsg() will not call passt_vsyslog(),
but during initialisation, LOG_PERROR is set, so to avoid duplicated
prints (which would result from passt_vsyslog() printing to stderr),
we don't call fprintf() from vlogmsg() either.
This is getting a bit too complicated. Instead of abusing LOG_PERROR,
define an internal logging flag that clearly represents that we're not
done with the initialisation phase yet.
If this flag is not set, make sure we always print to stderr, if the
log mask matches. Then, set LOG_PERROR only as we set this internal
flag, to make sure we don't duplicate messages.
Reported-by: Yalan Zhang <yalzhang@redhat.com>
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
log.c | 4 +++-
log.h | 1 +
passt.1 | 3 ++-
passt.c | 17 ++++++++++-------
4 files changed, 16 insertions(+), 9 deletions(-)
diff --git a/log.c b/log.c
index 3b5a1c6..939bb93 100644
--- a/log.c
+++ b/log.c
@@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
void vlogmsg(int pri, const char *format, va_list ap)
{
bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
+ bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
struct timespec tp;
@@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
va_end(ap2);
}
- if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
+ if (debug_print || early_print ||
+ (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
(void)vfprintf(stderr, format, ap);
if (format[strlen(format)] != '\n')
fprintf(stderr, "\n");
diff --git a/log.h b/log.h
index 6a3224a..680baab 100644
--- a/log.h
+++ b/log.h
@@ -10,6 +10,7 @@
#include <syslog.h>
#define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
+#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
#define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
diff --git a/passt.1 b/passt.1
index 3a23a43..31e528e 100644
--- a/passt.1
+++ b/passt.1
@@ -99,7 +99,8 @@ 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.
+Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
+and not to the system logger.
.TP
.BR \-\-log-size " " \fISIZE\fR
diff --git a/passt.c b/passt.c
index aa9648a..fa86164 100644
--- a/passt.c
+++ b/passt.c
@@ -225,7 +225,7 @@ int main(int argc, char **argv)
strncpy(argv0, argv[0], PATH_MAX - 1);
name = basename(argv0);
if (strstr(name, "pasta")) {
- __openlog(log_name = "pasta", LOG_PERROR, LOG_DAEMON);
+ __openlog(log_name = "pasta", 0, LOG_DAEMON);
sa.sa_handler = pasta_child_handler;
if (sigaction(SIGCHLD, &sa, NULL)) {
@@ -240,7 +240,7 @@ int main(int argc, char **argv)
c.mode = MODE_PASTA;
} else if (strstr(name, "passt")) {
- __openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
+ __openlog(log_name = "passt", 0, LOG_DAEMON);
c.mode = MODE_PASST;
} else {
@@ -302,13 +302,16 @@ int main(int argc, char **argv)
if (isolate_prefork(&c))
die("Failed to sandbox process, exiting");
- if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
- __openlog(log_name, 0, LOG_DAEMON);
-
- if (!c.foreground)
+ if (!c.foreground) {
__daemon(c.pidfile_fd, devnull_fd);
- else
+ } else {
+ if (c.force_stderr || isatty(fileno(stderr)))
+ __openlog(log_name, LOG_PERROR, LOG_DAEMON);
+
pidfile_write(c.pidfile_fd, getpid());
+ }
+
+ log_set_flag(LOG_FLAG_DAEMON_READY);
if (pasta_child_pid)
kill(pasta_child_pid, SIGUSR1);
--
@@ -225,7 +225,7 @@ int main(int argc, char **argv)
strncpy(argv0, argv[0], PATH_MAX - 1);
name = basename(argv0);
if (strstr(name, "pasta")) {
- __openlog(log_name = "pasta", LOG_PERROR, LOG_DAEMON);
+ __openlog(log_name = "pasta", 0, LOG_DAEMON);
sa.sa_handler = pasta_child_handler;
if (sigaction(SIGCHLD, &sa, NULL)) {
@@ -240,7 +240,7 @@ int main(int argc, char **argv)
c.mode = MODE_PASTA;
} else if (strstr(name, "passt")) {
- __openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
+ __openlog(log_name = "passt", 0, LOG_DAEMON);
c.mode = MODE_PASST;
} else {
@@ -302,13 +302,16 @@ int main(int argc, char **argv)
if (isolate_prefork(&c))
die("Failed to sandbox process, exiting");
- if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
- __openlog(log_name, 0, LOG_DAEMON);
-
- if (!c.foreground)
+ if (!c.foreground) {
__daemon(c.pidfile_fd, devnull_fd);
- else
+ } else {
+ if (c.force_stderr || isatty(fileno(stderr)))
+ __openlog(log_name, LOG_PERROR, LOG_DAEMON);
+
pidfile_write(c.pidfile_fd, getpid());
+ }
+
+ log_set_flag(LOG_FLAG_DAEMON_READY);
if (pasta_child_pid)
kill(pasta_child_pid, SIGUSR1);
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* [PATCH 4/6] log: Add _perror() logging function variants
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
` (2 preceding siblings ...)
2024-06-17 12:03 ` [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:46 ` David Gibson
2024-06-17 12:03 ` [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions Stefano Brivio
2024-06-17 12:03 ` [PATCH 6/6] treewide: Replace strerror() calls Stefano Brivio
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
In many places, we have direct perror() calls, which completely bypass
logging functions and log files.
They are definitely convenient: offer similar convenience with
_perror() logging variants, so that we can drop those direct perror()
calls.
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
log.c | 21 +++++++++++++++++++++
log.h | 21 +++++++++++++++++----
2 files changed, 38 insertions(+), 4 deletions(-)
diff --git a/log.c b/log.c
index 939bb93..6764b2b 100644
--- a/log.c
+++ b/log.c
@@ -80,6 +80,11 @@ void vlogmsg(int pri, const char *format, va_list ap)
}
}
+/**
+ * logmsg() - vlogmsg() wrapper for variable argument lists
+ * @pri: Facility and level map, same as priority for vsyslog()
+ * @format: Message
+ */
void logmsg(int pri, const char *format, ...)
{
va_list ap;
@@ -89,6 +94,22 @@ void logmsg(int pri, const char *format, ...)
va_end(ap);
}
+/**
+ * logmsg_perror() - vlogmsg() wrapper with perror()-like functionality
+ * @pri: Facility and level map, same as priority for vsyslog()
+ * @format: Message
+ */
+void logmsg_perror(int pri, const char *format, ...)
+{
+ va_list ap;
+
+ logmsg(pri, "%s: ", strerror(errno));
+
+ va_start(ap, format);
+ vlogmsg(pri, format, ap);
+ va_end(ap);
+}
+
/* Prefixes for log file messages, indexed by priority */
const char *logfile_prefix[] = {
NULL, NULL, NULL, /* Unused: LOG_EMERG, LOG_ALERT, LOG_CRIT */
diff --git a/log.h b/log.h
index 680baab..5be0be9 100644
--- a/log.h
+++ b/log.h
@@ -19,11 +19,18 @@
void vlogmsg(int pri, const char *format, va_list ap);
void logmsg(int pri, const char *format, ...)
__attribute__((format(printf, 2, 3)));
+void logmsg_perror(int pri, const char *format, ...)
+ __attribute__((format(printf, 2, 3)));
+
+#define err(...) logmsg( LOG_ERR, __VA_ARGS__)
+#define warn(...) logmsg( LOG_WARNING, __VA_ARGS__)
+#define info(...) logmsg( LOG_INFO, __VA_ARGS__)
+#define debug(...) logmsg( LOG_DEBUG, __VA_ARGS__)
-#define err(...) logmsg(LOG_ERR, __VA_ARGS__)
-#define warn(...) logmsg(LOG_WARNING, __VA_ARGS__)
-#define info(...) logmsg(LOG_INFO, __VA_ARGS__)
-#define debug(...) logmsg(LOG_DEBUG, __VA_ARGS__)
+#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
+#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
+#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
+#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
#define die(...) \
do { \
@@ -31,6 +38,12 @@ void logmsg(int pri, const char *format, ...)
exit(EXIT_FAILURE); \
} while (0)
+#define die_perror(...) \
+ do { \
+ err_perror(__VA_ARGS__); \
+ exit(EXIT_FAILURE); \
+ } while (0)
+
extern int log_trace;
void trace_init(int enable);
#define trace(...) \
--
@@ -19,11 +19,18 @@
void vlogmsg(int pri, const char *format, va_list ap);
void logmsg(int pri, const char *format, ...)
__attribute__((format(printf, 2, 3)));
+void logmsg_perror(int pri, const char *format, ...)
+ __attribute__((format(printf, 2, 3)));
+
+#define err(...) logmsg( LOG_ERR, __VA_ARGS__)
+#define warn(...) logmsg( LOG_WARNING, __VA_ARGS__)
+#define info(...) logmsg( LOG_INFO, __VA_ARGS__)
+#define debug(...) logmsg( LOG_DEBUG, __VA_ARGS__)
-#define err(...) logmsg(LOG_ERR, __VA_ARGS__)
-#define warn(...) logmsg(LOG_WARNING, __VA_ARGS__)
-#define info(...) logmsg(LOG_INFO, __VA_ARGS__)
-#define debug(...) logmsg(LOG_DEBUG, __VA_ARGS__)
+#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
+#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
+#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
+#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
#define die(...) \
do { \
@@ -31,6 +38,12 @@ void logmsg(int pri, const char *format, ...)
exit(EXIT_FAILURE); \
} while (0)
+#define die_perror(...) \
+ do { \
+ err_perror(__VA_ARGS__); \
+ exit(EXIT_FAILURE); \
+ } while (0)
+
extern int log_trace;
void trace_init(int enable);
#define trace(...) \
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
` (3 preceding siblings ...)
2024-06-17 12:03 ` [PATCH 4/6] log: Add _perror() logging function variants Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:50 ` David Gibson
2024-06-17 12:03 ` [PATCH 6/6] treewide: Replace strerror() calls Stefano Brivio
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
perror() prints directly to standard error, but in many cases standard
error might be already closed, or we might want to skip logging, based
on configuration. Our logging functions provide all that.
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
arch.c | 10 +++++-----
conf.c | 6 ++----
isolation.c | 18 ++++++++----------
log.c | 12 ++++--------
passt.c | 41 ++++++++++++++++-------------------------
pasta.c | 9 +++------
6 files changed, 38 insertions(+), 58 deletions(-)
diff --git a/arch.c b/arch.c
index 80a41bc..41bea01 100644
--- a/arch.c
+++ b/arch.c
@@ -18,6 +18,8 @@
#include <string.h>
#include <unistd.h>
+#include "log.h"
+
/**
* arch_avx2_exec() - Switch to AVX2 build if supported
* @argv: Arguments from command line
@@ -28,10 +30,8 @@ void arch_avx2_exec(char **argv)
char exe[PATH_MAX] = { 0 };
const char *p;
- if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0) {
- perror("readlink /proc/self/exe");
- exit(EXIT_FAILURE);
- }
+ if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0)
+ die_perror("readlink /proc/self/exe");
p = strstr(exe, ".avx2");
if (p && strlen(p) == strlen(".avx2"))
@@ -42,7 +42,7 @@ void arch_avx2_exec(char **argv)
snprintf(new_path, PATH_MAX + sizeof(".avx2"), "%s.avx2", exe);
execve(new_path, argv, environ);
- perror("Can't run AVX2 build, using non-AVX2 version");
+ warn_perror("Can't run AVX2 build, using non-AVX2 version");
}
}
#else
diff --git a/conf.c b/conf.c
index 0b76da9..7042f92 100644
--- a/conf.c
+++ b/conf.c
@@ -1098,10 +1098,8 @@ static void conf_ugid(char *runas, uid_t *uid, gid_t *gid)
const struct passwd *pw;
/* cppcheck-suppress getpwnamCalled */
pw = getpwnam("nobody");
- if (!pw) {
- perror("getpwnam");
- exit(EXIT_FAILURE);
- }
+ if (!pw)
+ die_perror("getpwnam");
*uid = pw->pw_uid;
*gid = pw->pw_gid;
diff --git a/isolation.c b/isolation.c
index ca2c68b..871bbac 100644
--- a/isolation.c
+++ b/isolation.c
@@ -316,34 +316,34 @@ int isolate_prefork(const struct ctx *c)
flags |= CLONE_NEWPID;
if (unshare(flags)) {
- perror("unshare");
+ err_perror("unshare");
return -errno;
}
if (mount("", "/", "", MS_UNBINDABLE | MS_REC, NULL)) {
- perror("mount /");
+ err_perror("mount /");
return -errno;
}
if (mount("", TMPDIR, "tmpfs",
MS_NODEV | MS_NOEXEC | MS_NOSUID | MS_RDONLY,
"nr_inodes=2,nr_blocks=0")) {
- perror("mount tmpfs");
+ err_perror("mount tmpfs");
return -errno;
}
if (chdir(TMPDIR)) {
- perror("chdir");
+ err_perror("chdir");
return -errno;
}
if (syscall(SYS_pivot_root, ".", ".")) {
- perror("pivot_root");
+ err_perror("pivot_root");
return -errno;
}
if (umount2(".", MNT_DETACH | UMOUNT_NOFOLLOW)) {
- perror("umount2");
+ err_perror("umount2");
return -errno;
}
@@ -388,8 +388,6 @@ void isolate_postfork(const struct ctx *c)
}
if (prctl(PR_SET_NO_NEW_PRIVS, 1, 0, 0, 0) ||
- prctl(PR_SET_SECCOMP, SECCOMP_MODE_FILTER, &prog)) {
- perror("prctl");
- exit(EXIT_FAILURE);
- }
+ prctl(PR_SET_SECCOMP, SECCOMP_MODE_FILTER, &prog))
+ die_perror("prctl");
}
diff --git a/log.c b/log.c
index 6764b2b..4aa800d 100644
--- a/log.c
+++ b/log.c
@@ -218,10 +218,8 @@ 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);
- }
+ if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0)
+ die_perror("readlink /proc/self/exe");
log_file = open(path, O_CREAT | O_TRUNC | O_APPEND | O_RDWR | O_CLOEXEC,
S_IRUSR | S_IWUSR);
@@ -234,10 +232,8 @@ void logfile_init(const char *name, const char *path, size_t size)
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);
- }
+ write(log_file, &nl, 1) <= 0)
+ die_perror("Couldn't write to log file\n");
/* 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);
diff --git a/passt.c b/passt.c
index fa86164..4bc4251 100644
--- a/passt.c
+++ b/passt.c
@@ -136,14 +136,13 @@ static void secret_init(struct ctx *c)
}
if (dev_random >= 0)
close(dev_random);
- if (random_read < sizeof(c->hash_secret)) {
+
+ if (random_read < sizeof(c->hash_secret))
#else
if (getrandom(&c->hash_secret, sizeof(c->hash_secret),
- GRND_RANDOM) < 0) {
+ GRND_RANDOM) < 0)
#endif /* !HAS_GETRANDOM */
- perror("TCP initial sequence getrandom");
- exit(EXIT_FAILURE);
- }
+ die_perror("TCP initial sequence getrandom");
}
/**
@@ -250,20 +249,16 @@ int main(int argc, char **argv)
madvise(pkt_buf, TAP_BUF_BYTES, MADV_HUGEPAGE);
c.epollfd = epoll_create1(EPOLL_CLOEXEC);
- if (c.epollfd == -1) {
- perror("epoll_create1");
- exit(EXIT_FAILURE);
- }
+ if (c.epollfd == -1)
+ die_perror("epoll_create1");
+
+ if (getrlimit(RLIMIT_NOFILE, &limit))
+ die_perror("getrlimit");
- if (getrlimit(RLIMIT_NOFILE, &limit)) {
- perror("getrlimit");
- exit(EXIT_FAILURE);
- }
c.nofile = limit.rlim_cur = limit.rlim_max;
- if (setrlimit(RLIMIT_NOFILE, &limit)) {
- perror("setrlimit");
- exit(EXIT_FAILURE);
- }
+ if (setrlimit(RLIMIT_NOFILE, &limit))
+ die_perror("setrlimit");
+
sock_probe_mem(&c);
conf(&c, argc, argv);
@@ -293,10 +288,8 @@ int main(int argc, char **argv)
pcap_init(&c);
if (!c.foreground) {
- if ((devnull_fd = open("/dev/null", O_RDWR | O_CLOEXEC)) < 0) {
- perror("/dev/null open");
- exit(EXIT_FAILURE);
- }
+ if ((devnull_fd = open("/dev/null", O_RDWR | O_CLOEXEC)) < 0)
+ die_perror("/dev/null open");
}
if (isolate_prefork(&c))
@@ -324,10 +317,8 @@ loop:
/* NOLINTNEXTLINE(bugprone-branch-clone): intervals can be the same */
/* cppcheck-suppress [duplicateValueTernary, unmatchedSuppression] */
nfds = epoll_wait(c.epollfd, events, EPOLL_EVENTS, TIMER_INTERVAL);
- if (nfds == -1 && errno != EINTR) {
- perror("epoll_wait");
- exit(EXIT_FAILURE);
- }
+ if (nfds == -1 && errno != EINTR)
+ die_perror("epoll_wait");
clock_gettime(CLOCK_MONOTONIC, &now);
diff --git a/pasta.c b/pasta.c
index b85ea2b..ac2f898 100644
--- a/pasta.c
+++ b/pasta.c
@@ -197,8 +197,7 @@ static int pasta_spawn_cmd(void *arg)
a = (const struct pasta_spawn_cmd_arg *)arg;
execvp(a->exe, a->argv);
- perror("execvp");
- exit(EXIT_FAILURE);
+ die_perror("execvp");
}
/**
@@ -261,10 +260,8 @@ void pasta_start_ns(struct ctx *c, uid_t uid, gid_t gid,
CLONE_NEWUTS | CLONE_NEWNS | SIGCHLD,
(void *)&arg);
- if (pasta_child_pid == -1) {
- perror("clone");
- exit(EXIT_FAILURE);
- }
+ if (pasta_child_pid == -1)
+ die_perror("clone");
NS_CALL(pasta_wait_for_ns, c);
if (c->pasta_netns_fd < 0)
--
@@ -197,8 +197,7 @@ static int pasta_spawn_cmd(void *arg)
a = (const struct pasta_spawn_cmd_arg *)arg;
execvp(a->exe, a->argv);
- perror("execvp");
- exit(EXIT_FAILURE);
+ die_perror("execvp");
}
/**
@@ -261,10 +260,8 @@ void pasta_start_ns(struct ctx *c, uid_t uid, gid_t gid,
CLONE_NEWUTS | CLONE_NEWNS | SIGCHLD,
(void *)&arg);
- if (pasta_child_pid == -1) {
- perror("clone");
- exit(EXIT_FAILURE);
- }
+ if (pasta_child_pid == -1)
+ die_perror("clone");
NS_CALL(pasta_wait_for_ns, c);
if (c->pasta_netns_fd < 0)
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* [PATCH 6/6] treewide: Replace strerror() calls
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
` (4 preceding siblings ...)
2024-06-17 12:03 ` [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions Stefano Brivio
@ 2024-06-17 12:03 ` Stefano Brivio
2024-06-18 0:51 ` David Gibson
5 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-17 12:03 UTC (permalink / raw)
To: passt-dev; +Cc: Yalan Zhang
Now that we have logging functions embedding perror() functionality,
we can make _some_ calls more terse by using them. In many places,
the strerror() calls are still more convenient because, for example,
they are used in flow debugging functions, or because the return code
variable of interest is not 'errno'.
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
---
conf.c | 31 +++++++++++++++++--------------
fwd.c | 2 +-
isolation.c | 28 +++++++++++-----------------
log.c | 2 +-
netlink.c | 4 ++--
passt.c | 12 ++++--------
pasta.c | 32 ++++++++++++++++----------------
pcap.c | 8 +++-----
tap.c | 14 +++++++-------
tcp.c | 24 ++++++++----------------
util.c | 12 +++++-------
11 files changed, 75 insertions(+), 94 deletions(-)
diff --git a/conf.c b/conf.c
index 7042f92..42badea 100644
--- a/conf.c
+++ b/conf.c
@@ -461,7 +461,7 @@ static void get_dns(struct ctx *c)
}
if (line_len < 0)
- warn("Error reading /etc/resolv.conf: %s", strerror(errno));
+ warn_perror("Error reading /etc/resolv.conf");
close(fd);
out:
@@ -592,8 +592,8 @@ static unsigned int conf_ip4(unsigned int ifi,
if (IN4_IS_ADDR_UNSPECIFIED(&ip4->gw)) {
int rc = nl_route_get_def(nl_sock, ifi, AF_INET, &ip4->gw);
if (rc < 0) {
- err("Couldn't discover IPv4 gateway address: %s",
- strerror(-rc));
+ errno = -rc;
+ err_perror("Couldn't discover IPv4 gateway address");
return 0;
}
}
@@ -602,8 +602,8 @@ static unsigned int conf_ip4(unsigned int ifi,
int rc = nl_addr_get(nl_sock, ifi, AF_INET,
&ip4->addr, &ip4->prefix_len, NULL);
if (rc < 0) {
- err("Couldn't discover IPv4 address: %s",
- strerror(-rc));
+ errno = -rc;
+ err_perror("Couldn't discover IPv4 address");
return 0;
}
}
@@ -626,8 +626,10 @@ static unsigned int conf_ip4(unsigned int ifi,
int rc = nl_link_get_mac(nl_sock, ifi, mac);
if (rc < 0) {
char ifname[IFNAMSIZ];
- err("Couldn't discover MAC address for %s: %s",
- if_indextoname(ifi, ifname), strerror(-rc));
+
+ errno = -rc;
+ err_perror("Couldn't discover MAC address for %s",
+ if_indextoname(ifi, ifname));
return 0;
}
@@ -666,8 +668,8 @@ static unsigned int conf_ip6(unsigned int ifi,
if (IN6_IS_ADDR_UNSPECIFIED(&ip6->gw)) {
rc = nl_route_get_def(nl_sock, ifi, AF_INET6, &ip6->gw);
if (rc < 0) {
- err("Couldn't discover IPv6 gateway address: %s",
- strerror(-rc));
+ errno = -rc;
+ err_perror("Couldn't discover IPv6 gateway address");
return 0;
}
}
@@ -676,7 +678,8 @@ static unsigned int conf_ip6(unsigned int ifi,
IN6_IS_ADDR_UNSPECIFIED(&ip6->addr) ? &ip6->addr : NULL,
&prefix_len, &ip6->addr_ll);
if (rc < 0) {
- err("Couldn't discover IPv6 address: %s", strerror(-rc));
+ errno = -rc;
+ err_perror("Couldn't discover IPv6 address");
return 0;
}
@@ -687,8 +690,9 @@ static unsigned int conf_ip6(unsigned int ifi,
rc = nl_link_get_mac(nl_sock, ifi, mac);
if (rc < 0) {
char ifname[IFNAMSIZ];
- err("Couldn't discover MAC address for %s: %s",
- if_indextoname(ifi, ifname), strerror(-rc));
+ errno = -rc;
+ err_perror("Couldn't discover MAC address for %s",
+ if_indextoname(ifi, ifname));
return 0;
}
@@ -1560,8 +1564,7 @@ void conf(struct ctx *c, int argc, char **argv)
die("Redundant interface: %s", optarg);
if (!(ifi4 = ifi6 = if_nametoindex(optarg)))
- die("Invalid interface name %s: %s", optarg,
- strerror(errno));
+ die_perror("Invalid interface name %s", optarg);
break;
case 'o':
if (IN6_IS_ADDR_UNSPECIFIED(&c->ip6.addr_out) &&
diff --git a/fwd.c b/fwd.c
index b3d5a37..d3f1798 100644
--- a/fwd.c
+++ b/fwd.c
@@ -52,7 +52,7 @@ static void procfs_scan_listen(int fd, unsigned int lstate,
return;
if (lseek(fd, 0, SEEK_SET)) {
- warn("lseek() failed on /proc/net file: %s", strerror(errno));
+ warn_perror("lseek() failed on /proc/net file");
return;
}
diff --git a/isolation.c b/isolation.c
index 871bbac..832341a 100644
--- a/isolation.c
+++ b/isolation.c
@@ -105,7 +105,7 @@ static void drop_caps_ep_except(uint64_t keep)
int i;
if (syscall(SYS_capget, &hdr, data))
- die("Couldn't get current capabilities: %s", strerror(errno));
+ die_perror("Couldn't get current capabilities");
for (i = 0; i < CAP_WORDS; i++) {
uint32_t mask = keep >> (32 * i);
@@ -115,7 +115,7 @@ static void drop_caps_ep_except(uint64_t keep)
}
if (syscall(SYS_capset, &hdr, data))
- die("Couldn't drop capabilities: %s", strerror(errno));
+ die_perror("Couldn't drop capabilities");
}
/**
@@ -152,19 +152,17 @@ static void clamp_caps(void)
*/
if (prctl(PR_CAPBSET_DROP, i, 0, 0, 0) &&
errno != EINVAL && errno != EPERM)
- die("Couldn't drop cap %i from bounding set: %s",
- i, strerror(errno));
+ die_perror("Couldn't drop cap %i from bounding set", i);
}
if (syscall(SYS_capget, &hdr, data))
- die("Couldn't get current capabilities: %s", strerror(errno));
+ die_perror("Couldn't get current capabilities");
for (i = 0; i < CAP_WORDS; i++)
data[i].inheritable = 0;
if (syscall(SYS_capset, &hdr, data))
- die("Couldn't drop inheritable capabilities: %s",
- strerror(errno));
+ die_perror("Couldn't drop inheritable capabilities");
}
/**
@@ -234,34 +232,30 @@ void isolate_user(uid_t uid, gid_t gid, bool use_userns, const char *userns,
if (setgroups(0, NULL)) {
/* If we don't have CAP_SETGID, this will EPERM */
if (errno != EPERM)
- die("Can't drop supplementary groups: %s",
- strerror(errno));
+ die_perror("Can't drop supplementary groups");
}
if (setgid(gid) != 0)
- die("Can't set GID to %u: %s", gid, strerror(errno));
+ die_perror("Can't set GID to %u", gid);
if (setuid(uid) != 0)
- die("Can't set UID to %u: %s", uid, strerror(errno));
+ die_perror("Can't set UID to %u", uid);
if (*userns) { /* If given a userns, join it */
int ufd;
ufd = open(userns, O_RDONLY | O_CLOEXEC);
if (ufd < 0)
- die("Couldn't open user namespace %s: %s",
- userns, strerror(errno));
+ die_perror("Couldn't open user namespace %s", userns);
if (setns(ufd, CLONE_NEWUSER) != 0)
- die("Couldn't enter user namespace %s: %s",
- userns, strerror(errno));
+ die_perror("Couldn't enter user namespace %s", userns);
close(ufd);
} else if (use_userns) { /* Create and join a new userns */
if (unshare(CLONE_NEWUSER) != 0)
- die("Couldn't create user namespace: %s",
- strerror(errno));
+ die_perror("Couldn't create user namespace");
}
/* Joining a new userns gives us full capabilities; drop the
diff --git a/log.c b/log.c
index 4aa800d..014fc19 100644
--- a/log.c
+++ b/log.c
@@ -224,7 +224,7 @@ void logfile_init(const char *name, const char *path, size_t size)
log_file = open(path, O_CREAT | O_TRUNC | O_APPEND | O_RDWR | O_CLOEXEC,
S_IRUSR | S_IWUSR);
if (log_file == -1)
- die("Couldn't open log file %s: %s", path, strerror(errno));
+ die_perror("Couldn't open log file %s", path);
log_size = size ? size : LOGFILE_SIZE_DEFAULT;
diff --git a/netlink.c b/netlink.c
index d3bea68..4dbddb2 100644
--- a/netlink.c
+++ b/netlink.c
@@ -133,7 +133,7 @@ static uint32_t nl_send(int s, void *req, uint16_t type,
n = send(s, req, len, 0);
if (n < 0)
- die("netlink: Failed to send(): %s", strerror(errno));
+ die_perror("netlink: Failed to send()");
else if (n < len)
die("netlink: Short send (%zd of %zd bytes)", n, len);
@@ -189,7 +189,7 @@ static struct nlmsghdr *nl_next(int s, char *buf, struct nlmsghdr *nh, ssize_t *
*n = recv(s, buf, NLBUFSIZ, 0);
if (*n < 0)
- die("netlink: Failed to recv(): %s", strerror(errno));
+ die_perror("netlink: Failed to recv()");
nh = (struct nlmsghdr *)buf;
if (!NLMSG_OK(nh, *n))
diff --git a/passt.c b/passt.c
index 4bc4251..4b5722f 100644
--- a/passt.c
+++ b/passt.c
@@ -227,15 +227,11 @@ int main(int argc, char **argv)
__openlog(log_name = "pasta", 0, LOG_DAEMON);
sa.sa_handler = pasta_child_handler;
- if (sigaction(SIGCHLD, &sa, NULL)) {
- die("Couldn't install signal handlers: %s",
- strerror(errno));
- }
+ if (sigaction(SIGCHLD, &sa, NULL))
+ die_perror("Couldn't install signal handlers");
- if (signal(SIGPIPE, SIG_IGN) == SIG_ERR) {
- die("Couldn't set disposition for SIGPIPE: %s",
- strerror(errno));
- }
+ if (signal(SIGPIPE, SIG_IGN) == SIG_ERR)
+ die_perror("Couldn't set disposition for SIGPIPE");
c.mode = MODE_PASTA;
} else if (strstr(name, "passt")) {
diff --git a/pasta.c b/pasta.c
index ac2f898..1eb4471 100644
--- a/pasta.c
+++ b/pasta.c
@@ -138,17 +138,15 @@ void pasta_open_ns(struct ctx *c, const char *netns)
int nfd = -1;
nfd = open(netns, O_RDONLY | O_CLOEXEC);
- if (nfd < 0) {
- die("Couldn't open network namespace %s: %s",
- netns, strerror(errno));
- }
+ if (nfd < 0)
+ die_perror("Couldn't open network namespace %s", netns);
c->pasta_netns_fd = nfd;
NS_CALL(ns_check, c);
if (c->pasta_netns_fd < 0)
- die("Couldn't switch to pasta namespaces: %s", strerror(errno));
+ die_perror("Couldn't switch to pasta namespaces");
if (!c->no_netns_quit) {
char buf[PATH_MAX] = { 0 };
@@ -184,7 +182,7 @@ static int pasta_spawn_cmd(void *arg)
/* We run in a detached PID and mount namespace: mount /proc over */
if (mount("", "/proc", "proc", 0, NULL))
- warn("Couldn't mount /proc: %s", strerror(errno));
+ warn_perror("Couldn't mount /proc");
if (write_file("/proc/sys/net/ipv4/ping_group_range", "0 0"))
warn("Cannot set ping_group_range, ICMP requests might fail");
@@ -265,7 +263,7 @@ void pasta_start_ns(struct ctx *c, uid_t uid, gid_t gid,
NS_CALL(pasta_wait_for_ns, c);
if (c->pasta_netns_fd < 0)
- die("Failed to join network namespace: %s", strerror(errno));
+ die_perror("Failed to join network namespace");
}
/**
@@ -277,18 +275,20 @@ void pasta_ns_conf(struct ctx *c)
int rc = 0;
rc = nl_link_up(nl_sock_ns, 1 /* lo */, 0);
- if (rc < 0)
- die("Couldn't bring up loopback interface in namespace: %s",
- strerror(-rc));
+ if (rc < 0) {
+ errno = -rc;
+ die_perror("Couldn't bring up loopback interface in namespace");
+ }
/* Get or set MAC in target namespace */
if (MAC_IS_ZERO(c->mac_guest))
nl_link_get_mac(nl_sock_ns, c->pasta_ifi, c->mac_guest);
else
rc = nl_link_set_mac(nl_sock_ns, c->pasta_ifi, c->mac_guest);
- if (rc < 0)
- die("Couldn't set MAC address in namespace: %s",
- strerror(-rc));
+ if (rc < 0) {
+ errno = -rc;
+ die_perror("Couldn't set MAC address in namespace");
+ }
if (c->pasta_conf_ns) {
nl_link_up(nl_sock_ns, c->pasta_ifi, c->mtu);
@@ -369,12 +369,12 @@ static int pasta_netns_quit_timer(void)
struct itimerspec it = { { 1, 0 }, { 1, 0 } }; /* one-second interval */
if (fd == -1) {
- err("timerfd_create(): %s", strerror(errno));
+ err_perror("timerfd_create()");
return -errno;
}
if (timerfd_settime(fd, 0, &it, NULL) < 0) {
- err("timerfd_settime(): %s", strerror(errno));
+ err_perror("timerfd_settime()");
close(fd);
return -errno;
}
@@ -467,7 +467,7 @@ void pasta_netns_quit_timer_handler(struct ctx *c, union epoll_ref ref)
n = read(ref.fd, &expirations, sizeof(expirations));
if (n < 0)
- die("Namespace watch timer read() error: %s", strerror(errno));
+ die_perror("Namespace watch timer read() error");
if ((size_t)n < sizeof(expirations))
warn("Namespace watch timer: short read(): %zi", n);
diff --git a/pcap.c b/pcap.c
index 507be2a..46cc4b0 100644
--- a/pcap.c
+++ b/pcap.c
@@ -89,10 +89,8 @@ static void pcap_frame(const struct iovec *iov, size_t iovcnt,
struct iovec hiov = { &h, sizeof(h) };
if (write_remainder(pcap_fd, &hiov, 1, 0) < 0 ||
- write_remainder(pcap_fd, iov, iovcnt, offset) < 0) {
- debug("Cannot log packet, length %zu: %s",
- l2len, strerror(errno));
- }
+ write_remainder(pcap_fd, iov, iovcnt, offset) < 0)
+ debug_perror("Cannot log packet, length %zu", l2len);
}
/**
@@ -178,5 +176,5 @@ void pcap_init(struct ctx *c)
info("Saving packet capture to %s", c->pcap);
if (write(pcap_fd, &pcap_hdr, sizeof(pcap_hdr)) < 0)
- warn("Cannot write PCAP header: %s", strerror(errno));
+ warn_perror("Cannot write PCAP header");
}
diff --git a/tap.c b/tap.c
index c9aeff1..eaa7f65 100644
--- a/tap.c
+++ b/tap.c
@@ -325,7 +325,7 @@ static size_t tap_send_frames_pasta(const struct ctx *c,
size_t framelen = iov_size(iov + i, bufs_per_frame);
if (rc < 0) {
- debug("tap write: %s", strerror(errno));
+ debug_perror("tap write");
switch (errno) {
case EAGAIN:
@@ -387,7 +387,7 @@ static size_t tap_send_frames_passt(const struct ctx *c,
size_t rembufs = bufs_per_frame - (i % bufs_per_frame);
if (write_remainder(c->fd_tap, &iov[i], rembufs, buf_offset) < 0) {
- err("tap: partial frame send: %s", strerror(errno));
+ err_perror("tap: partial frame send");
return i;
}
i += rembufs;
@@ -1122,7 +1122,7 @@ int tap_sock_unix_open(char *sock_path)
int i;
if (fd < 0)
- die("UNIX socket: %s", strerror(errno));
+ die_perror("UNIX socket");
for (i = 1; i < UNIX_SOCK_MAX; i++) {
char *path = addr.sun_path;
@@ -1135,7 +1135,7 @@ int tap_sock_unix_open(char *sock_path)
ex = socket(AF_UNIX, SOCK_STREAM | SOCK_NONBLOCK, 0);
if (ex < 0)
- die("UNIX domain socket check: %s", strerror(errno));
+ die_perror("UNIX domain socket check");
ret = connect(ex, (const struct sockaddr *)&addr, sizeof(addr));
if (!ret || (errno != ENOENT && errno != ECONNREFUSED &&
@@ -1155,7 +1155,7 @@ int tap_sock_unix_open(char *sock_path)
}
if (i == UNIX_SOCK_MAX)
- die("UNIX socket bind: %s", strerror(errno));
+ die_perror("UNIX socket bind");
info("UNIX domain socket bound at %s", addr.sun_path);
if (!*sock_path)
@@ -1261,11 +1261,11 @@ static int tap_ns_tun(void *arg)
fd = open("/dev/net/tun", flags);
if (fd < 0)
- die("Failed to open() /dev/net/tun: %s", strerror(errno));
+ die_perror("Failed to open() /dev/net/tun");
rc = ioctl(fd, TUNSETIFF, &ifr);
if (rc < 0)
- die("TUNSETIFF failed: %s", strerror(errno));
+ die_perror("TUNSETIFF failed");
if (!(c->pasta_ifi = if_nametoindex(c->pasta_ifn)))
die("Tap device opened but no network interface found");
diff --git a/tcp.c b/tcp.c
index 6852423..231f63b 100644
--- a/tcp.c
+++ b/tcp.c
@@ -1553,19 +1553,15 @@ static void tcp_bind_outbound(const struct ctx *c, int s, sa_family_t af)
.sin_addr = c->ip4.addr_out,
};
- if (bind(s, (struct sockaddr *)&addr4, sizeof(addr4))) {
- debug("Can't bind IPv4 TCP socket address: %s",
- strerror(errno));
- }
+ if (bind(s, (struct sockaddr *)&addr4, sizeof(addr4)))
+ debug_perror("IPv4 TCP socket address bind");
}
if (*c->ip4.ifname_out) {
if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
c->ip4.ifname_out,
- strlen(c->ip4.ifname_out))) {
- debug("Can't bind IPv4 TCP socket to interface:"
- " %s", strerror(errno));
- }
+ strlen(c->ip4.ifname_out)))
+ debug_perror("IPv4 TCP socket interface bind");
}
} else if (af == AF_INET6) {
if (!IN6_IS_ADDR_UNSPECIFIED(&c->ip6.addr_out)) {
@@ -1575,19 +1571,15 @@ static void tcp_bind_outbound(const struct ctx *c, int s, sa_family_t af)
.sin6_addr = c->ip6.addr_out,
};
- if (bind(s, (struct sockaddr *)&addr6, sizeof(addr6))) {
- debug("Can't bind IPv6 TCP socket address: %s",
- strerror(errno));
- }
+ if (bind(s, (struct sockaddr *)&addr6, sizeof(addr6)))
+ debug_perror("IPv6 TCP socket address bind");
}
if (*c->ip6.ifname_out) {
if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
c->ip6.ifname_out,
- strlen(c->ip6.ifname_out))) {
- debug("Can't bind IPv6 TCP socket to interface:"
- " %s", strerror(errno));
- }
+ strlen(c->ip6.ifname_out)))
+ debug_perror("IPv6 TCP socket interface bind");
}
}
}
diff --git a/util.c b/util.c
index 77448ec..dd2e57f 100644
--- a/util.c
+++ b/util.c
@@ -315,7 +315,7 @@ void bitmap_or(uint8_t *dst, size_t size, const uint8_t *a, const uint8_t *b)
void ns_enter(const struct ctx *c)
{
if (setns(c->pasta_netns_fd, CLONE_NEWNET))
- die("setns() failed entering netns: %s", strerror(errno));
+ die_perror("setns() failed entering netns");
}
/**
@@ -330,10 +330,8 @@ bool ns_is_init(void)
bool ret = true;
int fd;
- if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0) {
- die("Can't determine if we're in init namespace: %s",
- strerror(errno));
- }
+ if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0)
+ die_perror("Can't determine if we're in init namespace");
if (read(fd, buf, sizeof(root_uid_map)) != sizeof(root_uid_map) - 1 ||
strncmp(buf, root_uid_map, sizeof(root_uid_map)))
@@ -509,7 +507,7 @@ int write_file(const char *path, const char *buf)
size_t len = strlen(buf);
if (fd < 0) {
- warn("Could not open %s: %s", path, strerror(errno));
+ warn_perror("Could not open %s", path);
return -1;
}
@@ -517,7 +515,7 @@ int write_file(const char *path, const char *buf)
ssize_t rc = write(fd, buf, len);
if (rc <= 0) {
- warn("Couldn't write to %s: %s", path, strerror(errno));
+ warn_perror("Couldn't write to %s", path);
break;
}
--
@@ -315,7 +315,7 @@ void bitmap_or(uint8_t *dst, size_t size, const uint8_t *a, const uint8_t *b)
void ns_enter(const struct ctx *c)
{
if (setns(c->pasta_netns_fd, CLONE_NEWNET))
- die("setns() failed entering netns: %s", strerror(errno));
+ die_perror("setns() failed entering netns");
}
/**
@@ -330,10 +330,8 @@ bool ns_is_init(void)
bool ret = true;
int fd;
- if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0) {
- die("Can't determine if we're in init namespace: %s",
- strerror(errno));
- }
+ if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0)
+ die_perror("Can't determine if we're in init namespace");
if (read(fd, buf, sizeof(root_uid_map)) != sizeof(root_uid_map) - 1 ||
strncmp(buf, root_uid_map, sizeof(root_uid_map)))
@@ -509,7 +507,7 @@ int write_file(const char *path, const char *buf)
size_t len = strlen(buf);
if (fd < 0) {
- warn("Could not open %s: %s", path, strerror(errno));
+ warn_perror("Could not open %s", path);
return -1;
}
@@ -517,7 +515,7 @@ int write_file(const char *path, const char *buf)
ssize_t rc = write(fd, buf, len);
if (rc <= 0) {
- warn("Couldn't write to %s: %s", path, strerror(errno));
+ warn_perror("Couldn't write to %s", path);
break;
}
--
2.43.0
^ permalink raw reply related [flat|nested] 27+ messages in thread
* Re: [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-17 12:03 ` [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it Stefano Brivio
@ 2024-06-18 0:36 ` David Gibson
2024-06-18 6:00 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:36 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 1729 bytes --]
On Mon, Jun 17, 2024 at 02:03:14PM +0200, Stefano Brivio wrote:
> If we don't run in foreground, we close standard error as we
> daemonise, so it makes no sense to check if the controlling terminal
> is an interactive terminal or if --force-stderr was given, to decide
> if we want to log to standard error.
>
> Make --force-stderr depend on --foreground.
>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
> ---
> conf.c | 3 +++
> passt.c | 2 +-
> 2 files changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/conf.c b/conf.c
> index 94b3ed6..dbdbb62 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
>
> conf_ugid(runas, &uid, &gid);
>
> + if (!c->foreground && c->force_stderr)
> + die("Can't log to standard error if not running in foreground");
> +
> if (logfile) {
> logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
> logfile, logsize);
> diff --git a/passt.c b/passt.c
> index a5e2c5a..aa9648a 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -302,7 +302,7 @@ int main(int argc, char **argv)
> if (isolate_prefork(&c))
> die("Failed to sandbox process, exiting");
>
> - if (!c.force_stderr && !isatty(fileno(stderr)))
> + if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
What's the rationale for the isatty() check in any case?
> __openlog(log_name, 0, LOG_DAEMON);
>
> if (!c.foreground)
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels
2024-06-17 12:03 ` [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels Stefano Brivio
@ 2024-06-18 0:39 ` David Gibson
2024-06-18 6:01 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:39 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 4444 bytes --]
On Mon, Jun 17, 2024 at 02:03:15PM +0200, Stefano Brivio wrote:
> We currently use a LOG_EMERG log mask to represent the fact that we
> don't know yet what the mask resulting from configuration should be,
> before the command line is parsed.
>
> However, we have the necessity of representing another phase as well,
> that is, configuration is parsed but we didn't daemonise yet, or
> we're not ready for operation yet. The next patch will add that
> notion explicitly.
>
> Mapping these cases to further log levels isn't really practical.
> Introduce internal log flags to represent them, instead of abusing
> log priorities.
>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
I like not abusing the log priorities. But, do we actually need a
flags field with constants and helpers, rather than just
bool log_conf_parsed;
and open code it from there?
> ---
> conf.c | 5 ++---
> log.c | 18 +++++++++++++-----
> log.h | 4 ++++
> 3 files changed, 19 insertions(+), 8 deletions(-)
>
> diff --git a/conf.c b/conf.c
> index dbdbb62..0b76da9 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -1701,9 +1701,6 @@ void conf(struct ctx *c, int argc, char **argv)
> logfile, logsize);
> }
>
> - /* Once the log mask is not LOG_EARLY, we will no longer log to stderr
> - * if there was a log file specified.
> - */
> if (c->debug)
> __setlogmask(LOG_UPTO(LOG_DEBUG));
> else if (c->quiet)
> @@ -1711,6 +1708,8 @@ void conf(struct ctx *c, int argc, char **argv)
> else
> __setlogmask(LOG_UPTO(LOG_INFO));
>
> + log_set_flag(LOG_FLAG_CONF_PARSED); /* Stop printing everything */
> +
> nl_sock_init(c, false);
> if (!v6_only)
> c->ifi4 = conf_ip4(ifi4, &c->ip4, c->mac);
> diff --git a/log.c b/log.c
> index aaf2beb..3b5a1c6 100644
> --- a/log.c
> +++ b/log.c
> @@ -30,14 +30,13 @@
> #include "util.h"
> #include "passt.h"
>
> -/* LOG_EARLY means we don't know yet: log everything. LOG_EMERG is unused */
> -#define LOG_EARLY LOG_MASK(LOG_EMERG)
> -
> static int log_sock = -1; /* Optional socket to system logger */
> static char log_ident[BUFSIZ]; /* Identifier string for openlog() */
> -static int log_mask = LOG_EARLY; /* Current log priority mask */
> +static int log_mask; /* Current log priority mask */
> static int log_opt; /* Options for openlog() */
>
> +static uint8_t log_flags; /* Internal, see LOG_FLAG_* in log.h */
> +
> 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 */
> @@ -50,7 +49,7 @@ int log_trace; /* --trace mode enabled */
> void vlogmsg(int pri, const char *format, va_list ap)
> {
> bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> - bool early_print = LOG_PRI(log_mask) == LOG_EARLY;
> + bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> struct timespec tp;
>
> if (debug_print) {
> @@ -150,6 +149,15 @@ void __setlogmask(int mask)
> setlogmask(mask);
> }
>
> +/**
> + * log_set_flag() - Set an internal log flag
> + * @flag: Flag as defined by LOG_FLAG_* in log.h
> + */
> +void log_set_flag(uint8_t flag)
> +{
> + log_flags |= flag;
> +}
> +
> /**
> * passt_vsyslog() - vsyslog() implementation not using heap memory
> * @pri: Facility and level map, same as priority for vsyslog()
> diff --git a/log.h b/log.h
> index e0aab5a..6a3224a 100644
> --- a/log.h
> +++ b/log.h
> @@ -6,8 +6,11 @@
> #ifndef LOG_H
> #define LOG_H
>
> +#include <stdint.h>
> #include <syslog.h>
>
> +#define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> +
> #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> #define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
> @@ -40,5 +43,6 @@ 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);
> +void log_set_flag(uint8_t flag);
>
> #endif /* LOG_H */
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-17 12:03 ` [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete Stefano Brivio
@ 2024-06-18 0:44 ` David Gibson
2024-06-18 6:01 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:44 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 4961 bytes --]
On Mon, Jun 17, 2024 at 02:03:16PM +0200, Stefano Brivio wrote:
> After commit 15001b39ef1d ("conf: set the log level much earlier"), we
> had a phase during initialisation when messages wouldn't be printed to
> standard error anymore.
>
> Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
> stderr until we detach") fixed that, but only for the case where no
> log files are given.
>
> If a log file is configured, vlogmsg() will not call passt_vsyslog(),
> but during initialisation, LOG_PERROR is set, so to avoid duplicated
> prints (which would result from passt_vsyslog() printing to stderr),
> we don't call fprintf() from vlogmsg() either.
>
> This is getting a bit too complicated. Instead of abusing LOG_PERROR,
> define an internal logging flag that clearly represents that we're not
> done with the initialisation phase yet.
>
> If this flag is not set, make sure we always print to stderr, if the
> log mask matches. Then, set LOG_PERROR only as we set this internal
> flag, to make sure we don't duplicate messages.
>
> Reported-by: Yalan Zhang <yalzhang@redhat.com>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> ---
> log.c | 4 +++-
> log.h | 1 +
> passt.1 | 3 ++-
> passt.c | 17 ++++++++++-------
> 4 files changed, 16 insertions(+), 9 deletions(-)
>
> diff --git a/log.c b/log.c
> index 3b5a1c6..939bb93 100644
> --- a/log.c
> +++ b/log.c
> @@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
> void vlogmsg(int pri, const char *format, va_list ap)
> {
> bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> + bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
As in 2/6 would just a global bool be simpler than flags.
> bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> struct timespec tp;
>
> @@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
> va_end(ap2);
> }
>
> - if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
> + if (debug_print || early_print ||
> + (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
> (void)vfprintf(stderr, format, ap);
> if (format[strlen(format)] != '\n')
> fprintf(stderr, "\n");
> diff --git a/log.h b/log.h
> index 6a3224a..680baab 100644
> --- a/log.h
> +++ b/log.h
> @@ -10,6 +10,7 @@
> #include <syslog.h>
>
> #define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> +#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
>
> #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> diff --git a/passt.1 b/passt.1
> index 3a23a43..31e528e 100644
> --- a/passt.1
> +++ b/passt.1
> @@ -99,7 +99,8 @@ 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.
> +Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
> +and not to the system logger.
IIUC when -l is set we'll log to the logfile _as well as_ stderr
before we daemonize. The description above doesn't exactly contradict
that, but seems to imply something different.
> .TP
> .BR \-\-log-size " " \fISIZE\fR
> diff --git a/passt.c b/passt.c
> index aa9648a..fa86164 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -225,7 +225,7 @@ int main(int argc, char **argv)
> strncpy(argv0, argv[0], PATH_MAX - 1);
> name = basename(argv0);
> if (strstr(name, "pasta")) {
> - __openlog(log_name = "pasta", LOG_PERROR, LOG_DAEMON);
> + __openlog(log_name = "pasta", 0, LOG_DAEMON);
>
> sa.sa_handler = pasta_child_handler;
> if (sigaction(SIGCHLD, &sa, NULL)) {
> @@ -240,7 +240,7 @@ int main(int argc, char **argv)
>
> c.mode = MODE_PASTA;
> } else if (strstr(name, "passt")) {
> - __openlog(log_name = "passt", LOG_PERROR, LOG_DAEMON);
> + __openlog(log_name = "passt", 0, LOG_DAEMON);
>
> c.mode = MODE_PASST;
> } else {
> @@ -302,13 +302,16 @@ int main(int argc, char **argv)
> if (isolate_prefork(&c))
> die("Failed to sandbox process, exiting");
>
> - if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
> - __openlog(log_name, 0, LOG_DAEMON);
> -
> - if (!c.foreground)
> + if (!c.foreground) {
> __daemon(c.pidfile_fd, devnull_fd);
> - else
> + } else {
> + if (c.force_stderr || isatty(fileno(stderr)))
> + __openlog(log_name, LOG_PERROR, LOG_DAEMON);
> +
> pidfile_write(c.pidfile_fd, getpid());
> + }
> +
> + log_set_flag(LOG_FLAG_DAEMON_READY);
>
> if (pasta_child_pid)
> kill(pasta_child_pid, SIGUSR1);
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 4/6] log: Add _perror() logging function variants
2024-06-17 12:03 ` [PATCH 4/6] log: Add _perror() logging function variants Stefano Brivio
@ 2024-06-18 0:46 ` David Gibson
2024-06-18 6:02 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:46 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 3522 bytes --]
On Mon, Jun 17, 2024 at 02:03:17PM +0200, Stefano Brivio wrote:
> In many places, we have direct perror() calls, which completely bypass
> logging functions and log files.
>
> They are definitely convenient: offer similar convenience with
> _perror() logging variants, so that we can drop those direct perror()
> calls.
>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
Hm, for anything bigger than like a screenful of code, I generally
find an explicit message with strerror(errno) more useful than
perror() or equivalents, but I guess if you think these are useful.
> ---
> log.c | 21 +++++++++++++++++++++
> log.h | 21 +++++++++++++++++----
> 2 files changed, 38 insertions(+), 4 deletions(-)
>
> diff --git a/log.c b/log.c
> index 939bb93..6764b2b 100644
> --- a/log.c
> +++ b/log.c
> @@ -80,6 +80,11 @@ void vlogmsg(int pri, const char *format, va_list ap)
> }
> }
>
> +/**
> + * logmsg() - vlogmsg() wrapper for variable argument lists
> + * @pri: Facility and level map, same as priority for vsyslog()
> + * @format: Message
> + */
> void logmsg(int pri, const char *format, ...)
> {
> va_list ap;
> @@ -89,6 +94,22 @@ void logmsg(int pri, const char *format, ...)
> va_end(ap);
> }
>
> +/**
> + * logmsg_perror() - vlogmsg() wrapper with perror()-like functionality
> + * @pri: Facility and level map, same as priority for vsyslog()
> + * @format: Message
> + */
> +void logmsg_perror(int pri, const char *format, ...)
> +{
> + va_list ap;
> +
> + logmsg(pri, "%s: ", strerror(errno));
> +
> + va_start(ap, format);
> + vlogmsg(pri, format, ap);
> + va_end(ap);
> +}
> +
> /* Prefixes for log file messages, indexed by priority */
> const char *logfile_prefix[] = {
> NULL, NULL, NULL, /* Unused: LOG_EMERG, LOG_ALERT, LOG_CRIT */
> diff --git a/log.h b/log.h
> index 680baab..5be0be9 100644
> --- a/log.h
> +++ b/log.h
> @@ -19,11 +19,18 @@
> void vlogmsg(int pri, const char *format, va_list ap);
> void logmsg(int pri, const char *format, ...)
> __attribute__((format(printf, 2, 3)));
> +void logmsg_perror(int pri, const char *format, ...)
> + __attribute__((format(printf, 2, 3)));
> +
> +#define err(...) logmsg( LOG_ERR, __VA_ARGS__)
> +#define warn(...) logmsg( LOG_WARNING, __VA_ARGS__)
> +#define info(...) logmsg( LOG_INFO, __VA_ARGS__)
> +#define debug(...) logmsg( LOG_DEBUG, __VA_ARGS__)
>
> -#define err(...) logmsg(LOG_ERR, __VA_ARGS__)
> -#define warn(...) logmsg(LOG_WARNING, __VA_ARGS__)
> -#define info(...) logmsg(LOG_INFO, __VA_ARGS__)
> -#define debug(...) logmsg(LOG_DEBUG, __VA_ARGS__)
> +#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
> +#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
> +#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
> +#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
>
> #define die(...) \
> do { \
> @@ -31,6 +38,12 @@ void logmsg(int pri, const char *format, ...)
> exit(EXIT_FAILURE); \
> } while (0)
>
> +#define die_perror(...) \
> + do { \
> + err_perror(__VA_ARGS__); \
> + exit(EXIT_FAILURE); \
> + } while (0)
> +
> extern int log_trace;
> void trace_init(int enable);
> #define trace(...) \
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions
2024-06-17 12:03 ` [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions Stefano Brivio
@ 2024-06-18 0:50 ` David Gibson
0 siblings, 0 replies; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:50 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 8128 bytes --]
On Mon, Jun 17, 2024 at 02:03:18PM +0200, Stefano Brivio wrote:
> perror() prints directly to standard error, but in many cases standard
> error might be already closed, or we might want to skip logging, based
> on configuration. Our logging functions provide all that.
>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> ---
> arch.c | 10 +++++-----
> conf.c | 6 ++----
> isolation.c | 18 ++++++++----------
> log.c | 12 ++++--------
> passt.c | 41 ++++++++++++++++-------------------------
> pasta.c | 9 +++------
> 6 files changed, 38 insertions(+), 58 deletions(-)
>
> diff --git a/arch.c b/arch.c
> index 80a41bc..41bea01 100644
> --- a/arch.c
> +++ b/arch.c
> @@ -18,6 +18,8 @@
> #include <string.h>
> #include <unistd.h>
>
> +#include "log.h"
> +
> /**
> * arch_avx2_exec() - Switch to AVX2 build if supported
> * @argv: Arguments from command line
> @@ -28,10 +30,8 @@ void arch_avx2_exec(char **argv)
> char exe[PATH_MAX] = { 0 };
> const char *p;
>
> - if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0) {
> - perror("readlink /proc/self/exe");
> - exit(EXIT_FAILURE);
> - }
> + if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0)
> + die_perror("readlink /proc/self/exe");
>
> p = strstr(exe, ".avx2");
> if (p && strlen(p) == strlen(".avx2"))
> @@ -42,7 +42,7 @@ void arch_avx2_exec(char **argv)
>
> snprintf(new_path, PATH_MAX + sizeof(".avx2"), "%s.avx2", exe);
> execve(new_path, argv, environ);
> - perror("Can't run AVX2 build, using non-AVX2 version");
> + warn_perror("Can't run AVX2 build, using non-AVX2 version");
> }
> }
> #else
> diff --git a/conf.c b/conf.c
> index 0b76da9..7042f92 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -1098,10 +1098,8 @@ static void conf_ugid(char *runas, uid_t *uid, gid_t *gid)
> const struct passwd *pw;
> /* cppcheck-suppress getpwnamCalled */
> pw = getpwnam("nobody");
> - if (!pw) {
> - perror("getpwnam");
> - exit(EXIT_FAILURE);
> - }
> + if (!pw)
> + die_perror("getpwnam");
>
> *uid = pw->pw_uid;
> *gid = pw->pw_gid;
> diff --git a/isolation.c b/isolation.c
> index ca2c68b..871bbac 100644
> --- a/isolation.c
> +++ b/isolation.c
> @@ -316,34 +316,34 @@ int isolate_prefork(const struct ctx *c)
> flags |= CLONE_NEWPID;
>
> if (unshare(flags)) {
> - perror("unshare");
> + err_perror("unshare");
If we're changing these, I'd be inclined to make them more complete
error messages, e.g.
err("Failed to create isolating namespace: %s",
strerror(errno));
> return -errno;
> }
>
> if (mount("", "/", "", MS_UNBINDABLE | MS_REC, NULL)) {
> - perror("mount /");
> + err_perror("mount /");
> return -errno;
> }
>
> if (mount("", TMPDIR, "tmpfs",
> MS_NODEV | MS_NOEXEC | MS_NOSUID | MS_RDONLY,
> "nr_inodes=2,nr_blocks=0")) {
> - perror("mount tmpfs");
> + err_perror("mount tmpfs");
> return -errno;
> }
>
> if (chdir(TMPDIR)) {
> - perror("chdir");
> + err_perror("chdir");
> return -errno;
> }
>
> if (syscall(SYS_pivot_root, ".", ".")) {
> - perror("pivot_root");
> + err_perror("pivot_root");
> return -errno;
> }
>
> if (umount2(".", MNT_DETACH | UMOUNT_NOFOLLOW)) {
> - perror("umount2");
> + err_perror("umount2");
> return -errno;
> }
>
> @@ -388,8 +388,6 @@ void isolate_postfork(const struct ctx *c)
> }
>
> if (prctl(PR_SET_NO_NEW_PRIVS, 1, 0, 0, 0) ||
> - prctl(PR_SET_SECCOMP, SECCOMP_MODE_FILTER, &prog)) {
> - perror("prctl");
> - exit(EXIT_FAILURE);
> - }
> + prctl(PR_SET_SECCOMP, SECCOMP_MODE_FILTER, &prog))
> + die_perror("prctl");
> }
> diff --git a/log.c b/log.c
> index 6764b2b..4aa800d 100644
> --- a/log.c
> +++ b/log.c
> @@ -218,10 +218,8 @@ 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);
> - }
> + if (readlink("/proc/self/exe", exe, PATH_MAX - 1) < 0)
> + die_perror("readlink /proc/self/exe");
>
> log_file = open(path, O_CREAT | O_TRUNC | O_APPEND | O_RDWR | O_CLOEXEC,
> S_IRUSR | S_IWUSR);
> @@ -234,10 +232,8 @@ void logfile_init(const char *name, const char *path, size_t size)
> 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);
> - }
> + write(log_file, &nl, 1) <= 0)
> + die_perror("Couldn't write to log file\n");
>
> /* 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);
> diff --git a/passt.c b/passt.c
> index fa86164..4bc4251 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -136,14 +136,13 @@ static void secret_init(struct ctx *c)
> }
> if (dev_random >= 0)
> close(dev_random);
> - if (random_read < sizeof(c->hash_secret)) {
> +
> + if (random_read < sizeof(c->hash_secret))
> #else
> if (getrandom(&c->hash_secret, sizeof(c->hash_secret),
> - GRND_RANDOM) < 0) {
> + GRND_RANDOM) < 0)
> #endif /* !HAS_GETRANDOM */
> - perror("TCP initial sequence getrandom");
> - exit(EXIT_FAILURE);
> - }
> + die_perror("TCP initial sequence getrandom");
> }
>
> /**
> @@ -250,20 +249,16 @@ int main(int argc, char **argv)
> madvise(pkt_buf, TAP_BUF_BYTES, MADV_HUGEPAGE);
>
> c.epollfd = epoll_create1(EPOLL_CLOEXEC);
> - if (c.epollfd == -1) {
> - perror("epoll_create1");
> - exit(EXIT_FAILURE);
> - }
> + if (c.epollfd == -1)
> + die_perror("epoll_create1");
> +
> + if (getrlimit(RLIMIT_NOFILE, &limit))
> + die_perror("getrlimit");
>
> - if (getrlimit(RLIMIT_NOFILE, &limit)) {
> - perror("getrlimit");
> - exit(EXIT_FAILURE);
> - }
> c.nofile = limit.rlim_cur = limit.rlim_max;
> - if (setrlimit(RLIMIT_NOFILE, &limit)) {
> - perror("setrlimit");
> - exit(EXIT_FAILURE);
> - }
> + if (setrlimit(RLIMIT_NOFILE, &limit))
> + die_perror("setrlimit");
> +
> sock_probe_mem(&c);
>
> conf(&c, argc, argv);
> @@ -293,10 +288,8 @@ int main(int argc, char **argv)
> pcap_init(&c);
>
> if (!c.foreground) {
> - if ((devnull_fd = open("/dev/null", O_RDWR | O_CLOEXEC)) < 0) {
> - perror("/dev/null open");
> - exit(EXIT_FAILURE);
> - }
> + if ((devnull_fd = open("/dev/null", O_RDWR | O_CLOEXEC)) < 0)
> + die_perror("/dev/null open");
> }
>
> if (isolate_prefork(&c))
> @@ -324,10 +317,8 @@ loop:
> /* NOLINTNEXTLINE(bugprone-branch-clone): intervals can be the same */
> /* cppcheck-suppress [duplicateValueTernary, unmatchedSuppression] */
> nfds = epoll_wait(c.epollfd, events, EPOLL_EVENTS, TIMER_INTERVAL);
> - if (nfds == -1 && errno != EINTR) {
> - perror("epoll_wait");
> - exit(EXIT_FAILURE);
> - }
> + if (nfds == -1 && errno != EINTR)
> + die_perror("epoll_wait");
>
> clock_gettime(CLOCK_MONOTONIC, &now);
>
> diff --git a/pasta.c b/pasta.c
> index b85ea2b..ac2f898 100644
> --- a/pasta.c
> +++ b/pasta.c
> @@ -197,8 +197,7 @@ static int pasta_spawn_cmd(void *arg)
> a = (const struct pasta_spawn_cmd_arg *)arg;
> execvp(a->exe, a->argv);
>
> - perror("execvp");
> - exit(EXIT_FAILURE);
> + die_perror("execvp");
> }
>
> /**
> @@ -261,10 +260,8 @@ void pasta_start_ns(struct ctx *c, uid_t uid, gid_t gid,
> CLONE_NEWUTS | CLONE_NEWNS | SIGCHLD,
> (void *)&arg);
>
> - if (pasta_child_pid == -1) {
> - perror("clone");
> - exit(EXIT_FAILURE);
> - }
> + if (pasta_child_pid == -1)
> + die_perror("clone");
>
> NS_CALL(pasta_wait_for_ns, c);
> if (c->pasta_netns_fd < 0)
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 6/6] treewide: Replace strerror() calls
2024-06-17 12:03 ` [PATCH 6/6] treewide: Replace strerror() calls Stefano Brivio
@ 2024-06-18 0:51 ` David Gibson
2024-06-18 6:02 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-18 0:51 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 19428 bytes --]
On Mon, Jun 17, 2024 at 02:03:19PM +0200, Stefano Brivio wrote:
> Now that we have logging functions embedding perror() functionality,
> we can make _some_ calls more terse by using them. In many places,
> the strerror() calls are still more convenient because, for example,
> they are used in flow debugging functions, or because the return code
> variable of interest is not 'errno'.
>
> Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
Hrm, this also changes
What we were doing: <strerror>
into
<strerror>: What we were doing
which I think is a weirder convention.
> ---
> conf.c | 31 +++++++++++++++++--------------
> fwd.c | 2 +-
> isolation.c | 28 +++++++++++-----------------
> log.c | 2 +-
> netlink.c | 4 ++--
> passt.c | 12 ++++--------
> pasta.c | 32 ++++++++++++++++----------------
> pcap.c | 8 +++-----
> tap.c | 14 +++++++-------
> tcp.c | 24 ++++++++----------------
> util.c | 12 +++++-------
> 11 files changed, 75 insertions(+), 94 deletions(-)
>
> diff --git a/conf.c b/conf.c
> index 7042f92..42badea 100644
> --- a/conf.c
> +++ b/conf.c
> @@ -461,7 +461,7 @@ static void get_dns(struct ctx *c)
> }
>
> if (line_len < 0)
> - warn("Error reading /etc/resolv.conf: %s", strerror(errno));
> + warn_perror("Error reading /etc/resolv.conf");
> close(fd);
>
> out:
> @@ -592,8 +592,8 @@ static unsigned int conf_ip4(unsigned int ifi,
> if (IN4_IS_ADDR_UNSPECIFIED(&ip4->gw)) {
> int rc = nl_route_get_def(nl_sock, ifi, AF_INET, &ip4->gw);
> if (rc < 0) {
> - err("Couldn't discover IPv4 gateway address: %s",
> - strerror(-rc));
> + errno = -rc;
> + err_perror("Couldn't discover IPv4 gateway address");
> return 0;
> }
> }
> @@ -602,8 +602,8 @@ static unsigned int conf_ip4(unsigned int ifi,
> int rc = nl_addr_get(nl_sock, ifi, AF_INET,
> &ip4->addr, &ip4->prefix_len, NULL);
> if (rc < 0) {
> - err("Couldn't discover IPv4 address: %s",
> - strerror(-rc));
> + errno = -rc;
> + err_perror("Couldn't discover IPv4 address");
> return 0;
> }
> }
> @@ -626,8 +626,10 @@ static unsigned int conf_ip4(unsigned int ifi,
> int rc = nl_link_get_mac(nl_sock, ifi, mac);
> if (rc < 0) {
> char ifname[IFNAMSIZ];
> - err("Couldn't discover MAC address for %s: %s",
> - if_indextoname(ifi, ifname), strerror(-rc));
> +
> + errno = -rc;
> + err_perror("Couldn't discover MAC address for %s",
> + if_indextoname(ifi, ifname));
> return 0;
> }
>
> @@ -666,8 +668,8 @@ static unsigned int conf_ip6(unsigned int ifi,
> if (IN6_IS_ADDR_UNSPECIFIED(&ip6->gw)) {
> rc = nl_route_get_def(nl_sock, ifi, AF_INET6, &ip6->gw);
> if (rc < 0) {
> - err("Couldn't discover IPv6 gateway address: %s",
> - strerror(-rc));
> + errno = -rc;
> + err_perror("Couldn't discover IPv6 gateway address");
> return 0;
> }
> }
> @@ -676,7 +678,8 @@ static unsigned int conf_ip6(unsigned int ifi,
> IN6_IS_ADDR_UNSPECIFIED(&ip6->addr) ? &ip6->addr : NULL,
> &prefix_len, &ip6->addr_ll);
> if (rc < 0) {
> - err("Couldn't discover IPv6 address: %s", strerror(-rc));
> + errno = -rc;
> + err_perror("Couldn't discover IPv6 address");
> return 0;
> }
>
> @@ -687,8 +690,9 @@ static unsigned int conf_ip6(unsigned int ifi,
> rc = nl_link_get_mac(nl_sock, ifi, mac);
> if (rc < 0) {
> char ifname[IFNAMSIZ];
> - err("Couldn't discover MAC address for %s: %s",
> - if_indextoname(ifi, ifname), strerror(-rc));
> + errno = -rc;
> + err_perror("Couldn't discover MAC address for %s",
> + if_indextoname(ifi, ifname));
> return 0;
> }
>
> @@ -1560,8 +1564,7 @@ void conf(struct ctx *c, int argc, char **argv)
> die("Redundant interface: %s", optarg);
>
> if (!(ifi4 = ifi6 = if_nametoindex(optarg)))
> - die("Invalid interface name %s: %s", optarg,
> - strerror(errno));
> + die_perror("Invalid interface name %s", optarg);
> break;
> case 'o':
> if (IN6_IS_ADDR_UNSPECIFIED(&c->ip6.addr_out) &&
> diff --git a/fwd.c b/fwd.c
> index b3d5a37..d3f1798 100644
> --- a/fwd.c
> +++ b/fwd.c
> @@ -52,7 +52,7 @@ static void procfs_scan_listen(int fd, unsigned int lstate,
> return;
>
> if (lseek(fd, 0, SEEK_SET)) {
> - warn("lseek() failed on /proc/net file: %s", strerror(errno));
> + warn_perror("lseek() failed on /proc/net file");
> return;
> }
>
> diff --git a/isolation.c b/isolation.c
> index 871bbac..832341a 100644
> --- a/isolation.c
> +++ b/isolation.c
> @@ -105,7 +105,7 @@ static void drop_caps_ep_except(uint64_t keep)
> int i;
>
> if (syscall(SYS_capget, &hdr, data))
> - die("Couldn't get current capabilities: %s", strerror(errno));
> + die_perror("Couldn't get current capabilities");
>
> for (i = 0; i < CAP_WORDS; i++) {
> uint32_t mask = keep >> (32 * i);
> @@ -115,7 +115,7 @@ static void drop_caps_ep_except(uint64_t keep)
> }
>
> if (syscall(SYS_capset, &hdr, data))
> - die("Couldn't drop capabilities: %s", strerror(errno));
> + die_perror("Couldn't drop capabilities");
> }
>
> /**
> @@ -152,19 +152,17 @@ static void clamp_caps(void)
> */
> if (prctl(PR_CAPBSET_DROP, i, 0, 0, 0) &&
> errno != EINVAL && errno != EPERM)
> - die("Couldn't drop cap %i from bounding set: %s",
> - i, strerror(errno));
> + die_perror("Couldn't drop cap %i from bounding set", i);
> }
>
> if (syscall(SYS_capget, &hdr, data))
> - die("Couldn't get current capabilities: %s", strerror(errno));
> + die_perror("Couldn't get current capabilities");
>
> for (i = 0; i < CAP_WORDS; i++)
> data[i].inheritable = 0;
>
> if (syscall(SYS_capset, &hdr, data))
> - die("Couldn't drop inheritable capabilities: %s",
> - strerror(errno));
> + die_perror("Couldn't drop inheritable capabilities");
> }
>
> /**
> @@ -234,34 +232,30 @@ void isolate_user(uid_t uid, gid_t gid, bool use_userns, const char *userns,
> if (setgroups(0, NULL)) {
> /* If we don't have CAP_SETGID, this will EPERM */
> if (errno != EPERM)
> - die("Can't drop supplementary groups: %s",
> - strerror(errno));
> + die_perror("Can't drop supplementary groups");
> }
>
> if (setgid(gid) != 0)
> - die("Can't set GID to %u: %s", gid, strerror(errno));
> + die_perror("Can't set GID to %u", gid);
>
> if (setuid(uid) != 0)
> - die("Can't set UID to %u: %s", uid, strerror(errno));
> + die_perror("Can't set UID to %u", uid);
>
> if (*userns) { /* If given a userns, join it */
> int ufd;
>
> ufd = open(userns, O_RDONLY | O_CLOEXEC);
> if (ufd < 0)
> - die("Couldn't open user namespace %s: %s",
> - userns, strerror(errno));
> + die_perror("Couldn't open user namespace %s", userns);
>
> if (setns(ufd, CLONE_NEWUSER) != 0)
> - die("Couldn't enter user namespace %s: %s",
> - userns, strerror(errno));
> + die_perror("Couldn't enter user namespace %s", userns);
>
> close(ufd);
>
> } else if (use_userns) { /* Create and join a new userns */
> if (unshare(CLONE_NEWUSER) != 0)
> - die("Couldn't create user namespace: %s",
> - strerror(errno));
> + die_perror("Couldn't create user namespace");
> }
>
> /* Joining a new userns gives us full capabilities; drop the
> diff --git a/log.c b/log.c
> index 4aa800d..014fc19 100644
> --- a/log.c
> +++ b/log.c
> @@ -224,7 +224,7 @@ void logfile_init(const char *name, const char *path, size_t size)
> log_file = open(path, O_CREAT | O_TRUNC | O_APPEND | O_RDWR | O_CLOEXEC,
> S_IRUSR | S_IWUSR);
> if (log_file == -1)
> - die("Couldn't open log file %s: %s", path, strerror(errno));
> + die_perror("Couldn't open log file %s", path);
>
> log_size = size ? size : LOGFILE_SIZE_DEFAULT;
>
> diff --git a/netlink.c b/netlink.c
> index d3bea68..4dbddb2 100644
> --- a/netlink.c
> +++ b/netlink.c
> @@ -133,7 +133,7 @@ static uint32_t nl_send(int s, void *req, uint16_t type,
>
> n = send(s, req, len, 0);
> if (n < 0)
> - die("netlink: Failed to send(): %s", strerror(errno));
> + die_perror("netlink: Failed to send()");
> else if (n < len)
> die("netlink: Short send (%zd of %zd bytes)", n, len);
>
> @@ -189,7 +189,7 @@ static struct nlmsghdr *nl_next(int s, char *buf, struct nlmsghdr *nh, ssize_t *
>
> *n = recv(s, buf, NLBUFSIZ, 0);
> if (*n < 0)
> - die("netlink: Failed to recv(): %s", strerror(errno));
> + die_perror("netlink: Failed to recv()");
>
> nh = (struct nlmsghdr *)buf;
> if (!NLMSG_OK(nh, *n))
> diff --git a/passt.c b/passt.c
> index 4bc4251..4b5722f 100644
> --- a/passt.c
> +++ b/passt.c
> @@ -227,15 +227,11 @@ int main(int argc, char **argv)
> __openlog(log_name = "pasta", 0, LOG_DAEMON);
>
> sa.sa_handler = pasta_child_handler;
> - if (sigaction(SIGCHLD, &sa, NULL)) {
> - die("Couldn't install signal handlers: %s",
> - strerror(errno));
> - }
> + if (sigaction(SIGCHLD, &sa, NULL))
> + die_perror("Couldn't install signal handlers");
>
> - if (signal(SIGPIPE, SIG_IGN) == SIG_ERR) {
> - die("Couldn't set disposition for SIGPIPE: %s",
> - strerror(errno));
> - }
> + if (signal(SIGPIPE, SIG_IGN) == SIG_ERR)
> + die_perror("Couldn't set disposition for SIGPIPE");
>
> c.mode = MODE_PASTA;
> } else if (strstr(name, "passt")) {
> diff --git a/pasta.c b/pasta.c
> index ac2f898..1eb4471 100644
> --- a/pasta.c
> +++ b/pasta.c
> @@ -138,17 +138,15 @@ void pasta_open_ns(struct ctx *c, const char *netns)
> int nfd = -1;
>
> nfd = open(netns, O_RDONLY | O_CLOEXEC);
> - if (nfd < 0) {
> - die("Couldn't open network namespace %s: %s",
> - netns, strerror(errno));
> - }
> + if (nfd < 0)
> + die_perror("Couldn't open network namespace %s", netns);
>
> c->pasta_netns_fd = nfd;
>
> NS_CALL(ns_check, c);
>
> if (c->pasta_netns_fd < 0)
> - die("Couldn't switch to pasta namespaces: %s", strerror(errno));
> + die_perror("Couldn't switch to pasta namespaces");
>
> if (!c->no_netns_quit) {
> char buf[PATH_MAX] = { 0 };
> @@ -184,7 +182,7 @@ static int pasta_spawn_cmd(void *arg)
>
> /* We run in a detached PID and mount namespace: mount /proc over */
> if (mount("", "/proc", "proc", 0, NULL))
> - warn("Couldn't mount /proc: %s", strerror(errno));
> + warn_perror("Couldn't mount /proc");
>
> if (write_file("/proc/sys/net/ipv4/ping_group_range", "0 0"))
> warn("Cannot set ping_group_range, ICMP requests might fail");
> @@ -265,7 +263,7 @@ void pasta_start_ns(struct ctx *c, uid_t uid, gid_t gid,
>
> NS_CALL(pasta_wait_for_ns, c);
> if (c->pasta_netns_fd < 0)
> - die("Failed to join network namespace: %s", strerror(errno));
> + die_perror("Failed to join network namespace");
> }
>
> /**
> @@ -277,18 +275,20 @@ void pasta_ns_conf(struct ctx *c)
> int rc = 0;
>
> rc = nl_link_up(nl_sock_ns, 1 /* lo */, 0);
> - if (rc < 0)
> - die("Couldn't bring up loopback interface in namespace: %s",
> - strerror(-rc));
> + if (rc < 0) {
> + errno = -rc;
> + die_perror("Couldn't bring up loopback interface in namespace");
> + }
>
> /* Get or set MAC in target namespace */
> if (MAC_IS_ZERO(c->mac_guest))
> nl_link_get_mac(nl_sock_ns, c->pasta_ifi, c->mac_guest);
> else
> rc = nl_link_set_mac(nl_sock_ns, c->pasta_ifi, c->mac_guest);
> - if (rc < 0)
> - die("Couldn't set MAC address in namespace: %s",
> - strerror(-rc));
> + if (rc < 0) {
> + errno = -rc;
> + die_perror("Couldn't set MAC address in namespace");
> + }
>
> if (c->pasta_conf_ns) {
> nl_link_up(nl_sock_ns, c->pasta_ifi, c->mtu);
> @@ -369,12 +369,12 @@ static int pasta_netns_quit_timer(void)
> struct itimerspec it = { { 1, 0 }, { 1, 0 } }; /* one-second interval */
>
> if (fd == -1) {
> - err("timerfd_create(): %s", strerror(errno));
> + err_perror("timerfd_create()");
> return -errno;
> }
>
> if (timerfd_settime(fd, 0, &it, NULL) < 0) {
> - err("timerfd_settime(): %s", strerror(errno));
> + err_perror("timerfd_settime()");
> close(fd);
> return -errno;
> }
> @@ -467,7 +467,7 @@ void pasta_netns_quit_timer_handler(struct ctx *c, union epoll_ref ref)
>
> n = read(ref.fd, &expirations, sizeof(expirations));
> if (n < 0)
> - die("Namespace watch timer read() error: %s", strerror(errno));
> + die_perror("Namespace watch timer read() error");
> if ((size_t)n < sizeof(expirations))
> warn("Namespace watch timer: short read(): %zi", n);
>
> diff --git a/pcap.c b/pcap.c
> index 507be2a..46cc4b0 100644
> --- a/pcap.c
> +++ b/pcap.c
> @@ -89,10 +89,8 @@ static void pcap_frame(const struct iovec *iov, size_t iovcnt,
> struct iovec hiov = { &h, sizeof(h) };
>
> if (write_remainder(pcap_fd, &hiov, 1, 0) < 0 ||
> - write_remainder(pcap_fd, iov, iovcnt, offset) < 0) {
> - debug("Cannot log packet, length %zu: %s",
> - l2len, strerror(errno));
> - }
> + write_remainder(pcap_fd, iov, iovcnt, offset) < 0)
> + debug_perror("Cannot log packet, length %zu", l2len);
> }
>
> /**
> @@ -178,5 +176,5 @@ void pcap_init(struct ctx *c)
> info("Saving packet capture to %s", c->pcap);
>
> if (write(pcap_fd, &pcap_hdr, sizeof(pcap_hdr)) < 0)
> - warn("Cannot write PCAP header: %s", strerror(errno));
> + warn_perror("Cannot write PCAP header");
> }
> diff --git a/tap.c b/tap.c
> index c9aeff1..eaa7f65 100644
> --- a/tap.c
> +++ b/tap.c
> @@ -325,7 +325,7 @@ static size_t tap_send_frames_pasta(const struct ctx *c,
> size_t framelen = iov_size(iov + i, bufs_per_frame);
>
> if (rc < 0) {
> - debug("tap write: %s", strerror(errno));
> + debug_perror("tap write");
>
> switch (errno) {
> case EAGAIN:
> @@ -387,7 +387,7 @@ static size_t tap_send_frames_passt(const struct ctx *c,
> size_t rembufs = bufs_per_frame - (i % bufs_per_frame);
>
> if (write_remainder(c->fd_tap, &iov[i], rembufs, buf_offset) < 0) {
> - err("tap: partial frame send: %s", strerror(errno));
> + err_perror("tap: partial frame send");
> return i;
> }
> i += rembufs;
> @@ -1122,7 +1122,7 @@ int tap_sock_unix_open(char *sock_path)
> int i;
>
> if (fd < 0)
> - die("UNIX socket: %s", strerror(errno));
> + die_perror("UNIX socket");
>
> for (i = 1; i < UNIX_SOCK_MAX; i++) {
> char *path = addr.sun_path;
> @@ -1135,7 +1135,7 @@ int tap_sock_unix_open(char *sock_path)
>
> ex = socket(AF_UNIX, SOCK_STREAM | SOCK_NONBLOCK, 0);
> if (ex < 0)
> - die("UNIX domain socket check: %s", strerror(errno));
> + die_perror("UNIX domain socket check");
>
> ret = connect(ex, (const struct sockaddr *)&addr, sizeof(addr));
> if (!ret || (errno != ENOENT && errno != ECONNREFUSED &&
> @@ -1155,7 +1155,7 @@ int tap_sock_unix_open(char *sock_path)
> }
>
> if (i == UNIX_SOCK_MAX)
> - die("UNIX socket bind: %s", strerror(errno));
> + die_perror("UNIX socket bind");
>
> info("UNIX domain socket bound at %s", addr.sun_path);
> if (!*sock_path)
> @@ -1261,11 +1261,11 @@ static int tap_ns_tun(void *arg)
>
> fd = open("/dev/net/tun", flags);
> if (fd < 0)
> - die("Failed to open() /dev/net/tun: %s", strerror(errno));
> + die_perror("Failed to open() /dev/net/tun");
>
> rc = ioctl(fd, TUNSETIFF, &ifr);
> if (rc < 0)
> - die("TUNSETIFF failed: %s", strerror(errno));
> + die_perror("TUNSETIFF failed");
>
> if (!(c->pasta_ifi = if_nametoindex(c->pasta_ifn)))
> die("Tap device opened but no network interface found");
> diff --git a/tcp.c b/tcp.c
> index 6852423..231f63b 100644
> --- a/tcp.c
> +++ b/tcp.c
> @@ -1553,19 +1553,15 @@ static void tcp_bind_outbound(const struct ctx *c, int s, sa_family_t af)
> .sin_addr = c->ip4.addr_out,
> };
>
> - if (bind(s, (struct sockaddr *)&addr4, sizeof(addr4))) {
> - debug("Can't bind IPv4 TCP socket address: %s",
> - strerror(errno));
> - }
> + if (bind(s, (struct sockaddr *)&addr4, sizeof(addr4)))
> + debug_perror("IPv4 TCP socket address bind");
> }
>
> if (*c->ip4.ifname_out) {
> if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
> c->ip4.ifname_out,
> - strlen(c->ip4.ifname_out))) {
> - debug("Can't bind IPv4 TCP socket to interface:"
> - " %s", strerror(errno));
> - }
> + strlen(c->ip4.ifname_out)))
> + debug_perror("IPv4 TCP socket interface bind");
> }
> } else if (af == AF_INET6) {
> if (!IN6_IS_ADDR_UNSPECIFIED(&c->ip6.addr_out)) {
> @@ -1575,19 +1571,15 @@ static void tcp_bind_outbound(const struct ctx *c, int s, sa_family_t af)
> .sin6_addr = c->ip6.addr_out,
> };
>
> - if (bind(s, (struct sockaddr *)&addr6, sizeof(addr6))) {
> - debug("Can't bind IPv6 TCP socket address: %s",
> - strerror(errno));
> - }
> + if (bind(s, (struct sockaddr *)&addr6, sizeof(addr6)))
> + debug_perror("IPv6 TCP socket address bind");
> }
>
> if (*c->ip6.ifname_out) {
> if (setsockopt(s, SOL_SOCKET, SO_BINDTODEVICE,
> c->ip6.ifname_out,
> - strlen(c->ip6.ifname_out))) {
> - debug("Can't bind IPv6 TCP socket to interface:"
> - " %s", strerror(errno));
> - }
> + strlen(c->ip6.ifname_out)))
> + debug_perror("IPv6 TCP socket interface bind");
> }
> }
> }
> diff --git a/util.c b/util.c
> index 77448ec..dd2e57f 100644
> --- a/util.c
> +++ b/util.c
> @@ -315,7 +315,7 @@ void bitmap_or(uint8_t *dst, size_t size, const uint8_t *a, const uint8_t *b)
> void ns_enter(const struct ctx *c)
> {
> if (setns(c->pasta_netns_fd, CLONE_NEWNET))
> - die("setns() failed entering netns: %s", strerror(errno));
> + die_perror("setns() failed entering netns");
> }
>
> /**
> @@ -330,10 +330,8 @@ bool ns_is_init(void)
> bool ret = true;
> int fd;
>
> - if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0) {
> - die("Can't determine if we're in init namespace: %s",
> - strerror(errno));
> - }
> + if ((fd = open("/proc/self/uid_map", O_RDONLY | O_CLOEXEC)) < 0)
> + die_perror("Can't determine if we're in init namespace");
>
> if (read(fd, buf, sizeof(root_uid_map)) != sizeof(root_uid_map) - 1 ||
> strncmp(buf, root_uid_map, sizeof(root_uid_map)))
> @@ -509,7 +507,7 @@ int write_file(const char *path, const char *buf)
> size_t len = strlen(buf);
>
> if (fd < 0) {
> - warn("Could not open %s: %s", path, strerror(errno));
> + warn_perror("Could not open %s", path);
> return -1;
> }
>
> @@ -517,7 +515,7 @@ int write_file(const char *path, const char *buf)
> ssize_t rc = write(fd, buf, len);
>
> if (rc <= 0) {
> - warn("Couldn't write to %s: %s", path, strerror(errno));
> + warn_perror("Couldn't write to %s", path);
> break;
> }
>
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-18 0:36 ` David Gibson
@ 2024-06-18 6:00 ` Stefano Brivio
2024-06-19 2:06 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-18 6:00 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Tue, 18 Jun 2024 10:36:28 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Mon, Jun 17, 2024 at 02:03:14PM +0200, Stefano Brivio wrote:
> > If we don't run in foreground, we close standard error as we
> > daemonise, so it makes no sense to check if the controlling terminal
> > is an interactive terminal or if --force-stderr was given, to decide
> > if we want to log to standard error.
> >
> > Make --force-stderr depend on --foreground.
> >
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
>
> Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
>
> > ---
> > conf.c | 3 +++
> > passt.c | 2 +-
> > 2 files changed, 4 insertions(+), 1 deletion(-)
> >
> > diff --git a/conf.c b/conf.c
> > index 94b3ed6..dbdbb62 100644
> > --- a/conf.c
> > +++ b/conf.c
> > @@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
> >
> > conf_ugid(runas, &uid, &gid);
> >
> > + if (!c->foreground && c->force_stderr)
> > + die("Can't log to standard error if not running in foreground");
> > +
> > if (logfile) {
> > logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
> > logfile, logsize);
> > diff --git a/passt.c b/passt.c
> > index a5e2c5a..aa9648a 100644
> > --- a/passt.c
> > +++ b/passt.c
> > @@ -302,7 +302,7 @@ int main(int argc, char **argv)
> > if (isolate_prefork(&c))
> > die("Failed to sandbox process, exiting");
> >
> > - if (!c.force_stderr && !isatty(fileno(stderr)))
> > + if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
>
> What's the rationale for the isatty() check in any case?
To implement the behaviour from the man page:
-e, --stderr
Log to standard error too. Default is to log to the sys‐
tem logger only, if started from an interactive terminal,
and to both system logger and standard error otherwise.
which was needed, in turn, because of earlier versions of passt and of
the KubeVirt integration where passt was running in foreground, but (of
course) not attached to a terminal, and there was no option to force
printing to standard error.
Given that KubeVirt doesn't have a system logger, it was otherwise
impossible to get messages out of passt.
It's an abomination that just adds complexity now, and I don't think
anybody uses it that way anymore. I guess we should drop that, together
with qrap, in a few months from now.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels
2024-06-18 0:39 ` David Gibson
@ 2024-06-18 6:01 ` Stefano Brivio
0 siblings, 0 replies; 27+ messages in thread
From: Stefano Brivio @ 2024-06-18 6:01 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Tue, 18 Jun 2024 10:39:13 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Mon, Jun 17, 2024 at 02:03:15PM +0200, Stefano Brivio wrote:
> > We currently use a LOG_EMERG log mask to represent the fact that we
> > don't know yet what the mask resulting from configuration should be,
> > before the command line is parsed.
> >
> > However, we have the necessity of representing another phase as well,
> > that is, configuration is parsed but we didn't daemonise yet, or
> > we're not ready for operation yet. The next patch will add that
> > notion explicitly.
> >
> > Mapping these cases to further log levels isn't really practical.
> > Introduce internal log flags to represent them, instead of abusing
> > log priorities.
> >
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
>
> I like not abusing the log priorities. But, do we actually need a
> flags field with constants and helpers, rather than just
> bool log_conf_parsed;
> and open code it from there?
Right, we probably don't need a flags field. I went this way because I
thought I needed more than two flags, originally, but I can't see that
happening after all, so I'll switch to two boolean flags.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-18 0:44 ` David Gibson
@ 2024-06-18 6:01 ` Stefano Brivio
2024-06-19 2:10 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-18 6:01 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Tue, 18 Jun 2024 10:44:20 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Mon, Jun 17, 2024 at 02:03:16PM +0200, Stefano Brivio wrote:
> > After commit 15001b39ef1d ("conf: set the log level much earlier"), we
> > had a phase during initialisation when messages wouldn't be printed to
> > standard error anymore.
> >
> > Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
> > stderr until we detach") fixed that, but only for the case where no
> > log files are given.
> >
> > If a log file is configured, vlogmsg() will not call passt_vsyslog(),
> > but during initialisation, LOG_PERROR is set, so to avoid duplicated
> > prints (which would result from passt_vsyslog() printing to stderr),
> > we don't call fprintf() from vlogmsg() either.
> >
> > This is getting a bit too complicated. Instead of abusing LOG_PERROR,
> > define an internal logging flag that clearly represents that we're not
> > done with the initialisation phase yet.
> >
> > If this flag is not set, make sure we always print to stderr, if the
> > log mask matches. Then, set LOG_PERROR only as we set this internal
> > flag, to make sure we don't duplicate messages.
> >
> > Reported-by: Yalan Zhang <yalzhang@redhat.com>
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > ---
> > log.c | 4 +++-
> > log.h | 1 +
> > passt.1 | 3 ++-
> > passt.c | 17 ++++++++++-------
> > 4 files changed, 16 insertions(+), 9 deletions(-)
> >
> > diff --git a/log.c b/log.c
> > index 3b5a1c6..939bb93 100644
> > --- a/log.c
> > +++ b/log.c
> > @@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
> > void vlogmsg(int pri, const char *format, va_list ap)
> > {
> > bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> > + bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
>
> As in 2/6 would just a global bool be simpler than flags.
>
> > bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> > struct timespec tp;
> >
> > @@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
> > va_end(ap2);
> > }
> >
> > - if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
> > + if (debug_print || early_print ||
> > + (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
> > (void)vfprintf(stderr, format, ap);
> > if (format[strlen(format)] != '\n')
> > fprintf(stderr, "\n");
> > diff --git a/log.h b/log.h
> > index 6a3224a..680baab 100644
> > --- a/log.h
> > +++ b/log.h
> > @@ -10,6 +10,7 @@
> > #include <syslog.h>
> >
> > #define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> > +#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
> >
> > #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> > #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> > diff --git a/passt.1 b/passt.1
> > index 3a23a43..31e528e 100644
> > --- a/passt.1
> > +++ b/passt.1
> > @@ -99,7 +99,8 @@ 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.
> > +Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
> > +and not to the system logger.
>
> IIUC when -l is set we'll log to the logfile _as well as_ stderr
> before we daemonize. The description above doesn't exactly contradict
> that, but seems to imply something different.
Is that because "(once initialisation is complete)" doesn't clearly
refer to "not to standard error"?
I could go with something slightly more verbose:
Log to file \fIPATH\fR, not to standard error, and not to the system
logger.
During initialisation phase, that is, before forking to background,
or before being ready for communication when running in foreground,
messages are always printed to standard error as well.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 4/6] log: Add _perror() logging function variants
2024-06-18 0:46 ` David Gibson
@ 2024-06-18 6:02 ` Stefano Brivio
2024-06-19 2:11 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-18 6:02 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Tue, 18 Jun 2024 10:46:36 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Mon, Jun 17, 2024 at 02:03:17PM +0200, Stefano Brivio wrote:
> > In many places, we have direct perror() calls, which completely bypass
> > logging functions and log files.
> >
> > They are definitely convenient: offer similar convenience with
> > _perror() logging variants, so that we can drop those direct perror()
> > calls.
> >
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
>
> Hm, for anything bigger than like a screenful of code, I generally
> find an explicit message with strerror(errno) more useful than
> perror() or equivalents, but I guess if you think these are useful.
Okay, yes, it probably makes sense to have more descriptive messages as
you suggest in the comment to 5/6, but even then, we still have a lot
of cases like this one (from 6/6):
- warn("lseek() failed on /proc/net file: %s", strerror(errno));
+ warn_perror("lseek() failed on /proc/net file");
where these _perror() variants make for tidier code, I find, regardless
of the error message itself.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 6/6] treewide: Replace strerror() calls
2024-06-18 0:51 ` David Gibson
@ 2024-06-18 6:02 ` Stefano Brivio
0 siblings, 0 replies; 27+ messages in thread
From: Stefano Brivio @ 2024-06-18 6:02 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Tue, 18 Jun 2024 10:51:49 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Mon, Jun 17, 2024 at 02:03:19PM +0200, Stefano Brivio wrote:
> > Now that we have logging functions embedding perror() functionality,
> > we can make _some_ calls more terse by using them. In many places,
> > the strerror() calls are still more convenient because, for example,
> > they are used in flow debugging functions, or because the return code
> > variable of interest is not 'errno'.
> >
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
>
> Hrm, this also changes
> What we were doing: <strerror>
> into
> <strerror>: What we were doing
>
> which I think is a weirder convention.
Oops, that was not intended, I forgot to switch it back in 4/6 after
some experiments. I'll fix this in 4/6.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-18 6:00 ` Stefano Brivio
@ 2024-06-19 2:06 ` David Gibson
2024-06-19 8:13 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-19 2:06 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 3432 bytes --]
On Tue, Jun 18, 2024 at 08:00:14AM +0200, Stefano Brivio wrote:
> On Tue, 18 Jun 2024 10:36:28 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Mon, Jun 17, 2024 at 02:03:14PM +0200, Stefano Brivio wrote:
> > > If we don't run in foreground, we close standard error as we
> > > daemonise, so it makes no sense to check if the controlling terminal
> > > is an interactive terminal or if --force-stderr was given, to decide
> > > if we want to log to standard error.
> > >
> > > Make --force-stderr depend on --foreground.
> > >
> > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> >
> > Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
> >
> > > ---
> > > conf.c | 3 +++
> > > passt.c | 2 +-
> > > 2 files changed, 4 insertions(+), 1 deletion(-)
> > >
> > > diff --git a/conf.c b/conf.c
> > > index 94b3ed6..dbdbb62 100644
> > > --- a/conf.c
> > > +++ b/conf.c
> > > @@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
> > >
> > > conf_ugid(runas, &uid, &gid);
> > >
> > > + if (!c->foreground && c->force_stderr)
> > > + die("Can't log to standard error if not running in foreground");
> > > +
> > > if (logfile) {
> > > logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
> > > logfile, logsize);
> > > diff --git a/passt.c b/passt.c
> > > index a5e2c5a..aa9648a 100644
> > > --- a/passt.c
> > > +++ b/passt.c
> > > @@ -302,7 +302,7 @@ int main(int argc, char **argv)
> > > if (isolate_prefork(&c))
> > > die("Failed to sandbox process, exiting");
> > >
> > > - if (!c.force_stderr && !isatty(fileno(stderr)))
> > > + if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
> >
> > What's the rationale for the isatty() check in any case?
>
> To implement the behaviour from the man page:
>
> -e, --stderr
> Log to standard error too. Default is to log to the sys‐
> tem logger only, if started from an interactive terminal,
> and to both system logger and standard error otherwise.
Hmm.. maybe I'm getting confused reading either the man page or the
code, but isn't that the opposite of what the code is doing? The code
appears to be opening the log if we're *not* on an interactive terminal.
> which was needed, in turn, because of earlier versions of passt and of
> the KubeVirt integration where passt was running in foreground, but (of
> course) not attached to a terminal, and there was no option to force
> printing to standard error.
>
> Given that KubeVirt doesn't have a system logger, it was otherwise
> impossible to get messages out of passt.
>
> It's an abomination that just adds complexity now, and I don't think
> anybody uses it that way anymore. I guess we should drop that, together
> with qrap, in a few months from now.
Right.. but what I'm after is the rationale for this depending on
whether it's an interactive terminal at all. Seems to me the logical
thing to do is to (by default) always log to stderr before
daemonization (i.e. forever when in foreground mode), then to logfile
and/or syslog after daemonization. Regardless of whether there's a
tty or not.
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-18 6:01 ` Stefano Brivio
@ 2024-06-19 2:10 ` David Gibson
2024-06-19 8:17 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-19 2:10 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 4948 bytes --]
On Tue, Jun 18, 2024 at 08:01:31AM +0200, Stefano Brivio wrote:
> On Tue, 18 Jun 2024 10:44:20 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Mon, Jun 17, 2024 at 02:03:16PM +0200, Stefano Brivio wrote:
> > > After commit 15001b39ef1d ("conf: set the log level much earlier"), we
> > > had a phase during initialisation when messages wouldn't be printed to
> > > standard error anymore.
> > >
> > > Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
> > > stderr until we detach") fixed that, but only for the case where no
> > > log files are given.
> > >
> > > If a log file is configured, vlogmsg() will not call passt_vsyslog(),
> > > but during initialisation, LOG_PERROR is set, so to avoid duplicated
> > > prints (which would result from passt_vsyslog() printing to stderr),
> > > we don't call fprintf() from vlogmsg() either.
> > >
> > > This is getting a bit too complicated. Instead of abusing LOG_PERROR,
> > > define an internal logging flag that clearly represents that we're not
> > > done with the initialisation phase yet.
> > >
> > > If this flag is not set, make sure we always print to stderr, if the
> > > log mask matches. Then, set LOG_PERROR only as we set this internal
> > > flag, to make sure we don't duplicate messages.
> > >
> > > Reported-by: Yalan Zhang <yalzhang@redhat.com>
> > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > > ---
> > > log.c | 4 +++-
> > > log.h | 1 +
> > > passt.1 | 3 ++-
> > > passt.c | 17 ++++++++++-------
> > > 4 files changed, 16 insertions(+), 9 deletions(-)
> > >
> > > diff --git a/log.c b/log.c
> > > index 3b5a1c6..939bb93 100644
> > > --- a/log.c
> > > +++ b/log.c
> > > @@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
> > > void vlogmsg(int pri, const char *format, va_list ap)
> > > {
> > > bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> > > + bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
> >
> > As in 2/6 would just a global bool be simpler than flags.
> >
> > > bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> > > struct timespec tp;
> > >
> > > @@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
> > > va_end(ap2);
> > > }
> > >
> > > - if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
> > > + if (debug_print || early_print ||
> > > + (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
> > > (void)vfprintf(stderr, format, ap);
> > > if (format[strlen(format)] != '\n')
> > > fprintf(stderr, "\n");
> > > diff --git a/log.h b/log.h
> > > index 6a3224a..680baab 100644
> > > --- a/log.h
> > > +++ b/log.h
> > > @@ -10,6 +10,7 @@
> > > #include <syslog.h>
> > >
> > > #define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> > > +#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
> > >
> > > #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> > > #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> > > diff --git a/passt.1 b/passt.1
> > > index 3a23a43..31e528e 100644
> > > --- a/passt.1
> > > +++ b/passt.1
> > > @@ -99,7 +99,8 @@ 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.
> > > +Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
> > > +and not to the system logger.
> >
> > IIUC when -l is set we'll log to the logfile _as well as_ stderr
> > before we daemonize. The description above doesn't exactly contradict
> > that, but seems to imply something different.
>
> Is that because "(once initialisation is complete)" doesn't clearly
> refer to "not to standard error"?
Yes, or rather that it's not entirely clear it refers *only* to that
clause and not to the "Log to file" part at the beginning.
> I could go with something slightly more verbose:
>
> Log to file \fIPATH\fR, not to standard error, and not to the system
> logger.
>
> During initialisation phase, that is, before forking to background,
> or before being ready for communication when running in foreground,
> messages are always printed to standard error as well.
Hrm... so I want to say:
Log to file PATH instead of to system logger.
Which may not be totally accurate for the current behaviour... but
seems like it might be a sensible behaviour. That is, we typically
log to syslog, but -l replaces it with a logfile. Regardless of
which, under some circumstances we'll also log to stderr.
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 4/6] log: Add _perror() logging function variants
2024-06-18 6:02 ` Stefano Brivio
@ 2024-06-19 2:11 ` David Gibson
2024-06-19 8:25 ` Stefano Brivio
0 siblings, 1 reply; 27+ messages in thread
From: David Gibson @ 2024-06-19 2:11 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 1642 bytes --]
On Tue, Jun 18, 2024 at 08:02:16AM +0200, Stefano Brivio wrote:
> On Tue, 18 Jun 2024 10:46:36 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Mon, Jun 17, 2024 at 02:03:17PM +0200, Stefano Brivio wrote:
> > > In many places, we have direct perror() calls, which completely bypass
> > > logging functions and log files.
> > >
> > > They are definitely convenient: offer similar convenience with
> > > _perror() logging variants, so that we can drop those direct perror()
> > > calls.
> > >
> > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> >
> > Hm, for anything bigger than like a screenful of code, I generally
> > find an explicit message with strerror(errno) more useful than
> > perror() or equivalents, but I guess if you think these are useful.
>
> Okay, yes, it probably makes sense to have more descriptive messages as
> you suggest in the comment to 5/6, but even then, we still have a lot
> of cases like this one (from 6/6):
>
> - warn("lseek() failed on /proc/net file: %s", strerror(errno));
> + warn_perror("lseek() failed on /proc/net file");
>
> where these _perror() variants make for tidier code, I find, regardless
> of the error message itself.
Eh, I mildly prefer the first variant. It is slightly longer, but
makes it very clear where the strerror piece is going to appear in the
context of the whole message. It's not a strong preference, though.
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-19 2:06 ` David Gibson
@ 2024-06-19 8:13 ` Stefano Brivio
2024-06-20 0:12 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-19 8:13 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Wed, 19 Jun 2024 12:06:01 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Tue, Jun 18, 2024 at 08:00:14AM +0200, Stefano Brivio wrote:
> > On Tue, 18 Jun 2024 10:36:28 +1000
> > David Gibson <david@gibson.dropbear.id.au> wrote:
> >
> > > On Mon, Jun 17, 2024 at 02:03:14PM +0200, Stefano Brivio wrote:
> > > > If we don't run in foreground, we close standard error as we
> > > > daemonise, so it makes no sense to check if the controlling terminal
> > > > is an interactive terminal or if --force-stderr was given, to decide
> > > > if we want to log to standard error.
> > > >
> > > > Make --force-stderr depend on --foreground.
> > > >
> > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > >
> > > Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
> > >
> > > > ---
> > > > conf.c | 3 +++
> > > > passt.c | 2 +-
> > > > 2 files changed, 4 insertions(+), 1 deletion(-)
> > > >
> > > > diff --git a/conf.c b/conf.c
> > > > index 94b3ed6..dbdbb62 100644
> > > > --- a/conf.c
> > > > +++ b/conf.c
> > > > @@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
> > > >
> > > > conf_ugid(runas, &uid, &gid);
> > > >
> > > > + if (!c->foreground && c->force_stderr)
> > > > + die("Can't log to standard error if not running in foreground");
> > > > +
> > > > if (logfile) {
> > > > logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
> > > > logfile, logsize);
> > > > diff --git a/passt.c b/passt.c
> > > > index a5e2c5a..aa9648a 100644
> > > > --- a/passt.c
> > > > +++ b/passt.c
> > > > @@ -302,7 +302,7 @@ int main(int argc, char **argv)
> > > > if (isolate_prefork(&c))
> > > > die("Failed to sandbox process, exiting");
> > > >
> > > > - if (!c.force_stderr && !isatty(fileno(stderr)))
> > > > + if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
> > >
> > > What's the rationale for the isatty() check in any case?
> >
> > To implement the behaviour from the man page:
> >
> > -e, --stderr
> > Log to standard error too. Default is to log to the sys‐
> > tem logger only, if started from an interactive terminal,
> > and to both system logger and standard error otherwise.
>
> Hmm.. maybe I'm getting confused reading either the man page or the
> code, but isn't that the opposite of what the code is doing? The code
> appears to be opening the log if we're *not* on an interactive terminal.
Ouch, right, this became the opposite of the original intended
behaviour from 84a62b79a2bc ("passt: Also log to stderr, don't fork to
background if not interactive") which again was implemented as a workaround
for issues in the old version of the KubeVirt integration that's not used
anymore.
The swap happened in 1e49d194d017 ("passt, pasta: Introduce command-line
options and port re-mapping"), which makes me think that we should probably
think of a reasonable default and meaning of --stderr regardless of the
original workaround (which is surely not needed anymore) and implement it.
Probably it would make sense to log to standard error if we're running in
foreground, unless a log file is specified. The check above would simply
become:
if (!c.foreground)
and we could accept -e, --stderr for compatibility only, but it wouldn't
do anything.
> > which was needed, in turn, because of earlier versions of passt and of
> > the KubeVirt integration where passt was running in foreground, but (of
> > course) not attached to a terminal, and there was no option to force
> > printing to standard error.
> >
> > Given that KubeVirt doesn't have a system logger, it was otherwise
> > impossible to get messages out of passt.
> >
> > It's an abomination that just adds complexity now, and I don't think
> > anybody uses it that way anymore. I guess we should drop that, together
> > with qrap, in a few months from now.
>
> Right.. but what I'm after is the rationale for this depending on
> whether it's an interactive terminal at all. Seems to me the logical
> thing to do is to (by default) always log to stderr before
> daemonization (i.e. forever when in foreground mode), then to logfile
> and/or syslog after daemonization. Regardless of whether there's a
> tty or not.
The original rationale was that if it was started from an interactive
terminal, I didn't want the whole spam associated with it, but if it was
started from a non-interactive terminal (KubeVirt integration), that was
the only way to get messages out.
Then we had the opposite issue with KubeVirt (which is the reason why
the log file disables stderr logging): passt started in a
non-interactive terminal, but stderr logging would cause a lot of
overhead in some KubeVirt component.
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-19 2:10 ` David Gibson
@ 2024-06-19 8:17 ` Stefano Brivio
2024-06-20 0:12 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-19 8:17 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Wed, 19 Jun 2024 12:10:38 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Tue, Jun 18, 2024 at 08:01:31AM +0200, Stefano Brivio wrote:
> > On Tue, 18 Jun 2024 10:44:20 +1000
> > David Gibson <david@gibson.dropbear.id.au> wrote:
> >
> > > On Mon, Jun 17, 2024 at 02:03:16PM +0200, Stefano Brivio wrote:
> > > > After commit 15001b39ef1d ("conf: set the log level much earlier"), we
> > > > had a phase during initialisation when messages wouldn't be printed to
> > > > standard error anymore.
> > > >
> > > > Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
> > > > stderr until we detach") fixed that, but only for the case where no
> > > > log files are given.
> > > >
> > > > If a log file is configured, vlogmsg() will not call passt_vsyslog(),
> > > > but during initialisation, LOG_PERROR is set, so to avoid duplicated
> > > > prints (which would result from passt_vsyslog() printing to stderr),
> > > > we don't call fprintf() from vlogmsg() either.
> > > >
> > > > This is getting a bit too complicated. Instead of abusing LOG_PERROR,
> > > > define an internal logging flag that clearly represents that we're not
> > > > done with the initialisation phase yet.
> > > >
> > > > If this flag is not set, make sure we always print to stderr, if the
> > > > log mask matches. Then, set LOG_PERROR only as we set this internal
> > > > flag, to make sure we don't duplicate messages.
> > > >
> > > > Reported-by: Yalan Zhang <yalzhang@redhat.com>
> > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > > > ---
> > > > log.c | 4 +++-
> > > > log.h | 1 +
> > > > passt.1 | 3 ++-
> > > > passt.c | 17 ++++++++++-------
> > > > 4 files changed, 16 insertions(+), 9 deletions(-)
> > > >
> > > > diff --git a/log.c b/log.c
> > > > index 3b5a1c6..939bb93 100644
> > > > --- a/log.c
> > > > +++ b/log.c
> > > > @@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
> > > > void vlogmsg(int pri, const char *format, va_list ap)
> > > > {
> > > > bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> > > > + bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
> > >
> > > As in 2/6 would just a global bool be simpler than flags.
> > >
> > > > bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> > > > struct timespec tp;
> > > >
> > > > @@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
> > > > va_end(ap2);
> > > > }
> > > >
> > > > - if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
> > > > + if (debug_print || early_print ||
> > > > + (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
> > > > (void)vfprintf(stderr, format, ap);
> > > > if (format[strlen(format)] != '\n')
> > > > fprintf(stderr, "\n");
> > > > diff --git a/log.h b/log.h
> > > > index 6a3224a..680baab 100644
> > > > --- a/log.h
> > > > +++ b/log.h
> > > > @@ -10,6 +10,7 @@
> > > > #include <syslog.h>
> > > >
> > > > #define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> > > > +#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
> > > >
> > > > #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> > > > #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> > > > diff --git a/passt.1 b/passt.1
> > > > index 3a23a43..31e528e 100644
> > > > --- a/passt.1
> > > > +++ b/passt.1
> > > > @@ -99,7 +99,8 @@ 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.
> > > > +Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
> > > > +and not to the system logger.
> > >
> > > IIUC when -l is set we'll log to the logfile _as well as_ stderr
> > > before we daemonize. The description above doesn't exactly contradict
> > > that, but seems to imply something different.
> >
> > Is that because "(once initialisation is complete)" doesn't clearly
> > refer to "not to standard error"?
>
> Yes, or rather that it's not entirely clear it refers *only* to that
> clause and not to the "Log to file" part at the beginning.
>
> > I could go with something slightly more verbose:
> >
> > Log to file \fIPATH\fR, not to standard error, and not to the system
> > logger.
> >
> > During initialisation phase, that is, before forking to background,
> > or before being ready for communication when running in foreground,
> > messages are always printed to standard error as well.
>
> Hrm... so I want to say:
>
> Log to file PATH instead of to system logger.
>
> Which may not be totally accurate for the current behaviour... but
> seems like it might be a sensible behaviour. That is, we typically
> log to syslog, but -l replaces it with a logfile. Regardless of
> which, under some circumstances we'll also log to stderr.
No, not really: it's not regardless of that. If the log file is given,
we don't want to log to standard error (once we're up and running)
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 4/6] log: Add _perror() logging function variants
2024-06-19 2:11 ` David Gibson
@ 2024-06-19 8:25 ` Stefano Brivio
2024-06-20 0:13 ` David Gibson
0 siblings, 1 reply; 27+ messages in thread
From: Stefano Brivio @ 2024-06-19 8:25 UTC (permalink / raw)
To: David Gibson; +Cc: passt-dev, Yalan Zhang
On Wed, 19 Jun 2024 12:11:51 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:
> On Tue, Jun 18, 2024 at 08:02:16AM +0200, Stefano Brivio wrote:
> > On Tue, 18 Jun 2024 10:46:36 +1000
> > David Gibson <david@gibson.dropbear.id.au> wrote:
> >
> > > On Mon, Jun 17, 2024 at 02:03:17PM +0200, Stefano Brivio wrote:
> > > > In many places, we have direct perror() calls, which completely bypass
> > > > logging functions and log files.
> > > >
> > > > They are definitely convenient: offer similar convenience with
> > > > _perror() logging variants, so that we can drop those direct perror()
> > > > calls.
> > > >
> > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > >
> > > Hm, for anything bigger than like a screenful of code, I generally
> > > find an explicit message with strerror(errno) more useful than
> > > perror() or equivalents, but I guess if you think these are useful.
> >
> > Okay, yes, it probably makes sense to have more descriptive messages as
> > you suggest in the comment to 5/6, but even then, we still have a lot
> > of cases like this one (from 6/6):
> >
> > - warn("lseek() failed on /proc/net file: %s", strerror(errno));
> > + warn_perror("lseek() failed on /proc/net file");
> >
> > where these _perror() variants make for tidier code, I find, regardless
> > of the error message itself.
>
> Eh, I mildly prefer the first variant. It is slightly longer, but
> makes it very clear where the strerror piece is going to appear in the
> context of the whole message. It's not a strong preference, though.
Well, it depends. If you're used to perror() it's obvious where the
error description will appear, and it's actually faster for me to read
something called "_perror" than %s plus the argument. Plus we can save
a few lines like that and substantially improve readability in some
cases:
if (prctl(PR_CAPBSET_DROP, i, 0, 0, 0) &&
errno != EINVAL && errno != EPERM)
- die("Couldn't drop cap %i from bounding set: %s",
- i, strerror(errno));
+ die_perror("Couldn't drop cap %i from bounding set", i);
--
Stefano
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it
2024-06-19 8:13 ` Stefano Brivio
@ 2024-06-20 0:12 ` David Gibson
0 siblings, 0 replies; 27+ messages in thread
From: David Gibson @ 2024-06-20 0:12 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 5602 bytes --]
On Wed, Jun 19, 2024 at 10:13:46AM +0200, Stefano Brivio wrote:
> On Wed, 19 Jun 2024 12:06:01 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Tue, Jun 18, 2024 at 08:00:14AM +0200, Stefano Brivio wrote:
> > > On Tue, 18 Jun 2024 10:36:28 +1000
> > > David Gibson <david@gibson.dropbear.id.au> wrote:
> > >
> > > > On Mon, Jun 17, 2024 at 02:03:14PM +0200, Stefano Brivio wrote:
> > > > > If we don't run in foreground, we close standard error as we
> > > > > daemonise, so it makes no sense to check if the controlling terminal
> > > > > is an interactive terminal or if --force-stderr was given, to decide
> > > > > if we want to log to standard error.
> > > > >
> > > > > Make --force-stderr depend on --foreground.
> > > > >
> > > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > > >
> > > > Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
> > > >
> > > > > ---
> > > > > conf.c | 3 +++
> > > > > passt.c | 2 +-
> > > > > 2 files changed, 4 insertions(+), 1 deletion(-)
> > > > >
> > > > > diff --git a/conf.c b/conf.c
> > > > > index 94b3ed6..dbdbb62 100644
> > > > > --- a/conf.c
> > > > > +++ b/conf.c
> > > > > @@ -1693,6 +1693,9 @@ void conf(struct ctx *c, int argc, char **argv)
> > > > >
> > > > > conf_ugid(runas, &uid, &gid);
> > > > >
> > > > > + if (!c->foreground && c->force_stderr)
> > > > > + die("Can't log to standard error if not running in foreground");
> > > > > +
> > > > > if (logfile) {
> > > > > logfile_init(c->mode == MODE_PASTA ? "pasta" : "passt",
> > > > > logfile, logsize);
> > > > > diff --git a/passt.c b/passt.c
> > > > > index a5e2c5a..aa9648a 100644
> > > > > --- a/passt.c
> > > > > +++ b/passt.c
> > > > > @@ -302,7 +302,7 @@ int main(int argc, char **argv)
> > > > > if (isolate_prefork(&c))
> > > > > die("Failed to sandbox process, exiting");
> > > > >
> > > > > - if (!c.force_stderr && !isatty(fileno(stderr)))
> > > > > + if (!c.foreground || (!c.force_stderr && !isatty(fileno(stderr))))
> > > >
> > > > What's the rationale for the isatty() check in any case?
> > >
> > > To implement the behaviour from the man page:
> > >
> > > -e, --stderr
> > > Log to standard error too. Default is to log to the sys‐
> > > tem logger only, if started from an interactive terminal,
> > > and to both system logger and standard error otherwise.
> >
> > Hmm.. maybe I'm getting confused reading either the man page or the
> > code, but isn't that the opposite of what the code is doing? The code
> > appears to be opening the log if we're *not* on an interactive terminal.
>
> Ouch, right, this became the opposite of the original intended
> behaviour from 84a62b79a2bc ("passt: Also log to stderr, don't fork to
> background if not interactive") which again was implemented as a workaround
> for issues in the old version of the KubeVirt integration that's not used
> anymore.
>
> The swap happened in 1e49d194d017 ("passt, pasta: Introduce command-line
> options and port re-mapping"), which makes me think that we should probably
> think of a reasonable default and meaning of --stderr regardless of the
> original workaround (which is surely not needed anymore) and implement it.
I agree.
> Probably it would make sense to log to standard error if we're running in
> foreground, unless a log file is specified. The check above would simply
> become:
I think logging to stderr when foreground even if we do have a logfile
makes even more sense.
> if (!c.foreground)
>
> and we could accept -e, --stderr for compatibility only, but it wouldn't
> do anything.
>
> > > which was needed, in turn, because of earlier versions of passt and of
> > > the KubeVirt integration where passt was running in foreground, but (of
> > > course) not attached to a terminal, and there was no option to force
> > > printing to standard error.
> > >
> > > Given that KubeVirt doesn't have a system logger, it was otherwise
> > > impossible to get messages out of passt.
> > >
> > > It's an abomination that just adds complexity now, and I don't think
> > > anybody uses it that way anymore. I guess we should drop that, together
> > > with qrap, in a few months from now.
> >
> > Right.. but what I'm after is the rationale for this depending on
> > whether it's an interactive terminal at all. Seems to me the logical
> > thing to do is to (by default) always log to stderr before
> > daemonization (i.e. forever when in foreground mode), then to logfile
> > and/or syslog after daemonization. Regardless of whether there's a
> > tty or not.
>
> The original rationale was that if it was started from an interactive
> terminal, I didn't want the whole spam associated with it, but if it was
> started from a non-interactive terminal (KubeVirt integration), that was
> the only way to get messages out.
>
> Then we had the opposite issue with KubeVirt (which is the reason why
> the log file disables stderr logging): passt started in a
> non-interactive terminal, but stderr logging would cause a lot of
> overhead in some KubeVirt component.
Again, KubeVirt can fix that with the Go equivalent of '2> /dev/null'.
I don't think we should make our semantics more complex for the sake
of that.
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete
2024-06-19 8:17 ` Stefano Brivio
@ 2024-06-20 0:12 ` David Gibson
0 siblings, 0 replies; 27+ messages in thread
From: David Gibson @ 2024-06-20 0:12 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 5731 bytes --]
On Wed, Jun 19, 2024 at 10:17:21AM +0200, Stefano Brivio wrote:
> On Wed, 19 Jun 2024 12:10:38 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Tue, Jun 18, 2024 at 08:01:31AM +0200, Stefano Brivio wrote:
> > > On Tue, 18 Jun 2024 10:44:20 +1000
> > > David Gibson <david@gibson.dropbear.id.au> wrote:
> > >
> > > > On Mon, Jun 17, 2024 at 02:03:16PM +0200, Stefano Brivio wrote:
> > > > > After commit 15001b39ef1d ("conf: set the log level much earlier"), we
> > > > > had a phase during initialisation when messages wouldn't be printed to
> > > > > standard error anymore.
> > > > >
> > > > > Commit f67238aa864d ("passt, log: Call __openlog() earlier, log to
> > > > > stderr until we detach") fixed that, but only for the case where no
> > > > > log files are given.
> > > > >
> > > > > If a log file is configured, vlogmsg() will not call passt_vsyslog(),
> > > > > but during initialisation, LOG_PERROR is set, so to avoid duplicated
> > > > > prints (which would result from passt_vsyslog() printing to stderr),
> > > > > we don't call fprintf() from vlogmsg() either.
> > > > >
> > > > > This is getting a bit too complicated. Instead of abusing LOG_PERROR,
> > > > > define an internal logging flag that clearly represents that we're not
> > > > > done with the initialisation phase yet.
> > > > >
> > > > > If this flag is not set, make sure we always print to stderr, if the
> > > > > log mask matches. Then, set LOG_PERROR only as we set this internal
> > > > > flag, to make sure we don't duplicate messages.
> > > > >
> > > > > Reported-by: Yalan Zhang <yalzhang@redhat.com>
> > > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > > > > ---
> > > > > log.c | 4 +++-
> > > > > log.h | 1 +
> > > > > passt.1 | 3 ++-
> > > > > passt.c | 17 ++++++++++-------
> > > > > 4 files changed, 16 insertions(+), 9 deletions(-)
> > > > >
> > > > > diff --git a/log.c b/log.c
> > > > > index 3b5a1c6..939bb93 100644
> > > > > --- a/log.c
> > > > > +++ b/log.c
> > > > > @@ -49,6 +49,7 @@ int log_trace; /* --trace mode enabled */
> > > > > void vlogmsg(int pri, const char *format, va_list ap)
> > > > > {
> > > > > bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
> > > > > + bool before_daemon = !(log_flags & LOG_FLAG_DAEMON_READY);
> > > >
> > > > As in 2/6 would just a global bool be simpler than flags.
> > > >
> > > > > bool early_print = !(log_flags & LOG_FLAG_CONF_PARSED);
> > > > > struct timespec tp;
> > > > >
> > > > > @@ -71,7 +72,8 @@ void vlogmsg(int pri, const char *format, va_list ap)
> > > > > va_end(ap2);
> > > > > }
> > > > >
> > > > > - if (debug_print || (early_print && !(log_opt & LOG_PERROR))) {
> > > > > + if (debug_print || early_print ||
> > > > > + (before_daemon && (log_mask & LOG_MASK(LOG_PRI(pri))))) {
> > > > > (void)vfprintf(stderr, format, ap);
> > > > > if (format[strlen(format)] != '\n')
> > > > > fprintf(stderr, "\n");
> > > > > diff --git a/log.h b/log.h
> > > > > index 6a3224a..680baab 100644
> > > > > --- a/log.h
> > > > > +++ b/log.h
> > > > > @@ -10,6 +10,7 @@
> > > > > #include <syslog.h>
> > > > >
> > > > > #define LOG_FLAG_CONF_PARSED BIT(0) /* We already parsed logging options */
> > > > > +#define LOG_FLAG_DAEMON_READY BIT(1) /* Daemonised, or ready in foreground */
> > > > >
> > > > > #define LOGFILE_SIZE_DEFAULT (1024 * 1024UL)
> > > > > #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> > > > > diff --git a/passt.1 b/passt.1
> > > > > index 3a23a43..31e528e 100644
> > > > > --- a/passt.1
> > > > > +++ b/passt.1
> > > > > @@ -99,7 +99,8 @@ 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.
> > > > > +Log to file \fIPATH\fR, not to standard error (once initialisation is complete),
> > > > > +and not to the system logger.
> > > >
> > > > IIUC when -l is set we'll log to the logfile _as well as_ stderr
> > > > before we daemonize. The description above doesn't exactly contradict
> > > > that, but seems to imply something different.
> > >
> > > Is that because "(once initialisation is complete)" doesn't clearly
> > > refer to "not to standard error"?
> >
> > Yes, or rather that it's not entirely clear it refers *only* to that
> > clause and not to the "Log to file" part at the beginning.
> >
> > > I could go with something slightly more verbose:
> > >
> > > Log to file \fIPATH\fR, not to standard error, and not to the system
> > > logger.
> > >
> > > During initialisation phase, that is, before forking to background,
> > > or before being ready for communication when running in foreground,
> > > messages are always printed to standard error as well.
> >
> > Hrm... so I want to say:
> >
> > Log to file PATH instead of to system logger.
> >
> > Which may not be totally accurate for the current behaviour... but
> > seems like it might be a sensible behaviour. That is, we typically
> > log to syslog, but -l replaces it with a logfile. Regardless of
> > which, under some circumstances we'll also log to stderr.
>
> No, not really: it's not regardless of that. If the log file is given,
> we don't want to log to standard error (once we're up and running)
But... why?
--
David Gibson (he or they) | 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] 27+ messages in thread
* Re: [PATCH 4/6] log: Add _perror() logging function variants
2024-06-19 8:25 ` Stefano Brivio
@ 2024-06-20 0:13 ` David Gibson
0 siblings, 0 replies; 27+ messages in thread
From: David Gibson @ 2024-06-20 0:13 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev, Yalan Zhang
[-- Attachment #1: Type: text/plain, Size: 2533 bytes --]
On Wed, Jun 19, 2024 at 10:25:17AM +0200, Stefano Brivio wrote:
> On Wed, 19 Jun 2024 12:11:51 +1000
> David Gibson <david@gibson.dropbear.id.au> wrote:
>
> > On Tue, Jun 18, 2024 at 08:02:16AM +0200, Stefano Brivio wrote:
> > > On Tue, 18 Jun 2024 10:46:36 +1000
> > > David Gibson <david@gibson.dropbear.id.au> wrote:
> > >
> > > > On Mon, Jun 17, 2024 at 02:03:17PM +0200, Stefano Brivio wrote:
> > > > > In many places, we have direct perror() calls, which completely bypass
> > > > > logging functions and log files.
> > > > >
> > > > > They are definitely convenient: offer similar convenience with
> > > > > _perror() logging variants, so that we can drop those direct perror()
> > > > > calls.
> > > > >
> > > > > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > > >
> > > > Hm, for anything bigger than like a screenful of code, I generally
> > > > find an explicit message with strerror(errno) more useful than
> > > > perror() or equivalents, but I guess if you think these are useful.
> > >
> > > Okay, yes, it probably makes sense to have more descriptive messages as
> > > you suggest in the comment to 5/6, but even then, we still have a lot
> > > of cases like this one (from 6/6):
> > >
> > > - warn("lseek() failed on /proc/net file: %s", strerror(errno));
> > > + warn_perror("lseek() failed on /proc/net file");
> > >
> > > where these _perror() variants make for tidier code, I find, regardless
> > > of the error message itself.
> >
> > Eh, I mildly prefer the first variant. It is slightly longer, but
> > makes it very clear where the strerror piece is going to appear in the
> > context of the whole message. It's not a strong preference, though.
>
> Well, it depends. If you're used to perror() it's obvious where the
> error description will appear, and it's actually faster for me to read
> something called "_perror" than %s plus the argument. Plus we can save
> a few lines like that and substantially improve readability in some
> cases:
>
> if (prctl(PR_CAPBSET_DROP, i, 0, 0, 0) &&
> errno != EINVAL && errno != EPERM)
> - die("Couldn't drop cap %i from bounding set: %s",
> - i, strerror(errno));
> + die_perror("Couldn't drop cap %i from bounding set", i);
Eh, ok. You more or less convinced me.
--
David Gibson (he or they) | 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] 27+ messages in thread
end of thread, other threads:[~2024-06-20 0:13 UTC | newest]
Thread overview: 27+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-06-17 12:03 [PATCH 0/6] Fixes for early logging/prints and related cleanups Stefano Brivio
2024-06-17 12:03 ` [PATCH 1/6] conf, passt: Don't try to log to stderr after we close it Stefano Brivio
2024-06-18 0:36 ` David Gibson
2024-06-18 6:00 ` Stefano Brivio
2024-06-19 2:06 ` David Gibson
2024-06-19 8:13 ` Stefano Brivio
2024-06-20 0:12 ` David Gibson
2024-06-17 12:03 ` [PATCH 2/6] conf, log: Introduce internal log flags, instead of abusing log levels Stefano Brivio
2024-06-18 0:39 ` David Gibson
2024-06-18 6:01 ` Stefano Brivio
2024-06-17 12:03 ` [PATCH 3/6] log, passt: Always print to stderr before initialisation is complete Stefano Brivio
2024-06-18 0:44 ` David Gibson
2024-06-18 6:01 ` Stefano Brivio
2024-06-19 2:10 ` David Gibson
2024-06-19 8:17 ` Stefano Brivio
2024-06-20 0:12 ` David Gibson
2024-06-17 12:03 ` [PATCH 4/6] log: Add _perror() logging function variants Stefano Brivio
2024-06-18 0:46 ` David Gibson
2024-06-18 6:02 ` Stefano Brivio
2024-06-19 2:11 ` David Gibson
2024-06-19 8:25 ` Stefano Brivio
2024-06-20 0:13 ` David Gibson
2024-06-17 12:03 ` [PATCH 5/6] treewide: Replace perror() calls with calls to logging functions Stefano Brivio
2024-06-18 0:50 ` David Gibson
2024-06-17 12:03 ` [PATCH 6/6] treewide: Replace strerror() calls Stefano Brivio
2024-06-18 0:51 ` David Gibson
2024-06-18 6:02 ` Stefano Brivio
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).