Hi Björn,
On Mon, Oct 04, 2021 at 04:22:32PM +0200, Björn Jacke wrote:
> Hi Willy,
>
> I lost track of this issue but I caught this up finally again.
>
> I updated the setsockopt error patch as part of the mptcp branch here:
>
> https://gitlab.com/bjacke/haproxy/-/commits/bjacke-mptcp
>
> The output with failing setsockopt calls is now like this:
>
> [WARNING] (66986) : Starting frontend ft_mp:
> cannot set MSS
> cannot enable TCP_FASTOPEN
> for [:::2350]
> [WARNING] (66986) : Starting frontend ft_test:
> cannot set MSS
> for [:::235]
Thanks. To be honest I don't find this easy to read nor to understand.
Also I noticed that the change in protocol_bind_all() caused a socket
binding error to appear like this:
$ ./haproxy -db -f binderr.cfg
[NOTICE] (20118) : haproxy version is 2.5-dev8-e3e46b-117
[NOTICE] (20118) : path to executable is ./haproxy
[ALERT] (20118) : Starting proxy http:
cannot bind socket (Permission denied) [0.0.0.0:80]
[ALERT] (20118) : Starting proxy https:
cannot bind socket (Permission denied) [0.0.0.0:443]
[ALERT] (20118) : [./haproxy.main()] Some protocols failed to start their
listeners! Exiting.
I tried to fix it by forcing two spaces after the "\n" and that gave this:
$ ./haproxy -db -f binderr.cfg
[NOTICE] (20308) : haproxy version is 2.5-dev8-e3e46b-117
[NOTICE] (20308) : path to executable is ./haproxy
[ALERT] (20308) : Starting proxy http:
cannot bind socket (Permission denied) [0.0.0.0:80]
[ALERT] (20308) : Starting proxy https:
cannot bind socket (Permission denied) [0.0.0.0:443]
[ALERT] (20308) : [./haproxy.main()] Some protocols failed to start their
listeners! Exiting.
That I find much less clear than the original:
$ ./haproxy -db -f binderr.cfg
[NOTICE] (20213) : haproxy version is 2.5-dev8-e3e46b-117
[NOTICE] (20213) : path to executable is ./haproxy
[ALERT] (20213) : Starting proxy http: cannot bind socket (Permission
denied) [0.0.0.0:80]
[ALERT] (20213) : Starting proxy https: cannot bind socket (Permission
denied) [0.0.0.0:443]
[ALERT] (20213) : [./haproxy.main()] Some protocols failed to start their
listeners! Exiting.
I tried something with this config:
listen http
bind :1080 tcp-ut 10 mss 12 tfo defer-accept
I hacked setsockopt() to always fail. With your patch only I'm getting
this (I had to extend the string in protocol_bind_all since 100 would
truncate the output):
$ ./haproxy -db -f binderr.cfg
[NOTICE] (21241) : haproxy version is 2.5-dev8-31b9e1-118
[NOTICE] (21241) : path to executable is ./haproxy
[WARNING] (21241) : Starting proxy http:
cannot set MSS
cannot enable DEFER_ACCEPT
cannot set TCP User Timeout
cannot enable TCP_FASTOPEN
for [0.0.0.0:1080]
With some small changes instead I'm getting this which I personally
find more parsable and more greppable, and more importantly all errors
continue to be reported similarly:
$ ./haproxy -db -f binderr.cfg
[NOTICE] (20997) : haproxy version is 2.5-dev8-e3e46b-117
[NOTICE] (20997) : path to executable is ./haproxy
[WARNING] (20997) : Starting proxy http: [0.0.0.0:1080]: cannot set MSS,
cannot set TCP User Timeout, cannot enable DEFER_ACCEPT, cannot enable
TCP_FASTOPEN
There's another aspect to think about. With all the evolutions we're
currently bringing towards more dynamic changes, it's important that
we're able to easily report messages both on stderr and on the CLI for
changes that are pushed from there. As such we cannot presume of the
output formatting and in the end providing a single line with all the
relevant info, with multiple errors delimited by commas certainly is
way more versatile and future-proof.
I'm attaching the experimental patch I added on top of yours to produce
that output. Be careful, it contains the setsockopt() redefinition and
the resizing of the protocol_bind_all() buffer. Also I spotted a leftover
from an earlier "msg" that wasn't modified, I fixed it there.
Please let me know what you think, and if that's OK for you, feel free
to remerge it into yours.
Now switching to the second patch :-)
Thanks,
Willy
>From 9866bea00f11ab0091da752dc66e0d402244a298 Mon Sep 17 00:00:00 2001
From: Willy Tarreau <[email protected]>
Date: Thu, 7 Oct 2021 08:44:38 +0200
Subject: [PATCH] EXP with better formatting
---
src/proto_tcp.c | 22 +++++++++++-----------
src/protocol.c | 10 +++++-----
2 files changed, 16 insertions(+), 16 deletions(-)
diff --git a/src/proto_tcp.c b/src/proto_tcp.c
index 68f0ffc56..2bd3020bc 100644
--- a/src/proto_tcp.c
+++ b/src/proto_tcp.c
@@ -586,7 +586,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
int fd, err;
int ready;
struct buffer *msg = alloc_trash_chunk();
-
+inline int setsockopt(int fd, int ipproto, int opt, const void *foo, socklen_t
len) { return -1; }
err = ERR_NONE;
/* ensure we never return garbage */
@@ -597,7 +597,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
return ERR_NONE; /* already bound */
if (!(listener->rx.flags & RX_F_BOUND)) {
- chunk_appendf(msg, " receiving socket not bound\n");
+ chunk_appendf(msg, "%sreceiving socket not bound", msg->data ?
", " : "");
goto tcp_return;
}
@@ -621,7 +621,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
if (listener->maxseg > 0) {
if (setsockopt(fd, IPPROTO_TCP, TCP_MAXSEG,
&listener->maxseg, sizeof(listener->maxseg)) ==
-1) {
- chunk_appendf(msg, " cannot set MSS\n");
+ chunk_appendf(msg, "%scannot set MSS", msg->data ? ", "
: "");
err |= ERR_WARN;
}
} else {
@@ -639,7 +639,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
if (defaultmss > 0 &&
tmpmaxseg != defaultmss &&
setsockopt(fd, IPPROTO_TCP, TCP_MAXSEG, &defaultmss,
sizeof(defaultmss)) == -1) {
- chunk_appendf(msg, " cannot set MSS\n");
+ chunk_appendf(msg, "%scannot set MSS", msg->data ? ", "
: "");
err |= ERR_WARN;
}
}
@@ -648,7 +648,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
if (listener->tcp_ut) {
if (setsockopt(fd, IPPROTO_TCP, TCP_USER_TIMEOUT,
&listener->tcp_ut, sizeof(listener->tcp_ut)) ==
-1) {
- chunk_appendf(msg, " cannot set TCP User Timeout\n");
+ chunk_appendf(msg, "%scannot set TCP User Timeout",
msg->data ? ", " : "");
err |= ERR_WARN;
}
} else
@@ -660,7 +660,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
/* defer accept by up to one second */
int accept_delay = 1;
if (setsockopt(fd, IPPROTO_TCP, TCP_DEFER_ACCEPT,
&accept_delay, sizeof(accept_delay)) == -1) {
- chunk_appendf(msg, " cannot enable DEFER_ACCEPT\n");
+ chunk_appendf(msg, "%scannot enable DEFER_ACCEPT",
msg->data ? ", " : "");
err |= ERR_WARN;
}
} else
@@ -672,7 +672,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
/* TFO needs a queue length, let's use the configured backlog */
int qlen = listener_backlog(listener);
if (setsockopt(fd, IPPROTO_TCP, TCP_FASTOPEN, &qlen,
sizeof(qlen)) == -1) {
- chunk_appendf(msg, " cannot enable TCP_FASTOPEN\n");
+ chunk_appendf(msg, "%scannot enable TCP_FASTOPEN",
msg->data ? ", " : "");
err |= ERR_WARN;
}
} else {
@@ -686,7 +686,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
qlen != 0) {
if (setsockopt(fd, IPPROTO_TCP, TCP_FASTOPEN, &zero,
sizeof(zero)) == -1) {
- chunk_appendf(msg, " cannot disable
TCP_FASTOPEN\n");
+ chunk_appendf(msg, "%scannot disable
TCP_FASTOPEN", msg->data ? ", " : "");
err |= ERR_WARN;
}
}
@@ -698,7 +698,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
if (!ready && /* only listen if not already done by external process */
listen(fd, listener_backlog(listener)) == -1) {
err |= ERR_RETRYABLE | ERR_ALERT;
- chunk_appendf(msg, " cannot listen to socket\n");
+ chunk_appendf(msg, "%scannot listen to socket", msg->data ? ",
" : "");
goto tcp_close_return;
}
@@ -709,7 +709,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
memset(&accept, 0, sizeof(accept));
strcpy(accept.af_name, "dataready");
if (setsockopt(fd, SOL_SOCKET, SO_ACCEPTFILTER, &accept,
sizeof(accept)) == -1) {
- msg = "cannot enable ACCEPT_FILTER";
+ chunk_appendf(msg, "%scannot enable ACCEPT_FILTER",
msg->data ? ", " : "");
err |= ERR_WARN;
}
}
@@ -734,7 +734,7 @@ int tcp_bind_listener(struct listener *listener, char
*errmsg, int errlen)
char pn[INET6_ADDRSTRLEN];
addr_to_str(&listener->rx.addr, pn, sizeof(pn));
- snprintf(errmsg, errlen, "%s for [%s:%d]", msg->area, pn,
get_host_port(&listener->rx.addr));
+ snprintf(errmsg, errlen, "[%s:%d]: %s", pn,
get_host_port(&listener->rx.addr), msg->area);
}
free_trash_chunk(msg);
msg = NULL;
diff --git a/src/protocol.c b/src/protocol.c
index b1ca32fbf..ece2b5b8f 100644
--- a/src/protocol.c
+++ b/src/protocol.c
@@ -63,7 +63,7 @@ int protocol_bind_all(int verbose)
struct protocol *proto;
struct listener *listener;
struct receiver *receiver;
- char msg[100];
+ char msg[1000];
char *errmsg;
int err, lerr;
@@ -81,10 +81,10 @@ int protocol_bind_all(int verbose)
struct proxy *px =
listener->bind_conf->frontend;
if (lerr & ERR_ALERT)
- ha_alert("Starting %s %s:\n%s\n",
+ ha_alert("Starting %s %s: %s\n",
proxy_type_str(px), px->id,
errmsg);
else if (lerr & ERR_WARN)
- ha_warning("Starting %s %s:\n%s\n",
+ ha_warning("Starting %s %s: %s\n",
proxy_type_str(px), px->id,
errmsg);
ha_free(&errmsg);
}
@@ -103,10 +103,10 @@ int protocol_bind_all(int verbose)
struct proxy *px =
listener->bind_conf->frontend;
if (lerr & ERR_ALERT)
- ha_alert("Starting %s %s:\n%s\n",
+ ha_alert("Starting %s %s: %s\n",
proxy_type_str(px), px->id,
msg);
else if (lerr & ERR_WARN)
- ha_warning("Starting %s %s:\n%s\n",
+ ha_warning("Starting %s %s: %s\n",
proxy_type_str(px), px->id,
msg);
}
if (lerr & ERR_ABORT)
--
2.28.0
