BUG/CRITICAL: log: fix risk of crash in development snapshot
Commit a1cc38 introduced a regression which was easy to trigger till ad4cd58
(snapshots 20120222 to 20120311 included). The bug was still present after
that but harder to trigger.
The bug is caused by the use of two distinct log buffers due to intermediary
changes. The issue happens when an HTTP request is logged just after a TCP
request during the same second and the HTTP request is too large for the buffer.
In this case, it happens that the HTTP request is logged into the TCP buffer
instead and that length controls can't detect anything.
Starting with bddd4f, the issue is still possible when logging too large an
HTTP request just after a send_log() call (typically a server status change).
We owe a big thanks to Sander Klein for testing several snapshots and more
specifically for taking significant risks in production by letting the buggy
version crash several times in order to provide an exploitable core ! The bug
could not have been found without this precious help. Thank you Sander !
This fix does not need to be backported, it did not affect any released version.
diff --git a/include/proto/log.h b/include/proto/log.h
index 43c84be..0ee60a0 100644
--- a/include/proto/log.h
+++ b/include/proto/log.h
@@ -88,9 +88,6 @@
void qfprintf(FILE *out, const char *fmt, ...)
__attribute__ ((format(printf, 2, 3)));
-/* generate the syslog header one time per second */
-char *hdr_log(char *dst);
-
/*
* This function adds a header to the message and sends the syslog message
* using a printf format string
diff --git a/src/log.c b/src/log.c
index 4ef51e1..f095297 100644
--- a/src/log.c
+++ b/src/log.c
@@ -106,6 +106,11 @@
char default_tcp_log_format[] = "%Ci:%Cp [%t] %f %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq";
char *log_format = NULL;
+/* This is a global syslog line, common to all outgoing messages. It begins
+ * with the syslog tag and the date that are updated by update_log_hdr().
+ */
+static char logline[MAX_SYSLOG_LEN];
+
struct logformat_var_args {
char *name;
int mask;
@@ -515,21 +520,23 @@
return dst;
}
-/* generate the syslog header once a second */
-char *hdr_log(char *dst)
+/* Re-generate the syslog header at the beginning of logline once a second and
+ * return the pointer to the first character after the header.
+ */
+static char *update_log_hdr()
{
- int hdr_len = 0;
- static long tvsec = -1; /* to force the string to be initialized */
- static char *dataptr = NULL;
+ static long tvsec;
+ static char *dataptr = NULL; /* backup of last end of header, NULL first time */
if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
/* this string is rebuild only once a second */
struct tm tm;
+ int hdr_len;
tvsec = date.tv_sec;
get_localtime(tvsec, &tm);
- hdr_len = snprintf(dst, MAX_SYSLOG_LEN,
+ hdr_len = snprintf(logline, MAX_SYSLOG_LEN,
"<<<<>%s %2d %02d:%02d:%02d %s%s[%d]: ",
monthname[tm.tm_mon],
tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
@@ -542,7 +549,7 @@
if (hdr_len < 0 || hdr_len > MAX_SYSLOG_LEN)
hdr_len = MAX_SYSLOG_LEN;
- dataptr = dst + hdr_len;
+ dataptr = logline + hdr_len;
}
return dataptr;
@@ -555,23 +562,22 @@
void send_log(struct proxy *p, int level, const char *format, ...)
{
va_list argp;
- static char logmsg[MAX_SYSLOG_LEN];
- static char *dataptr = NULL;
- int data_len = 0;
+ char *dataptr;
+ int data_len;
if (level < 0 || format == NULL)
return;
- dataptr = hdr_log(logmsg); /* create header */
- data_len = dataptr - logmsg;
+ dataptr = update_log_hdr(); /* update log header and skip it */
+ data_len = dataptr - logline;
va_start(argp, format);
- data_len += vsnprintf(dataptr, MAX_SYSLOG_LEN, format, argp);
+ data_len += vsnprintf(dataptr, logline + sizeof(logline) - dataptr, format, argp);
if (data_len < 0 || data_len > MAX_SYSLOG_LEN)
data_len = MAX_SYSLOG_LEN;
va_end(argp);
- __send_log(p, level, logmsg, data_len);
+ __send_log(p, level, logline, data_len);
}
/*
@@ -713,8 +719,7 @@
int t_request;
int hdr;
int last_isspace = 1;
- static char logline[MAX_SYSLOG_LEN] = { 0 };
- static char *tmplog;
+ char *tmplog;
struct logformat_node *tmp;
/* if we don't want to log normal traffic, return now */
@@ -763,8 +768,7 @@
/* fill logbuffer */
- tmplog = logline;
- tmplog = hdr_log(tmplog);
+ tmplog = update_log_hdr(); /* update log header and skip it */
list_for_each_entry(tmp, &fe->logformat, list) {
char *src = NULL;