From 0af2912fd1c5e72b1547bb841b6eb7c3fe14f659 Mon Sep 17 00:00:00 2001
From: Willy Tarreau <w@1wt.eu>
Date: Mon, 3 Dec 2012 15:35:00 +0100
Subject: [PATCH] MEDIUM: connection: add minimal error reporting in logs for
 incomplete connections

Since the introduction of SSL, it became quite annoying not to get any useful
info in logs about handshake failures. Let's improve reporting for embryonic
sessions by checking a per-connection error code and reporting it into the logs
if an error happens before the session is completely instanciated.

The "dontlognull" option is supported in that if a connection does not talk
before being aborted, nothing will be emitted.

At the moment, only timeouts are considered for SSL and the PROXY protocol,
but next patches will handle more errors.
---
 include/proto/connection.h | 13 +++++++++
 include/types/connection.h |  2 ++
 src/session.c              | 57 ++++++++++++++++++++++++++++++++++++++
 3 files changed, 72 insertions(+)

diff --git a/include/proto/connection.h b/include/proto/connection.h
index 35b6312bd..741e88ec6 100644
--- a/include/proto/connection.h
+++ b/include/proto/connection.h
@@ -462,6 +462,19 @@ static inline void conn_prepare(struct connection *conn, const struct data_cb *d
 	conn->xprt_ctx = NULL;
 }
 
+/* returns a human-readable error code for conn->err_code, or NULL if the code
+ * is unknown.
+ */
+static inline const char *conn_err_code_str(struct connection *c)
+{
+	switch (c->err_code) {
+	case CO_ER_NONE:          return "Success";
+	case CO_ER_PRX_TIMEOUT:   return "Timeout while waiting for PROXY protocol header";
+	case CO_ER_SSL_TIMEOUT:   return "Timeout during SSL handshake";
+	}
+	return NULL;
+}
+
 #endif /* _PROTO_CONNECTION_H */
 
 /*
diff --git a/include/types/connection.h b/include/types/connection.h
index 6f8a59f2d..6b6ddab24 100644
--- a/include/types/connection.h
+++ b/include/types/connection.h
@@ -146,6 +146,8 @@ enum {
 /* possible connection error codes */
 enum {
 	CO_ER_NONE,             /* no error */
+	CO_ER_PRX_TIMEOUT,      /* timeout while waiting for a PROXY header */
+	CO_ER_SSL_TIMEOUT,      /* timeout during SSL handshake */
 };
 
 /* xprt_ops describes transport-layer operations for a connection. They
diff --git a/src/session.c b/src/session.c
index f7c802b8d..12f7f581e 100644
--- a/src/session.c
+++ b/src/session.c
@@ -243,12 +243,69 @@ int session_accept(struct listener *l, int cfd, struct sockaddr_storage *addr)
 	return ret;
 }
 
+
+/* prepare the trash with a log prefix for session <s> */
+static void prepare_mini_sess_log_prefix(struct session *s)
+{
+	struct tm tm;
+	char pn[INET6_ADDRSTRLEN];
+	int ret;
+	char *end;
+
+	ret = addr_to_str(&s->si[0].conn->addr.from, pn, sizeof(pn));
+	if (ret <= 0)
+		chunk_printf(&trash, "unknown [");
+	else if (ret == AF_UNIX)
+		chunk_printf(&trash, "%s:%d [", pn, s->listener->luid);
+	else
+		chunk_printf(&trash, "%s:%d [", pn, get_host_port(&s->si[0].conn->addr.from));
+
+	get_localtime(s->logs.accept_date.tv_sec, &tm);
+	end = date2str_log(trash.str + trash.len, &tm, &(s->logs.accept_date), trash.size - trash.len);
+	trash.len = end - trash.str;
+	if (s->listener->name)
+		chunk_appendf(&trash, "] %s/%s", s->fe->id, s->listener->name);
+	else
+		chunk_appendf(&trash, "] %s/%d", s->fe->id, s->listener->luid);
+}
+
 /* This function kills an existing embryonic session. It stops the connection's
  * transport layer, releases assigned resources, resumes the listener if it was
  * disabled and finally kills the file descriptor.
  */
 static void kill_mini_session(struct session *s)
 {
+	int level = LOG_INFO;
+	struct connection *conn = s->si[0].conn;
+	unsigned int log = s->logs.logwait;
+	const char *err_msg;
+
+	if (s->fe->options2 & PR_O2_LOGERRORS)
+		level = LOG_ERR;
+
+	if (log && (s->fe->options & PR_O_NULLNOLOG)) {
+		/* with "option dontlognull", we don't log connections with no transfer */
+		if (!conn->err_code)
+			log = 0;
+	}
+
+	if (log) {
+		if (!conn->err_code && (s->task->state & TASK_WOKEN_TIMER)) {
+			if (conn->flags & CO_FL_ACCEPT_PROXY)
+				conn->err_code = CO_ER_PRX_TIMEOUT;
+			else if (conn->flags & CO_FL_SSL_WAIT_HS)
+				conn->err_code = CO_ER_SSL_TIMEOUT;
+		}
+
+		prepare_mini_sess_log_prefix(s);
+		err_msg = conn_err_code_str(conn);
+		if (err_msg)
+			send_log(s->fe, level, "%s: %s\n", trash.str, err_msg);
+		else
+			send_log(s->fe, level, "%s: unknown connection error (code=%d flags=%08x)\n",
+				 trash.str, conn->err_code, conn->flags);
+	}
+
 	/* kill the connection now */
 	conn_full_close(s->si[0].conn);