mirrors/haproxy
1
0
Fork 0
mirror of https://git.haproxy.org/git/haproxy.git/ synced 2025-11-29 06:40:59 +01:00
Code Issues Projects Releases Wiki Activity

BUG/CRITICAL: log: fix risk of crash in development snapshot

Browse Source 
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.
This commit is contained in:
Willy Tarreau 2012-03-19 16:51:53 +01:00
parent 6580c06ba3
commit b1a2faf7c9
2 changed files with 22 additions and 21 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3
include/proto/log.h
View File

@ -88,9 +88,6 @@ void Warning(const char *fmt, ...)
void qfprintf(FILE *out, const char *fmt, ...) void qfprintf(FILE *out, const char *fmt, ...)
__attribute__ ((format(printf, 2, 3))); __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 * This function adds a header to the message and sends the syslog message
* using a printf format string * using a printf format string

40
src/log.c
View File

@ -106,6 +106,11 @@ char clf_http_log_format[] = "%{+Q}o %{-Q}Ci - - [%T] %r %st %B \"\" \"\" %Cp %m
char default_tcp_log_format[] = "%Ci:%Cp [%t] %f %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"; 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; 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 { struct logformat_var_args {
char *name; char *name;
int mask; int mask;
@ -515,21 +520,23 @@ char *logformat_write_string(char *dst, char *src, size_t size, struct logformat
return dst; return dst;
} }
/* generate the syslog header once a second */ /* Re-generate the syslog header at the beginning of logline once a second and
char *hdr_log(char *dst) * return the pointer to the first character after the header.
*/
static char *update_log_hdr()
{ {
int hdr_len = 0; static long tvsec;
static long tvsec = -1; /* to force the string to be initialized */ static char *dataptr = NULL; /* backup of last end of header, NULL first time */
static char *dataptr = NULL;
if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) { if (unlikely(date.tv_sec != tvsec || dataptr == NULL)) {
/* this string is rebuild only once a second */ /* this string is rebuild only once a second */
struct tm tm; struct tm tm;
int hdr_len;
tvsec = date.tv_sec; tvsec = date.tv_sec;
get_localtime(tvsec, &tm); 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]: ", "<<<<>%s %2d %02d:%02d:%02d %s%s[%d]: ",
monthname[tm.tm_mon], monthname[tm.tm_mon],
tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
@ -542,7 +549,7 @@ char *hdr_log(char *dst)
if (hdr_len < 0 || hdr_len > MAX_SYSLOG_LEN) if (hdr_len < 0 || hdr_len > MAX_SYSLOG_LEN)
hdr_len = MAX_SYSLOG_LEN; hdr_len = MAX_SYSLOG_LEN;
dataptr = dst + hdr_len; dataptr = logline + hdr_len;
} }
return dataptr; return dataptr;
@ -555,23 +562,22 @@ char *hdr_log(char *dst)
void send_log(struct proxy *p, int level, const char *format, ...) void send_log(struct proxy *p, int level, const char *format, ...)
{ {
va_list argp; va_list argp;
static char logmsg[MAX_SYSLOG_LEN]; char *dataptr;
static char *dataptr = NULL; int data_len;
int data_len = 0;
if (level < 0 || format == NULL) if (level < 0 || format == NULL)
return; return;
dataptr = hdr_log(logmsg); /* create header */ dataptr = update_log_hdr(); /* update log header and skip it */
data_len = dataptr - logmsg; data_len = dataptr - logline;
va_start(argp, format); 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) if (data_len < 0 || data_len > MAX_SYSLOG_LEN)
data_len = MAX_SYSLOG_LEN; data_len = MAX_SYSLOG_LEN;
va_end(argp); va_end(argp);
__send_log(p, level, logmsg, data_len); __send_log(p, level, logline, data_len);
} }
/* /*
@ -713,8 +719,7 @@ void sess_log(struct session *s)
int t_request; int t_request;
int hdr; int hdr;
int last_isspace = 1; int last_isspace = 1;
static char logline[MAX_SYSLOG_LEN] = { 0 }; char *tmplog;
static char *tmplog;
struct logformat_node *tmp; struct logformat_node *tmp;
/* if we don't want to log normal traffic, return now */ /* if we don't want to log normal traffic, return now */
@ -763,8 +768,7 @@ void sess_log(struct session *s)
/* fill logbuffer */ /* fill logbuffer */
tmplog = logline; tmplog = update_log_hdr(); /* update log header and skip it */
tmplog = hdr_log(tmplog);
list_for_each_entry(tmp, &fe->logformat, list) { list_for_each_entry(tmp, &fe->logformat, list) {
char *src = NULL; char *src = NULL;