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]


Feel free also to comment on the current state of the mptcp patch there. The mptcp backend support still misses a piece to be working right. The frontend support is working fine for me already.

Björn

On 15.01.21 11:17, Willy Tarreau wrote:
Hi Björne,

On Tue, Jan 12, 2021 at 08:40:44PM +0100, Björn Jacke wrote:
Hello,

okay, the link to the MR patch landed on the list, so I assume I don't
need to attache it here again. Confusing, that the issues are tracked
there...

The issues are not tracked here, it's only the code reviews, discussions
and possible adaptations. While the issue tracker is quite convenient for
what we do with it, it's not the case for PRs and it's not possible to
disable them for a project (which is understandable as it's what made
the github user base grow, they wouldn't shoot themselves in the foot).
Their reviewing process is the worst I've ever seen, maximizing the effort
on the reviewer side, encouraging many projects to merge as-is, resulting
in terrible commits and fancy code everywhere :-(  Some other projects
like Nginx decided to simply close all PRs to address this limitation. At
least we are trying to be kind with contributors and review their work :-)

 From c6b3af58e977c2694108a0e665403ae53aa3ca09 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Bj=C3=B6rn=20Jacke?= <b...@sernet.de>
Date: Tue, 12 Jan 2021 19:24:43 +0100
Subject: [PATCH] proto_tcp.c: fix printing of muliple setsockopt errors

Signed-off-by: Bjoern Jacke <bja...@samba.org>

Please have a look at CONTRIBUTING. We use a moderately structured subject
line and we ask for a detailed description of what problem the patch tries
to address and how it was decided to address it (and if relevant why it's
believed to be the best solution in case alternatives were identified).

By principle, and in respect to Git's DCO, we never edit patches that are
signed-off, so I will not reword your message without your consent (and
I prefer to avoid anyway since it's pretty much time consuming).

---
  src/proto_tcp.c | 24 ++++++++++++++----------
  1 file changed, 14 insertions(+), 10 deletions(-)

diff --git a/src/proto_tcp.c b/src/proto_tcp.c
index 485603d57..5cae4e6e4 100644
--- a/src/proto_tcp.c
+++ b/src/proto_tcp.c
@@ -594,7 +594,7 @@ int tcp_bind_listener(struct listener *listener, char 
*errmsg, int errlen)
  {
        int fd, err;
        int ready;
-       char *msg = NULL;
+       struct buffer *msg = alloc_trash_chunk();
err = ERR_NONE; @@ -606,7 +606,7 @@ int tcp_bind_listener(struct listener *listener, char *errmsg, int errlen)
                return ERR_NONE; /* already bound */
if (!(listener->rx.flags & RX_F_BOUND)) {
-               msg = "receiving socket not bound";
+               chunk_appendf(msg, "\nreceiving socket not bound");
                goto tcp_return;

It will be quite confusing to see random messages printed at the beginning
of a line out of context. I just gave it a try to see, and it produces this:

   [WARNING] 014/104713 (5267) : Starting frontend recv:
   cannot set MSS
   cannot set TCP User Timeout
   cannot enable DEFER_ACCEPT
   cannot enable TCP_FASTOPEN
   f

Note the lone "f" on the last line which I suspect is the beginning of the
"for" message, making me think the recipient is too short, which is indeed
confirmed if I get one extra warning:

   [WARNING] 014/104930 (5376) : Starting frontend recv:
   receiving socket not bound
   cannot set MSS
   cannot set TCP User Timeout
   cannot enable DEFER_ACCEPT
   c

With less warnings it looks like this:

   [WARNING] 014/105355 (5479) : Starting frontend recv:
   receiving socket not bound
   cannot set MSS
   cannot enable TCP_FASTOPEN
   for [0.0.0.0:4445]


OK I found it, that's indeed the case, we're dedicating 100 bytes to the
output message since it was supposed to be a one-liner:

   src/listener.c:372:             char msg[100];
   src/listener.c:373:             int err;
   src/listener.c:374:
   src/listener.c:375:             err = l->rx.proto->listen(l, msg, 
sizeof(msg));

   src/protocol.c:66:      char msg[100];
   (...)
   src/protocol.c:99:                      lerr = proto->listen(listener, msg, 
sizeof(msg));


So these two should be significantly increased for multi-line messages
(go 1kB, that "should be enough for everyone" :-)).

Whenever we can, we try hard to indent error messages so that they appear
in context. I tried to do that at the end by calling indent_msg() (lacking
any error checking there, just a test):

        char pn[INET6_ADDRSTRLEN];
        char *msg2 = strdup(msg->area);

        indent_msg(&msg2, 2);

        addr_to_str(&listener->rx.addr, pn, sizeof(pn));
        snprintf(errmsg, errlen, "listener [%s:%d] encountered the following 
issues:%s", pn, get_host_port(&listener->rx.addr), msg2);
        free(msg2);

I changed the "\n" in the error messages to appear at the end of the line
instead, and it gave me the following:

   [WARNING] 014/110232 (6132) : Starting frontend recv: listener 
[0.0.0.0:4445] encountered the following issues:
     receiving socket not bound
     cannot set MSS
     cannot set TCP User Timeout
     cannot enable DEFER_ACCEPT
     cannot enable TCP_FASTOPEN

There is still the usual issue of mixing warning and error messages, but
in the worst case if at least one error appears, it will report all of
them as errors, which is less of a problem than what it currently is.

This makes me realize that since you've switched to chunk_appendf() we
don't even need this complex dance with indent_msg(), we can simplify
everything by prepending two spaces in front of each message and placing
the "\n" at the end. And in some cases it's even possible to output the
value that failed, to help the user locate it (e.g. "cannot set MSS to 1234").

        if (msg && errlen) {

Please add "&& msg->data" above so that we don't do this if no message was
emitted.

I definitely think that this would be a nice improvement over the current
situation.

If this can help you with the tests, here's what I've used in the config
to trigger all these warnings at once:

      bind :4445 proto h2 tfo mss 1234 tcp-ut 10s defer-accept

And I cheated by using a fake setsockopt() function which always returns
errors:

   diff --git a/src/proto_tcp.c b/src/proto_tcp.c
   index 485603d57..b525e7cec 100644
   --- a/src/proto_tcp.c
   +++ b/src/proto_tcp.c
   @@ -594,9 +594,11 @@ 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;
   +       chunk_appendf(msg, "receiving socket not bound\n");
/* ensure we never return garbage */

Could you try to experiment a bit more along these lines ? I think we're
very close to something mergeable already.

Thanks!
Willy



Reply via email to