[MINOR] add a new CLF log format

Appending the "clf" word after "option httplog" turns the HTTP log
format into a CLF format, more suited for certain tools.
This commit is contained in:
Emeric Brun 2009-06-30 18:26:00 +02:00 committed by Willy Tarreau
parent 647caf1ebc
commit 3a058f3091
5 changed files with 252 additions and 4 deletions

View File

@ -2345,11 +2345,16 @@ no option httpclose
See also : "option forceclose"
option httplog
option httplog [ clf ]
Enable logging of HTTP request, session state and timers
May be used in sections : defaults | frontend | listen | backend
yes | yes | yes | yes
Arguments : none
Arguments :
clf if the "clf" argument is added, then the output format will be
the CLF format instead of HAProxy's default HTTP format. You can
use this when you need to feed HAProxy's logs through a specific
log analyser which only support the CLF format and which is not
extensible.
By default, the log output format is very poor, as it only contains the
source and destination addresses, and the instance name. By specifying
@ -2361,6 +2366,11 @@ option httplog
This option may be set either in the frontend or the backend.
If this option has been enabled in a "defaults" section, it can be disabled
in a specific instance by prepending the "no" keyword before it. Specifying
only "option httplog" will automatically clear the 'clf' mode if it was set
by default.
See also : section 8 about logging.
@ -5224,7 +5234,7 @@ facilities.
8.2. Log formats
----------------
HAProxy supports 3 log formats. Several fields are common between these formats
HAProxy supports 4 log formats. Several fields are common between these formats
and will be detailed in the next sections. A few of them may slightly vary with
the configuration, due to indicators specific to certain options. The supported
formats are the following ones :
@ -5247,6 +5257,11 @@ formats are the following ones :
the request, the status code, and captures of headers and cookies. This
format is recommended for HTTP proxies.
- the CLF HTTP format, which is equivalent to the HTTP format, but with the
fields arranged in the same order as the CLF format. In this mode, all
timers, captures, flags, etc... appear one per field after the end of the
common fields, in the same order they appear in the standard HTTP format.
Next sections will go deeper into details for each of these formats. Format
specification will be performed on a "field" basis. Unless stated otherwise, a
field is a portion of text delimited by any number of spaces. Since syslog

View File

@ -286,6 +286,16 @@ static inline void get_localtime(const time_t now, struct tm *tm)
localtime_r(&now, tm);
}
/* This function converts the time_t value <now> into a broken out struct tm
* which must be allocated by the caller. It is highly recommended to use this
* function intead of gmtime() because that one requires a time_t* which
* is not always compatible with tv_sec depending on OS/hardware combinations.
*/
static inline void get_gmtime(const time_t now, struct tm *tm)
{
gmtime_r(&now, tm);
}
/* This function parses a time value optionally followed by a unit suffix among
* "d", "h", "m", "s", "ms" or "us". It converts the value into the unit
* expected by the caller. The computation does its best to avoid overflows.

View File

@ -120,6 +120,7 @@
#define PR_O2_SMARTACC 0x00000080 /* don't immediately ACK request after accept */
#define PR_O2_SMARTCON 0x00000100 /* don't immediately send empty ACK after connect */
#define PR_O2_RDPC_PRST 0x00000200 /* Actvate rdp cookie analyser */
#define PR_O2_CLFLOG 0x00000400 /* log into clf format */
/* This structure is used to apply fast weighted round robin on a server group */
struct fwrr_group {

View File

@ -1734,9 +1734,19 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm)
return -1;
}
if (!strcmp(args[1], "httplog"))
if (!strcmp(args[1], "httplog")) {
/* generate a complete HTTP log */
curproxy->options2 &= ~PR_O2_CLFLOG;
curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_REQ | LW_PXID | LW_RESP | LW_BYTES;
if (*(args[2]) != '\0') {
if (!strcmp(args[2], "clf")) {
curproxy->options2 |= PR_O2_CLFLOG;
} else {
Alert("parsing [%s:%d] : keyword '%s' only supports option 'clf'.\n", file, linenum, args[2]);
return -1;
}
}
}
else if (!strcmp(args[1], "tcplog"))
/* generate a detailed TCP log */
curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_PXID | LW_BYTES;

View File

@ -726,6 +726,215 @@ const char sess_set_cookie[8] = "N1I3PD5R"; /* No set-cookie, unknown, Set-Cooki
struct pool_head *pool2_requri;
struct pool_head *pool2_capture;
void http_sess_clflog(struct session *s)
{
char pn[INET6_ADDRSTRLEN + strlen(":65535")];
struct proxy *fe = s->fe;
struct proxy *be = s->be;
struct proxy *prx_log;
struct http_txn *txn = &s->txn;
int tolog, level, err;
char *uri, *h;
char *svid;
struct tm tm;
static char tmpline[MAX_SYSLOG_LEN];
int hdr;
size_t w;
int t_request;
prx_log = fe;
err = (s->flags & (SN_ERR_MASK | SN_REDISP)) ||
(s->conn_retries != be->conn_retries) ||
txn->status >= 500;
if (s->cli_addr.ss_family == AF_INET)
inet_ntop(AF_INET,
(const void *)&((struct sockaddr_in *)&s->cli_addr)->sin_addr,
pn, sizeof(pn));
else
inet_ntop(AF_INET6,
(const void *)&((struct sockaddr_in6 *)(&s->cli_addr))->sin6_addr,
pn, sizeof(pn));
get_gmtime(s->logs.accept_date.tv_sec, &tm);
/* FIXME: let's limit ourselves to frontend logging for now. */
tolog = fe->to_log;
h = tmpline;
w = snprintf(h, sizeof(tmpline),
"%s - - [%02d/%s/%04d:%02d:%02d:%02d +0000]",
pn,
tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900,
tm.tm_hour, tm.tm_min, tm.tm_sec);
if (w < 0 || w >= sizeof(tmpline) - (h - tmpline))
goto trunc;
h += w;
if (h >= tmpline + sizeof(tmpline) - 4)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
uri = txn->uri ? txn->uri : "<BADREQ>";
h = encode_string(h, tmpline + sizeof(tmpline) - 1,
'#', url_encode_map, uri);
*(h++) = '\"';
w = snprintf(h, sizeof(tmpline) - (h - tmpline), " %d %lld", txn->status, s->logs.bytes_out);
if (w < 0 || w >= sizeof(tmpline) - (h - tmpline))
goto trunc;
h += w;
if (h >= tmpline + sizeof(tmpline) - 9)
goto trunc;
memcpy(h, " \"-\" \"-\"", 8);
h += 8;
w = snprintf(h, sizeof(tmpline) - (h - tmpline),
" %d %03d",
(s->cli_addr.ss_family == AF_INET) ?
ntohs(((struct sockaddr_in *)&s->cli_addr)->sin_port) :
ntohs(((struct sockaddr_in6 *)&s->cli_addr)->sin6_port),
(int)s->logs.accept_date.tv_usec/1000);
if (w < 0 || w >= sizeof(tmpline) - (h - tmpline))
goto trunc;
h += w;
w = strlen(fe->id);
if (h >= tmpline + sizeof(tmpline) - 4 - w)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
memcpy(h, fe->id, w);
h += w;
*(h++) = '\"';
w = strlen(be->id);
if (h >= tmpline + sizeof(tmpline) - 4 - w)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
memcpy(h, be->id, w);
h += w;
*(h++) = '\"';
svid = (tolog & LW_SVID) ?
(s->data_source != DATA_SRC_STATS) ?
(s->srv != NULL) ? s->srv->id : "<NOSRV>" : "<STATS>" : "-";
w = strlen(svid);
if (h >= tmpline + sizeof(tmpline) - 4 - w)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
memcpy(h, svid, w);
h += w;
*(h++) = '\"';
t_request = -1;
if (tv_isge(&s->logs.tv_request, &s->logs.tv_accept))
t_request = tv_ms_elapsed(&s->logs.tv_accept, &s->logs.tv_request);
w = snprintf(h, sizeof(tmpline) - (h - tmpline),
" %d %ld %ld %ld %ld",
t_request,
(s->logs.t_queue >= 0) ? s->logs.t_queue - t_request : -1,
(s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1,
(s->logs.t_data >= 0) ? s->logs.t_data - s->logs.t_connect : -1,
s->logs.t_close);
if (w < 0 || w >= sizeof(tmpline) - (h - tmpline))
goto trunc;
h += w;
if (h >= tmpline + sizeof(tmpline) - 8)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
*(h++) = sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT];
*(h++) = sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT];
*(h++) = (be->options & PR_O_COOK_ANY) ? sess_cookie[(txn->flags & TX_CK_MASK) >> TX_CK_SHIFT] : '-',
*(h++) = (be->options & PR_O_COOK_ANY) ? sess_set_cookie[(txn->flags & TX_SCK_MASK) >> TX_SCK_SHIFT] : '-';
*(h++) = '\"';
w = snprintf(h, sizeof(tmpline) - (h - tmpline),
" %d %d %d %d %d %ld %ld",
actconn, fe->feconn, be->beconn, s->srv ? s->srv->cur_sess : 0,
(s->conn_retries > 0) ? (be->conn_retries - s->conn_retries) : be->conn_retries,
s->logs.srv_queue_size, s->logs.prx_queue_size);
if (w < 0 || w >= sizeof(tmpline) - (h - tmpline))
goto trunc;
h += w;
if (txn->cli_cookie) {
w = strlen(txn->cli_cookie);
if (h >= tmpline + sizeof(tmpline) - 4 - w)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
memcpy(h, txn->cli_cookie, w);
h += w;
*(h++) = '\"';
} else {
if (h >= tmpline + sizeof(tmpline) - 5)
goto trunc;
memcpy(h, " \"-\"", 4);
h += 4;
}
if (txn->srv_cookie) {
w = strlen(txn->srv_cookie);
if (h >= tmpline + sizeof(tmpline) - 4 - w)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
memcpy(h, txn->srv_cookie, w);
h += w;
*(h++) = '\"';
} else {
if (h >= tmpline + sizeof(tmpline) - 5)
goto trunc;
memcpy(h, " \"-\"", 4);
h += 4;
}
if ((fe->to_log & LW_REQHDR) && txn->req.cap) {
for (hdr = 0; hdr < fe->nb_req_cap; hdr++) {
if (h >= sizeof (tmpline) + tmpline - 4)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
h = encode_string(h, tmpline + sizeof(tmpline) - 2,
'#', hdr_encode_map, txn->req.cap[hdr]);
*(h++) = '\"';
}
}
if ((fe->to_log & LW_RSPHDR) && txn->rsp.cap) {
for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) {
if (h >= sizeof (tmpline) + tmpline - 4)
goto trunc;
*(h++) = ' ';
*(h++) = '\"';
h = encode_string(h, tmpline + sizeof(tmpline) - 2,
'#', hdr_encode_map, txn->rsp.cap[hdr]);
*(h++) = '\"';
}
}
trunc:
*h = '\0';
level = LOG_INFO;
if (err && (fe->options2 & PR_O2_LOGERRORS))
level = LOG_ERR;
send_log(prx_log, level, "%s\n", tmpline);
s->logs.logwait = 0;
}
/*
* send a log for the session when we have enough info about it.
* Will not log if the frontend has no log defined.
@ -756,6 +965,9 @@ void http_sess_log(struct session *s)
return;
prx_log = fe;
if (prx_log->options2 & PR_O2_CLFLOG)
return http_sess_clflog(s);
if (s->cli_addr.ss_family == AF_INET)
inet_ntop(AF_INET,
(const void *)&((struct sockaddr_in *)&s->cli_addr)->sin_addr,