From: Willy Tarreau <w@1wt.eu>
Date: Mon, 3 Dec 2012 14:35:00 +0000 (+0100)
Subject: MEDIUM: connection: add minimal error reporting in logs for incomplete connections
X-Git-Tag: v1.5-dev15~34
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=0af2912fd1c5e72b1547bb841b6eb7c3fe14f659;p=thirdparty%2Fhaproxy.git

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.
---

diff --git a/include/proto/connection.h b/include/proto/connection.h
index 35b6312bd5..741e88ec64 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 6f8a59f2db..6b6ddab244 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 f7c802b8dd..12f7f581e5 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);