[PATCH v2 16/22] tcp_splice: Improve error reporting on connect path

[David Gibson <david@gibson.dropbear.id.au>]

This makes a number of changes to improve error reporting while connecting
a new spliced socket:
 * We use flow_err() and similar functions so all messages include info
   on which specific flow was affected
 * We use strerror() to interpret raw error values
 * We now report errors on connection (at "trace" level, since this would
   allow spamming the logs)
 * We also look up and report some details on EPOLLERR events, which can
   include connection errors, since we use a non-blocking connect().  Again
   we use "trace" level since this can spam the logs.

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
---
 tcp_splice.c | 24 ++++++++++++++++++++----
 1 file changed, 20 insertions(+), 4 deletions(-)

diff --git a/tcp_splice.c b/tcp_splice.c
index 5ba9c8ea..49075e5c 100644
--- a/tcp_splice.c
+++ b/tcp_splice.c
@@ -349,8 +349,9 @@ static int tcp_splice_connect(const struct ctx *c, struct tcp_splice_conn *conn,
 		ASSERT(0);
 
 	if (conn->s[1] < 0) {
-		warn("Couldn't open connectable socket for splice (%d)",
-		     conn->s[1]);
+		flow_err(conn,
+			 "Couldn't open connectable socket for splice: %s",
+			 strerror(-conn->s[1]));
 		return conn->s[1];
 	}
 
@@ -369,8 +370,11 @@ static int tcp_splice_connect(const struct ctx *c, struct tcp_splice_conn *conn,
 	}
 
 	if (connect(conn->s[1], sa, sl)) {
-		if (errno != EINPROGRESS)
+		if (errno != EINPROGRESS) {
+			flow_trace(conn, "Couldn't connect socket for splice: %s",
+				   strerror(errno));
 			return -errno;
+		}
 		conn_event(c, conn, SPLICE_CONNECT);
 	} else {
 		conn_event(c, conn, SPLICE_ESTABLISHED);
@@ -457,8 +461,20 @@ void tcp_splice_sock_handler(struct ctx *c, union epoll_ref ref,
 	if (conn->events == SPLICE_CLOSED)
 		return;
 
-	if (events & EPOLLERR)
+	if (events & EPOLLERR) {
+		int err, rc;
+		socklen_t sl = sizeof(err);
+
+		rc = getsockopt(ref.fd, SOL_SOCKET, SO_ERROR, &err, &sl);
+		if (rc)
+			flow_err(conn, "Error retrieving SO_ERROR: %s",
+				 strerror(errno));
+		else
+			flow_trace(conn, "Error event on socket: %s",
+				   strerror(err));
+
 		goto close;
+	}
 
 	if (conn->events == SPLICE_CONNECT) {
 		if (!(events & EPOLLOUT))
-- 
@@ -349,8 +349,9 @@ static int tcp_splice_connect(const struct ctx *c, struct tcp_splice_conn *conn,
 		ASSERT(0);
 
 	if (conn->s[1] < 0) {
-		warn("Couldn't open connectable socket for splice (%d)",
-		     conn->s[1]);
+		flow_err(conn,
+			 "Couldn't open connectable socket for splice: %s",
+			 strerror(-conn->s[1]));
 		return conn->s[1];
 	}
 
@@ -369,8 +370,11 @@ static int tcp_splice_connect(const struct ctx *c, struct tcp_splice_conn *conn,
 	}
 
 	if (connect(conn->s[1], sa, sl)) {
-		if (errno != EINPROGRESS)
+		if (errno != EINPROGRESS) {
+			flow_trace(conn, "Couldn't connect socket for splice: %s",
+				   strerror(errno));
 			return -errno;
+		}
 		conn_event(c, conn, SPLICE_CONNECT);
 	} else {
 		conn_event(c, conn, SPLICE_ESTABLISHED);
@@ -457,8 +461,20 @@ void tcp_splice_sock_handler(struct ctx *c, union epoll_ref ref,
 	if (conn->events == SPLICE_CLOSED)
 		return;
 
-	if (events & EPOLLERR)
+	if (events & EPOLLERR) {
+		int err, rc;
+		socklen_t sl = sizeof(err);
+
+		rc = getsockopt(ref.fd, SOL_SOCKET, SO_ERROR, &err, &sl);
+		if (rc)
+			flow_err(conn, "Error retrieving SO_ERROR: %s",
+				 strerror(errno));
+		else
+			flow_trace(conn, "Error event on socket: %s",
+				   strerror(err));
+
 		goto close;
+	}
 
 	if (conn->events == SPLICE_CONNECT) {
 		if (!(events & EPOLLOUT))
-- 
2.43.0