BUG/MINOR: log: make log-format, unique-id-format and add-header more independant

It happens that all of them call parse_logformat_line() which sets
proxy->to_log with a number of flags affecting the line format for
all three users. For example, having a unique-id specified disables
the default log-format since fe->to_log is tested when the session
is established.

Similarly, having "option logasap" will cause "+" to be inserted in
unique-id or headers referencing some of the fields depending on
LW_BYTES.

This patch first removes most of the dependency on fe->to_log whenever
possible. The first possible cleanup is to stop checking fe->to_log
for being null, considering that it always contains at least LW_INIT
when any such usage is made of the log-format!

Also, some checks are wrong. s->logs.logwait cannot be nulled by
"logwait &= ~LW_*" since LW_INIT is always there. This results in
getting the wrong log at the end of a request or session when a
unique-id or add-header is set, because logwait is still not null
but the log-format is not checked.

Further cleanups are required. Most LW_* flags should be removed or at
least replaced with what they really mean (eg: depend on client-side
connection, depend on server-side connection, etc...) and this should
only affect logging, not other mechanisms.

This patch fixes the default log-format and tries to limit interferences
between the log formats, but does not pretend to do more for the moment,
since it's the most visible breakage.
This commit is contained in:
Willy Tarreau 2012-12-28 09:40:16 +01:00
parent cbc743e36c
commit d79a3b248e
6 changed files with 33 additions and 39 deletions

View File

@ -127,8 +127,12 @@ struct logformat_node {
#define LOG_OPT_RES_CAP 0x00000010
/* fields that need to be logged. They appear as flags in session->logs.logwait */
#define LW_INIT 1 /* date */
/* Fields that need to be extracted from the incoming connection or request for
* logging or for sending specific header information. They're set in px->to_log
* and appear as flags in session->logs.logwait, which are removed once the
* required information has been collected.
*/
#define LW_INIT 1 /* anything */
#define LW_CLIP 2 /* CLient IP */
#define LW_SVIP 4 /* SerVer IP */
#define LW_SVID 8 /* server ID */

View File

@ -6667,7 +6667,7 @@ int check_config_validity()
curproxy->to_log &= ~LW_BYTES;
if ((curproxy->mode == PR_MODE_TCP || curproxy->mode == PR_MODE_HTTP) &&
(curproxy->cap & PR_CAP_FE) && curproxy->to_log && LIST_ISEMPTY(&curproxy->logsrvs)) {
(curproxy->cap & PR_CAP_FE) && !LIST_ISEMPTY(&curproxy->logformat) && LIST_ISEMPTY(&curproxy->logsrvs)) {
Warning("config : log format ignored for %s '%s' since it has no log address.\n",
proxy_type_str(curproxy), curproxy->id);
err_code |= ERR_WARN;

View File

@ -130,10 +130,10 @@ int frontend_accept(struct session *s)
if ((s->fe->mode == PR_MODE_TCP || s->fe->mode == PR_MODE_HTTP)
&& (!LIST_ISEMPTY(&s->fe->logsrvs))) {
if (likely(s->fe->to_log)) {
if (likely(!LIST_ISEMPTY(&s->fe->logformat))) {
/* we have the client ip */
if (s->logs.logwait & LW_CLIP)
if (!(s->logs.logwait &= ~LW_CLIP))
if (!(s->logs.logwait &= ~(LW_CLIP|LW_INIT)))
s->do_log(s);
}
else {

View File

@ -854,7 +854,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
struct proxy *fe = s->fe;
struct proxy *be = s->be;
struct http_txn *txn = &s->txn;
int tolog;
char *uri;
const char *svid;
struct tm tm;
@ -867,21 +866,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
struct logformat_node *tmp;
/* FIXME: let's limit ourselves to frontend logging for now. */
tolog = fe->to_log;
if (!(tolog & LW_SVID))
svid = "-";
else switch (obj_type(s->target)) {
case OBJ_TYPE_SERVER:
svid = objt_server(s->target)->id;
break;
case OBJ_TYPE_APPLET:
svid = objt_applet(s->target)->name;
break;
default:
svid = "<NOSRV>";
break;
}
t_request = -1;
if (tv_isge(&s->logs.tv_request, &s->logs.tv_accept))
@ -1133,7 +1117,17 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
break;
case LOG_FMT_SERVER: // %s
src = (char *)svid;
switch (obj_type(s->target)) {
case OBJ_TYPE_SERVER:
src = objt_server(s->target)->id;
break;
case OBJ_TYPE_APPLET:
src = objt_applet(s->target)->name;
break;
default:
src = "<NOSRV>";
break;
}
ret = lf_text(tmplog, src, dst + maxsize - tmplog, tmp);
if (ret == NULL)
goto out;
@ -1177,7 +1171,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
break;
case LOG_FMT_TT: // %Tt
if (!(tolog & LW_BYTES))
if (!(fe->to_log & LW_BYTES))
LOGCHAR('+');
ret = ltoa_o(s->logs.t_close, tmplog, dst + maxsize - tmplog);
if (ret == NULL)
@ -1195,7 +1189,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
break;
case LOG_FMT_BYTES: // %B
if (!(tolog & LW_BYTES))
if (!(fe->to_log & LW_BYTES))
LOGCHAR('+');
ret = lltoa(s->logs.bytes_out, tmplog, dst + maxsize - tmplog);
if (ret == NULL)
@ -1205,8 +1199,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
break;
case LOG_FMT_BYTES_UP: // %U
if (!(tolog & LW_BYTES))
LOGCHAR('+');
ret = lltoa(s->logs.bytes_in, tmplog, dst + maxsize - tmplog);
if (ret == NULL)
goto out;
@ -1311,7 +1303,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
case LOG_FMT_HDRREQUEST: // %hr
/* request header */
if (fe->to_log & LW_REQHDR && txn->req.cap) {
if (fe->nb_req_cap && txn->req.cap) {
if (tmp->options & LOG_OPT_QUOTE)
LOGCHAR('"');
LOGCHAR('{');
@ -1337,7 +1329,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
case LOG_FMT_HDRREQUESTLIST: // %hrl
/* request header list */
if (fe->to_log & LW_REQHDR && txn->req.cap) {
if (fe->nb_req_cap && txn->req.cap) {
for (hdr = 0; hdr < fe->nb_req_cap; hdr++) {
if (hdr > 0)
LOGCHAR(' ');
@ -1361,8 +1353,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
case LOG_FMT_HDRRESPONS: // %hs
/* response header */
if (fe->to_log & LW_RSPHDR &&
txn->rsp.cap) {
if (fe->nb_rsp_cap && txn->rsp.cap) {
if (tmp->options & LOG_OPT_QUOTE)
LOGCHAR('"');
LOGCHAR('{');
@ -1386,7 +1377,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis
case LOG_FMT_HDRRESPONSLIST: // %hsl
/* response header list */
if (fe->to_log & LW_RSPHDR && txn->rsp.cap) {
if (fe->nb_rsp_cap && txn->rsp.cap) {
for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) {
if (hdr > 0)
LOGCHAR(' ');

View File

@ -2545,16 +2545,15 @@ int http_wait_for_request(struct session *s, struct channel *req, int an_bit)
memcpy(txn->uri, req->buf->p, urilen);
txn->uri[urilen] = 0;
if (!(s->logs.logwait &= ~LW_REQ))
if (!(s->logs.logwait &= ~(LW_REQ|LW_INIT)))
s->do_log(s);
} else {
Alert("HTTP logging : out of memory.\n");
}
}
if (!LIST_ISEMPTY(&s->fe->format_unique_id)) {
s->unique_id = pool_alloc2(pool2_uniqueid);
}
if (!LIST_ISEMPTY(&s->fe->format_unique_id))
s->unique_id = pool_alloc2(pool2_uniqueid);
/* 4. We may have to convert HTTP/0.9 requests to HTTP/1.0 */
if (unlikely(msg->sl.rq.v_l == 0) && !http_upgrade_v09_to_v10(txn))
@ -4165,7 +4164,7 @@ void http_end_txn_clean_session(struct session *s)
s->logs.bytes_out -= s->rep->buf->i;
/* let's do a final log if we need it */
if (s->logs.logwait &&
if (!LIST_ISEMPTY(&s->fe->logformat) && s->logs.logwait &&
!(s->flags & SN_MONITOR) &&
(!(s->fe->options & PR_O_NULLNOLOG) || s->req->total)) {
s->do_log(s);
@ -5668,7 +5667,7 @@ int http_process_res_common(struct session *t, struct channel *rep, int an_bit,
* bytes from the server, then this is the right moment. We have
* to temporarily assign bytes_out to log what we currently have.
*/
if (t->fe->to_log && !(t->logs.logwait & LW_BYTES)) {
if (!LIST_ISEMPTY(&t->fe->logformat) && !(t->logs.logwait & LW_BYTES)) {
t->logs.t_close = t->logs.t_data; /* to get a valid end date */
t->logs.bytes_out = txn->rsp.eoh;
t->do_log(t);

View File

@ -944,7 +944,7 @@ static void sess_establish(struct session *s, struct stream_interface *si)
if (s->be->mode == PR_MODE_TCP) { /* let's allow immediate data connection in this case */
/* if the user wants to log as soon as possible, without counting
* bytes from the server, then this is the right moment. */
if (s->fe->to_log && !(s->logs.logwait & LW_BYTES)) {
if (!LIST_ISEMPTY(&s->fe->logformat) && !(s->logs.logwait & LW_BYTES)) {
s->logs.t_close = s->logs.t_connect; /* to get a valid end date */
s->do_log(s);
}
@ -2472,7 +2472,7 @@ struct task *process_session(struct task *t)
}
/* let's do a final log if we need it */
if (s->logs.logwait &&
if (!LIST_ISEMPTY(&s->fe->logformat) && s->logs.logwait &&
!(s->flags & SN_MONITOR) &&
(!(s->fe->options & PR_O_NULLNOLOG) || s->req->total)) {
s->do_log(s);