penguin/tinyproxy

An L4 proxy designed to act as a tiny transparent shim

commit 9906c3d9a0739ed5c1acf3f15f2c5be809fd6c32

author斟酌 鵬兄 <tgckpg@gmail.com>
date2026-05-26T12:36:19Z
subjectBetter logging format
commit 9906c3d9a0739ed5c1acf3f15f2c5be809fd6c32
Author: 斟酌 鵬兄 <tgckpg@gmail.com>
Date:   2026-05-26T12:36:19Z

    Better logging format
---
 file_conf.c |  2 +-
 klog.c      | 87 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++---
 klog.h      | 84 +++++++++++++++++++++++++++++++++++++++++++++++++++++++---
 signal.c    |  6 ++---
 tcp_route.c | 19 +++++++-------
 tinyproxy.c | 20 +++++++-------
 6 files changed, 188 insertions(+), 30 deletions(-)

diff --git a/file_conf.c b/file_conf.c
index 5d86348..11d125c 100644
--- a/file_conf.c
+++ b/file_conf.c
@@ -195,7 +195,7 @@ int load_routes_from_file(const char *path, struct route **routes_out, size_t *c
 
 		struct route *r = &routes[count];
 		if (parse_route_line(line, r) != 0) {
-			LOG_ERROR("%s:%u: invalid route config", path, line_no);
+			LOG_ERROR("invalid route config", "path", _LOGV(path), "line", _LOGV(line_no));
 			fclose(fp);
 			free(routes);
 			return -EINVAL;
diff --git a/klog.c b/klog.c
index 451316a..cde9f21 100644
--- a/klog.c
+++ b/klog.c
@@ -5,7 +5,72 @@
 #include <time.h>
 #include <unistd.h>
 
-void log_at(char sev, const char *file, int line, const char *fmt, ...)
+static void print_quoted_value(const char *s)
+{
+	if (s == NULL) {
+		fputs("\"\"", stderr);
+		return;
+	}
+
+	fputc('"', stderr);
+
+	for (; *s != '\0'; s++) {
+		switch (*s) {
+		case '\\':
+			fputs("\\\\", stderr);
+			break;
+		case '"':
+			fputs("\\\"", stderr);
+			break;
+		case '\n':
+			fputs("\\n", stderr);
+			break;
+		case '\r':
+			fputs("\\r", stderr);
+			break;
+		case '\t':
+			fputs("\\t", stderr);
+			break;
+		default:
+			fputc(*s, stderr);
+			break;
+		}
+	}
+
+	fputc('"', stderr);
+}
+
+static void print_log_value(struct log_value value)
+{
+	switch (value.type) {
+	case LOG_VALUE_STR:
+		print_quoted_value(value.v.s);
+		break;
+	case LOG_VALUE_INT:
+		fprintf(stderr, "%d", value.v.i);
+		break;
+	case LOG_VALUE_UINT:
+		fprintf(stderr, "%u", value.v.u);
+		break;
+	case LOG_VALUE_LONG:
+		fprintf(stderr, "%ld", value.v.l);
+		break;
+	case LOG_VALUE_ULONG:
+		fprintf(stderr, "%lu", value.v.ul);
+		break;
+	case LOG_VALUE_LLONG:
+		fprintf(stderr, "%lld", value.v.ll);
+		break;
+	case LOG_VALUE_ULLONG:
+		fprintf(stderr, "%llu", value.v.ull);
+		break;
+	default:
+		fputs("<invalid>", stderr);
+		break;
+	}
+}
+
+void log_at(char sev, const char *file, int line, const char *msg, ...)
 {
 	struct timespec ts;
 	struct tm tm;
@@ -16,7 +81,7 @@ void log_at(char sev, const char *file, int line, const char *fmt, ...)
 
 	strftime(tbuf, sizeof(tbuf), "%m%d %H:%M:%S", &tm);
 
-	fprintf(stderr, "%c%s.%06ld %7ld %s:%d] ",
+	fprintf(stderr, "%c%s.%06ld %7ld %s:%d] msg=",
 		sev,
 		tbuf,
 		ts.tv_nsec / 1000,
@@ -24,9 +89,23 @@ void log_at(char sev, const char *file, int line, const char *fmt, ...)
 		file,
 		line);
 
+	print_quoted_value(msg);
+
 	va_list ap;
-	va_start(ap, fmt);
-	vfprintf(stderr, fmt, ap);
+	va_start(ap, msg);
+
+	for (;;) {
+		const char *key = va_arg(ap, const char *);
+		if (key == NULL) {
+			break;
+		}
+
+		struct log_value value = va_arg(ap, struct log_value);
+
+		fprintf(stderr, " %s=", key);
+		print_log_value(value);
+	}
+
 	va_end(ap);
 
 	fputc('\n', stderr);
diff --git a/klog.h b/klog.h
index b4c24b5..6a23f68 100644
--- a/klog.h
+++ b/klog.h
@@ -1,10 +1,86 @@
 #ifndef KLOG_H
 #define KLOG_H
 
-void log_at(char sev, const char *file, int line, const char *fmt, ...);
+#include <stdint.h>
 
-#define LOG_INFO(...)  log_at('I', __FILE__, __LINE__, __VA_ARGS__)
-#define LOG_WARN(...)  log_at('W', __FILE__, __LINE__, __VA_ARGS__)
-#define LOG_ERROR(...) log_at('E', __FILE__, __LINE__, __VA_ARGS__)
+enum log_value_type {
+	LOG_VALUE_STR = 1,
+	LOG_VALUE_INT,
+	LOG_VALUE_UINT,
+	LOG_VALUE_LONG,
+	LOG_VALUE_ULONG,
+	LOG_VALUE_LLONG,
+	LOG_VALUE_ULLONG,
+};
+
+struct log_value {
+	enum log_value_type type;
+	union {
+		const char *s;
+		int i;
+		unsigned int u;
+		long l;
+		unsigned long ul;
+		long long ll;
+		unsigned long long ull;
+	} v;
+};
+
+void log_at(char sev, const char *file, int line, const char *msg, ...);
+
+static inline struct log_value log_value_str(const char *v)
+{
+	return (struct log_value){ LOG_VALUE_STR, { .s = v } };
+}
+
+static inline struct log_value log_value_int(int v)
+{
+	return (struct log_value){ LOG_VALUE_INT, { .i = v } };
+}
+
+static inline struct log_value log_value_uint(unsigned int v)
+{
+	return (struct log_value){ LOG_VALUE_UINT, { .u = v } };
+}
+
+static inline struct log_value log_value_long(long v)
+{
+	return (struct log_value){ LOG_VALUE_LONG, { .l = v } };
+}
+
+static inline struct log_value log_value_ulong(unsigned long v)
+{
+	return (struct log_value){ LOG_VALUE_ULONG, { .ul = v } };
+}
+
+static inline struct log_value log_value_llong(long long v)
+{
+	return (struct log_value){ LOG_VALUE_LLONG, { .ll = v } };
+}
+
+static inline struct log_value log_value_ullong(unsigned long long v)
+{
+	return (struct log_value){ LOG_VALUE_ULLONG, { .ull = v } };
+}
+
+#define _LOGV(v) \
+	_Generic((v), \
+		char *: log_value_str, \
+		const char *: log_value_str, \
+		signed char: log_value_int, \
+		unsigned char: log_value_uint, \
+		short: log_value_int, \
+		unsigned short: log_value_uint, \
+		int: log_value_int, \
+		unsigned int: log_value_uint, \
+		long: log_value_long, \
+		unsigned long: log_value_ulong, \
+		long long: log_value_llong, \
+		unsigned long long: log_value_ullong \
+	)(v)
+
+#define LOG_INFO(msg, ...)  log_at('I', __FILE__, __LINE__, (msg), ##__VA_ARGS__, NULL)
+#define LOG_WARN(msg, ...)  log_at('W', __FILE__, __LINE__, (msg), ##__VA_ARGS__, NULL)
+#define LOG_ERROR(msg, ...) log_at('E', __FILE__, __LINE__, (msg), ##__VA_ARGS__, NULL)
 
 #endif
diff --git a/signal.c b/signal.c
index 2e23425..efb0fb6 100644
--- a/signal.c
+++ b/signal.c
@@ -13,13 +13,13 @@ static void signal_cb(evutil_socket_t sig, short events, void *arg)
 
 	switch (sig) {
 	case SIGINT:
-		LOG_INFO("received signal, shutting down", "signal", "SIGINT");
+		LOG_INFO("received signal, shutting down", "signal", _LOGV("SIGINT"));
 		break;
 	case SIGTERM:
-		LOG_INFO("received signal, shutting down", "signal", "SIGTERM");
+		LOG_INFO("received signal, shutting down", "signal", _LOGV("SIGTERM"));
 		break;
 	default:
-		LOG_INFO("received signal, shutting down", "signal", "unknown");
+		LOG_INFO("received signal, shutting down", "signal", _LOGV("unknown"));
 		break;
 	}
 
diff --git a/tcp_route.c b/tcp_route.c
index fcd5240..18c273e 100644
--- a/tcp_route.c
+++ b/tcp_route.c
@@ -65,7 +65,7 @@ static void event_cb(struct bufferevent *bev, short events, void *arg) {
 	if (events & (BEV_EVENT_EOF | BEV_EVENT_ERROR | BEV_EVENT_TIMEOUT)) {
 		if (events & BEV_EVENT_ERROR) {
 			int err = EVUTIL_SOCKET_ERROR();
-			LOG_ERROR("connection error: %s", evutil_socket_error_to_string(err));
+			LOG_ERROR("connection error", "msg", _LOGV(evutil_socket_error_to_string(err)));
 		}
 
 		free_conn(conn);
@@ -217,7 +217,7 @@ static void accept_error_cb(struct evconnlistener *listener, void *arg) {
 	struct event_base *base = arg;
 	int err = EVUTIL_SOCKET_ERROR();
 
-	LOG_ERROR("accept error: %s", evutil_socket_error_to_string(err));
+	LOG_ERROR("accept error", "msg", _LOGV(evutil_socket_error_to_string(err)));
 
 	evconnlistener_free(listener);
 	event_base_loopexit(base, NULL);
@@ -234,7 +234,7 @@ int start_tcp_route(
 	listen_addr.sin_port = htons(r->listen_port);
 
 	if (inet_pton(AF_INET, r->listen_host, &listen_addr.sin_addr) != 1) {
-		LOG_ERROR("invalid listen address: %s", r->listen_host);
+		LOG_ERROR("invalid listen address", "listen_host", _LOGV(r->listen_host));
 		return -EINVAL;
 	}
 
@@ -269,12 +269,13 @@ int start_tcp_route(
 
 	route_options_str(r, opts, sizeof(opts));
 
-	LOG_INFO("msg=\"route started\" line=%u listen_host=%s listen_port=%u upstream_host=%s upstream_port=%u%s%s",
-		r->line_no,
-		r->listen_host, r->listen_port,
-		r->upstream_host, r->upstream_port,
-		opts[0] ? " options=" : "",
-		opts[0] ? opts : ""
+	LOG_INFO("route started",
+		"line", _LOGV(r->line_no),
+		"listen_host", _LOGV(r->listen_host),
+		"listen_port", _LOGV(r->listen_port),
+		"upstream_host", _LOGV(r->upstream_host),
+		"upstream_port", _LOGV(r->upstream_port),
+		"options", _LOGV(opts[0] ? opts : "")
 	);
 
 	*out = ctx;
diff --git a/tinyproxy.c b/tinyproxy.c
index e831c5b..e52de95 100644
--- a/tinyproxy.c
+++ b/tinyproxy.c
@@ -53,7 +53,7 @@ int main(int argc, char **argv)
 	}
 
 	if (optind != argc) {
-		LOG_ERROR("unexpected argument: %s", argv[optind]);
+		LOG_ERROR("unexpected argument", "argv", _LOGV(argv[optind]));
 		usage(stderr, argv[0]);
 		return 2;
 	}
@@ -63,12 +63,12 @@ int main(int argc, char **argv)
 
 	int rc = load_routes_from_file(conf_path, &routes, &route_count);
 	if (rc != 0) {
-		LOG_ERROR("failed to load config %s: %s", conf_path, strerror(-rc));
+		LOG_ERROR("failed to load config", "path", conf_path, "msg", _LOGV(strerror(-rc)));
 		return 1;
 	}
 
 	if (route_count == 0) {
-		LOG_ERROR("config %s has no routes", conf_path);
+		LOG_ERROR("config has no routes", "path", _LOGV(conf_path));
 		free_routes(routes);
 		return 1;
 	}
@@ -118,16 +118,18 @@ int main(int argc, char **argv)
 			break;
 
 		default:
-			LOG_ERROR("route %zu has unknown protocol", i);
+			LOG_ERROR("route has unknown protocol", "line", _LOGV(r->line_no));
 			rc = -EINVAL;
 			break;
 		}
 
 		if (rc != 0) {
-			LOG_ERROR("msg=\"failed to start route\" line=%u listen_host=%s listen_port=%u upstream_host=%s upstream_port=%u",
-				r->line_no,
-				r->listen_host, r->listen_port,
-				r->upstream_host, r->upstream_port
+			LOG_ERROR("failed to start route",
+				"line", _LOGV(r->line_no),
+				"listen_host", _LOGV(r->listen_port),
+				"listen_port", _LOGV(r->listen_host),
+				"upstream_host", _LOGV(r->upstream_host),
+				"upstream_port", _LOGV(r->upstream_port)
 			);
 
 			for (size_t j = 0; j < tcp_ctx_count; j++) {
@@ -153,7 +155,7 @@ int main(int argc, char **argv)
 	free_routes(routes);
 
 	if (rc != 0) {
-		LOG_ERROR("event loop failed: %s", strerror(-rc));
+		LOG_ERROR("event loop failed", "msg", _LOGV(strerror(-rc)));
 		return 1;
 	}