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 35b6312bd55c5880153e560b572d213c607b3c21..741e88ec644cac8b2b68f36b9f46cda18ec50e2a 100644 (file)
--- 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 6f8a59f2dbda5a44ce965db6b5a99ff2a668b159..6b6ddab2449d013470a857cdd678fef51ba7a547 100644 (file)
--- 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 f7c802b8dd57ba07650a10e06dc87fa79eb23419..12f7f581e5c0844cdd953ff93417d8fa6ec23f93 100644 (file)
--- 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);